Debug of DB connection on call qualification

[joao.carlos]

Hi everybody,

I'm using GCE 1.0 and the feature of qualification of a call with a Visual IVR Resource Group.
The Visual IVR script asks for a PIN Code, and then makes two databases queries, to get name and VIP status of the cliente.

Based on the VIP status, i want to redirect the call to a specific segment.

I've created the Database Access Point, created the script (3 blocks - Digit Collection, Database Lookup and Database Lookup) and attach data in all of the blocks with each return (PIN_Code, NAME, VIP status).

Well, It does not work, and I don't know how to figure out what's the problem, because I don't know how to generate the logs os DATABASE CONNECTION for example.

Can anyone help ?

Thanks

[joao.carlos]

If anyone can help, i can see the logs on UniversalRoutingServer and the query is quite perfect (and tested with copy/paste direct on Database works), mas i still get

_I_I_006f021b0321c1e8 [09:04] ASSIGN: stratHeader(LOCAL) <- STRING: "#### - 006f021b0321c1e8 - IxnRouting - Qualifying - VisualIvrGroup - AutoAttendant - DBLookUp - "
_I_I_006f021b0321c1e8 [09:04] ASSIGN: sqlStatment(LOCAL) <- STRING: "Select RAMAL from CLIENTEMARCA where CPF=%CPF%;"
_I_I_006f021b0321c1e8 [09:04] ASSIGN: currentIndex(LOCAL) <- INTEGER: 1
_I_I_006f021b0321c1e8 [09:04] ASSIGN: previousIndex(LOCAL) <- INTEGER: 1
_I_I_006f021b0321c1e8 [09:04] ASSIGN: supervisedTransferIN(LOCAL) <- INTEGER: 2
_I_I_006f021b0321c1e8 [09:04] ASSIGN: DBErrorCode(LOCAL) <- STRING: "-1"
_I_I_006f021b0321c1e8 [07:3f] get data from cfglist(ChicagoSystem) item constants, key single-quote result: '
_I_I_006f021b0321c1e8 [09:04] ASSIGN: trimChar(LOCAL) <- STRING: "'"
_I_I_006f021b0321c1e8 [09:04] ASSIGN: mediaType(LOCAL) <- STRING: "voice"
_I_I_006f021b0321c1e8 [09:04] ASSIGN: index(LOCAL) <- INTEGER: 42
_I_I_006f021b0321c1e8 [09:04] ASSIGN: currentIndex(LOCAL) <- INTEGER: 42
_I_I_006f021b0321c1e8 [09:04] ASSIGN: index(LOCAL) <- INTEGER: 46
_I_I_006f021b0321c1e8 [09:04] ASSIGN: localResult(LOCAL) <- STRING: "%CPF%"
_I_I_006f021b0321c1e8 [09:04] ASSIGN: sqlValue(LOCAL) <- STRING: "84519355915"
_I_I_006f021b0321c1e8 [09:04] ASSIGN: sqlValue(LOCAL) <- STRING: "'84519355915'"
_I_I_006f021b0321c1e8 [09:04] ASSIGN: sqlStatment(LOCAL) <- STRING: "Select RAMAL from CLIENTEMARCA where CPF='84519355915';"
_I_I_006f021b0321c1e8 [09:04] ASSIGN: currentIndex(LOCAL) <- INTEGER: 55
_I_I_006f021b0321c1e8 [09:04] ASSIGN: index(LOCAL) <- INTEGER: 0
_I_I_006f021b0321c1e8 [09:04] ASSIGN: index(LOCAL) <- INTEGER: 7
_I_I_006f021b0321c1e8 [09:04] ASSIGN: sqlStatementStart(LOCAL) <- STRING: "Select"
_I_I_006f021b0321c1e8 [09:04] ASSIGN: sqlStatementStart(LOCAL) <- STRING: "SELECT"

09:04:17.194 Int 22000 #### - 006f021b0321c1e8 - IxnRouting - Qualifying - VisualIvrGroup - AutoAttendant - DBLookUp - SqlStatment : Select RAMAL from CLIENTEMARCA where CPF='84519355915'; calltype : 2

09:04:17.194 Int 22000 #### - 006f021b0321c1e8 - IxnRouting - Qualifying - VisualIvrGroup - AutoAttendant - DBLookUp - SqlStatementStart : SELECT.
09:04:17.216_I_I_006f021b0321c1e8 [07:38] HERE IS XDATA
_I_E_006f021b0321c1e8 [09:04] error in strategy: 0015 Closed server
_I_I_006f021b0321c1e8 [09:04] ASSIGN: DBResult(LOCAL) <- STRING: ""

