Transcoder not allocated for sip call

[Louis-Philippe Descamps]

hi

I have a xcoder to convert between g711/g729.

in my test, a 7940 (sccp) and 8945(sip or sccp) in a region that only allows g729

the voip is a sip trunk that only accepts g711

if i call from 7940, the call is successful because is allocating the mtp xcoder to transcode the call

if i call from 8945, the call fails because is not allocating the mtp xcoder

i aslo have a sip trunk to another cucm cluster that is sending calls to my cluster using g729. calls fail too

any idea?

attached some logs too

Thanks

[Abhay Singh Reyal]

Provide the below details for which you have collected the logs

Calling Number :- 

Called Number :- 

Time of call :-

Exact call flow :- 

Regards

Abhay

[Louis-Philippe Descamps]

please see the readme.txt file in the folder log. everything is in there. thanks

[Abhay Singh Reyal]

Below is the Incoming invite from the Phone
+++++
INVITE sip:447795827533@10.20.44.24;user=phone SIP/2.0
Via: SIP/2.0/TCP 10.24.128.86:40066;branch=z9hG4bK7644a74f
From: "London - Logged Out Phone" <sip:7114901@10.20.44.24>;tag=dceb94fc1aa5004464a544c7-1abc8080
To: <sip:447795827533@10.20.44.24>
Call-ID: dceb94fc-1aa50003-35e0fa56-3044a1c3@10.24.128.86
Max-Forwards: 70
Date: Thu, 29 Jun 2017 10:21:08 GMT
CSeq: 101 INVITE
User-Agent: Cisco-CP8945/9.4.2
Contact: <sip:88869fe4-56c0-778b-14ce-4198ec86baa2@10.24.128.86:40066;transport=tcp>
Expires: 180
Accept: application/sdp
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE,INFO
Remote-Party-ID: "London - Logged Out Phone" <sip:7114901@10.20.44.24>;party=calling;id-type=subscriber;privacy=off;screen=yes
Supported: replaces,join,sdp-anat,norefersub,resource-priority,extended-refer,X-cisco-callinfo,X-cisco-serviceuri,X-cisco-escapecodes,X-cisco-service-control,X-cisco-srtp-fallback,X-cisco-monrec,X-cisco-config,X-cisco-sis-7.0.0,X-cisco-xsi-8.5.1
Allow-Events: kpml,dialog
Recv-Info: conference
Recv-Info: x-cisco-conference
Content-Length: 425
Content-Type: application/sdp
Content-Disposition: session;handling=optional

v=0
o=Cisco-SIPUA 25654 0 IN IP4 10.24.128.86
s=SIP Call
t=0 0
m=audio 16384 RTP/AVP 0 8 18 102 9 116 101
c=IN IP4 10.24.128.86
a=trafficclass:conversational.audio.aq:admitted
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:102 L16/16000
a=rtpmap:9 G722/8000
a=rtpmap:116 iLBC/8000
a=fmtp:116 mode=20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv

Route list used is below
++++
73861762.003 |11:21:11.184 |AppInfo |RouteListControl::idle_CcSetupReq - RouteList(UK_SIP_RL_DEV), RouteListCdrc::create CI = 183593586 BRANCH = 0 mIsEmccHunt=0

