cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
5835
Views
5
Helpful
16
Replies

UCCE (CVP, ICM, CUCM) Calls disconnect on answer

I've been working on a disconnect on transfer issue for quite some time. Very few calls are disconnected and I haven't found a pattern to it yet. I have noticed that when a call disconnects I get the following in the RTR log

5:59:59:781 ra-rtr Trace: (67544 x 0 : 0 0) NewCall: CID=(151201,4501), DN=1112001, ANI=1231234, CED=1112001, RCID=5000, MRDID=1, CallAtVRU=0, OpCode=0
15:59:59:781 ra-rtr Trace: (67544 x 0 : 0 0) DeviceTargetPreCall_V11: CID=(151201,4501), PerID=5000, SGSTID=5004, AGSTID=5272, NetworkCallFlags=1, InvokeID=1518594, GREET=
15:59:59:781 ra-rtr Trace: (67544 x 0 : 0 0) RC CCM1_RC (ID 5000) is not capable of handling Whisper Announcement call.
15:59:59:781 ra-rtr Trace: (67544 x 0 : 0 0) Connect: CID=(151201,4501), EventSelect=104, ServiceType=1, RCID=5000, Label(s)=
15:59:59:803 ra-rtr Trace: (67544 x 0 : 0 0) CallEventReport: CID=(151201,4501),Event=DIVERT_ON_BUSY_NOT_SUPPORTED, DlgEnds=0, FromVRU=0, CallState=15, Cause=INVALID_CAUSE
15:59:59:803 ra-rtr Trace: (67544 x 0 : 0 0) Deleting Dialog. 

On the database side, each of the call disconnects can be identified with  

PeripheralCallType = 13 and CallDisposition = 13 and Duration = 0 

but that seems to be where the similarities end. 

Any help is appreciated. 

 

16 Replies 16

Reena Mundary
Level 1
Level 1

Hi,

What's the call flow? Is it the comprehensive call flow?

and where the call is disconnecting.

Can you attach the PG logs also (jgw and PIM logs)?

Here it is using comprehensive call flow  RTRCallKey=151208.2477

I forgot to mention that this is on transfers. 

 

Do you have whisper in your script, and if you do, what model phone are we talking here ? Also, can you elaborate on the term "disconnect on transfer", do you mean the call disconnects while transferring from IVR to Agent ? 

RC CCM1_RC (ID 5000) is not capable of handling Whisper Announcement call.

Call comes in

CVP IVR Treatment

Queue 1 - Agent 1

Agent 1 transfers to Queue 2

Queue 2 -> Agent 2

Call disconnects when agent transfers

 

I'm pretty sure this is going to have something to do with whisper announcements. I'm looking up the phone models now. 

Hi,

 

Can u update if this issue has been resolved, if so kindly let us the know the cause of this issue, it would be much helpful.

Hi,

Is there any solution identified for this transfer issue? and what is the cause code 1015 in PG log represents?

I believe it ended up being a codec mismatch, I never could get an answer on what cause code 1015 meant. 

Are you seeing the same issue with comprehensive call flow?

Yes, I noticed this cause code in my comprehensive call flow. But its happening intermittently. Can you please let me know where exactly codec mismatch identified on your environment?

19:40:59:731 PG4A-jgw1 Trace:   MsgCallCleared:  CID: 34648154 ConnDevID: /0 LocConnInfo: -1 Cause: 1015 Unique ID: 000000000010B05A0296025500000000.
19:40:59:731 PG4A-jgw1 Trace: CallObservationEndedEv CID: 34648154.

Sasi - If cause 1015 meant for 'Redirection' then the call should not have ended I believe. But the very next logs I noticed after the logs above is as below

19:40:59:731 PG4A-jgw1 Trace: *** Freeing Call CID: 34648154 MyCID: 199653.

Any idea how to track the call after redirection?

Hopefully you already have CVP tracing turned up but if not:

go to http://<cvpcallsserver>:8000/cvp/diag

Click Debug 41
Set the dropdown at the top to com.Dynamicsoft.dslibs.DsUALibs then set to DEBUG

Click set

