Author Message
CarlosDuarteBarrosPereiraPinto
Joined: Dec 21, 2016
Messages: 1
Offline
Hi ALL,

Has anyone ever had a similar problem?

Some calls and transfer processes are not complete successfully.

Calls that not transfer in
- aesconnector log: Call stay in held and does not complete.
- AES logs: Held state appears and is followed by a drop event.
This is causing silent calls to agent while customer is kept on hold in IVR. Seems there is no ‘merge’ of the call.
I have already explained, and I quoted above again, I think that aesconnector is likely not aware the call has been dropped, likely due to timing issue.

Below is the call flow analysis from AES on extension 125197.

Call-10669 connected.
<135>Dec 4 11:02:34 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 500 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 Sent CSTA Msg (CSTAUNSOLICITED)(4) (CSTA_ESTABLISHED)(59)
<135>Dec 4 11:02:34 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 500 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 msgoff(24)msglen(368)privoff(392)privlen(262)
<135>Dec 4 11:02:34 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 500 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 invokeID(2989)monXref(198)sessionID(6)clsOfServ(0)
<135>Dec 4 11:02:34 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 500 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 establishedConnection.callID(10669) .devID(125197) .devIDType(STATIC)
<135>Dec 4 11:02:34 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 500 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 answeringDevice.device(125197) (EXPLICIT_PRIVATE_LOCAL_NUMBER)(55) (ID_PROVIDED)(0)

Application invoked Hold-10669
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 518 1 com.avaya.aes | g3trace-cmsbee:cmsbee Received CSTA Msg (CSTAREQUEST)(3) (CSTA_HOLD_CALL)(21)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 518 1 com.avaya.aes | g3trace-cmsbee:cmsbee msgoff(24)msglen(76)privoff(24)privlen(0)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 518 1 com.avaya.aes | g3trace-cmsbee:cmsbee invokeID(47223)monXref(0)sessionID(6)clsOfServ(0)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 518 1 com.avaya.aes | g3trace-cmsbee:cmsbee reservation(F)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 518 1 com.avaya.aes | g3trace-cmsbee:cmsbee activeCall.callID(10669) .devID(125197) .devIDType(STATIC)