09:04:17.216 Int 22000 #### - 006f021b0321c1e8 - IxnRouting - Qualifying - VisualIvrGroup - AutoAttendant - DBLookUp - DB result : () error : ( Closed server )
_I_I_006f021b0321c1e8 [09:04] ASSIGN: DBErrorCode(LOCAL) <- STRING: "15"

09:04:17.216 Int 22000 #### - 006f021b0321c1e8 - IxnRouting - Qualifying - VisualIvrGroup - AutoAttendant - DBLookUp - update of the DB_ERROR_CODE data
_I_I_006f021b0321c1e8 [09:04] ASSIGN: outError(LOCAL) <- INTEGER: -3

09:04:17.216 Int 22000 #### - 006f021b0321c1e8 - IxnRouting - Qualifying - VisualIvrGroup - AutoAttendant - DBLookUp - DB result bad script or unkown request error : 15
request to 65200(TServerA4400) message RequestUpdateUserData
AttributeReferenceID 3789
AttributeUserData [32] 00 02 00 00..
'RAMAL' ''
'DB_ERROR_CODE' '15'
AttributeConnID 006f021b0321c1e8
AttributeThisDN '09970100'
..sent to gce-rq:3100(fd=572)

[joao.carlos]

Tried with Oracle and MSSQL Server.

same thing!

[cavagnaro]

Can you post DBServer logs?

[joao.carlos]

Hi cavagnaro, Thanks for your reply.

See the DBServers logs:

VisualCCDBServer:

15:18:26.792 Std 04523 Connection to client 'App (UniversalRoutingServer,GCE-RQ,0)' closed, reason ''client disconnected''
15:18:26.884 Std 05023 Process 'dbclient_msql' stopped
15:18:36.793 Trc 04521 New client 65377 connected from '10.100.129.185'
15:18:36.796 Std 05022 Process 'dbclient_msql' started
15:18:36.858 Trc 04521 New client 65379 connected from '10.100.129.185'
15:18:52.409 Std 04523 Connection to client 'App (UniversalRoutingServer,GCE-RQ,0)' closed, reason ''client disconnected''
15:18:52.448 Std 05023 Process 'dbclient_msql' stopped
15:19:02.409 Trc 04521 New client 65409 connected from '10.100.129.185'
15:19:02.411 Std 05022 Process 'dbclient_msql' started
15:19:02.474 Trc 04521 New client 65412 connected from '10.100.129.185'
15:19:19.130 Std 05023 Process 'dbclient_msql' stopped
15:19:29.024 Trc 04521 New client 65445 connected from '10.100.129.185'
15:19:29.027 Std 05022 Process 'dbclient_msql' started
15:19:29.090 Trc 04521 New client 65447 connected from '10.100.129.185'
15:19:44.631 Std 04523 Connection to client 'App (UniversalRoutingServer,GCE-RQ,0)' closed, reason ''client disconnected''
15:19:44.704 Std 05023 Process 'dbclient_msql' stopped
15:19:54.632 Trc 04521 New client 65476 connected from '10.100.129.185'
15:19:54.634 Std 05022 Process 'dbclient_msql' started
15:19:54.703 Trc 04521 New client 65478 connected from '10.100.129.185'
15:20:10.271 Std 05023 Process 'dbclient_msql' stopped
15:20:20.249 Trc 04521 New client 65507 connected from '10.100.129.185'
15:20:20.251 Std 05022 Process 'dbclient_msql' started
15:20:20.305 Trc 04521 New client 65509 connected from '10.100.129.185'
15:20:36.952 Std 05023 Process 'dbclient_msql' stopped


An update on my tries:

1. I had configured the GCE in the test environment in the same way and it works fine with MSSQL.
2. I tried to use the GCE production to consult my MSSQL server in the test environment, and got the same problem.
3. In MSSQL, i can see the connection from the GCE host, it stays in sleeping status.

In the Standard Centralized Log on SCI, i get these messages:
29/11/2012 18:22:25 Standard GCE-RQ VisualCCDBServer GCTI-00-05022 Process 'dbclient_msql' started
29/11/2012 18:22:40 Standard GCE-RQ UniversalRoutingServer GCTI-00-04502 Cannot connect to DBServer 'VisualCCDBServer' at host 'gce-rq', port 4568, reason 'unknown'
29/11/2012 18:22:40 Standard GCE-RQ VisualCCDBServer GCTI-00-05023 Process 'dbclient_msql' stopped