Next time you see the issue grab the CVP logs and attach that. It's going to be the best help to see what is going on and where it is happening. 

This is enabled. What are all logs need to be pulled from CVP server to troubleshoot?

grab the file from C:\Cisco\CVP\logs for that time period. 

Thanks Allen, checked the call logs and identified that the call is being terminated by the caller after waiting in queue for a long time. The only point which I am not clarified is: after termination its been logged as 'outbound' in between. Do you have any thoughts on this

CVP.2016-08-11.45.log:2562775: 172.30.160.15: Aug 11 2016 20:36:20.153 -0600: %CVP_10_5_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.19} CALLGUID = 6E3CAADA01E66021BC13000000000000 LEGID = BW013812043120816-1922850111 - [INBOUND] DURATION (msecs) = 3488086 - DIALOG TERMINATED. null  
CVP.2016-08-11.45.log:2562776: 172.30.160.15: Aug 11 2016 20:36:20.153 -0600: %CVP_10_5_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.19} Sending BUS MSG:>>HEADERS: (JMSType)=MsgBus:CALL_STATE_EVENT (JMSDestination)=Topic(CVP.SIP.CC.EVENT) (JMSTimestamp)=1470969380153 >>BODY: callguid=6E3CAADA01E66021BC13000000000000 RouterCallKey=2606 RouterCallKeySent=true causecode=1 timezone=America/Denver RouterCallKeySequenceNumber=3 version=CVP_10_5 labeltype=-1 RouterCallKeyDay=151798 calldate=Thu Aug 11 20:36:20 MDT 2016 label=77711110008904 localOffset=-360 eventid=6 calllegid=BW013812043120816-1922850111  >>STATE: isTabular=false isWriteable=true cursor=-1  
CVP.2016-08-11.45.log:2562777: 172.30.160.15: Aug 11 2016 20:36:20.153 -0600: %CVP_10_5_SIP-7-CALL:  {Thrd=pool-1-thread-142-SIP-927898} CALLGUID = 6E3CAADA01E66021BC13000000000000 LEGID = 6E3CAADA01E66021BC13000000000000-147096606003583140 - [OUTBOUND]: Updated by : CALLGUID = 6E3CAADA01E66021BC13000000000000 LEGID = BW013812043120816-1922850111 - [INBOUND]: with event type TERMINATED  
CVP.2016-08-11.45.log:2562778: 172.30.160.15: Aug 11 2016 20:36:20.153 -0600: %CVP_10_5_SIP-7-CALL:  {Thrd=pool-1-thread-142-SIP-927899} CALLGUID = 6E3CAADA01E66021BC13000000000000 LEGID = 6E3CAADA01E66021BC13000000000000-147096606003583140 - [OUTBOUND] DURATION (msecs) = 3320118 - HANGUP with Call History  
CVP.2016-08-11.45.log:89284881: 172.30.160.15: Aug 11 2016 20:36:20.153 -0600: %_Connection-7-com.dynamicsoft.DsLibs.DsUALibs.DsSipLlApi.Connection:  writing message to queue: callid: 6E3CAADA01E66021BC13000000000000-147096606003583140@172.30.160.15, cseq: BYE 2  
CVP.2016-08-11.45.log:Call-ID: 6E3CAADA01E66021BC13000000000000-147096606003583140@172.30.160.15
CVP.2016-08-11.45.log:89284886: 172.30.160.15: Aug 11 2016 20:36:20.153 -0600: %_callState-6-com.dynamicsoft.DsLibs.DsUALibs.DsSipMlApi.callState:  DsSipDialogTable.remove: key == ds170b51c2,F51F369E-1F73,6E3CAADA01E66021BC13000000000000-147096606003583140@172.30.160.15; returning com.dynamicsoft.DsLibs.DsSipDialog.DsSipInviteDialog@a97f09  
CVP.2016-08-11.45.log:2562779: 172.30.160.15: Aug 11 2016 20:36:20.153 -0600: %CVP_10_5_SIP-7-CALL:  {Thrd=pool-1-thread-142-SIP-927899} CALLGUID = 6E3CAADA01E66021BC13000000000000 LEGID = 6E3CAADA01E66021BC13000000000000-147096606003583140 - [OUTBOUND]: Terminated with Q.850;cause=16  
CVP.2016-08-11.45.log:969596: 172.30.160.15: Aug 11 2016 20:36:20.153 -0600: %CVP_10_5_ICM-7-CALL:  {Thrd=pool-1-thread-216-ICM-356290} CALLGUID = 6E3CAADA01E66021BC13000000000000, DLGID = 61518 [SIP_LEG] - Processing ,, [MsgBus:CALL_STATE_EVENT],   ssId=SYS_SIP4,   eventId=DISCONNECT,   causeCode=NORMAL_COMPLETION,, LEGID = BW013812043120816-1922850111, DNIS = 5128132376, ANI = 6464190848  
CVP.2016-08-11.45.log:969597: 172.30.160.15: Aug 11 2016 20:36:20.153 -0600: %CVP_10_5_ICM-7-CALL:  {Thrd=pool-1-thread-216-ICM-356290} CALLGUID = 6E3CAADA01E66021BC13000000000000, DLGID = 61518 [SIP_LEG] - Publishing ,, [ICM_EVENT_REPORT],   dialogueId=61518,   sendSeqNo=5,   eventId=DISCONNECT,   causeCode=NORMAL_COMPLETION,, LEGID = BW013812043120816-1922850111, DNIS = 5128132376, ANI = 6464190848  
CVP.2016-08-11.45.log:969598: 172.30.160.15: Aug 11 2016 20:36:20.153 -0600: %CVP_10_5_ICM-7-CALL:  {Thrd=pool-1-thread-216-ICM-356290} CALLGUID = 6E3CAADA01E66021BC13000000000000, DLGID = 61518 [SIP_LEG] - Deleted dialogue. Duration: 0 hrs, 58 mins, 8 secs, 86 msecs 