You must be using SIP normalization script and it changes the invite to below and sends the same to 10.20.4.181
++++
73861790.001 |11:21:11.191 |AppInfo |SIPTcp - wait_SdlSPISignal: Outgoing SIP TCP message to 10.20.4.181 on port 5060 index 54047
[34093825,NET]
INVITE sip:07795827533@10.20.4.181:5060 SIP/2.0
Via: SIP/2.0/TCP 10.20.44.21:5060;branch=z9hG4bK22311b60fd00a5
From: Anonymous <sip:anonymous@anonymous.invalid>;tag=11483532~691d352a-3cdb-4674-beac-9a44bf063354-183593586
To: <sip:07795827533@10.20.4.181>
Date: Thu, 29 Jun 2017 10:21:11 GMT
Call-ID: aaec0b00-9541d497-184a6f-152c140a@10.20.44.21
Supported: timer,resource-priority,replaces
Min-SE: 500
User-Agent: Cisco-CUCM10.5
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY
CSeq: 101 INVITE
Expires: 180
Allow-Events: presence
Supported: X-cisco-srtp-fallback,X-cisco-original-called
Call-Info: <urn:x-cisco-remotecc:callinfo>;x-cisco-video-traffic-class=DESKTOP;x-cisco-qos-tcl=true
Cisco-Guid: 2867596032-0000065536-0000239762-0355210250
Session-Expires: 1800
P-Asserted-Identity: "London - Logged Out Phone" <sip:+442071054000@10.20.44.21>
Privacy: none
Remote-Party-ID: "London - Logged Out Phone" <sip:+442071054000@10.20.44.21>;party=calling;screen=yes;privacy=full
Contact: <sip:+442071054000@10.20.44.21:5060;transport=tcp>
Max-Forwards: 69
Content-Type: application/sdp
Content-Length: 296
Privacy: id

v=0
o=CiscoSystemsCCM-SIP 11483532 1 IN IP4 10.20.44.21
s=SIP Call
c=IN IP4 10.24.128.86
b=TIAS:8000
b=AS:8
t=0 0
m=audio 16384 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=trafficclass:conversational.audio.aq:admitted

And below you receive 488 Not Acceptable Here from 10.20.4.181
+++++
73861878.002 |11:21:11.462 |AppInfo |SIPTcp - wait_SdlReadRsp: Incoming SIP TCP message from 10.20.4.181 on port 5060 index 54047 with 377 bytes:
[34093843,NET]
SIP/2.0 488 Not Acceptable Here
Via: SIP/2.0/TCP 10.20.44.21:5060;branch=z9hG4bK22311b60fd00a5
From: Anonymous <sip:anonymous@anonymous.invalid>;tag=11483532~691d352a-3cdb-4674-beac-9a44bf063354-183593586
To: <sip:07795827533@10.20.4.181>;tag=gK06969422
Call-ID: aaec0b00-9541d497-184a6f-152c140a@10.20.44.21
CSeq: 101 INVITE
Reason: Q.850;cause=47
Content-Length: 0

That is why call got disconnected below.
++++
73861884.002 |11:21:11.463 |AppInfo |RouteListCdrc::null0_CcSetupReq - Terminating a call after the RouteListCdrc cannot find any more device.
73861884.003 |11:21:11.463 |AppInfo |RouteListCdrc::terminateCall - No more Routes in RouteListName = UK_SIP_RL_DEV. Rejecting the call
73861884.004 |11:21:11.463 |AppInfo |RouteListCdrc::terminateCall - Sending CcRejInd, with the cause code (47), to RouteListControl because all devices are busy/stopped.
73861884.005 |11:21:11.464 |AppInfo |GenAlarm: AlarmName = RouteListExhausted, subFac = CALLMANAGERKeyParam = , severity = 4, AlarmMsg = RouteListName : UK_SIP_RL_DEV, Reason=47, RouteGroups(UK_SIP_RG_DEV)
AppID : Cisco CallManager
ClusterID : QBE.UK.Cluster01
NodeID : GBSLOCCMLP0002

+++++++

SIP Dialogue did not get completed and there was no media exchange as CUCM received 488 Not Acceptable Here from 10.20.4.181

HTH

Regards

Abhay

Kindly rate all helpful posts !!!

[Louis-Philippe Descamps]

thank you for the logs but why the xcoder doesnt kick in and transcode the call like it does for a call using 7940?

[Rajan]

For the working call from 7940, could see all both g711 and g729 in the invite sent to the provider as below and hence g711ulaw negotiated successfully with the other side.

