Hi,

Navaneethakrishnan Muralidharan · ‎10-30-2014

Hi All,

The agents are not able to answer the call , they made several attemps to pick the call but it still keep ringing.

While check through the cvp log I have able to find " HANG UP ON RINGTONE SERVER" and PortCheckinStatus=PORT_CHECKIN_OK_PORT_STILL_IN_USE.

As I can see hang up on ringtone server, my understanding is about in VXML Gateway the ringtone.tcl file will got hangup.

Kindly post your suggestions.

Chintan Gajjar · ‎10-30-2014

Can you share CVP and agent Desktop logs for the incident?

Chintan

Navaneethakrishnan Muralidharan · ‎10-31-2014

Chintan,

Thanks for your response, ANI (7862574500) and Dialed number (6063) with call ID, I'm able to see hang up on ringtone server error, which leads the agent unable to pick up the call.

CALLGUID = 7560370000010000005EB7870B10010A

Attached the Call server CVP logs.

Chintan Gajjar · ‎10-31-2014

I checked the logs briefly and saw some wrong behaviour.

I dont see any problem with Ringtone service or hang up here, but i feel it is something to do with Codec negotiation:

lets try to follow call behaviour from logs(we will be look very important steps):

1. Call hits CVP:

CVP.2014-10-27.27.log(11989): 49848358: 10.1.16.20: Oct 27 2014 16:04:13.600 -0400: %CVP_9_0_SIP-7-PARAM:  {Thrd=DATAI.25} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 75603700-44e1a54f-6e007b-b10010a - [INBOUND]: ReqURI (DN) sip:6063@10.1.16.20:5060 FromURI sip:7862574500@10.1.16.11 Video:false m_needs_postcallsurvey:false

2. ICM sends Temporary connect (VXML label to CVP to connect to find VXML GW) and gets success(send to VRU Success)

CVP.2014-10-27.27.log(12003): 49848367: 10.1.16.20: Oct 27 2014 16:04:13.616 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=pool-1-thread-58-SIP-11252858} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444025361631266 - [OUTBOUND]: INVITE TO <sip:88888888881455@vxml-gw.st.com;transport=tcp> FROM "THE MIAMI BEACH" <sip:7862574500@10.1.16.20:5060> EXPIRES[11] 100REL[Unsupported]  
CVP.2014-10-27.27.log(12004): 49848368: 10.1.16.20: Oct 27 2014 16:04:13.616 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.8} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444025361631266 - [OUTBOUND]: Invitation proceeding 100  
CVP.2014-10-27.27.log(12005): 49848369: 10.1.16.20: Oct 27 2014 16:04:13.616 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.8} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444025361631266 - [OUTBOUND]: Invitation accepted - ack'ing

3) ICM instructs CVP to run External script, CVP runs it successfully and submits result back to ICM

4) Agent with Extension 6774 becomes available, ICM instruct CVP to Disconnect call from VXML Gateway and connect to cucm for 6774 DN.

5) CVP sends invite to VXML gateway and re invite to caller to establish ringtone leg, and ringtone successfully gets established.

CVP.2014-10-27.27.log(15825): 49850899: 10.1.16.20: Oct 27 2014 16:06:14.123 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=pool-1-thread-104-SIP-11253407} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444037412331337 - [OUTBOUND]: INVITE TO <sip:91919191@vxml-gw.st.com;transport=tcp> FROM "THE MIAMI BEACH" <sip:7862574500@10.1.16.20:5060> EXPIRES[10] 100REL[Unsupported]  
CVP.2014-10-27.27.log(15830): 49850900: 10.1.16.20: Oct 27 2014 16:06:14.138 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.4} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444037412331337 - [RING-OUT]: Invitation proceeding 100  
CVP.2014-10-27.27.log(15831): 49850901: 10.1.16.20: Oct 27 2014 16:06:14.138 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.4} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444037412331337 - [RING-OUT]: Invitation accepted - ack'ing  
CVP.2014-10-27.27.log(15832): 49850902: 10.1.16.20: Oct 27 2014 16:06:14.138 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.4} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444037412331337 - [RING-OUT]: CountObserver() is >0 and sending Re-Invite to caller.  
CVP.2014-10-27.27.log(15833): 49850903: 10.1.16.20: Oct 27 2014 16:06:14.138 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=pool-1-thread-377-SIP-11253410} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 75603700-44e1a54f-6e007b-b10010a - [INBOUND]: Updated by : CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444037412331337 - [RING-OUT]: with event type INV_ACCEPTED  
CVP.2014-10-27.27.log(15834): 49850904: 10.1.16.20: Oct 27 2014 16:06:14.138 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=pool-1-thread-377-SIP-11253410} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 75603700-44e1a54f-6e007b-b10010a - [INBOUND]: reinviting caller.  
CVP.2014-10-27.27.log(15835): 9525400: 10.1.16.20: Oct 27 2014 16:06:14.138 -0400: %CVP_9_0_IVR-7-CALL:  {Thrd=http-8000-Processor23} VXMLManager:generateAckVXML: CALLGUID=7560370000010000005EB7870B10010A Generated VXML from template 'Ack.template' for client: 10.1.16.51 clientType: IOS  
CVP.2014-10-27.27.log(15836): 49850905: 10.1.16.20: Oct 27 2014 16:06:14.138 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=pool-1-thread-377-SIP-11253410} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 75603700-44e1a54f-6e007b-b10010a - [INBOUND]: Sending reinvite request. CSEQ:1  
CVP.2014-10-27.27.log(15844): 49850907: 10.1.16.20: Oct 27 2014 16:06:14.170 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.4} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 75603700-44e1a54f-6e007b-b10010a - [INBOUND]: Reinvitation accepted. CSeq: 1 INVITE  
CVP.2014-10-27.27.log(15845): 49850908: 10.1.16.20: Oct 27 2014 16:06:14.170 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=pool-1-thread-158-SIP-11253411} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444037412331337 - [RING-OUT]: Updated by : CALLGUID = 7560370000010000005EB7870B10010A LEGID = 75603700-44e1a54f-6e007b-b10010a - [INBOUND]: with event type REINV_ACCEPTED  
CVP.2014-10-27.27.log(15846): 49850909: 10.1.16.20: Oct 27 2014 16:06:14.170 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=pool-1-thread-158-SIP-11253411} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444037412331337 - [RING-OUT]: Acked the invite.  
CVP.2014-10-27.27.log(15847): 49850910: 10.1.16.20: Oct 27 2014 16:06:14.170 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=pool-1-thread-158-SIP-11253411} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 75603700-44e1a54f-6e007b-b10010a - [INBOUND]: Sent reinvite ack.  
CVP.2014-10-27.27.log(15848): 49850911: 10.1.16.20: Oct 27 2014 16:06:14.170 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=pool-1-thread-158-SIP-11253411} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444037412331337 - [RING-OUT]: Notifying that ringtone is established 200 OK with caller.