Cause 1015 means call is redirected. you can see the same in below logs.

12:45:42:792 PG1A-pim1 Trace: CallCleared: CID=35407957 ConnDevID=/0 LocalConn=-1 Cause=1015UniqueID=00000000001C485503F786CB00000000 
12:45:42:792 PG1A-pim1 Trace: CSTA CALL CLEARED, TelephonyDriver::CallCleared: SENT TO OPC
  CallID     = 35407957 DeviceID =   DeviceType = Static  LocalState = NONE
  Cause      = EC_DBCD_REDIRECTED

12:44:39:035 PG1A-pim1 Trace: CSTA DELIVERED, TelephonyDriver::Offered: SENT TO OPC
  CallID      = 35407957  DeviceID = 5418905236  DeviceType = Dynamic
  Alerting    =
  Calling     = 5418905236
  Called      = 8597383
  Redirection =
  LocalState  = INITIATE
  Cause       = EC_NEW_CALL
 
12:44:39:035 PG1A-pim1 Trace: CSTA DELIVERED, TelephonyDriver::Delivered: SENT TO OPC
  CallID      = 35407957  DeviceID = 5418905236  DeviceType = Dynamic
  Alerting    = 8597383
  Calling     = 5418905236
  Called      = 8597383
  Redirection =
  LocalState  = ALERTING
  Cause       = EC_NONE
 
12:44:42:239 PG1A-pim1 Trace: CSTA ESTABLISHED, TelephonyDriver::Established: SENT TO OPC
  CallID      = 35407957  DeviceID = 8597383  DeviceType = Static
  Answering   = 8597383
  Calling     = 5418905236
  Called      = 8597383
  Redirection =
  LocalState  = CONNECT
  Cause       = EC_NONE
 
 