The host is listening to 4568 port.
TCP 0.0.0.0:4568 0.0.0.0:0 LISTENING

[cavagnaro]

Please set the DBServer logs to full (all) so it will show more info
Those messages are normal

[joao.carlos]

Here follow the log with the All option.

GServer: new_client: fd=392, found server=132
14:23:18.094 Trc 04521 New client 57061 connected from '10.100.129.185'
14:23:18.094 Dbg 10745 './dbclient_oracle' registered; protocol version '1.4' id '2215.1'
14:23:18.094 Dbg 10734 Send message 'MSG_OPENDB' to 'Oracle: 2215.1', request id '8857'
14:23:18.094 Dbg 10734 Send message 'MSG_EXTPACKETS' to 'App (UniversalRoutingServer,GCE-RQ,0)', request id '0'
14:23:18.094 Dbg 10734 Send message 'MSG_EXTPACKET' to 'Oracle: 2215.1', request id '0'
14:23:18.094 Dbg 10743 'Oracle: 2215.1' is spare
14:23:18.259 Dbg 10739 Oracle: id='2215.1' req='-1'
DBClient Oracle, Copyright (c) 1997-2011 Genesys Telecommunications Labs, Inc.
All Rights Reserved
Db Client version: 8.1.000.05
DB Common part version: 8.1.000.05
Vendor supported versions: "Oracle 10g, 11g"
Process ID: 6588
Build on 'i686-winnt-vs8-64'
+0070 Connection to multiserver created, host 'gce-rq', port '57060', socket '236'
+0070 MSG_STARTDB status='Unknown (2215)'
Oracle: id='2215.1' req='8857' Protocols versions: dbclient='00010004' dbserver='00010004' dblib='00010004'
+0001 Database Access Point in TKVList:
+0001 Open DB: username = 'jcr', database = 'rqrescm.rqr.com.br', dbserver = '10.1.1.171'
+0165 dbstatus: 5 ocierror(12504): ORA-12504: TNS:listener não recebeu o SERVICE_NAME em CONNECT_DATA

+0165 MSG_ERROR status='dbNotOpened' msg='ORA-12504: TNS:listener não recebeu o SERVICE_NAME em CONNECT_DATA
'

14:23:18.259 Dbg 10749 Forwarding response '8857.1' from 'Oracle: 2215.1' to 'App (UniversalRoutingServer,GCE-RQ,0)'
14:23:18.259 Dbg 10734 Send message 'MSG_DISCONNECTED' to 'App (UniversalRoutingServer,GCE-RQ,0)', request id '-1'
14:23:18.259 Dbg 10734 Send message 'MSG_DISCONNECTED' to 'Oracle: 2215.1', request id '-1'
/Statistics
name = Oracle: 2215.1
app_name = App (UniversalRoutingServer,GCE-RQ,0)
req_rcvd = 5
req_sent = 3
data_rcvd = 1191
data_sent = 138
msg_error = 1
msg_log = 1
Client Oracle: 2215.1 is being closed. Current numofclients=0
Listener (port id = internal-0-0 fd = 132) is being closed. Checking for clients on listener...
Listener with port id = internal-0-0 has been closed and deleted from list of current ports. Number of db app connections affected: 0
Client App (UniversalRoutingServer,GCE-RQ,0) is being closed. Current numofclients=3
14:23:18.317 Std 05023 Process './dbclient_oracle' stopped
/./dbclient_oracle
pid = 6588
id = 2214
expiration_time = 2012-11-30T14:23:48
client copy = 0
DbClient name = Oracle: 2215.1
14:23:22.710 Dbg 10739 ODBC: id='2213.1' req='-1'
DBClient ODBC, Copyright (c) 1997-2011 Genesys Telecommunications Labs, Inc.
All Rights Reserved
Db Client version: 8.1.000.05
DB Common part version: 8.1.000.05
Vendor supported versions: 1.0
Process ID: 5040
Build on 'i686-winnt-vs8-64'
+0043 Connection to multiserver created, host 'gce-rq', port '57036', socket '236'
+0043 MSG_STARTDB status='Unknown (2213)'
ODBC: id='2213.1' req='8850' Protocols versions: dbclient='00010004' dbserver='00010004' dblib='00010004'
+0000 Database Access Point in TKVList:
+0000 section "dbclient":
+0000 "max-binding-memory" = 250
+0000 00000000004BFDE0,hDBC=5335808,5335808
+0000 Open DB: username = 'rqvc', database = 'RQVC', dbserver = '10.100.129.186'
+0002 Could not connect to SQL Server using SQL Native Client driver. Attemting default MS SQL Server driver...
+16546 odbcerr: [Microsoft][ODBC SQL Server Driver]Falha na caixa de diálogo
+16546 MSG_ERROR status='dbNotOpened' msg='[Microsoft][ODBC SQL Server Driver]Falha na caixa de diálogo '

