We developed an IVR application with integrated AES Connector and trying to pass CTI data through the our own DMCC softphone application. I have done XferTransfer in the IVR code as described Avaya OD Dev Guide. I used the Hold(AES) node and hold the first call then made a new call via Dial(AES) node. I set the uui with the value 'yasin' in the Dial(AES) node. After this new called answered, I verified this new callinfo state is established and then used the Transfer(AES) node to transfer the call.
On Softphone application side, we get the call information but uui is empty, not set with the value. When we checked the application logs in Tomcat, we see that we can set uui with aes command Dial but after executing CTI Command Transfer it seems empty. Could you please support us?
The first call:
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: Call ID 2146
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: Calling # (ANI) 4001
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: Called # (DNIS) 4503
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: Ext 3013
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: UCID 00999021461380023980
The transferred call:
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: Call ID 2147
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: Calling # (ANI) 3013
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: Called # (DNIS) 4000
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: Ext 3013
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: UCID 00999021471380023992
IVR APPLICATION logs;
24/09/2013 16:56:31 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : SCESession bound to HttpSession F2043BEA113B55060C9FB055BACF193A
24/09/2013 16:56:31 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Browser Version 2.1.4, terminationURL enabled : true
24/09/2013 16:56:31 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : PlatformParams:getPlatformParams: __VPVarGlobalDate is 1374511569920
24/09/2013 16:56:31 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : PlatformParams:getPlatformParams:Timestamp is 07/22/13 19:46:09
24/09/2013 16:56:31 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : PlatformParams: get global parameters from VPMS...
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : PlatformParams: AppRuntimeVarsResponse.getGlobalAppRuntimeVars returns status - success
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : PlatformParams: get parameter|value - __VPLicenseServerURL|https://192.168.48.16:8443/WebLM/LicenseServer
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Using SCESession F2043BEA113B55060C9FB055BACF193A:/CTITest servlet : Start
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : ** Pushed Stack Frame [/CTITest]
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : Not able to save posted variable information [__VPmaxbackuplogfiles]
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : Not able to save posted variable information [__VPappname]
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : Not able to save posted variable information [__VPVarAppURL]
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : Not able to save posted variable information [__VPloglevel]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___sessionid to complex: session:sessionid as [LABAAEP-2013267135631-18]
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : Not able to save posted variable information [__VPvpms]
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : Not able to save posted variable information [__VPbreadcrumb]
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : Not able to save posted variable information [__VPVarAppDate]
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : Not able to save posted variable information [__VPappvars]
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : Not able to save posted variable information [__VPlogname]
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : Not able to save posted variable information [__VPVarGlobalDate]
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : Not able to save posted variable information [__VPlogpassword]
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : Not able to save posted variable information [__VPapplog]
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : Not able to save posted variable information [__VPapploggingurl]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : runtime_platform : Experience Portal
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : runtime_asr : Desktop Microsoft Speech SAPI
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : Acquiring initial License
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Acquiring Avaya Platform runtime license
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : PlatformParams:getPlatformParams: __VPVarGlobalDate is 1374511569920
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : PlatformParams:getPlatformParams:Timestamp is 07/22/13 19:46:09
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : PlatformParams: get global parameters from VPMS...
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : PlatformParams: AppRuntimeVarsResponse.getGlobalAppRuntimeVars returns status - success
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : PlatformParams: get parameter|value - __VPLicenseServerURL|https://192.168.48.16:8443/WebLM/LicenseServer
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : License: Use the license server url in VPMS instead -
https://192.168.48.16:8443/WebLM/LicenseServer
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Runtime :true
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : IC :true
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTI :true
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : Grace Period timer cleared
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : License refresh timer started
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : MessageType is speech
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Using SCESession F2043BEA113B55060C9FB055BACF193A:/CTITest servlet : checkUUI
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___videofps to complex: session:videofps as [unknown]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___protocolname to complex: session:protocolname as [H323]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___vprdnis to complex: session:vprdnis as []
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___vpcoveragereason to complex: session:vpcoveragereason as []
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___videocodec to complex: session:videocodec as [unknown]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___videobitrate to complex: session:videobitrate as [unknown]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___channel to complex: session:channel as [3013]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___protocolversion to complex: session:protocolversion as [1.0]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___videonearfmtp to complex: session:videonearfmtp as [unknown]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___uui to complex: session:uui as []
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___aai to complex: session:aai as []
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___calltag to complex: session:calltag as [LABAAEP-3013-2013267135631]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :redirectinfo___uri to complex: redirectinfo:uri as []
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___ucid to complex: session:ucid as [00999021461380023980]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___videoformat to complex: session:videoformat as [unknown]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___vpcalledextension to complex: session:vpcalledextension as [3013]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___videowidth to complex: session:videowidth as [unknown]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___videoenabled to complex: session:videoenabled as [unknown]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :_sipcallid to simple: _sipcallid as [unknown]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___videofarfmtp to complex: session:videofarfmtp as [unknown]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___ani to complex: session:ani as [4001]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___sessionlabel to complex: session:sessionlabel as [00999021461380023980]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___dnis to complex: session:dnis as [4503]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___videoheight to complex: session:videoheight as [unknown]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :redirectinfo___reason to complex: redirectinfo:reason as []
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :redirectinfo___presentationinfo to complex: redirectinfo:presentationinfo as []
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :redirectinfo___screeninginfo to complex: redirectinfo:screeninginfo as []
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___mediatype to complex: session:mediatype as [unknown]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___sharedmode to complex: session:sharedmode as [serviceprovider]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :shareduui___value to complex: shareduui:value as [unknown]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :session___vpcoveragetype to complex: session:vpcoveragetype as []
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :shareduui___id to complex: shareduui:id as [unknown]
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: encrypted value is HeOhNXdyzSJDvqpbM8WEFa4ZWnvU9YSJCN3ce914jq4=
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: request to manager is
http://192.168.48.16:7080/aesconnector/CallInfoInitialCall?extension%3D3013&k=HeOhNXdyzSJDvqpbM8WEFa4ZWnvU9YSJCN3ce914jq4%3D
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: setting session cookie to F2043BEA113B55060C9FB055BACF193A:/CTITest
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: callinfo from Manager is callid=2146&ani=4001&dnis=4503&extension=3013&ucID=00999021461380023980&uui= &state=established
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.processCallInfoResults: rawResponse: callid=2146&ani=4001&dnis=4503&extension=3013&ucID=00999021461380023980&uui=+&state=established
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CallInfo.doGetCallInfo: Populating call info variable values...
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: Call ID 2146
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: Calling # (ANI) 4001
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: Called # (DNIS) 4503
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: Ext 3013
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: UCID 00999021461380023980
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: UUI
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: State established
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: encrypted value is HeOhNXdyzSJDvqpbM8WEFa4ZWnvU9YSJ4evK+CoifUU=
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: request to manager is
http://192.168.48.16:7080/aesconnector/CallInfoInitialCall?extension%3D3013&k=HeOhNXdyzSJDvqpbM8WEFa4ZWnvU9YSJ4evK%2BCoifUU%3D
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: setting session cookie to F2043BEA113B55060C9FB055BACF193A:/CTITest
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: callinfo from Manager is callid=2146&ani=4001&dnis=4503&extension=3013&ucID=00999021461380023980&uui= &state=established
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.processCallInfoResults: rawResponse: callid=2146&ani=4001&dnis=4503&extension=3013&ucID=00999021461380023980&uui=+&state=established
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CallInfo.doGetCallInfo: Populating call info variable values...
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: Call ID 2146
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: Calling # (ANI) 4001
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: Called # (DNIS) 4503
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: Ext 3013
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: UCID 00999021461380023980
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: UUI
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: State established
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : session id:LABAAEP-2013267135631-18 | CTITest:checkUUI | ************* CTI CALL INFO **************** | cticallinfo:ucid : 00999021461380023980
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : session id:LABAAEP-2013267135631-18 | CTITest:checkUUI | ************* MY CALL INFO ****************
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : session id:LABAAEP-2013267135631-18 | CTITest:checkUUI | ************* SESSION CALL INFO **************** | session:ucid : 00999021461380023980
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Assigning [cticallinfo:uui] to [conferenceParam]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : [condition1] Expression [conferenceParam] String Equal Ignorecase [fatih]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Assigning [session:ucid] to [selectRecord:_pSessionId]
24/09/2013 16:56:32 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : Executing DB statement : [{ ? = call dbo.P_CHECK_TEST_POC;1 ( ?, ?, ?) }]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : [condition2] Expression [selectRecord:_pResult] Numeric Equal [0]
24/09/2013 16:56:32 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Using SCESession F2043BEA113B55060C9FB055BACF193A:/CTITest servlet : getCardNumber
24/09/2013 16:56:41 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Using SCESession F2043BEA113B55060C9FB055BACF193A:/CTITest servlet : XferSetup
24/09/2013 16:56:41 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :getCardNumber___inputmode to complex: getCardNumber:inputmode as [dtmf]
24/09/2013 16:56:41 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :getCardNumber___noinputcount to complex: getCardNumber:noinputcount as [0]
24/09/2013 16:56:41 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :getCardNumber___interpretation to complex: getCardNumber:interpretation as [5656565623232323]
24/09/2013 16:56:41 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :getCardNumber___value to complex: getCardNumber:value as [5656565623232323]
24/09/2013 16:56:41 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :getCardNumber___utterance to complex: getCardNumber:utterance as [5656565623232323]
24/09/2013 16:56:41 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :getCardNumber___nomatchcount to complex: getCardNumber:nomatchcount as [0]
24/09/2013 16:56:41 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Storing :getCardNumber___confidence to complex: getCardNumber:confidence as [1]
24/09/2013 16:56:41 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: encrypted value is HeOhNXdyzSJDvqpbM8WEFc8dkpaHXa/fnH2c1zMWKzg=
24/09/2013 16:56:41 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : VariableUtil.getVariableValue: Variable value is 2146
24/09/2013 16:56:41 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: request to manager is
http://192.168.48.16:7080/aesconnector/Hold?callid%3D2146%26extension%3D3013&k=HeOhNXdyzSJDvqpbM8WEFc8dkpaHXa%2FfnH2c1zMWKzg%3D
24/09/2013 16:56:41 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: setting session cookie to F2043BEA113B55060C9FB055BACF193A:/CTITest
24/09/2013 16:56:41 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: callinfo from Manager is callid=2146&ani=4001&dnis=4503&extension=3013&ucID=00999021461380023980&uui= &state=held
24/09/2013 16:56:41 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.processCallInfoResults: rawResponse: callid=2146&ani=4001&dnis=4503&extension=3013&ucID=00999021461380023980&uui=+&state=held
24/09/2013 16:56:41 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: State held
24/09/2013 16:56:41 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : [condition1] Expression [cticallinfo:state] String Equal Ignorecase [held]
24/09/2013 16:56:41 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : session id:LABAAEP-2013267135631-18 | CTITest:XferSetup | *************** CTICALLINFO : UCID ****************** | cticallinfo:ucid : 00999021461380023980
24/09/2013 16:56:41 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : VariableUtil.getVariableValue: Variable value is 4000
24/09/2013 16:56:41 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : VariableUtil.getVariableValue: Variable value is yasin
24/09/2013 16:56:41 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: encrypted value is HeOhNXdyzSJDvqpbM8WEFc8dkpaHXa/fmWqNkgHIuRQ=
24/09/2013 16:56:41 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : VariableUtil.getVariableValue: Variable value is 2146
24/09/2013 16:56:41 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: request to manager is
http://192.168.48.16:7080/aesconnector/Dial?callee%3D4000%26uui%3Dyasin%26uuiAsAscii%3Dtrue%26ringMax%3D10%26extension%3D3013%26holdAddress%3D2146&k=HeOhNXdyzSJDvqpbM8WEFc8dkpaHXa%2FfmWqNkgHIuRQ%3D
24/09/2013 16:56:41 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: setting session cookie to F2043BEA113B55060C9FB055BACF193A:/CTITest
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: callinfo from Manager is callid=2147&ani=3013&dnis=4000&extension=3013&ucID=00999021471380023992&uui= &state=established
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.processCallInfoResults: rawResponse: callid=2147&ani=3013&dnis=4000&extension=3013&ucID=00999021471380023992&uui=+&state=established
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CallInfo.doGetCallInfo: Populating call info variable values...
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: Call ID 2147
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: Calling # (ANI) 3013
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: Called # (DNIS) 4000
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: Ext 3013
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: UCID 00999021471380023992
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: UUI
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: State established
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : session id:LABAAEP-2013267135631-18 | CTITest:XferSetup | DialCall:ANI | DialCall:ani : 3013
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : session id:LABAAEP-2013267135631-18 | CTITest:XferSetup | DialCall:CallID | DialCall:callid : 2147
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : session id:LABAAEP-2013267135631-18 | CTITest:XferSetup | DialCall:DNIS | DialCall:dnis : 4000
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : session id:LABAAEP-2013267135631-18 | CTITest:XferSetup | DialCall:State | DialCall:state : established
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : session id:LABAAEP-2013267135631-18 | CTITest:XferSetup | DialCall:STATIONEXT | DialCall:stationextension : 3013
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : session id:LABAAEP-2013267135631-18 | CTITest:XferSetup | DialCall:UCID | DialCall:ucid : 00999021471380023992
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : session id:LABAAEP-2013267135631-18 | CTITest:XferSetup | DialCall:UUI | DialCall:uui :
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : session id:LABAAEP-2013267135631-18 | CTITest:XferSetup | CTICALLINFO:ANI | cticallinfo:ani : 4001
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : session id:LABAAEP-2013267135631-18 | CTITest:XferSetup | CTICALLINFO:CallID | cticallinfo:callid : 2146
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : session id:LABAAEP-2013267135631-18 | CTITest:XferSetup | CTICALLINFO:DNIS | cticallinfo:dnis : 4503
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : session id:LABAAEP-2013267135631-18 | CTITest:XferSetup | CTICALLINFO:State | cticallinfo:state : held
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : session id:LABAAEP-2013267135631-18 | CTITest:XferSetup | CTICALLINFO:STATIONEXT | cticallinfo:stationextension : 3013
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : session id:LABAAEP-2013267135631-18 | CTITest:XferSetup | CTICALLINFO:UCID | cticallinfo:ucid : 00999021461380023980
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : session id:LABAAEP-2013267135631-18 | CTITest:XferSetup | CTICALLINFO:UUI | cticallinfo:uui :
24/09/2013 16:56:42 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : [condition2] Expression [DialCall:state] String Equal Ignorecase [established]
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: encrypted value is HeOhNXdyzSJDvqpbM8WEFWBhFmmKnT7TMAfJkugsPkg=
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : VariableUtil.getVariableValue: Variable value is 2146
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : VariableUtil.getVariableValue: Variable value is 2147
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: request to manager is
http://192.168.48.16:7080/aesconnector/Transfer?heldcallid%3D2146%26activeCallId%3D2147%26extension%3D3013&k=HeOhNXdyzSJDvqpbM8WEFWBhFmmKnT7TMAfJkugsPkg%3D
24/09/2013 16:56:42 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: setting session cookie to F2043BEA113B55060C9FB055BACF193A:/CTITest
24/09/2013 16:56:43 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: callinfo from Manager is callid=2146&ani=4001&dnis=4503&extension=3013&ucID=00999021461380023980&uui= &state=transferred
24/09/2013 16:56:43 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.processCallInfoResults: rawResponse: callid=2146&ani=4001&dnis=4503&extension=3013&ucID=00999021461380023980&uui=+&state=transferred
24/09/2013 16:56:43 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.setCallInfoVariableValues: State transferred
24/09/2013 16:56:43 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : session id:LABAAEP-2013267135631-18 | CTITest:XferSetup | ************ TRANSFER SUCCEED *****************
24/09/2013 16:56:43 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Using SCESession F2043BEA113B55060C9FB055BACF193A:/CTITest servlet : exit
24/09/2013 16:56:43 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTIEnd.execute:3013 callid is 2146
24/09/2013 16:56:43 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: encrypted value is HeOhNXdyzSJDvqpbM8WEFbaaqRP5vOGEKJ4ksodcNC8=
24/09/2013 16:56:43 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: request to manager is
http://192.168.48.16:7080/aesconnector/End?extension%3D3013%26callid%3D2146&k=HeOhNXdyzSJDvqpbM8WEFbaaqRP5vOGEKJ4ksodcNC8%3D
24/09/2013 16:56:43 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: setting session cookie to F2043BEA113B55060C9FB055BACF193A:/CTITest
24/09/2013 16:56:43 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : CTICommand.execute: callinfo from Manager is
24/09/2013 16:56:43 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Removing session from AvayaSessionTermination Servlet
24/09/2013 16:56:43 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : Termination URL reply : <?xml version="1.0" encoding="UTF-8"?>
<vxml version="2.1" xmlns="http://www.w3.org/2001/vxml" xml:lang="en-us">
</vxml>
24/09/2013 16:56:43 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : HTTP Session lost removing SCESession F2043BEA113B55060C9FB055BACF193A
24/09/2013 16:56:43 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : SCESession Removed
24/09/2013 16:56:43 DEBUG - F2043BEA113B55060C9FB055BACF193A:/CTITest : Removing 1 session stack frames.
24/09/2013 16:56:43 INFO - F2043BEA113B55060C9FB055BACF193A:/CTITest : ** Popped Stack Frame [/CTITest]
Application Server JTAPI Logs;
2013-09-24 16:56:31,594 [GetEventThread] INFO TsapiSession - Received monitorCrossRefID 4 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,595 [GetEventThread] DEBUG TsapiSession - CSTADeliveredEvent ::=
2013-09-24 16:56:31,595 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,595 [GetEventThread] DEBUG TsapiSession - monitorCrossRefID 4
2013-09-24 16:56:31,595 [GetEventThread] DEBUG TsapiSession - connection
2013-09-24 16:56:31,595 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,595 [GetEventThread] DEBUG TsapiSession - callID 2146
2013-09-24 16:56:31,595 [GetEventThread] DEBUG TsapiSession - deviceID "3013"
2013-09-24 16:56:31,595 [GetEventThread] DEBUG TsapiSession - devIDType 0 < STATIC_ID >
2013-09-24 16:56:31,595 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,595 [GetEventThread] DEBUG TsapiSession - alertingDevice
2013-09-24 16:56:31,595 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,595 [GetEventThread] DEBUG TsapiSession - deviceID "3013"
2013-09-24 16:56:31,595 [GetEventThread] DEBUG TsapiSession - deviceIDType 55 < EXPLICIT_PRIVATE_LOCAL_NUMBER >
2013-09-24 16:56:31,595 [GetEventThread] DEBUG TsapiSession - deviceIDStatus 0 < ID_PROVIDED >
2013-09-24 16:56:31,595 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,595 [GetEventThread] DEBUG TsapiSession - callingDevice
2013-09-24 16:56:31,595 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - deviceID "4001"
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - deviceIDType 55 < EXPLICIT_PRIVATE_LOCAL_NUMBER >
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - deviceIDStatus 0 < ID_PROVIDED >
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - calledDevice
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - deviceID "4503"
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - deviceIDType 55 < EXPLICIT_PRIVATE_LOCAL_NUMBER >
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - deviceIDStatus 0 < ID_PROVIDED >
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - lastRedirectionDevice
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - deviceID <null>
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - deviceIDType 30 < EXPLICIT_PUBLIC_UNKNOWN >
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - deviceIDStatus 2 < ID_NOT_REQUIRED >
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - localConnectionInfo 2 < CS_ALERTING >
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - cause 22 < EC_NEW_CALL >
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - TsapiPrivate ::=
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - vendor "ECS"
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - data 2 0 80 0 30 81 d7 a 1 2 16 0 16 0 16 4 32 39 39 38 30 13 a 1 ff a 1 0 2 1 0 2 1 0 2 1 0 16 0 30 0 30 a a 1 ff a 1 0 16 0 16 0 30 5 a 1 ff 4 0 a 1 0 30 66 a 1 0 30 8 16 0 a 1 1e a 1 2 30 8 16 0 a 1 1e a 1 2 16 0 16 0 30 13 a 1 ff a 1 0 2 1 0 2 1 0 2 1 0 16 0 30 0 30 a a 1 ff a 1 0 16 0 16 0 30 5 a 1 ff 4 0 16 14 30 30 30 30 30 30 30 30 30 30 30 30 30 30 30 30 30 30 30 30 30 6 1 1 0 2 1 0 1 1 0 30 0 30 8 16 0 a 1 1e a 1 1 16 14 30 30 39 39 39 30 32 31 34 36 31 33 38 30 30 32 33 39 38 30 30 6 1 1 0 2 1 0 1 1 0 30 0 30 8 16 0 a 1 1e a 1 1
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - tsType 57
2013-09-24 16:56:31,596 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,600 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTADeliveredEvent]@1790ce9. EVENT Q SIZE = 1 MAX Q SIZE = 1 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,600 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTADeliveredEvent]@1790ce9 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,611 [DistributeCSTAEvent] DEBUG LucentPrivateData - LucentV7DeliveredEvent ::=
2013-09-24 16:56:31,611 [DistributeCSTAEvent] DEBUG LucentPrivateData - {
2013-09-24 16:56:31,611 [DistributeCSTAEvent] DEBUG LucentPrivateData - deliveredType 2 < DELIVERED_TO_STATION >
2013-09-24 16:56:31,611 [DistributeCSTAEvent] DEBUG LucentPrivateData - trunkGroup <null>
2013-09-24 16:56:31,611 [DistributeCSTAEvent] DEBUG LucentPrivateData - trunkMember <null>
2013-09-24 16:56:31,611 [DistributeCSTAEvent] DEBUG LucentPrivateData - split "2998"
2013-09-24 16:56:31,611 [DistributeCSTAEvent] DEBUG LucentPrivateData - lookaheadInfo <null>
2013-09-24 16:56:31,611 [DistributeCSTAEvent] DEBUG LucentPrivateData - userEnteredCode <null>
2013-09-24 16:56:31,611 [DistributeCSTAEvent] DEBUG LucentPrivateData - userInfo <null>
2013-09-24 16:56:31,611 [DistributeCSTAEvent] DEBUG LucentPrivateData - reason 0 < AR_NONE >
2013-09-24 16:56:31,611 [DistributeCSTAEvent] DEBUG LucentPrivateData - originalCallInfo
2013-09-24 16:56:31,611 [DistributeCSTAEvent] DEBUG LucentPrivateData - {
2013-09-24 16:56:31,611 [DistributeCSTAEvent] DEBUG LucentPrivateData - reason 0 < OR_NONE >
2013-09-24 16:56:31,611 [DistributeCSTAEvent] DEBUG LucentPrivateData - callingDevice
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - {
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - deviceID <null>
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - deviceIDType 30 < EXPLICIT_PUBLIC_UNKNOWN >
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - deviceIDStatus 2 < ID_NOT_REQUIRED >
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - }
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - calledDevice
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - {
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - deviceID <null>
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - deviceIDType 30 < EXPLICIT_PUBLIC_UNKNOWN >
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - deviceIDStatus 2 < ID_NOT_REQUIRED >
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - }
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - trunkGroup <null>
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - trunkMember <null>
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - lookaheadInfo <null>
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - userEnteredCode <null>
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - userInfo <null>
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - }
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - distributingDevice
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - {
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - deviceID <null>
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - deviceIDType 30 < EXPLICIT_PUBLIC_UNKNOWN >
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - deviceIDStatus 1 < ID_NOT_KNOWN >
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - }
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - ucid "00999021461380023980"
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - callOriginatorInfo <none>
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - flexibleBilling FALSE
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - deviceHistory
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - {
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - }
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - distributingVDN
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - {
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - deviceID <null>
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - deviceIDType 30 < EXPLICIT_PUBLIC_UNKNOWN >
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - deviceIDStatus 1 < ID_NOT_KNOWN >
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - }
2013-09-24 16:56:31,612 [DistributeCSTAEvent] DEBUG LucentPrivateData - }
2013-09-24 16:56:31,612 [DistributeCSTAEvent] INFO TSEventHandler - CSTA Unsolicited Event: CSTAEvent[CSTADeliveredEvent]@1790ce9
2013-09-24 16:56:31,612 [DistributeCSTAEvent] INFO TSEventHandler - Free memory: 52486304
2013-09-24 16:56:31,612 [DistributeCSTAEvent] INFO TSEventHandler - Total memory: 65470464
2013-09-24 16:56:31,612 [DistributeCSTAEvent] INFO TSEventHandler - Handling CSTA_DELIVERED for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,620 [DistributeCSTAEvent] INFO TSCall - Constructing call TSCall[2146]@170119f with ID 2146 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,623 [DistributeCSTAEvent] INFO TsapiSession - Sent InvokeID 81 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,623 [DistributeCSTAEvent] DEBUG TsapiSession - CSTASnapshotCall ::=
2013-09-24 16:56:31,623 [DistributeCSTAEvent] DEBUG TsapiSession - {
2013-09-24 16:56:31,623 [DistributeCSTAEvent] DEBUG TsapiSession - snapshotObject
2013-09-24 16:56:31,623 [DistributeCSTAEvent] DEBUG TsapiSession - {
2013-09-24 16:56:31,623 [DistributeCSTAEvent] DEBUG TsapiSession - callID 2146
2013-09-24 16:56:31,623 [DistributeCSTAEvent] DEBUG TsapiSession - deviceID "3013"
2013-09-24 16:56:31,623 [DistributeCSTAEvent] DEBUG TsapiSession - devIDType 0 < STATIC_ID >
2013-09-24 16:56:31,623 [DistributeCSTAEvent] DEBUG TsapiSession - }
2013-09-24 16:56:31,623 [DistributeCSTAEvent] DEBUG TsapiSession - }
2013-09-24 16:56:31,624 [DistributeCSTAEvent] INFO TSEventHandler - DONE handling CSTA_DELIVERED for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,749 [GetEventThread] INFO TsapiSession - Received invokeID 81 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,749 [GetEventThread] DEBUG TsapiSession - CSTASnapshotCallConfEvent ::=
2013-09-24 16:56:31,749 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,749 [GetEventThread] DEBUG TsapiSession - snapshotData
2013-09-24 16:56:31,749 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,749 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,749 [GetEventThread] DEBUG TsapiSession - deviceOnCall
2013-09-24 16:56:31,749 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,749 [GetEventThread] DEBUG TsapiSession - deviceID "4001"
2013-09-24 16:56:31,749 [GetEventThread] DEBUG TsapiSession - deviceIDType 55 < EXPLICIT_PRIVATE_LOCAL_NUMBER >
2013-09-24 16:56:31,749 [GetEventThread] DEBUG TsapiSession - deviceIDStatus 0 < ID_PROVIDED >
2013-09-24 16:56:31,749 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,749 [GetEventThread] DEBUG TsapiSession - callIdentifier
2013-09-24 16:56:31,749 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,749 [GetEventThread] DEBUG TsapiSession - callID 2146
2013-09-24 16:56:31,749 [GetEventThread] DEBUG TsapiSession - deviceID "4001"
2013-09-24 16:56:31,749 [GetEventThread] DEBUG TsapiSession - devIDType 0 < STATIC_ID >
2013-09-24 16:56:31,749 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,749 [GetEventThread] DEBUG TsapiSession - localConnectionState 3 < CS_CONNECT >
2013-09-24 16:56:31,749 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,749 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,749 [GetEventThread] DEBUG TsapiSession - deviceOnCall
2013-09-24 16:56:31,749 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,749 [GetEventThread] DEBUG TsapiSession - deviceID "3013"
2013-09-24 16:56:31,750 [GetEventThread] DEBUG TsapiSession - deviceIDType 55 < EXPLICIT_PRIVATE_LOCAL_NUMBER >
2013-09-24 16:56:31,750 [GetEventThread] DEBUG TsapiSession - deviceIDStatus 0 < ID_PROVIDED >
2013-09-24 16:56:31,750 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,750 [GetEventThread] DEBUG TsapiSession - callIdentifier
2013-09-24 16:56:31,750 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,750 [GetEventThread] DEBUG TsapiSession - callID 2146
2013-09-24 16:56:31,750 [GetEventThread] DEBUG TsapiSession - deviceID "3013"
2013-09-24 16:56:31,750 [GetEventThread] DEBUG TsapiSession - devIDType 0 < STATIC_ID >
2013-09-24 16:56:31,750 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,750 [GetEventThread] DEBUG TsapiSession - localConnectionState 2 < CS_ALERTING >
2013-09-24 16:56:31,750 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,750 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,750 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,750 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTASnapshotCallConfEvent]@1be20c for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,750 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTASnapshotCallConfEvent]@1be20c. EVENT Q SIZE = 1 MAX Q SIZE = 1 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,750 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 81 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,750 [DistributeCSTAEvent] INFO TSDevice - Constructing device TSDevice[4001]@959fa1 with name 4001 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,750 [DistributeCSTAEvent] INFO TsapiSession - Sent InvokeID 82 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,750 [DistributeCSTAEvent] DEBUG TsapiSession - CSTAQueryDeviceInfo ::=
2013-09-24 16:56:31,750 [DistributeCSTAEvent] DEBUG TsapiSession - {
2013-09-24 16:56:31,750 [DistributeCSTAEvent] DEBUG TsapiSession - device "4001"
2013-09-24 16:56:31,750 [DistributeCSTAEvent] DEBUG TsapiSession - }
2013-09-24 16:56:31,751 [GetEventThread] INFO TsapiSession - Received monitorCrossRefID 4 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - CSTAEstablishedEvent ::=
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - monitorCrossRefID 4
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - establishedConnection
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - callID 2146
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - deviceID "3013"
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - devIDType 0 < STATIC_ID >
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - answeringDevice
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - deviceID "3013"
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - deviceIDType 55 < EXPLICIT_PRIVATE_LOCAL_NUMBER >
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - deviceIDStatus 0 < ID_PROVIDED >
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - callingDevice
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - deviceID "4001"
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - deviceIDType 55 < EXPLICIT_PRIVATE_LOCAL_NUMBER >
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - deviceIDStatus 0 < ID_PROVIDED >
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - calledDevice
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - deviceID "4503"
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - deviceIDType 55 < EXPLICIT_PRIVATE_LOCAL_NUMBER >
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - deviceIDStatus 0 < ID_PROVIDED >
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - lastRedirectionDevice
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - deviceID <null>
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - deviceIDType 30 < EXPLICIT_PUBLIC_UNKNOWN >
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - deviceIDStatus 2 < ID_NOT_REQUIRED >
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - localConnectionInfo 3 < CS_CONNECT >
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - cause 22 < EC_NEW_CALL >
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - TsapiPrivate ::=
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - vendor "ECS"
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - data 2 0 81 0 30 81 d4 16 0 16 0 16 4 32 39 39 38 30 13 a 1 ff a 1 0 2 1 0 2 1 0 2 1 0 16 0 30 0 30 a a 1 ff a 1 0 16 0 16 0 30 5 a 1 ff 4 0 a 1 0 30 66 a 1 0 30 8 16 0 a 1 1e a 1 2 30 8 16 0 a 1 1e a 1 2 16 0 16 0 30 13 a 1 ff a 1 0 2 1 0 2 1 0 2 1 0 16 0 30 0 30 a a 1 ff a 1 0 16 0 16 0 30 5 a 1 ff 4 0 16 14 30 30 30 30 30 30 30 30 30 30 30 30 30 30 30 30 30 30 30 30 30 6 1 1 0 2 1 0 1 1 0 30 0 30 8 16 0 a 1 1e a 1 1 16 14 30 30 39 39 39 30 32 31 34 36 31 33 38 30 30 32 33 39 38 30 30 6 1 1 0 2 1 0 1 1 0 30 0 30 8 16 0 a 1 1e a 1 1
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - tsType 59
2013-09-24 16:56:31,751 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,753 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAEstablishedEvent]@1480773. EVENT Q SIZE = 1 MAX Q SIZE = 1 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,754 [DistributeCSTAEvent] INFO TSDevice - isTerminal() for TSDevice[4001]@959fa1
2013-09-24 16:56:31,754 [DistributeCSTAEvent] INFO TSDevice - TSDevice[4001]@959fa1 waiting for initialization to complete
2013-09-24 16:56:31,800 [GetEventThread] INFO TsapiSession - Received invokeID 82 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,800 [GetEventThread] DEBUG TsapiSession - CSTAQueryDeviceInfoConfEvent ::=
2013-09-24 16:56:31,800 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,800 [GetEventThread] DEBUG TsapiSession - device "4001"
2013-09-24 16:56:31,800 [GetEventThread] DEBUG TsapiSession - deviceType 0 < DT_STATION >
2013-09-24 16:56:31,800 [GetEventThread] DEBUG TsapiSession - deviceClass 0x80000000 < DC_VOICE >
2013-09-24 16:56:31,800 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,801 [GetEventThread] DEBUG TsapiSession - TsapiPrivate ::=
2013-09-24 16:56:31,801 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,801 [GetEventThread] DEBUG TsapiSession - vendor "ECS"
2013-09-24 16:56:31,801 [GetEventThread] DEBUG TsapiSession - data 2 0 62 0 30 8 a 1 6 a 1 a 16 0
2013-09-24 16:56:31,801 [GetEventThread] DEBUG TsapiSession - tsType 38
2013-09-24 16:56:31,801 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,803 [GetEventThread] DEBUG LucentPrivateData - LucentV5QueryDeviceInfoConfEvent ::=
2013-09-24 16:56:31,803 [GetEventThread] DEBUG LucentPrivateData - {
2013-09-24 16:56:31,803 [GetEventThread] DEBUG LucentPrivateData - extensionClass 6 < EC_PROPRIETARY >
2013-09-24 16:56:31,803 [GetEventThread] DEBUG LucentPrivateData - associatedClass 10 < EC_OTHER >
2013-09-24 16:56:31,803 [GetEventThread] DEBUG LucentPrivateData - associatedDevice <null>
2013-09-24 16:56:31,803 [GetEventThread] DEBUG LucentPrivateData - }
2013-09-24 16:56:31,803 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 82 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,803 [GetEventThread] INFO TSDevice - Initialization complete for TSDevice TSDevice[4001]@959fa1 - making values available - for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,803 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 82 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,803 [DistributeCSTAEvent] INFO TSConnection - Constructing Lucent termConn TSConnection[termConn:(2146,4001)]@39859 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,803 [DistributeCSTAEvent] INFO TSProviderImpl - NOTICE: connHash.put() replaced null with TSConnection[termConn:(2146,4001)]@39859 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,804 [DistributeCSTAEvent] INFO TSConnection - Constructing Lucent conn TSConnection[conn:(-,4001)]@19dbdc4 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,804 [DistributeCSTAEvent] INFO TSConnection - Constructing Lucent termConn TSConnection[termConn:(2146,3013)]@3b5699 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,804 [DistributeCSTAEvent] INFO TSProviderImpl - NOTICE: connHash.put() replaced null with TSConnection[termConn:(2146,3013)]@3b5699 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,804 [DistributeCSTAEvent] INFO TSConnection - Constructing Lucent conn TSConnection[conn:(-,3013)]@1b258fa for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,805 [DistributeCSTAEvent] DEBUG UnsolicitedSnapshotCallConfHandler - UnsolicitedSnapshotCallConfHandler com.avaya.jtapi.tsapi.impl.core.UnsolicitedSnapshotCallConfHandler@10cc730 handling conf for call TSCall[2146]@170119f, eventType 57, subjectDevice TSDevice[3013]@4eb585, connID ConnectionID(2146,3013,0), rc true, cause 22, privateData com.avaya.jtapi.tsapi.csta1.LucentV7DeliveredEvent@93837b, provider TSProvider[#1]@13dcd27
2013-09-24 16:56:31,805 [DistributeCSTAEvent] DEBUG UnsolicitedSnapshotCallConfHandler - overriding cause for TSEvent eventTarget=TSConnection[conn:(2146,3013)]@1b258fa;eventType=6 (6,TSConnection[conn:(2146,3013)]@1b258fa from eventType 57 with new cause 22
2013-09-24 16:56:31,805 [DistributeCSTAEvent] DEBUG UnsolicitedSnapshotCallConfHandler - overriding cause for TSEvent eventTarget=TSConnection[conn:(2146,3013)]@1b258fa;eventType=9 (9,TSConnection[conn:(2146,3013)]@1b258fa from eventType 57 with new cause 22
2013-09-24 16:56:31,805 [DistributeCSTAEvent] DEBUG UnsolicitedSnapshotCallConfHandler - overriding cause for TSEvent eventTarget=TSConnection[conn:(2146,3013)]@1b258fa;eventType=26 (26,TSConnection[conn:(2146,3013)]@1b258fa from eventType 57 with new cause 22
2013-09-24 16:56:31,805 [DistributeCSTAEvent] INFO TSDevice - Constructing device TSDevice[4503]@9d267d with name 4503 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,805 [DistributeCSTAEvent] INFO TsapiSession - Sent InvokeID 83 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,805 [DistributeCSTAEvent] DEBUG TsapiSession - CSTAQueryDeviceInfo ::=
2013-09-24 16:56:31,805 [DistributeCSTAEvent] DEBUG TsapiSession - {
2013-09-24 16:56:31,805 [DistributeCSTAEvent] DEBUG TsapiSession - device "4503"
2013-09-24 16:56:31,805 [DistributeCSTAEvent] DEBUG TsapiSession - }
2013-09-24 16:56:31,806 [DistributeCSTAEvent] INFO TSDevice - Constructing device TSDevice[2998]@2c06b2 with name 2998 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,806 [DistributeCSTAEvent] INFO TsapiSession - Sent InvokeID 84 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,806 [DistributeCSTAEvent] DEBUG TsapiSession - CSTAQueryDeviceInfo ::=
2013-09-24 16:56:31,806 [DistributeCSTAEvent] DEBUG TsapiSession - {
2013-09-24 16:56:31,806 [DistributeCSTAEvent] DEBUG TsapiSession - device "2998"
2013-09-24 16:56:31,806 [DistributeCSTAEvent] DEBUG TsapiSession - }
2013-09-24 16:56:31,806 [DistributeCSTAEvent] TRACE LucentACDAddressImpl - --> LucentACDAddressImpl[TSProviderImpl tsProvider, String number]: com.avaya.jtapi.tsapi.impl.LucentACDAddressImpl@2c06b2
2013-09-24 16:56:31,806 [DistributeCSTAEvent] TRACE LucentACDAddressImpl - <-- LucentACDAddressImpl[TSProviderImpl tsProvider, String number]: com.avaya.jtapi.tsapi.impl.LucentACDAddressImpl@2c06b2
2013-09-24 16:56:31,806 [DistributeCSTAEvent] TRACE LucentACDAddressImpl - --> getTSDevice[]: com.avaya.jtapi.tsapi.impl.LucentACDAddressImpl@2c06b2
2013-09-24 16:56:31,806 [DistributeCSTAEvent] TRACE LucentACDAddressImpl - <-- getTSDevice[]: com.avaya.jtapi.tsapi.impl.LucentACDAddressImpl@2c06b2
2013-09-24 16:56:31,810 [DistributeCSTAEvent] DEBUG TsapiCallMonitor - Getting TsapiCallMonitor lock to deliver events for call observer com.avaya.sce.cticonnector.servlet.server.CTIConnectorManager$CTICallObserver@1d4ee7e
2013-09-24 16:56:31,810 [DistributeCSTAEvent] DEBUG TsapiCallMonitor - meta event BEGIN: cause (110) metaCode (128) for com.avaya.sce.cticonnector.servlet.server.CTIConnectorManager$CTICallObserver@1d4ee7e
2013-09-24 16:56:31,815 [DistributeCSTAEvent] TRACE LucentACDAddressImpl - --> LucentACDAddressImpl[TSProviderImpl tsProvider, String number]: com.avaya.jtapi.tsapi.impl.LucentACDAddressImpl@2c06b2
2013-09-24 16:56:31,815 [DistributeCSTAEvent] TRACE LucentACDAddressImpl - <-- LucentACDAddressImpl[TSProviderImpl tsProvider, String number]: com.avaya.jtapi.tsapi.impl.LucentACDAddressImpl@2c06b2
2013-09-24 16:56:31,817 [DistributeCSTAEvent] TRACE LucentAddressImpl - com.avaya.jtapi.tsapi.impl.LucentAddressImpl@959fa1 constructed.
2013-09-24 16:56:31,820 [DistributeCSTAEvent] TRACE LucentV5TerminalExImpl - com.avaya.jtapi.tsapi.impl.LucentV5TerminalExImpl@959fa1 constructed.
2013-09-24 16:56:31,820 [DistributeCSTAEvent] INFO TSDevice - getDeviceType() for TSDevice[4503]@9d267d
2013-09-24 16:56:31,820 [DistributeCSTAEvent] INFO TSDevice - TSDevice[4503]@9d267d waiting for initialization to complete
2013-09-24 16:56:31,852 [GetEventThread] INFO TsapiSession - Received invokeID 83 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,852 [GetEventThread] DEBUG TsapiSession - CSTAQueryDeviceInfoConfEvent ::=
2013-09-24 16:56:31,852 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,852 [GetEventThread] DEBUG TsapiSession - device "4503"
2013-09-24 16:56:31,852 [GetEventThread] DEBUG TsapiSession - deviceType 19 < DT_ACD_GROUP >
2013-09-24 16:56:31,852 [GetEventThread] DEBUG TsapiSession - deviceClass 0x80000000 < DC_VOICE >
2013-09-24 16:56:31,852 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,852 [GetEventThread] DEBUG TsapiSession - TsapiPrivate ::=
2013-09-24 16:56:31,852 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,852 [GetEventThread] DEBUG TsapiSession - vendor "ECS"
2013-09-24 16:56:31,852 [GetEventThread] DEBUG TsapiSession - data 2 0 62 0 30 8 a 1 0 a 1 a 16 0
2013-09-24 16:56:31,852 [GetEventThread] DEBUG TsapiSession - tsType 38
2013-09-24 16:56:31,852 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,853 [GetEventThread] DEBUG LucentPrivateData - LucentV5QueryDeviceInfoConfEvent ::=
2013-09-24 16:56:31,853 [GetEventThread] DEBUG LucentPrivateData - {
2013-09-24 16:56:31,853 [GetEventThread] DEBUG LucentPrivateData - extensionClass 0 < EC_VDN >
2013-09-24 16:56:31,853 [GetEventThread] DEBUG LucentPrivateData - associatedClass 10 < EC_OTHER >
2013-09-24 16:56:31,853 [GetEventThread] DEBUG LucentPrivateData - associatedDevice <null>
2013-09-24 16:56:31,853 [GetEventThread] DEBUG LucentPrivateData - }
2013-09-24 16:56:31,853 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 83 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,853 [GetEventThread] INFO TSDevice - Initialization complete for TSDevice TSDevice[4503]@9d267d - making values available - for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,853 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 83 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,853 [GetEventThread] INFO TsapiSession - Received invokeID 84 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,853 [GetEventThread] DEBUG TsapiSession - CSTAQueryDeviceInfoConfEvent ::=
2013-09-24 16:56:31,853 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,853 [GetEventThread] DEBUG TsapiSession - device "2998"
2013-09-24 16:56:31,853 [GetEventThread] DEBUG TsapiSession - deviceType 19 < DT_ACD_GROUP >
2013-09-24 16:56:31,853 [GetEventThread] DEBUG TsapiSession - deviceClass 0x80000000 < DC_VOICE >
2013-09-24 16:56:31,853 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,853 [GetEventThread] DEBUG TsapiSession - TsapiPrivate ::=
2013-09-24 16:56:31,853 [GetEventThread] DEBUG TsapiSession - {
2013-09-24 16:56:31,853 [GetEventThread] DEBUG TsapiSession - vendor "ECS"
2013-09-24 16:56:31,853 [GetEventThread] DEBUG TsapiSession - data 2 0 62 0 30 8 a 1 1 a 1 a 16 0
2013-09-24 16:56:31,853 [GetEventThread] DEBUG TsapiSession - tsType 38
2013-09-24 16:56:31,853 [GetEventThread] DEBUG TsapiSession - }
2013-09-24 16:56:31,854 [GetEventThread] DEBUG LucentPrivateData - LucentV5QueryDeviceInfoConfEvent ::=
2013-09-24 16:56:31,854 [GetEventThread] DEBUG LucentPrivateData - {
2013-09-24 16:56:31,854 [GetEventThread] DEBUG LucentPrivateData - extensionClass 1 < EC_ACD_SPLIT >
2013-09-24 16:56:31,854 [GetEventThread] DEBUG LucentPrivateData - associatedClass 10 < EC_OTHER >
2013-09-24 16:56:31,854 [GetEventThread] DEBUG LucentPrivateData - associatedDevice <null>
2013-09-24 16:56:31,854 [GetEventThread] DEBUG LucentPrivateData - }
2013-09-24 16:56:31,854 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 84 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,854 [DistributeCSTAEvent] TRACE LucentV7ACDManagerAddressImpl - com.avaya.jtapi.tsapi.impl.LucentV7ACDManagerAddressImpl@9d267d constructed.
2013-09-24 16:56:31,854 [GetEventThread] INFO TSDevice - Initialization complete for TSDevice TSDevice[2998]@2c06b2 - making values available - for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,856 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 84 for TSProvider[#1]@13dcd27
2013-09-24 16:56:31,864 [DistributeCSTAEvent] TRACE LucentV7CallImpl - com.avaya.jtapi.tsapi.impl.LucentV7CallImpl@13dcd27 constructed.
2013-09-24 16:56:31,864 [DistributeCSTAEvent] TRACE LucentV7CallImpl - --> getTrunks[]: com.avaya.jtapi.tsapi.impl.LucentV7CallImpl@13dcd27
2013-09-24 16:56:31,864 [DistributeCSTAEvent] TRACE LucentV7CallImpl - <-- getTrunks[]: com.avaya.jtapi.tsapi.impl.LucentV7CallImpl@13dcd27
2013-09-24 16:56:31,864 [DistributeCSTAEvent] DEBUG TsapiCallMonitor - CALLACTIVEEVENT for TSCall[2146]@170119f for observer com.avaya.sce.cticonnector.servlet.server.CTIConnectorManager$CTICallObserver@1d4ee7e
2013-09-24 16:56:31,869 [DistributeCSTAEvent] TRACE LucentACDAddressImpl - --> LucentACDAddressImpl[TSProviderImpl tsProvider, String number]: com.avaya.jtapi.tsapi.impl.LucentACDAddressImpl@2c06b2
2013-09-24 16:56:31,869 [DistributeCSTAEvent] TRACE LucentACDAddressImpl - <-- LucentACDAddressImpl[TSProviderImpl tsProvider, String number]: com.avaya.jtapi.tsapi.impl.LucentACDAddressImpl@2c06b2
2013-09-24 16:56:31,869 [DistributeCSTAEvent] TRACE LucentAddressImpl - com.avaya.jtapi.tsapi.impl.LucentAddressImpl@959fa1 constructed.
2013-09-24 16:56:31,869 [DistributeCSTAEvent] TRACE LucentV5TerminalExImpl - com.avaya.jtapi.tsapi.impl.LucentV5TerminalExImpl@959fa1 constructed.
2013-09-24 16:56:31,869 [DistributeCSTAEvent] TRACE LucentV7ACDManagerAddressImpl - com.avaya.jtapi.tsapi.impl.LucentV7ACDManagerAddressImpl@9d267d constructed.
2013-09-24 16:56:31,869 [DistributeCSTAEvent] TRACE LucentV7CallImpl - com.avaya.jtapi.tsapi.impl.LucentV7CallImpl@13dcd27 constructed.
2013-09-24 16:56:31,869 [DistributeCSTAEvent] TRACE LucentV7CallImpl - --> getTrunks[]: com.avaya.jtapi.tsapi.impl.LucentV7CallImpl@13dcd27
2013-09-24 16:56:31,869 [DistributeCSTAEvent] TRACE LucentV7CallImpl - <-- getTrunks[]: com.avaya.jtapi.tsapi.impl.LucentV7CallImpl@13dcd27
2013-09-24 16:56:31,869 [DistributeCSTAEvent] DEBUG TsapiCallMonitor - CONNECTIONCREATEDEVENT for TSConnection[conn:(2146,4001)]@19dbdc4 for observer com.avaya.sce.cticonnector.servlet.server.CTIConnectorManager$CTICallObserver@1d4ee7e
2013-09-24 16:56:31,870 [DistributeCSTAEvent] TRACE LucentACDAddressImpl - --> LucentACDAddressImpl[TSProviderImpl tsProvider, String number]: com.avaya.jtapi.tsapi.impl.LucentACDAddressImpl@2c06b2
2013-09-24 16:56:31,870 [DistributeCSTAEvent] TRACE LucentACDAddressImpl - <-- LucentACDAddressImpl[TSProviderImpl tsProvider, String number]: com.avaya.jtapi.tsapi.impl.LucentACDAddressImpl@2c06b2
2013-09-24 16:56:31,870 [DistributeCSTAEvent] TRACE LucentAddressImpl - com.avaya.jtapi.tsapi.impl.LucentAddressImpl@959fa1 constructed.
2013-09-24 16:56:31,870 [DistributeCSTAEvent] TRACE LucentV5TerminalExImpl - com.avaya.jtapi.tsapi.impl.LucentV5TerminalExImpl@959fa1 constructed.
2013-09-24 16:56:31,870 [DistributeCSTAEvent] TRACE LucentV7ACDManagerAddressImpl - com.avaya.jtapi.tsapi.impl.LucentV7ACDManagerAddressImpl@9d267d constructed.
2013-09-24 16:56:31,870 [Dis