12:45:33:576 PG1A-pim1 Trace: RTPStopped: CID=35407957, ConnDevID=8597383/0, Addr=10.40.10.88:24786, Direction=IN, UniqueID=00000000001C4855029A650000000000
12:45:33:576 PG1A-pim1 Trace: RTPStopped: CID=35407957, ConnDevID=8597383/0, Addr=10.40.210.23:28184, Direction=OUT, UniqueID=00000000001C4855029A650000000000
12:45:33:579 PG1A-pim1 Trace: Held: CID=35407957 ConnDevID=8597383/0 HoldingDev=8597383/0 LocalConn=4 Cause=-1UniqueID=00000000001C4855029A650000000000
12:45:33:579 PG1A-pim1 Trace: CSTA HELD, Held: SENT TO OPC
  CallID        = 35407957  DeviceID = 8597383  DeviceType = Static
  HoldingDevice = 8597383
  LocalState    = HOLD
  Cause         = EC_NONE
 
12:45:33:583 PG1A-pim1 Trace: ServiceInitiated: CID=17804509 ConnDevID=8597383/0 ConsOrigCID=35407957 ConsOrigConnDevID=8597383/0 LocalConn=1 Cause=-1UniqueID=00000000000FACDD03F786CA00000000 DevTgDevStr=8597383
12:45:33:583 PG1A-pim1 Trace: CSTA SERVICE INITIATED, TelephonyDriver::ServiceInitiated: SENT TO OPC
  CallID     = 17804509  DeviceID = 8597383  DeviceType = Static
  LocalState = INITIATE
  Cause      = EC_NONE

12:45:33:588 PG1A-pim1 Trace: Originated: CID=17804509 ConnDevID=8597383/0 CallingDev=8597383/0 CalledDev=8597470/0 LocalConn=3 Cause=-1UniqueID= 00000000000FACDD03F786CA00000000 DigitsDialed=8597470 DevTgDevStr=8597383
12:45:33:588 PG1A-pim1 Trace: CSTA ORIGINATED, TelephonyDriver::Originated: SENT TO OPC
  ConnectionID   = (17804509,8597383) DeviceType = Static
  Calling Device = 8597383      Type       = DEVICE_IDENTIFIER
  Called  Device = 8597470      Type       = DEVICE_IDENTIFIER
  Local State    = 3
  Cause          = -1
 
// 2nd call got delivered 
12:45:33:593 PG1A-pim1 Trace: CSTA DELIVERED, TelephonyDriver::Offered: SENT TO OPC
  CallID      = 17804509  DeviceID = 8597383  DeviceType = Static
  Alerting    =
  Calling     = 8597383
  Called      = 8597470
  Redirection =
  LocalState  = INITIATE
  Cause       = EC_NEW_CALL
 
 
12:45:33:593 PG1A-pim1 Trace: CSTA DELIVERED, TelephonyDriver::Delivered: SENT TO OPC
  CallID      = 17804509  DeviceID = 8597383  DeviceType = Static
  Alerting    = 8597470
  Calling     = 8597383
  Called      = 8597470
  Redirection =
  LocalState  = ALERTING
  Cause       = EC_NONE

12:45:34:621 PG1A-pim1 Trace: CSTA ESTABLISHED, TelephonyDriver::Established: SENT TO OPC
  CallID      = 17804509  DeviceID = 8597470  DeviceType = Static
  Answering   = 8597470
  Calling     = 8597383
  Called      = 8597470
  Redirection =
  LocalState  = CONNECT
  Cause       = EC_NONE
 
12:45:34:638 PG1A-pim1 Trace: RTPStarted: CID=17804509, ConnDevID=8597383/0, Addr=10.40.10.88:24792, Direction=IN, RtpType=Audio, BitRate=1, EchoCan=ON, PktSize=20, Payload=15 , UniqueID=00000000000FACDD03F786CB00000000
12:45:34:638 PG1A-pim1 Trace: RTPStarted: CID=17804509, ConnDevID=8597470/0, Addr=10.40.10.88:24792, Direction=OUT, RtpType=Audio, BitRate=1, EchoCan=ON, PktSize=20, Payload=15 , UniqueID=00000000000FACDD03F786CB00000000

12:45:34:703 PG1A-pim1 Trace: CSTATransferCall: Peripheral::ProcessCSTAThirdPartyServiceRequest InvokeID=0xf02d57a7 ActiveCall(CID=17804509,Dev=8597383,Type=Static) HeldCall(CID=35407957,Dev=8597383,Type=Static)