14:23:22.710 Dbg 10749 Forwarding response '8850.1' from 'MS SQL: 2213.1' to 'App (UniversalRoutingServer,GCE-RQ,0)'
14:23:22.710 Dbg 10734 Send message 'MSG_DISCONNECTED' to 'MS SQL: 2213.1', request id '-1'
/Statistics
name = MS SQL: 2213.1
app_name = App (UniversalRoutingServer,GCE-RQ,0)
req_rcvd = 4
req_sent = 3
data_rcvd = 1236
data_sent = 170
msg_error = 1
msg_log = 1
Client MS SQL: 2213.1 is being closed. Current numofclients=0
14:23:22.710 Dbg 10734 Send message 'MSG_DBCLOSED' to 'App (UniversalRoutingServer,GCE-RQ,0)', request id '8859'
14:23:22.711 Std 04523 Connection to client 'App (UniversalRoutingServer,GCE-RQ,0)' closed, reason ''client disconnected''
Listener (port id = internal-0-0 fd = 396) is being closed. Checking for clients on listener...
Listener with port id = internal-0-0 has been closed and deleted from list of current ports. Number of db app connections affected: 0
Client App (UniversalRoutingServer,GCE-RQ,0) is being closed. Current numofclients=2
14:23:22.758 Std 05023 Process 'dbclient_msql' stopped
/dbclient_msql
pid = 5040
id = 2212
expiration_time = 2012-11-30T14:23:52
client copy = 0
DbClient name = MS SQL: 2213.1
/Statistics
name = App (UniversalRoutingServer,GCE-RQ,0)
req_rcvd = 5
req_sent = 5
data_rcvd = 278
data_send = 208
invalid_params = 0
abandoned_req = 0
abandon_req_fail = 0
error_start_client = 0
invalid_register_req = 0
msg_error = 0
pending_requests = 0
pending_queue_size = 0
max_pending_requests = 0
max_pending_queue_size = 0
GServer (0x1374050) is being removed. numofclients = 0,current numofserveritems = 2
/Statistics
name = App (UniversalRoutingServer,GCE-RQ,0)
req_rcvd = 6
req_sent = 5
data_rcvd = 280
data_send = 210
invalid_params = 0
abandoned_req = 0
abandon_req_fail = 0
error_start_client = 0
invalid_register_req = 0
msg_error = 0
pending_requests = 0
pending_queue_size = 0
max_pending_requests = 0
max_pending_queue_size = 0
GServer (0x509680) is being removed. numofclients = 0,current numofserveritems = 2

[cavagnaro]

Oi,
Seems that you have missing configuration on your Oracle side, is tsnames configured? Can you execute this with SQLPlus?

[joao.carlos]

Hi cavagnaro. Thanks for your answer.

See that i sent you two logs, with oracle AND Sql Server.

I can connect to both ORACLE and SQL Servers with their clients (SQL Plus and SQL Management), I can connect to them either testing with ODBC Administrator in Windows Control Panel.

I see that these messages:
SQL SERVER
+0000 Open DB: username = 'rqvc', database = 'RQVC', dbserver = '10.100.129.186'
+0002 Could not connect to SQL Server using SQL Native Client driver. Attemting default MS SQL Server driver...
+16546 odbcerr: [Microsoft][ODBC SQL Server Driver]Falha na caixa de diálogo
+16546 MSG_ERROR status='dbNotOpened' msg='[Microsoft][ODBC SQL Server Driver]Falha na caixa de diálogo '

ORACLE
+0001 Open DB: username = 'jcr', database = 'rqrescm.rqr.com.br', dbserver = '10.1.1.171'
+0165 dbstatus: 5 ocierror(12504): ORA-12504: TNS:listener não recebeu o SERVICE_NAME em CONNECT_DATA
+0165 MSG_ERROR status='dbNotOpened' msg='ORA-12504: TNS:listener não recebeu o SERVICE_NAME em CONNECT_DATA

Seems that the configuration is wrong in some place, but i can't figure out where.
Do i have to configure anything on the database side?

The most weird is that in the test platform it works fine without any further configuration.

[cavagnaro]

Ok lets see,
Post MSSQL DAP screenshot and from your MSSQL DB Engine:
Server name:
Table Name:

Regards