73886901.001 |11:22:26.428 |AppInfo |SIPTcp - wait_SdlSPISignal: Outgoing SIP TCP message to 10.20.4.181 on port 5060 index 54047
[34096116,NET]
INVITE sip:07795827533@10.20.4.181:5060 SIP/2.0
Via: SIP/2.0/TCP 10.20.44.21:5060;branch=z9hG4bK223224616fcec3
From: Anonymous <sip:anonymous@anonymous.invalid>;tag=11484248~691d352a-3cdb-4674-beac-9a44bf063354-183593588
To: <sip:07795827533@10.20.4.181>
Date: Thu, 29 Jun 2017 10:22:26 GMT
Call-ID: d7a02280-9541d4e2-184af1-152c140a@10.20.44.21
Supported: timer,resource-priority,replaces
Min-SE: 500
User-Agent: Cisco-CUCM10.5
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY
CSeq: 101 INVITE
Expires: 180
Allow-Events: presence
Supported: X-cisco-srtp-fallback,X-cisco-original-called
Call-Info: <urn:x-cisco-remotecc:callinfo>;x-cisco-video-traffic-class=VIDEO_UNSPECIFIED
Cisco-Guid: 3617596032-0000065536-0000239811-0355210250
Session-Expires: 1800
P-Asserted-Identity: "Logged Out Phone" <sip:+442071054000@10.20.44.21>
Privacy: none
Remote-Party-ID: "Logged Out Phone" <sip:+442071054000@10.20.44.21>;party=calling;screen=yes;privacy=full
Contact: <sip:+442071054000@10.20.44.21:5060;transport=tcp>
Max-Forwards: 70
Content-Type: application/sdp
Content-Length: 296
Privacy: id

v=0
o=CiscoSystemsCCM-SIP 11484248 1 IN IP4 10.20.44.21
s=SIP Call
c=IN IP4 10.20.44.46
b=TIAS:64000
b=AS:64
t=0 0
m=audio 16414 RTP/AVP 0 8 18 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

+

73888365.002 |11:22:30.637 |AppInfo |SIPTcp - wait_SdlReadRsp: Incoming SIP TCP message from 10.20.4.181 on port 5060 index 54047 with 809 bytes:
[34096209,NET]
SIP/2.0 183 Session Progress
Via: SIP/2.0/TCP 10.20.44.21:5060;branch=z9hG4bK223224616fcec3
From: Anonymous <sip:anonymous@anonymous.invalid>;tag=11484248~691d352a-3cdb-4674-beac-9a44bf063354-183593588
To: <sip:07795827533@10.20.4.181>;tag=gK06a33a3f
Call-ID: d7a02280-9541d4e2-184af1-152c140a@10.20.44.21
CSeq: 101 INVITE
Contact: <sip:07795827533@10.20.4.181:5060;transport=tcp>
Allow: INVITE,ACK,CANCEL,BYE,REGISTER,REFER,INFO,SUBSCRIBE,NOTIFY,PRACK,UPDATE,OPTIONS
Content-Length: 229
Content-Disposition: session; handling=required
Content-Type: application/sdp

v=0
o=Sonus_UAC 22426 9737 IN IP4 10.20.4.181
s=SIP Media Capabilities
c=IN IP4 10.20.4.164
t=0 0
m=audio 5666 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
a=ptime:20

So there is no need for a transcoder as such and nothing invoked for this working call.

HTH

Rajan

Pls rate all useful posts

[Louis-Philippe Descamps]

i just did a test call from 7940 and i can see the xcoder transcoding the call so yes there is a need of xcoding

sh sccp conn
sess_id    conn_id      stype mode     codec   sport rport ripaddr conn_id_tx

167774451  167772370    xcode sendrecv g729    16430 19154 10.24.128.83
167774451  167772369    xcode sendrecv g711u   16428 18392 10.20.4.164

Total number of active session(s) 1, and connection(s) 2

[Abhay Singh Reyal]

Your Transcoder [XCODER_GBCRO] is acting like an MTP here and that is why you see it invoking on the gateway. 

09056915.002 |11:22:26.420 |AppInfo |MediaTerminationPointControl(19)::getResourcesAllocated -- DeviceName=XCODER_GBCRO Ci=183593589 ResourceCount=1

Like mentioned earlier the failed call for which I have provided the analysis, does not reach to the media layer. 

As if now, the CUBE/SIP gateway [with IP 10.20.4.181] is sending a disconnect before negotiation can happen. 

CUCM sends Invite and receives 100 Trying and 488 Not Acceptable Here from 10.20.4.181

You can run debugs on the gateway to see what happens with the other leg pointing towards provider. 

HTH

Regards

Abhay

[Louis-Philippe Descamps]

10.20.4.181 is the sip provider. cucm is connected directly to it. no cube (i know ...)

but why the fail call doesnt reach to the media layer?

the failed call should invoke the xcoder and get the call transcoded from g729 to g711 so the sip provider can accept it

thank you

[Abhay Singh Reyal]

As mentioned by Rajan as well,

Capabilities supported by Phone are

a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000

and Provider sends capabilities as a=rtpmap:0 PCMU/8000.

As there is matching codec Xcoder is not needed for this purpose.

Check the MTP required on the SIP trunk and see what happens then, as in the working scenario Transcoder [XCODER_GBCRO] is acting like an MTP here.

Regards

Abhay

[Louis-Philippe Descamps]

hello

if i tick mtp required on the sip trunk then it will use a mtp for each call right?

when ticked it's working, it's also working when i use late offer on the sip trunk

for the 7940, you are saying i dont need a xcoder but when i do a test call i can see a transcoding session in xcoder

see below

sh sccp connections
sess_id    conn_id      stype mode     codec   sport rport ripaddr conn_id_tx

251659247  167772193    xcode sendrecv g729    16402 18260 10.24.128.83
251659247  134346830    xcode sendrecv g711u   16400 28404 10.20.4.164

Total number of active session(s) 1, and connection(s) 2

thank you

[Abhay Singh Reyal]

Yes, you are correct, if you select MTP required on the SIP Trunk, then it would invoke it on every single call.I knew it by invoking MTP the call would work in your scenario, as it is happening with 7941.

It is important to understand that the reason for Xcoder being invoked in working scenario is due to the Early Offer being used for the SIP trunk. Xcoder can act as an MTP as well and in your scenario as you are using Early offer for the calls, MTP [Actually the Xcoder] gets invoked. CUCM sends an invite to the Provider with early offer which triggers MTP. Here is the below snippet which confirms EO invoked the MTP allocation request. 

++++

09056894.000 |11:22:26.418 |SdlSig |MediaEarlyOfferConnectReq |wait |MediaCoordinator(10,100,141,1) |RSVPSession(10,100,107,590) |10,100,14,1.1700^*^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] Party1: MR=0 CI=183593587 audioCapCount=8 region=G729 xferMode=4 mrid=0 audioId=0 MMCap=0x1 sipConfig: BFCPAllowed=F IXAllowed=F activeCap=0 cryptoCapCount=0 flushIns=0 dtm.mode=0 dtm.CI=0 dtm.MTPForDTMF=F IFPid=(0,0,0,0) dtMedia=F honorCodec=F EOType=0 DTMF Caps(1,3,0,0,F) vCTClass=0 Party2: MR=0 CI=183593588 audioCapCount=0 region=DEV_Colt_UK xferMode=16 mrid=0 audioId=0 MMCap=0x1 sipConfig: BFCPAllowed=F IXAllowed=F activeCap=0 cryptoCapCount=0 flushIns=0 dtm.mode=0 dtm.CI=0 dtm.MTPForDTMF=F IFPid=(0,0,0,0) dtMedia=F honorCodec=F EOType=2 DTMF Caps(3,1,0,1,F) vCTClass=4 videoCall=F confID =0 ci =0 capCt =0 reg= mtpType =2 agentCt =0 mmCapSet=0 agentAllo =0 RemoAgent=F DevCap=0 ipAddrMode=0 mtpInsReason=32 hasSDP=F
09056894.001 |11:22:26.418 |Created | | |MediaManager(10,100,140,373) |MediaCoordinator(10,100,141,1) | |NumOfCurrentInstances: 2

09056894.002 |11:22:26.418 |AppInfo |SIG-MediaCoordinator-wait_MediaEarlyOfferConnectRequest - new MediaManager(140,373) started for RSVP Session (107,590)
09056895.000 |11:22:26.418 |SdlSig |MediaEarlyOfferConnectReq |waitEOConnectRequest |MediaManager(10,100,140,373) |MediaCoordinator(10,100,141,1) |10,100,14,1.1700^*^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] Party1: MR=0 CI=183593587 audioCapCount=8 region=G729 xferMode=4 mrid=0 audioId=0 MMCap=0x1 sipConfig: BFCPAllowed=F IXAllowed=F activeCap=0 cryptoCapCount=0 flushIns=0 dtm.mode=0 dtm.CI=0 dtm.MTPForDTMF=F IFPid=(0,0,0,0) dtMedia=F honorCodec=F EOType=0 DTMF Caps(1,3,0,0,F) vCTClass=0 Party2: MR=0 CI=183593588 audioCapCount=0 region=DEV_Colt_UK xferMode=16 mrid=0 audioId=0 MMCap=0x1 sipConfig: BFCPAllowed=F IXAllowed=F activeCap=0 cryptoCapCount=0 flushIns=0 dtm.mode=0 dtm.CI=0 dtm.MTPForDTMF=F IFPid=(0,0,0,0) dtMedia=F honorCodec=F EOType=2 DTMF Caps(3,1,0,1,F) vCTClass=4 videoCall=F confID =0 ci =0 capCt =0 reg= mtpType =2 agentCt =0 mmCapSet=0 agentAllo =0 RemoAgent=F DevCap=0 ipAddrMode=0 mtpInsReason=32 hasSDP=F

09056895.001 |11:22:26.418 |AppInfo |SIG-MediaManager-(373)::sendMTPXcoderAllocationRequest, allocate MTP(ci=183593589), suppressMatchCap=0, mrgl=NULL_LIST:cd0e3e53-11e8-7346-f7d1-8d84ed701eaa DeviceCapsReqdMask=0x30
09056895.002 |11:22:26.418 |AppInfo |SIG-MediaManager-(373)::waitEOConnectReq_MediaEarlyOfferConnectReq, deviceCaps=48, getPortCapRequested=1, GetPortCapMandatory=1, resCount=1

Due to this you are able to see the usage of media resource. 

HTH

Regards

Abhay

Kindly rate all helpful posts !!!

[Louis-Philippe Descamps]

any suggestion on how to invoke the xcoder when g729 is presented to to the sip trunk without having mtp required ticked?

thanks

[Abhay Singh Reyal]

You seem to be getting confused between capabilities that a device has and region settings. You are not presenting G729 as a capability of a device.

Capabilities sent by SIP Phones are below

a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:102 L16/16000
a=rtpmap:9 G722/8000
a=rtpmap:116 iLBC/8000

Regions specify the maximum bit rates for audio and video calls within a region and between existing regions.By configuring regions on CUCM, you are not changing the capability of a device, it is just that you are specifying bit rates for audio and video calls to be used. 

HTH

Regards

Abhay

[Abhay Singh Reyal]

Transcoder will come into picture during the Media layer when Mediamanager layer will check the capabilities of both parties. As if now there was no media negotiation and that is why Xcoder did not get invoked. Sharing the example below 

++++++

55833664.004 |13:58:59.776 |AppInfo |DET-MediaManager-(646172)::preCheckCapabilities, region1=YYY, region2=XXX, Pty1 capCount=1 (Cap,ptime)= (2,20), Pty2 capCount=1 (Cap,ptime)= (4,80)

55833664.006 |13:58:59.776 |AppInfo |DET-MediaManager-(646172)::preCheckCapabilities, caps mismatch! Xcoder Reqd. kbps(64), filtered A[capCount=1 (Cap,ptime)= (2,20)], B[capCount=1 (Cap,ptime)= (4,80)] allowMTP=1 numXcoderRequired=1 xcodingSide=1
55833664.007 |13:58:59.776 |AppInfo |DET-MediaManager-(646172)::prepareInitialConnectionList, Party1CapCount=1 Party2CapCount=1 XcoderRequired=1 xcodingSide=1 allowMTP=1

In your scenario the call does not reach that point and gets disconnected with the error mentioned earlier.

HTH

Regards

Abhay