[cisco-voip] SIP call issue, call get connected after 10 sec.

Wed Apr 2 10:48:19 EDT 2014

Try running "debug mgcp packet" to see if it is actually relaying the
digits via Notify messages on the MGCP leg.

Brian

On Wed, Apr 2, 2014 at 2:48 AM, Rajkumar Yadav <rajkumaryadav at y7mail.com>wrote:

> Hi Brian,
>
> As what we have seen that MGCP gateway did not even received all the
> digits pressed by the user.
>
> However debug ccapi inout is showing that it's relaying the digit (twice).
>
> however the MGCP gateway is not able to catch that.
>
> Attached is the log for the same.
>
> Please suggest.
>
> Kind Regards,
> Raaj.
>
>   ------------------------------
>  *From:* Brian Meade <bmeade90 at vt.edu>
> *To:* Rajkumar Yadav <rajkumaryadav at y7mail.com>
> *Cc:* Amit Kumar <amit3.kum at gmail.com>; "Heim, Dennis" <
> Dennis.Heim at wwt.com>; "cisco-voip at puck.nether.net" <
> cisco-voip at puck.nether.net>
> *Sent:* Tuesday, 1 April 2014 8:15 PM
>
> *Subject:* Re: [cisco-voip] SIP call issue, call get connected after 10
> sec.
>
> Raaj,
>
> I looked at these traces and see the MTP is being pulled in due to the
> early offer configuration but would also be needed for the DTMF mismatch:
> 20:20:05.285 |MediaManager(710186)::wait_AuConnectRequest,
> CI(48708178,48708179), capCount(11,1), mcNodeId(0,0), xferMode(12,16),
> reConnectType(0), mrid (0, 0) IFCreated(0 0) proIns(0 0), AC(0,0)
> party1DTMF(1 1 0 1 0) party2DTMF(3 2 101 1 0),reConnFlag=0, connType(3,3),
> IFHand(0,0),MTP(0,0),MRGL(aaf6462d-d96d-8d78-e98b-f96a899cd470,aaf6462d-d96d-8d78-e98b-f96a899cd470)
> videoCap(0 0), mmCallType(0),FS(0,0) IpAddrMode(0 0) aPid(2, 135, 1366),
> bPid(2, 68, 209650) EOType(0 2)|2,100,57,1.1030654^10.14.0.46^*
>
> 20:20:05.285 |MediaManager(710186)::isMTPNeededForDTMF,
> isMTPNeeded(1)|2,100,57,1.1030654^10.14.0.46^*
>
> party1 only supports out of band and party 2 only supports in-band.  It
> looks like the SIP Trunk has a DTMF Preference hard set as well.
>
> As far as only getting 1 digit, I only see one digit actually being sent
> by the MGCP gateway:
> 20:20:11.021 |MGCPHandler received msg from: 10.128.0.2
> NTFY 200530244 S0/SU0/DS1-0/11 at 10.128.0.2 MGCP 0.1
> N: ca at 10.128.4.10:2427
> X: b
> O: D/1
> |2,100,152,1.5777096^10.128.0.2^*
>
>
> CUCM sends a request notification to continue receiving any future digits:
> 20:20:11.022 |MGCPHandler send msg SUCCESSFULLY to: 10.128.0.2
> RQNT 1863107 S0/SU0/DS1-0/11 at 10.128.0.2 MGCP 0.1
> X: b
> R: D/[0-9ABCD*#]
> Q: process,loop
>
> But the gateway never seems to send any further digits.
>
> Brian
>
>
>
> On Tue, Apr 1, 2014 at 2:13 AM, Rajkumar Yadav <rajkumaryadav at y7mail.com>wrote:
>
> Hi Brian,
>
> I got the traces  for the call without MTP checked.
>
> The call went good but the DTMF issue came up.
>
> Please find the attched logs.
>
>
> 20:20:04.259
> |//SIP/SIPCdpc(2,68,209650)/ci=48708179/ccbId=943721/scbId=0/StartTransition:
> requireInactiveSDPForMidcallMediaChange=0,
> isTrunkEnabledForVoiceEO=1|2,100,68,209650.1^*^*
>
> Here the EO is working due to the SIP profile for that SIP trunk having EO
> provisioned and MTP unchecked.
>
>
>
> 20:20:04.259 |MediaUtility::isMTPNeededForDTMFBeforeCutThru, there is DTMF
> MISMATCH, party1SuppDTMFMethod=1 party2DtmfConfig=3|*^*^*
>
>  In the traces the MTP is allocated too.
>
> 20:20:04.261 |MRM::updateMtpCounter devName=MTP_3,
> countChange=1|2,100,153,1.1418009^10.128.0.2^*
> 20:20:04.261 |MRM::updateXcodeCounter devName=MTP_3,
> countChange=1|2,100,153,1.1418009^10.128.0.2^*
>
>
>
> However as per the person having issue that only Digit 1 is passed on to
> the IVR system (SIP phone) and rest 8 digits are not.
>
>
> DTMFMTPSide(1), mtpNeededForDtmf(1) firstconnDTMF(2)
> secondconnDTMF(1)|2,100,57,1.1030654^10.14.0.46^*
> 20:20:05.285 |MediaManager(710186)::needToInjectDigitsToMTP,
> isMTPNeededDueToDTMFCapMismatch dtmfMTPSide(1)index(0)
> injecttoMTP(1)|2,100,57,1.1030654^10.14.0.46^*
> 20:20:05.285 |MediaManager(710186)::can2833beNegotiatedForCall, --2833 can
> nto be negotiated for the call|2,100,57,1.1030654^10.14.0.46^*
> 20:20:05.285 |MediaManager(710186)::setSubscriptionInfo, subscribe(1),
> passthru(0), inject(1) index(0)|2,100,57,1.1030654^10.14.0.46^*
> 20:20:05.285
> |MediaManager(710186)::allocatedMtpSupportsAnyDtmfCapability|2,100,57,1.1030654^10.14.0.46^*
> 20:20:05.285 |MediaManager(710186)::DTMFMTPSide(1), mtpNeededForDtmf(1)
> firstconnDTMF(2) secondconnDTMF(1)|2,100,57,1.1030654^10.14.0.46^*
> 20:20:05.285 |MediaManager(710186)::needToInjectDigitsToMTP,
> isMTPNeededDueToDTMFCapMismatch dtmfMTPSide(1)index(1)
> injecttoMTP(0)|2,100,57,1.1030654^10.14.0.46^*
> 20:20:05.285 |MediaManager(710186)::can2833beNegotiatedForCall, --2833 can
> nto be negotiated for the call|2,100,57,1.1030654^10.14.0.46^*
>
>
> Please suggest and have a look into the traces for more detail.
>
> Kind Regards,
> Raaj.
>
>
>   ------------------------------
>  *From:* Brian Meade <bmeade90 at vt.edu>
> *To:* Rajkumar Yadav <rajkumaryadav at y7mail.com>
> *Cc:* Amit Kumar <amit3.kum at gmail.com>; "Heim, Dennis" <
> Dennis.Heim at wwt.com>; "cisco-voip at puck.nether.net" <
> cisco-voip at puck.nether.net>
> *Sent:* Monday, 31 March 2014 7:07 PM
>
> *Subject:* Re: [cisco-voip] SIP call issue, call get connected after 10
> sec.
>
> Raaj,
>
> CUCM should dynamically insert an MTP when needed for a DTMF mismatch.
>  Would probably need to investigate what is happening when you leave MTP
> Required unchecked.
>
> MTP Required overrides the normal Early Offer process when turned on via
> the SIP Profile on the trunk.  It still results in an Early Offer invite
> though but through a different process.
>
> Brian
>
>
> On Mon, Mar 31, 2014 at 12:07 AM, Rajkumar Yadav <rajkumaryadav at y7mail.com
> > wrote:
>
> we do had unchecked the MTP and tested the call, all calls were properly
> treated.
>
> However the DTMF issue came up, since the Genesys side SIP softphone is
> supporting only inband (RFC 2833) and MGCP gateway would be configured with
> OOB DTMF method.
>
> (since SCCP phone support both DTMF method can we change the dtmf method
> in MGCP gateway itself)
>
> Also from the traces it fails to do EO due to configuration issue.
>
> 16:15:17.424
> |//SIP/SIPCdpc(2,68,205069)/ci=48665604/ccbId=918923/scbId=0/isTrunkConfiguredforVoiceEO:
> Trunk configured for EO but EO will not be effective due to other
> configuration - MTPRequired=1 IPAddrMode=0
> MediaPreference=0|2,100,68,205069.1^*^*
>
>
>
>
> Kind Regards,
> Raaj
>
>
>
>   ------------------------------
>  *From:* Brian Meade <bmeade90 at vt.edu>
> *To:* Amit Kumar <amit3.kum at gmail.com>
> *Cc:* "Heim, Dennis" <Dennis.Heim at wwt.com>; "cisco-voip at puck.nether.net" <
> cisco-voip at puck.nether.net>; Rajkumar Yadav <rajkumaryadav at y7mail.com>
> *Sent:* Monday, 31 March 2014 9:12 AM
> *Subject:* Re: [cisco-voip] SIP call issue, call get connected after 10
> sec.
>
> The only difference I was able to find between the working and nonworking
> is that the Create Connection Response is received before the outgoing
> invite in the working scenario:
> Create Connection:
> 16:15:17.423 |MGCPHandler send msg SUCCESSFULLY to: 10.128.0.2
> CRCX 1822574 S0/SU0/DS1-0/11 at 10.128.0.2 MGCP 0.1
> C: D000000002e69403000000F58000051d
> X: b
> L: p:20, a:PCMU, s:off, t:b8
> M: recvonly
> R: D/[0-9ABCD*#]
> Q: process,loop
> |2,100,153,1.1390558^10.128.0.2^*
>
> Create Connection Response:
>  16:15:17.433 |MGCPHandler received msg from: 10.128.0.2
> 200 1822574 OK
> I: D2D7
>
> v=0
> c=IN IP4 10.128.0.2
> m=audio 19388 RTP/AVP 0 100
> a=rtpmap:100 X-NSE/8000
> a=fmtp:100 192-194,200-202
> a=X-sqn:0
> a=X-cap: 1 audio RTP/AVP 100
> a=X-cpar: a=rtpmap:100 X-NSE/8000
> a=X-cpar: a=fmtp:100 192-194,200-202
> a=X-cap: 2 image udptl t38
> |2,100,152,1.5650860^10.128.0.2^*
>
> Outgoing Invite:
> 16:15:17.468 |//SIP/SIPTcp/wait_SdlSPISignal: Outgoing SIP TCP message to
> 10.14.0.46 on port 5460 index 2245
>  [3153414,NET]
> INVITE sip:2600 at 10.14.0.46:5460 SIP/2.0
> Via: SIP/2.0/TCP 10.128.4.10:5060;branch=z9hG4bK9ddfe2fc1b6c2
> From: <sip:226241315 at 10.128.4.10
> >;tag=918923~30427db0-275c-441d-b31f-5c77cf1a9379-48665604
> To: <sip:2600 at 10.14.0.46>
> Date: Sat, 29 Mar 2014 20:15:17 GMT
> Call-ID: d6d8fe00-337129d5-34100-a04800a at 10.128.4.10
> Supported: timer,resource-priority,replaces
> Min-SE:  1800
> User-Agent: Cisco-CUCM8.5
> Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER,
> SUBSCRIBE, NOTIFY
> CSeq: 101 INVITE
> Expires: 300
> Allow-Events: presence
> Supported: X-cisco-srtp-fallback
> Supported: Geolocation
> Cisco-Guid: 3604545024-0000065536-0000204906-0168067082
> Session-Expires:  1800
> P-Asserted-Identity: <sip:226241315 at 10.128.4.10>
> Remote-Party-ID: <sip:226241315 at 10.128.4.10
> >;party=calling;screen=yes;privacy=off
> Contact: <sip:226241315 at 10.128.4.10:5060;transport=tcp>
> Max-Forwards: 70
> Content-Type: application/sdp
> Content-Length: 210
>
> v=0
> o=CiscoSystemsCCM-SIP 2000 1 IN IP4 10.128.4.10
> s=SIP Call
> c=IN IP4 10.128.4.10
> t=0 0
> m=audio 28102 RTP/AVP 0 101
> a=rtpmap:0 PCMU/8000
> a=ptime:20
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-15
>
>
> Here's what the nonworking looks like:
> Create Connection:
> 16:17:47.391 |MGCPHandler send msg SUCCESSFULLY to: 10.128.4.12
> CRCX 1822579 S0/SU3/DS1-0/14 at 10.128.4.12 MGCP 0.1
> C: D000000002e69406000000F58000048a
> X: e
> L: p:20, a:PCMU, s:off, t:b8
> M: recvonly
> R: D/[0-9ABCD*#]
> Q: process,loop
> |2,100,153,1.1390562^10.128.4.12^*
>
> OpenLogicalChannelAck from MTP:
> 383984245 |2014/03/29 16:17:47.406 |100 |SdlSig-I
>  |MXAgenaOpenLogicalChannelAck           |outCall_waitOLCAck
> |SIPCdpc(2,100,68,205070)
> |MediaTerminationPointControl(1,100,122,3)
> |1,100,50,1.79616142^10.128.4.10^MTP_3    |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0]
> rc=0 partyId=34213137 port=28106 ipAddrType=0 ipv4=10.128.4.10
>
> Outgoing invite with a=inactive:
> 16:17:47.407 |//SIP/SIPTcp/wait_SdlSPISignal: Outgoing SIP TCP message to
> 10.14.0.46 on port 5460 index 2245
> [3153448,NET]
> INVITE sip:2600 at 10.14.0.46:5460 SIP/2.0
> Via: SIP/2.0/TCP 10.128.4.10:5060;branch=z9hG4bK9de045e6642c
> From: <sip:226241315 at 10.128.4.10
> >;tag=918936~30427db0-275c-441d-b31f-5c77cf1a9379-48665607
> To: <sip:2600 at 10.14.0.46>
> Date: Sat, 29 Mar 2014 20:17:47 GMT
> Call-ID: 30412d00-33712a6b-34104-a04800a at 10.128.4.10
> Supported: timer,resource-priority,replaces
> Min-SE:  1800
> User-Agent: Cisco-CUCM8.5
> Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER,
> SUBSCRIBE, NOTIFY
> CSeq: 101 INVITE
> Expires: 300
> Allow-Events: presence
> Supported: X-cisco-srtp-fallback
> Supported: Geolocation
> Cisco-Guid: 0809577728-0000065536-0000204907-0168067082
> Session-Expires:  1800
> P-Asserted-Identity: <sip:226241315 at 10.128.4.10>
> Remote-Party-ID: <sip:226241315 at 10.128.4.10
> >;party=calling;screen=yes;privacy=off
> Contact: <sip:226241315 at 10.128.4.10:5060;transport=tcp>
> Max-Forwards: 70
> Content-Type: application/sdp
> Content-Length: 222
>
> v=0
> o=CiscoSystemsCCM-SIP 2000 1 IN IP4 10.128.4.10
> s=SIP Call
> c=IN IP4 10.128.4.10
> t=0 0
> m=audio 28106 RTP/AVP 0 101
> a=rtpmap:0 PCMU/8000
> a=ptime:20
> a=inactive
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-15
>
> Create connection response comes after this:
> 16:17:47.408 |MGCPHandler received msg from: 10.128.4.12
> 200 1822579 OK
> I: 1430EE
>
> v=0
> c=IN IP4 10.128.4.12
> m=audio 18048 RTP/AVP 0 100
> a=rtpmap:100 X-NSE/8000
> a=fmtp:100 192-194
>
> It could be a potential race condition.  He's running 8.5.1 base so
> definitely huge bug potential here.  I found
> https://tools.cisco.com/bugsearch/bug/CSCtk77040 which seems to be a good
> match based on the conditions.  I would try getting rid of the MTP Required
> on the SIP Trunk and see if that resolves the issue.  If so, you should
> probably upgrade to the latest 8.5.1 SU if you need to send Early Media.
>
> -Brian Meade
>
>
> On Sun, Mar 30, 2014 at 3:38 PM, Amit Kumar <amit3.kum at gmail.com> wrote:
>
> Seems to be 8.5.1 , 16:11:57.327 HDR|03/29/2014
> CCM,StandAloneCluster,10.128.4.10,Detailed,8.5.1.10000-26|*^*^*
> 16:11:57.327 |
>
> checking traces Raj
>
>
> On Sun, Mar 30, 2014 at 11:18 PM, Heim, Dennis <Dennis.Heim at wwt.com>wrote:
>
> CUCM version is?
>
> *Dennis Heim | Solution Architect (Collaboration)*
> World Wide Technology, Inc. | 314-212-1814
>
> *PS Engineering: ** Innovate & Ignite.*
>
>
> *From:* cisco-voip [mailto:cisco-voip-bounces at puck.nether.net] *On Behalf
> Of *Rajkumar Yadav
> *Sent:* Sunday, March 30, 2014 3:16 AM
> *To:* cisco-voip at puck.nether.net
> *Subject:* [cisco-voip] SIP call issue, call get connected after 10 sec.
>
> Hi,
>
> Please kind request to help me for the attached logs.
>
> setup is like this
>
> PSTN--MGCP---CUCM--SIP Trunk--Genesys Contact center.
>
> Option selected in SIP trunk is MTP checked (DTMF interoperabiltiy), from
> SIP profile Early offer.
>
> Issue is sometime call goes good and sometime call connected after 10 sec.
>
> We get media inactive and reinvite makes the connection goes good.
>
> For good call     Call-ID: d6d8fe00-337129d5-34100-a04800a at 10.128.4.10
>
> For Bad call       Call-ID: 30412d00-33712a6b-34104-a04800a at 10.128.4.10
>
> Kind Regards,
> Raaj.
>
>
>
> _______________________________________________
> cisco-voip mailing list
> cisco-voip at puck.nether.net
> https://puck.nether.net/mailman/listinfo/cisco-voip
>
>
>
>
> _______________________________________________
> cisco-voip mailing list
> cisco-voip at puck.nether.net
> https://puck.nether.net/mailman/listinfo/cisco-voip
>
>
>
>
>
>
>
>
>
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://puck.nether.net/pipermail/cisco-voip/attachments/20140402/10801781/attachment.html>