Application invoke MakeCall to 160031
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 582 1 com.avaya.aes | g3trace-cmsbee:cmsbee Received CSTA Msg (CSTAREQUEST)(3) (CSTA_MAKE_CALL)(23)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 582 1 com.avaya.aes | g3trace-cmsbee:cmsbee msgoff(114)msglen(128)privoff(24)privlen(90)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 582 1 com.avaya.aes | g3trace-cmsbee:cmsbee invokeID(47226)monXref(0)sessionID(6)clsOfServ(0)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 582 1 com.avaya.aes | g3trace-cmsbee:cmsbee callingDevice(125197)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 582 1 com.avaya.aes | g3trace-cmsbee:cmsbee calledDevice(160031)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 582 1 com.avaya.aes | g3trace-cmsbee:cmsbee eventType(ATT_MAKE_CALL)(110)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 582 1 com.avaya.aes | g3trace-cmsbee:cmsbee priorityCalling(F)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 582 1 com.avaya.aes | g3trace-cmsbee:cmsbee destRoute()
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 582 1 com.avaya.aes | g3trace-cmsbee:cmsbee userInfotype(UUI_IA5_ASCII)(4)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 582 1 com.avaya.aes | g3trace-cmsbee:cmsbee .length(38)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 582 1 com.avaya.aes | g3trace-cmsbee:cmsbee .data(1812039502PM)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 582 1 com.avaya.aes | g3trace-cmsbee:cmsbee .data(#1812039502P)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 582 1 com.avaya.aes | g3trace-cmsbee:cmsbee .data(F#INST##nWSD)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 582 1 com.avaya.aes | g3trace-cmsbee:cmsbee .data(L#)

So AES sent 3PAD (Auto Dial) ASAI request to CM to make the outgoind call
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 584 1 com.avaya.aes | g3trace-cmsbee:cmsbee Sent ASAI Message A3PADInfo
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 584 1 com.avaya.aes | g3trace-cmsbee:cmsbee cap,prim,sao_id C_3PAD,C_REQUEST,7938
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 584 1 com.avaya.aes | g3trace-cmsbee:cmsbee called_num 160031
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 584 1 com.avaya.aes | g3trace-cmsbee:cmsbee ofac_ext (null)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 584 1 com.avaya.aes | g3trace-cmsbee:cmsbee ack_flag 0
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 584 1 com.avaya.aes | g3trace-cmsbee:cmsbee ofacility 0x80000000
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 584 1 com.avaya.aes | g3trace-cmsbee:cmsbee prio_call 3
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 584 1 com.avaya.aes | g3trace-cmsbee:cmsbee uudata[len,protocol] 38,0x4
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 584 1 com.avaya.aes | g3trace-cmsbee:cmsbee uudata[info] 1812039502PM
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 584 1 com.avaya.aes | g3trace-cmsbee:cmsbee uudata[info] #1812039502P
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 584 1 com.avaya.aes | g3trace-cmsbee:cmsbee uudata[info] F#INST##nWSD
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 584 1 com.avaya.aes | g3trace-cmsbee:cmsbee uudata[info] L#

CM responded Positive acknowledge of the request, provided the callID 11382.
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 629 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 Received ASAI Message A3PADAck
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 629 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 cap,prim,sao_id C_3PAD_CONF,C_POS_ACK,7938
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 629 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 callID 11382
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 629 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 callingDev,Party 125197,1
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 629 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 callingFlags 0x50000
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 629 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 callingState 0x0
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 629 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 party_id 1
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 629 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 ucid: 8 byte dump of 8 bytes of data:
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 629 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 ucid: hex '03e82c76 5c067b76'
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 629 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 ucid: std format: '01000113821543928694'

So AES sent MakeCallConf-11382 to Application
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 634 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 Sent CSTA Msg (CSTACONFIRMATION)(5) (CSTA_MAKE_CALL_CONF)(24)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 634 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 msgoff(24)msglen(72)privoff(96)privlen(63)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 634 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 invokeID(47226)monXref(2989)sessionID(6)clsOfServ(0)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 634 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 newCall.callID(11382) .devID(125197) .devIDType(STATIC)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 635 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 eventType(ATT_MAKE_CALL_CONF)(85)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 635 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 UCID(01000113821543928694)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 636 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 Sent CSTA Msg (CSTAUNSOLICITED)(4) (CSTA_SERVICE_INITIATED)(66)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 636 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 msgoff(24)msglen(80)privoff(104)privlen(66)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 636 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 invokeID(2989)monXref(198)sessionID(6)clsOfServ(0)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 636 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 initiatedConnection.callID(11382) .devID(125197) .devIDType(STATIC)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 636 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 localConnectionInfo(CS_INITIATE)(1)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 636 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 cause(EC_NONE)(-1)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 636 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 eventType(ATT_SERVICE_INITIATED)(147)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 636 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 UCID(01000113821543928694)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 636 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 consultMode(ATT_CM_NOT_PROVIDED)(4)

Immediately AES received drop-10669 (party 1 – calling party) event from CM instead, indicating 27996915134 has been dropped from the call-10669
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 751 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 Received ASAI Message DroppedList
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 751 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 cap,prim,sao_id C_EN_REP,C_REQUEST,7938
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 751 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 event_name C_DROP
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 751 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 callID 10669
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 751 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 affectdDev,Party (null),1
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 751 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 affectedFlags 0x20000
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 751 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 affectedState 0x0
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 752 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 party_id 1
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 752 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 cause_value CS0/16
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 752 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 dropped_num (null)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 752 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 dropped_type[addr_type,numb_plan] 0,0
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 752 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 uudata[len,protocol] 0,0x80000000
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 752 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 uudata[info] (null)

<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 753 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 Sent CSTA Msg (CSTAUNSOLICITED)(4) (CSTA_CONNECTION_CLEARED)(56)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 753 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 msgoff(24)msglen(152)privoff(176)privlen(90)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 753 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 invokeID(2989)monXref(198)sessionID(6)clsOfServ(0)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 753 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 droppedConnection.callID(10669) .devID(27996915134) .devIDType(STATIC)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 753 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 releasingDevice.device(27996915134) (EXPLICIT_PRIVATE_UNKNOWN)(50) (ID_PROVIDED)(0)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 753 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 localConnectionInfo(CS_HOLD)(4)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 753 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 cause(EC_NONE)(-1)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 753 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 eventType(ATT_CONNECTION_CLEARED)(134)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 753 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 userInfotype(UUI_NONE)(-1)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 753 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 .length(0)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 754 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 DeviceHistory: count(1) {
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 754 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 oldDeviceID(27996915134)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 754 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 cause(EC_NONE)(-1)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 754 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 oldConnectionID.callID(10669) .devID(27996915134) .devIDType(STATIC)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 754 1 com.avaya.aes | g3trace-cmsbee:LinkThread01 }

We can still see Application invoked TransferCall because application is not aware the call has been dropped yet. AES sent 3PM (merge call) to CM
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 756 1 com.avaya.aes | g3trace-cmsbee:cmsbee Received CSTA Msg (CSTAREQUEST)(3) (CSTA_TRANSFER_CALL)(51)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 756 1 com.avaya.aes | g3trace-cmsbee:cmsbee msgoff(24)msglen(144)privoff(24)privlen(0)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 756 1 com.avaya.aes | g3trace-cmsbee:cmsbee invokeID(47236)monXref(0)sessionID(6)clsOfServ(0)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 756 1 com.avaya.aes | g3trace-cmsbee:cmsbee heldCall.callID(10669) .devID(125197) .devIDType(STATIC)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 756 1 com.avaya.aes | g3trace-cmsbee:cmsbee activeCall.callID(11382) .devID(125197) .devIDType(STATIC)
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 758 1 com.avaya.aes | g3trace-cmsbee:cmsbee Sent ASAI Message A3PMInfo
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 758 1 com.avaya.aes | g3trace-cmsbee:cmsbee cap,prim,sao_id C_3PM,C_REQUEST,7938
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 758 1 com.avaya.aes | g3trace-cmsbee:cmsbee callID 11382
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 758 1 com.avaya.aes | g3trace-cmsbee:cmsbee held_call_id 10669
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 758 1 com.avaya.aes | g3trace-cmsbee:cmsbee com_party_id _
<135>Dec 4 11:05:03 aessbevt05.atento.br TSAPI[4688]: -02:00 2018 758 1 com.avaya.aes | g3trace-cmsbee:cmsbee conf_flag 2


WilsonYu
Joined: Nov 6, 2013
Messages: 3950
Offline
It's important to figure out what cause the disconnect of the original call. Do you have the aesconnector trace.log to match these csta logs?
WilsonYu
Joined: Nov 6, 2013
Messages: 3950
Offline
Also I'd like assure that the aesconnector does not drop call unless there is an error in the transfer when the transfer is been attempted.
Go to:   
Mobile view