6) CVP sends an invite to CUCM for defined extension, CUCM accepts invitation:

CVP.2014-10-27.27.log(15852): 49850915: 10.1.16.20: Oct 27 2014 16:06:14.170 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=pool-1-thread-104-SIP-11253407} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444037417031338 - [OUTBOUND]: INVITE TO <sip:6774@US.cucm.st.com;transport=tcp> FROM "THE MIAMI BEACH" <sip:7862574500@10.1.16.20:5060> EXPIRES[11] 100REL[Unsupported]  
CVP.2014-10-27.27.log(15853): 49850916: 10.1.16.20: Oct 27 2014 16:06:14.170 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.4} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444037417031338 - [OUTBOUND]: Invitation proceeding 100  
CVP.2014-10-27.27.log(15854): 49850917: 10.1.16.20: Oct 27 2014 16:06:14.185 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.4} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444037417031338 - [OUTBOUND]: Invitation proceeding 180 with dialog.  
CVP.2014-10-27.27.log(15855): 49850918: 10.1.16.20: Oct 27 2014 16:06:14.185 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=pool-1-thread-356-SIP-11253412} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444037412331337 - [RING-OUT]: Updated by : CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444037417031338 - [OUTBOUND]: with event type PROCEEDING_180  
CVP.2014-10-27.27.log(15856): 49850919: 10.1.16.20: Oct 27 2014 16:06:14.185 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=pool-1-thread-356-SIP-11253412} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 75603700-44e1a54f-6e007b-b10010a - [INBOUND]: Updated by : CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444037417031338 - [OUTBOUND]: with event type PROCEEDING_180  
CVP.2014-10-27.27.log(15974): 49850999: 10.1.16.20: Oct 27 2014 16:06:16.884 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.8} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444037417031338 - [OUTBOUND]: DsSipInviteDialog accepted. Contact: <sip:6774@10.1.16.11:5060;transport=tcp>  
CVP.2014-10-27.27.log(15975): 49851000: 10.1.16.20: Oct 27 2014 16:06:16.884 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.8} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444037417031338 - [OUTBOUND]: CountObserver() is >0 and sending Re-Invite to caller.

7) CVP sends re invite to caller with the SDP phone in CUCM (codec, rtp ip/port etc), this depends on the region configuration of the phone in CUCM.

Now CVP Hangs up on the ringtone service for the caller and tries to re invite caller as per above SDP.

CVP.2014-10-27.27.log(15977): 49851002: 10.1.16.20: Oct 27 2014 16:06:16.884 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=pool-1-thread-268-SIP-11253436} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444037412331337 - [RING-OUT]: Hang up on ringtone server.  
CVP.2014-10-27.27.log(15978): 49851003: 10.1.16.20: Oct 27 2014 16:06:16.884 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=pool-1-thread-268-SIP-11253436} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444037412331337 - [RING-OUT] DURATION (msecs) = 2761 - HANGUP with Call History  
CVP.2014-10-27.27.log(15979): 49851004: 10.1.16.20: Oct 27 2014 16:06:16.884 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=pool-1-thread-268-SIP-11253436} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444037412331337 - [RING-OUT]: Terminated with Q.850;cause=16

reinvite:

CVP.2014-10-27.27.log(15981): 49851006: 10.1.16.20: Oct 27 2014 16:06:16.884 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=pool-1-thread-268-SIP-11253436} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 75603700-44e1a54f-6e007b-b10010a - [INBOUND]: reinviting caller.  
CVP.2014-10-27.27.log(15982): 49851007: 10.1.16.20: Oct 27 2014 16:06:16.884 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=pool-1-thread-268-SIP-11253436} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 75603700-44e1a54f-6e007b-b10010a - [INBOUND]: Sending reinvite request. CSEQ:2  
CVP.2014-10-27.27.log(15983): 49851008: 10.1.16.20: Oct 27 2014 16:06:16.884 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.8} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 75603700-44e1a54f-6e007b-b10010a - [INBOUND]: Reinvitation proceeding TRYING.  
CVP.2014-10-27.27.log(15984): 49851009: 10.1.16.20: Oct 27 2014 16:06:16.900 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.8} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 75603700-44e1a54f-6e007b-b10010a - [INBOUND] - DsSipReinvitation - "THE MIAMI BEACH" <sip:7862574500@10.1.16.11>;tag=56126335~ebacaf5d-bbcb-4bd3-9323-b5378b5ab0e1-44848660 - 2 REJECTED WITH 488 - Not Acceptable Here  
CVP.2014-10-27.27.log(15985): 49851010: 10.1.16.20: Oct 27 2014 16:06:16.900 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.8} Sending BUS MSG:>>HEADERS: (JMSType)=MsgBus:CALL_STATE_EVENT (JMSDestination)=Topic(CVP.SIP.CC.EVENT) (JMSTimestamp)=1414440376900 >>BODY: callguid=7560370000010000005EB7870B10010A RouterCallKey=9300 RouterCallKeySent=true causecode=0 timezone=America/New_York RouterCallKeySequenceNumber=0 version=CVP_9_0 labeltype=1 RouterCallKeyDay=151144 calldate=Mon Oct 27 16:06:16 EDT 2014 label=6774 localOffset=-240 eventid=1 calllegid=75603700-44e1a54f-6e007b-b10010a  >>STATE: isTabular=false isWriteable=true cursor=-1  
CVP.2014-10-27.27.log(15986): 49851011: 10.1.16.20: Oct 27 2014 16:06:16.900 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.8} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444037417031338 - [OUTBOUND]: Updated by : CALLGUID = 7560370000010000005EB7870B10010A LEGID = 75603700-44e1a54f-6e007b-b10010a - [INBOUND]: with event type REINV_REJECTED  
CVP.2014-10-27.27.log(15987): 49851012: 10.1.16.20: Oct 27 2014 16:06:16.900 -0400: %CVP_9_0_SIP-7-CALL:  {Thrd=DIALOG_CALLBACK.8} CALLGUID = 7560370000010000005EB7870B10010A LEGID = 7560370000010000005EB7870B10010A-141444037412331337 - [RING-OUT]: Updated by : CALLGUID = 7560370000010000005EB7870B10010A LEGID = 75603700-44e1a54f-6e007b-b10010a - [INBOUND]: with event type REINV_REJECTED

as we see re invite is getting rejected with SIP code 488, this may be because of Some Codec Negotiation issue or Call manager is rejecting call because no location bandwidth is available.

so you have to do some analysis and find out which one of them is causing this issue.

i see too many rejection with sip code 488 for the given call ID. i think as per your ICM script router requery is enabled and CVP is trying the same for all extension chosen by ICM but all are getting rejected with the given sip code.

Navaneethakrishnan Muralidharan · ‎10-31-2014

Chintan,

Thanks for your analysis. I will check on things which you refered.

Chintan Gajjar · ‎11-03-2014

sure, please keep this thread posted for the problem and solution.

Chintan

Sheraz Saeed Lodhi · ‎11-22-2015

Hi,

Did you manage to fixed this issue.

Chintan Gajjar · ‎11-24-2015

Share the CVP logs and problem detail.

Sheraz Saeed Lodhi · ‎11-25-2015

Hi Chintan,

I have figured it out basically we have two CCM clusters and becaus of one of the route pattern calls are going to other cluster and coming bac form there. Now i am trying to re-design my Dial Plan to fix this problem.

Sheraz Saeed Lodhi · ‎11-28-2015

Hi Folks,

I have a situation here. As i mentioned earlier i have two CCM clusters and call coming on 1st cluster going to 2nd cluster due to one of the route pattern i have in 1st CCM cluster. Now if i remove the agent extenstion range from 1st cluster in order to avoid the calls going to 2nd cluster no call land on agent and customer hear the CCM message that the number you have dialed doesn't exist please consult your administrator Or Operator.

What could be the cause of this.

shinajcm@gmail.com · ‎05-18-2018

Hi All,

Even i too have the same issue.

My scenario is Caller will not get the ringback tone it will be silence and the Agent line will be ringing and he/she will picks up the call, the same error i can see in the logs which is already provided in the post.

We removed and added the TCL file but the issue remains.

Kindly suggest.

Agents unable to pick calls while Call rings.