//RTP stop in 2nd call
12:45:34:730 PG1A-pim1 Trace: RTPStopped: CID=17804509, ConnDevID=8597383/0, Addr=10.40.10.88:24792, Direction=IN, UniqueID=00000000000FACDD03F786CB00000000

//RTP stop in 1st call
12:45:34:754 PG1A-pim1 Trace: RTPStopped: CID=35407957, ConnDevID=8597470/0, Addr=10.40.10.88:24792, Direction=OUT, UniqueID=00000000001C485503F786CB00000000
12:45:34:763 PG1A-pim1 Trace: Failed: CID=35407957 ConnDevID=8597470/0 FailingDev=8597470/0 CalledDev=/0 LocalConn=3 Cause=-1 UniqueUD = 00000000001C485503F786CB00000000
12:45:34:763 PG1A-pim1 Trace: CSTA FAILED, TelephonyDriver::Failed: SENT TO OPC
  CallID        = 35407957 DeviceID = 8597470  DeviceType = Static
  FailingDevice = 8597470
  CalledDevice  =
  LocalState    = CONNECT
  Cause         = EC_NONE

 
//second call cleared
12:45:37:928 PG1A-pim1 Trace: CSTAClearConnection: Peripheral::ProcessCSTAThirdPartyServiceRequest InvokeID=0xf02d57ad Call(CID=17804509,Dev=8597470,Type=Static)
12:45:37:928 PG1A-pim1 Trace: PRIVATE_DATA: CompoundRequestType=Unknown CSTA Event Type SubjectDevice=8597470
12:45:37:929 PG1A-pim1 Trace: ConnectionCleared: CID=17804509 ConnDevID=8597470/0 ReleasingDev=8597470/0 LocalConn=-1 Cause=-1UniqueID=00000000000FACDD03F786CB00000000 DevTgDevStr=8597470
12:45:37:929 PG1A-pim1 Trace: CSTA CONNECTION CLEARED, TelephonyDriver::ConnectionCleared: SENT TO OPC
  CallID          = 17804509  DeviceID = 8597470  DeviceType = Static
  ReleasingDevice = 8597470
  LocalState      = NONE
  Cause           = EC_NONE
 
// transfered happened
12:45:42:792 PG1A-pim1 Trace: Transferred: PriCon: (CID=35407957 ConnDevID=8597383/0) SecCon: (CID=17804509 ConnDevID=8597470/0) XfingDev: 8597383/0 XferredDev: 8597470/0 XCon: (CallID=35407957 ConnDevID=8597470/0) LocalConn=3 Cause=32 ReClassDevList=8597470PriUniqueID=00000000001C4855029A650000000000SecUniqueiD=00000000000FACDD03F786CB00000000 DevTgDevStr=8597383
12:45:42:792 PG1A-pim1 Trace: RecvTransferredEventMsg: Couldn't find assigned line for transferred device: 8597470 CID: 17804509
12:45:42:792 PG1A-pim1 Trace: CSTA TRANSFERRED, TelephonyDriver::Transferred: SENT TO OPC
  PrimaryOldCallID   = 35407957  DeviceID = 8597383  DeviceType = Static
  SecondaryOldCallID = 17804509  DeviceID = 8597470  DeviceType = Static
  TransferringDev    = 8597383
  TransferredDev     = 8597470
  LocalState         = CONNECT
  Cause              = EC_TRANSFER
  TransferredConnections: (connectcount=1)
 
//after transfered 1st call cleared
12:45:42:792 PG1A-pim1 Trace: CallCleared: CID=35407957 ConnDevID=/0 LocalConn=-1 Cause=1015UniqueID=00000000001C485503F786CB00000000 
12:45:42:792 PG1A-pim1 Trace: CSTA CALL CLEARED, TelephonyDriver::CallCleared: SENT TO OPC
  CallID     = 35407957 DeviceID =   DeviceType = Static  LocalState = NONE
  Cause      = EC_DBCD_REDIRECTED

Getting Started

Find answers to your questions by entering keywords or phrases in the Search bar above. New here? Use these resources to familiarize yourself with the community: