06-06-2013 06:27 AM - edited 03-12-2019 10:01 AM
DTMF plays a key role in telephony solution. This document attempts to look at different DTMF transmission methods and how to troubleshoot these. This document looks at a few CUCM traces, gateway debugs and wireshark captures to get a detailed understanding of how DTMF is sent from each endpoint
Two key elements to consider is DTMF negotiation:
1. DTMF supported by the Phone, IVR, or Unity Connection
2. DTMF negotiated between CUCM and the associated gateway (sip trunk, h323 gateway or mgcp gateway)
DTMF mismatch often arise from different DTMF method supported by the two endpoints in a call. By endpoints here I mean a Phone/IVR/voicemail application and the gateway/trunk
We will be looking at different DTMF scenarios and look at both cucm and gateway logs
In all these test CUCM SIP trunk dtmf method is set to No preference
Jabber4windows--SIP----CUCM--SIP---Gateway---E1--PSTN
dial-peer voice 3 voip
incoming called number .
no vad
dtmf-relay sip-kpml
10:59:28.180 |//SIP/SIPUdp/wait_SdlSPISignal: Outgoing SIP UDP message to 172.10.104.32:[5060]:
[311079,NET]
INVITE sip:908446930701@172.10.104.32:5060 SIP/2.0
Via: SIP/2.0/UDP 172.10.40.11:5060;branch=z9hG4bK25e275fb33fa2
From: "Deji okanlawon" <sip:01215246408@172.10.40.11>;tag=155101~ffa80926-5fac-4dd6-b405-2dbbc56ae9a2-544608971
To: <sip:908446930701@172.10.104.32>
Date: Fri, 24 May 2013 09:59:28 GMT
Call-ID: 9de24580-19f13a00-25c63-b28690a@172.10.40.11
Supported: timer,resource-priority,replaces
Min-SE: 1800
User-Agent: Cisco-CUCM8.6
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY
CSeq: 101 INVITE
Expires: 180
Allow-Events: presence, kpml
Supported: X-cisco-srtp-fallback
Supported: Geolocation
Call-Info: <sip:172.10.40.11:5060>;method="NOTIFY;Event=telephone-event;Duration=500"
Cisco-Guid: 2648851840-0000065536-0000000282-0187197706
Session-Expires: 84600
P-Asserted-Identity: "Deji okanlawon" <sip:01215246408@172.10.40.11>
Remote-Party-ID: "Deji okanlawon" <sip:01215246408@172.10.40.11>;party=calling;screen=yes;privacy=off
Contact: <sip:01215246408@172.10.40.11:5060>;video;bfcp
Max-Forwards: 69
Content-Length: 0
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 172.10.40.11:5060;branch=z9hG4bK25e275fb33fa2
From: "Deji okanlawon" <sip:01215246408@172.10.40.11>;tag=155101~ffa80926-5fac-4dd6-b405-2dbbc56ae9a2-544608971
To: <sip:908446930701@172.10.104.32>;tag=4F448086-750
Date: Fri, 24 May 2013 09:59:28 GMT
Call-ID: 9de24580-19f13a00-25c63-b28690a@172.10.40.11
CSeq: 101 INVITE
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: kpml, telephone-event
Remote-Party-ID: <sip:08446930701@172.10.104.32>;party=called;screen=no;privacy=off
Contact: <sip:908446930701@172.10.104.32:5060>
Supported: sdp-anat
Server: Cisco-SIPGateway/IOS-12.x
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 217
v=0
o=CiscoSystemsSIP-GW-UserAgent 9228 1435 IN IP4 172.10.104.32
s=SIP Call
c=IN IP4 172.10.104.32
t=0 0
m=audio 16384 RTP/AVP 18
c=IN IP4 172.10.104.32
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=ptime:20
NB: The "mLocalDtmfCaps" (underlined) refers to the dtmf methods supported by CUCM...Here we see that CUCM supports unsolicited, KPML and RTP-NTE
On the right hand side after the mEndppointsDtmfCaps (highlighted red) refers to the dtmf supported by the gateway: which we can see is only KPML. We can see in the trace CUCM detects no inband support but detects KPML support
10:59:28.427 |//SIP/SIPCdpc(22,74,282)/ci=544608971/ccbId=155101/scbId=0/updateAllowedMethods: mEndpointAllowedMethods=07ff|22,100,230,1.155730^172.10.104.32^*
10:59:28.427 |setEndpointsDtmfCaps: KPML Supported.|*^*^*
10:59:28.427 |setEndpointsDtmfCaps: Detected NO inband DTMF support.|*^*^*
10:59:28.427 |SIP DTMF Info: mLocalDtmfCaps...UNSOL=1, KPML=1, Inband=1(101) mEndppointsDtmfCaps...UNSOL=0, KPML=1, Inband=0(0) mDefaultTelephonyEvent=101, mDtmfPreference=1, mMtpAllocated=0|*^*^*
NB: The ACK sent out to the gateway by CUCM doesn’t advertise RFC2833++
10:59:30.684 |//SIP/SIPUdp/wait_SdlSPISignal: Outgoing SIP UDP message to 172.10.104.32:[5060]:
[311084,NET]
ACK sip:908446930701@172.10.104.32:5060 SIP/2.0
Via: SIP/2.0/UDP 172.10.40.11:5060;branch=z9hG4bK25e2860b3d2ab
From: "Deji okanlawon" <sip:01215246408@172.10.40.11>;tag=155101~ffa80926-5fac-4dd6-b405-2dbbc56ae9a2-544608971
To: <sip:908446930701@172.10.104.32>;tag=4F448086-750
Date: Fri, 24 May 2013 09:59:28 GMT
Call-ID: 9de24580-19f13a00-25c63-b28690a@172.10.40.11
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: presence, kpml
Content-Type: application/sdp
Content-Length: 182
v=0
o=CiscoSystemsCCM-SIP 155101 1 IN IP4 172.10.40.11
s=SIP Call
c=IN IP4 172.10.40.190
t=0 0
m=audio 23012 RTP/AVP 18
a=rtpmap:18 G729/8000
a=ptime:20
a=fmtp:18 annexb=no
10:59:30.695 |//SIP/SIPUdp/wait_UdpDataInd: Incoming SIP UDP message size 906 from 172.10.104.32:[52877]:
[311085,NET]
SUBSCRIBE sip:01215246408@172.10.40.11:5060 SIP/2.0
Via: SIP/2.0/UDP 172.10.104.32:5060;branch=z9hG4bKC1AF6
From: <sip:908446930701@172.10.104.32>;tag=4F448086-750
To: "Deji okanlawon" <sip:01215246408@172.10.40.11>;tag=155101~ffa80926-5fac-4dd6-b405-2dbbc56ae9a2-544608971
Call-ID: 9de24580-19f13a00-25c63-b28690a@172.10.40.11
CSeq: 101 SUBSCRIBE
Max-Forwards: 70
Date: Fri, 24 May 2013 09:59:30 GMT
User-Agent: Cisco-SIPGateway/IOS-12.x
Event: kpml
Expires: 7200
Contact: <sip:172.10.104.32:5060>
Content-Type: application/kpml-request+xml
Content-Length: 327
<?xml version="1.0" encoding="UTF-8"?><kpml-request xmlns="urn:ietf:params:xml:ns:kpml-request" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="urn:ietf:params:xml:ns:kpml-request kpml-request.xsd" version="1.0"><pattern persist="persist"><regex tag="dtmf">[x*#ABCD]</regex></pattern></kpml-request>
10:59:30.695 |//SIP/SIPUdp/wait_SdlSPISignal: Outgoing SIP UDP message to 172.10.104.32:[5060]:
[311086,NET]
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.10.104.32:5060;branch=z9hG4bKC1AF6
From: <sip:908446930701@172.10.104.32>;tag=4F448086-750
To: "Deji okanlawon" <sip:01215246408@172.10.40.11>;tag=155101~ffa80926-5fac-4dd6-b405-2dbbc56ae9a2-544608971
Date: Fri, 24 May 2013 09:59:30 GMT
Call-ID: 9de24580-19f13a00-25c63-b28690a@172.10.40.11
CSeq: 101 SUBSCRIBE
Contact: <sip:01215246408@172.10.40.11:5060>
Expires: 7200
Content-Length: 0
NOTIFY sip:172.10.104.32:5060 SIP/2.0
Via: SIP/2.0/UDP 172.10.40.11:5060;branch=z9hG4bK25e29422465a0
From: "Deji okanlawon" <sip:01215246408@172.10.40.11>;tag=155101~ffa80926-5fac-4dd6-b405-2dbbc56ae9a2-544608971
To: <sip:908446930701@172.10.104.32>;tag=4F448086-750
Call-ID: 9de24580-19f13a00-25c63-b28690a@172.10.40.11
CSeq: 102 NOTIFY
Max-Forwards: 70
Date: Fri, 24 May 2013 09:59:30 GMT
User-Agent: Cisco-CUCM8.6
Event: kpml
Subscription-State: active;expires=7200
Contact: <sip:01215246408@172.10.40.11:5060>
P-Asserted-Identity: "Deji okanlawon" <sip:01215246408@172.10.40.11>
Content-Length: 0
10:59:30.705 |//SIP/SIPUdp/wait_UdpDataInd: Incoming SIP UDP message size 380 from 172.10.104.32:[5060]:
[311088,NET]
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.10.40.11:5060;branch=z9hG4bK25e29422465a0
From: "Deji okanlawon" <sip:01215246408@172.10.40.11>;tag=155101~ffa80926-5fac-4dd6-b405-2dbbc56ae9a2-544608971
To: <sip:908446930701@172.10.104.32>;tag=4F448086-750
Date: Fri, 24 May 2013 09:59:30 GMT
Call-ID: 9de24580-19f13a00-25c63-b28690a@172.10.40.11
CSeq: 102 NOTIFY
Content-Length: 0
10:59:35.969 |//SIP/SIPCdpc(22,74,282)/ci=544608971/ccbId=155101/scbId=0/star_CcUserInfoReq: Outbound DTMF method selected is 3. Digit=0 and isMTPPassingThru2833=0|23,100,63,1.1151^172.10.40.190^*
NB: we do not see the “KeypadButton” message in this trace because the IP phone is not registered to the CUCM in the sip trunk CUCM group. This trace exists on that CUCM.
10:59:35.969 |//SIP/SIPCdpc(22,74,282)/ci=544608971/ccbId=155101/scbId=155102/sendDtmfViaKpml: ccUserInfoReq.digit=0|23,100,63,1.1151^172.10.40.190^*
10:59:35.969 |//SIP/SIPCdpc(22,74,282)/ci=544608971/ccbId=155101/scbId=155102/sendDtmfViaKpml: notifyContent->mDigits=0|23,100,63,1.1151^172.10.40.190^*
To see the actual digit look into the xml encoding of the NOTIFY message, you can see digit=0
10:59:35.969 |//SIP/SIPUdp/wait_SdlSPISignal: Outgoing SIP UDP message to 172.10.104.32:[5060]:
[311089,NET]
NOTIFY sip:172.10.104.32:5060 SIP/2.0
Via: SIP/2.0/UDP 172.10.40.11:5060;branch=z9hG4bK25e2a78a7f435
From: "Deji okanlawon" <sip:01215246408@172.10.40.11>;tag=155101~ffa80926-5fac-4dd6-b405-2dbbc56ae9a2-544608971
To: <sip:908446930701@172.10.104.32>;tag=4F448086-750
Call-ID: 9de24580-19f13a00-25c63-b28690a@172.10.40.11
CSeq: 103 NOTIFY
Max-Forwards: 70
Date: Fri, 24 May 2013 09:59:35 GMT
User-Agent: Cisco-CUCM8.6
Event: kpml
Subscription-State: active;expires=7195
Contact: <sip:01215246408@172.10.40.11:5060>
P-Asserted-Identity: "Deji okanlawon" <sip:01215246408@172.10.40.11>
Content-Type: application/kpml-response+xml
Content-Length: 336
<?xml version="1.0" encoding="UTF-8" ?>
<kpml-response xmlns="urn:ietf:params:xml:ns:kpml-response" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="urn:ietf:params:xml:ns:kpml-response kpml-response.xsd" code="200" digits="0" forced_flush="false" suppressed="false" tag="dtmf" text="Success" version="1.0"/>
10:59:35.979 |//SIP/SIPUdp/wait_UdpDataInd: Incoming SIP UDP message size 380 from 172.10.104.32:[5060]:
[311090,NET]
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.10.40.11:5060;branch=z9hG4bK25e2a78a7f435
From: "Deji okanlawon" <sip:01215246408@172.10.40.11>;tag=155101~ffa80926-5fac-4dd6-b405-2dbbc56ae9a2-544608971
To: <sip:908446930701@172.10.104.32>;tag=4F448086-750
Date: Fri, 24 May 2013 09:59:35 GMT
Call-ID: 9de24580-19f13a00-25c63-b28690a@172.10.40.11
CSeq: 103 NOTIFY
Content-Length: 0
080984: May 24 10:59:35.905 BST: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
NOTIFY sip:172.10.104.32:5060 SIP/2.0
Via: SIP/2.0/UDP 172.10.40.11:5060;branch=z9hG4bK25e2a78a7f435
From: "Deji okanlawon" <sip:01215246408@172.10.40.11>;tag=155101~ffa80926-5fac-4dd6-b405-2dbbc56ae9a2-544608971
To: <sip:908446930701@172.10.104.32>;tag=4F448086-750
Call-ID: 9de24580-19f13a00-25c63-b28690a@172.10.40.11
CSeq: 103 NOTIFY
Max-Forwards: 70
Date: Fri, 24 May 2013 09:59:35 GMT
User-Agent: Cisco-CUCM8.6
Event: kpml
Subscription-State: active;expires=7195
Contact: <sip:01215246408@172.10.40.11:5060>
P-Asserted-Identity: "Deji okanlawon" <sip:01215246408@172.10.40.11>
Content-Type: application/kpml-response+xml
Content-Length: 336
<?xml version="1.0" encoding="UTF-8" ?>
<kpml-response xmlns="urn:ietf:params:xml:ns:kpml-response" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="urn:ietf:params:xml:ns:kpml-response kpml-response.xsd" code="200" digits="0" forced_flush="false" suppressed="false" tag="dtmf" text="Success" version="1.0"/>
080985: May 24 10:59:35.905 BST: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.10.40.11:5060;branch=z9hG4bK25e2a78a7f435
From: "Deji okanlawon" <sip:01215246408@172.10.40.11>;tag=155101~ffa80926-5fac-4dd6-b405-2dbbc56ae9a2-544608971
To: <sip:908446930701@172.10.104.32>;tag=4F448086-750
Date: Fri, 24 May 2013 09:59:35 GMT
Call-ID: 9de24580-19f13a00-25c63-b28690a@172.10.40.11
CSeq: 103 NOTIFY
Content-Length: 0
Hence we can conclude that the gateway receives the digits sent by CUCM
IPPhone--sccp----CUCM--SIP---Gateway---E1--PSTN
dial-peer voice 3 voip
incoming called number .
no vad
dtmf-relay rtp-nte
I am going to skip the SIP signalling messages and go to the DTMF negotiation bit
16:59:41.964 |//SIP/SIPUdp/wait_UdpDataInd: Incoming SIP UDP message size 1119 from 172.10.104.32:[5060]:
[289744,NET]
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.10.40.11:5060;branch=z9hG4bK2348d9c6fccc
From: "Strand" <sip:02070043000@172.10.40.11>;tag=144444~ffa80926-5fac-4dd6-b405-2dbbc56ae9a2-392166160
To: <sip:908446930701@172.10.104.32>;tag=3BF6421A-410
Date: Mon, 20 May 2013 15:59:39 GMT
Call-ID: 45642d00-19a1486b-232d7-b28690a@172.10.40.11
CSeq: 101 INVITE
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Remote-Party-ID: <sip:08446930701@172.10.104.32>;party=called;screen=no;privacy=off
Contact: <sip:908446930701@172.10.104.32:5060>
Supported: replaces
Supported: sdp-anat
Server: Cisco-SIPGateway/IOS-12.x
Session-Expires: 84600;refresher=uac
Require: timer
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 273
v=0
o=CiscoSystemsSIP-GW-UserAgent 2394 1999 IN IP4 172.10.104.32
s=SIP Call
c=IN IP4 172.10.104.32
t=0 0
m=audio 18984 RTP/AVP 18 101
c=IN IP4 172.10.104.32
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
16:59:42.037 |setLocalDtmfCaps: supportedDTMFMethod=3, mWantDtmfReception=1, mPeersWantDtmfReceptionFlag=0, mDtmfPreference=1|*^*^*
16:59:42.037 |SIP DTMF Info: mLocalDtmfCaps...UNSOL=1, KPML=1, Inband=1(101) mEndppointsDtmfCaps...UNSOL=0, KPML=0, Inband=1(101) mDefaultTelephonyEvent=101, mDtmfPreference=1, mMtpAllocated=0|*^*^*
16:59:42.037 |//SIP/SIPUdp/wait_SdlSPISignal: Outgoing SIP UDP message to 172.10.104.32:[5060]:
[289745,NET]
ACK sip:908446930701@172.10.104.32:5060 SIP/2.0
Via: SIP/2.0/UDP 172.10.40.11:5060;branch=z9hG4bK2348e279e05fe
From: "Strand" <sip:02070043000@172.10.40.11>;tag=144444~ffa80926-5fac-4dd6-b405-2dbbc56ae9a2-392166160
To: <sip:908446930701@172.10.104.32>;tag=3BF6421A-410
Date: Mon, 20 May 2013 15:59:39 GMT
Call-ID: 45642d00-19a1486b-232d7-b28690a@172.10.40.11
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: presence, kpml
Content-Type: application/sdp
Content-Length: 236
v=0
o=CiscoSystemsCCM-SIP 144444 1 IN IP4 172.10.40.11
s=SIP Call
c=IN IP4 172.10.1.69
t=0 0
m=audio 29766 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=ptime:20
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
As explained above we can see CUCM adverties rtp-nte , KPML and UNSOL (highlighted red), where as the gateway only supports rtp-nte (set by dial-peer config)
However in the sip stack we can still see the DTMF digits the endpoint is sending
16:59:49.763 |//SIP/SIPD(22,73,28)/ccbId=0/scbId=0/getCdpcPid: found Cdpc Pid (22,100,74,268) for mapKey 392166160|23,100,13,72951.131^172.10.1.69^SEP5C5015A9D75B
16:59:49.763 |//SIP/SIPCdpc(22,74,268)/ci=392166160/ccbId=144444/scbId=0/star_CcUserInfoReq: Outbound DTMF method selected is 1. Digit=0 and isMTPPassingThru2833=0|23,100,13,72951.131^172.10.1.69^SEP5C5015A9D75B
++digits=2++
16:59:50.292 |//SIP/SIPD(22,73,28)/ccbId=0/scbId=0/getCdpcPid: found Cdpc Pid (22,100,74,268) for mapKey 392166160|23,100,13,72951.133^172.10.1.69^SEP5C5015A9D75B
16:59:50.292 |//SIP/SIPCdpc(22,74,268)/ci=392166160/ccbId=144444/scbId=0/star_CcUserInfoReq: Outbound DTMF method selected is 1. Digit=2 and isMTPPassingThru2833=0|23,100,13,72951.133^172.10.1.69^SEP5C5015A9D75B
we can see the actual dtmf digits sent in RTP stream with payload 101
067897: .May 20 16:59:50.453 BST: s=VoIP d=DSP payload 0x65 ssrc 0x1DDD3867 sequence 0x60D timestamp 0xED976557
067898: .May 20 16:59:50.453 BST: <<<Rcv> Pt:101 Evt:0 Pkt:09 00 00
067899: .May 20 16:59:50.473 BST: s=VoIP d=DSP payload 0x65 ssrc 0x1DDD3867 sequence 0x60F timestamp 0xED976557
067900: .May 20 16:59:50.473 BST: <<<Rcv> Pt:101 Evt:0 Pkt:09 00 A0
067901: .May 20 16:59:50.493 BST: s=VoIP d=DSP payload 0x65 ssrc 0x1DDD3867 sequence 0x611 timestamp 0xED976557
067902: .May 20 16:59:50.493 BST: <<<Rcv> Pt:101 Evt:0 Pkt:09 01 40
067903: .May 20 16:59:50.513 BST: s=VoIP d=DSP payload 0x65 ssrc 0x1DDD3867 sequence 0x613 timestamp 0xED976557
067904: .May 20 16:59:50.513 BST: <<<Rcv> Pt:101 Evt:0 Pkt:89 01 E0
067905: .May 20 16:59:50.513 BST: s=VoIP d=DSP payload 0x65 ssrc 0x1DDD3867 sequence 0x614 timestamp 0xED976557
067906: .May 20 16:59:50.513 BST: <<<Rcv> Pt:101 Evt:0 Pkt:89 01 E0
067907: .May 20 16:59:50.533 BST: s=VoIP d=DSP payload 0x65 ssrc 0x1DDD3867 sequence 0x615 timestamp 0xED976557
067908: .May 20 16:59:50.533 BST: <<<Rcv> Pt:101 Evt:0 Pkt:89 01 E0
067909: .May 20 16:59:50.553 BST: s=VoIP d=DSP payload 0x65 ssrc 0x1DDD3867 sequence 0x623 timestamp 0xED976F57
067910: .May 20 16:59:50.553 BST: <<<Rcv> Pt:101 Evt:2 Pkt:09 00 00
067911: .May 20 16:59:50.573 BST: s=VoIP d=DSP payload 0x65 ssrc 0x1DDD3867 sequence 0x625 timestamp 0xED976F57
067912: .May 20 16:59:50.573 BST: <<<Rcv> Pt:101 Evt:2 Pkt:09 00 A0
067913: .May 20 16:59:50.593 BST: s=VoIP d=DSP payload 0x65 ssrc 0x1DDD3867 sequence 0x627 timestamp 0xED976F57
067914: .May 20 16:59:50.593 BST: <<<Rcv> Pt:101 Evt:2 Pkt:09 01 40
067915: .May 20 16:59:50.613 BST: s=VoIP d=DSP payload 0x65 ssrc 0x1DDD3867 sequence 0x629 timestamp 0xED976F57
067916: .May 20 16:59:50.613 BST: <<<Rcv> Pt:101 Evt:2 Pkt:09 01 E0
067917: .May 20 16:59:50.633 BST: s=VoIP d=DSP payload 0x65 ssrc 0x1DDD3867 sequence 0x62B timestamp 0xED976F57
067918: .May 20 16:59:50.633 BST: <<<Rcv> Pt:101 Evt:2 Pkt:89 02 80
067919: .May 20 16:59:50.633 BST: s=VoIP d=DSP payload 0x65 ssrc 0x1DDD3867 sequence 0x62C timestamp 0xED976F57
067920: .May 20 16:59:50.633 BST: <<<Rcv> Pt:101 Evt:2 Pkt:89 02 80
067921: .May 20 16:59:50.633 BST: s=VoIP d=DSP payload 0x65 ssrc 0x1DDD3867 sequence 0x62D timestamp 0xED976F57
067922: .May 20 16:59:50.633 BST: <<<Rcv> Pt:101 Evt:2 Pkt:89 02 80
IPPhone--sccp------CUCM--------SIP-------Exchange Unified messaging
00028171.006 |12:59:46.332 |AppInfo |SIPTcp - wait_SdlReadRsp: Incoming SIP TCP message from 192.168.131.40 on port 5065 index 377 with 1539 bytes:
[204,NET]
SIP/2.0 200 OK
FROM: "bob banks2"<sip:800193850@192.168.131.11>;tag=562~736dccb8-3be2-4f69-88f8-ec5946dd6872-27034350
TO: <sip:755670001@192.168.131.40>;tag=3c42c6b9c1;epid=4F9342F874
CSEQ: 101 INVITE
CALL-ID: 6aa02a80-1a713f32-1e3-b83a8c0@192.168.131.11
VIA: SIP/2.0/TCP 192.168.131.11:5060;branch=z9hG4bK1f51b101ed3
CONTACT: <sip:UCLAB-DC.uclab.com:5065;transport=Tcp;maddr=192.168.131.40>;automata;text;audio;video;image
CONTENT-LENGTH: 678
PRIORITY: Normal
SUPPORTED: Replaces
SUPPORTED: timer
SUPPORTED: 100rel
CONTENT-TYPE: application/sdp
ALLOW: ACK
P-ASSERTED-IDENTITY: <sip:755670001@192.168.131.40>
SERVER: RTCC/3.5.0.0 MSExchangeUM/14.01.0218.012
Content-ID: af19ca95-d81b-413e-8657-f90d5ea9b4aa
Allow: CANCEL,BYE,INVITE,MESSAGE,INFO,SERVICE,OPTIONS,BENOTIFY,NOTIFY,PRACK,UPDATE
Session-Expires: 1800;refresher=uac
Min-SE: 1800
v=0
o=- 11 0 IN IP4 192.168.131.40
s=session
c=IN IP4 192.168.131.40
b=CT:1000
t=0 0
m=audio 32764 RTP/AVP 114 115 112 111 116 3 4 0 8 13 118 97 101
c=IN IP4 192.168.131.40
a=rtcp:32765
a=sendrecv
a=label:main-audio
a=rtpmap:114 x-msrta/16000
a=fmtp:114 bitrate=29000
a=rtpmap:115 x-msrta/8000
a=fmtp:115 bitrate=11800
a=rtpmap:112 G7221/16000
a=fmtp:112 bitrate=24000
a=rtpmap:111 SIREN/16000
a=fmtp:111 bitrate=16000
a=rtpmap:116 AAL2-G726-32/8000
a=rtpmap:3 GSM/8000
a=rtpmap:4 G723/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:13 CN/8000
a=rtpmap:118 CN/16000
a=rtpmap:97 RED/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16,36
NB: From the CUCM logs we can see that CUCM DTMF info does not yet indicate that its going to do RFC2833. This is because CUCM will not send support for rfc2833 untill it allocates an MTP since the endpoint cant do rfc2833.
00028195.006 |12:59:46.337 |AppInfo |SIP DTMF Info: mLocalDtmfCaps...UNSOL=1, KPML=1, Inband=0(0) mEndppointsDtmfCaps...UNSOL=0, KPML=0, Inband=1(101) mDefaultTelephonyEvent=101, mDtmfPreference=1, mMtpAllocated=0
00028211.015 |12:59:46.338 |AppInfo |DET-MediaManager-(13)::isMTPNeededForMismatchOrConfig, MTPNeededDueToDTMFCapMismatch(2833/OOB) mtpinsertionReason=1 dtmfMTPSide=2
00028219.020 |12:59:46.339 |AppInfo |MediaTerminationPointControl(1)::getResourcesAllocated -- DeviceName=MTP_2 Ci=27034351 ResourceAllocated=1
00028362.002 |12:59:46.524 |AppInfo |SIP DTMF Info: mLocalDtmfCaps...UNSOL=1, KPML=1, Inband=1(101) mEndppointsDtmfCaps...UNSOL=0, KPML=0, Inband=1(101) mDefaultTelephonyEvent=101, mDtmfPreference=1, mMtpAllocated=1
Observe that the ip address of CUCM is where media is sent to (look at the connection parameter)
00028384.001 |12:59:46.526 |AppInfo |SIPTcp - wait_SdlSPISignal: Outgoing SIP TCP message to 192.168.131.40 on port 5065 index 377
[205,NET]
ACK sip:UCLAB-DC.uclab.com:5065;maddr=192.168.131.40;transport=Tcp SIP/2.0
Via: SIP/2.0/TCP 192.168.131.11:5060;branch=z9hG4bK1f61b97d076
From: "bob banks2" <sip:800193850@192.168.131.11>;tag=562~736dccb8-3be2-4f69-88f8-ec5946dd6872-27034350
To: <sip:755670001@192.168.131.40>;tag=3c42c6b9c1
Date: Thu, 30 May 2013 11:59:46 GMT
Call-ID: 6aa02a80-1a713f32-1e3-b83a8c0@192.168.131.11
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: presence, kpml
Content-Type: application/sdp
Content-Length: 224
v=0
o=CiscoSystemsCCM-SIP 562 1 IN IP4 192.168.131.11
s=SIP Call
c=IN IP4 192.168.131.11
b=CT:64
t=0 0
m=audio 24584 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=ptime:20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
++digit pressed=1++
00028404.001 |12:59:51.296 |AppInfo |StationInit: (0000006) KeypadButton kpButton=1
From my experience, here are the DTMF methods you will see in CUCM traces
00028412.001 |12:59:51.297 |AppInfo |SIPCdpc(11) - star_CcUserInfoReq: Outbound DTMF method selected is 2. Digit=1 and isMTPPassingThru2833=0
00028412.002 |12:59:51.297 |AppInfo |SIPCdpc(11) - sendDtmfVia2833: sending sipOutgoingDTMFTone Tone 1 for digit 1.
00028416.000 |12:59:51.297 |SdlSig |MXOutgoingDTMFTone |waiting |MediaTerminationPointControl(1,100,130,1) |MTPAgenaInterface(1,100,233,6) |1,100,13,79.26^192.168.131.60^SEP001BD584B00D |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] tone=1 CI=27034351 confId=16779219 passthruPartyID=0x1000013 isMTPPassingThru2833=F
00028416.001 |12:59:51.297 |AppInfo |MediaTerminationPointControl(1)::star_MediaExchangeOutgoingDTMFTone tone=1, conferenceID=16779219, passthruID=16777235
00028416.002 |12:59:51.297 |AppInfo |MediaTerminationPointControl(1)::star_MediaExchangeOutgoingDTMFTone TCPPid = [1.100.13.4] myIP: 0xb83a8c0 (192.168.131.11) conferenceID=16779219, passthruPartyID=16777235, tone=1
00028424.001 |12:59:51.808 |AppInfo |StationInit: (0000006) KeypadButton kpButton=2.
00028432.001 |12:59:51.808 |AppInfo |SIPCdpc(11) - star_CcUserInfoReq: Outbound DTMF method selected is 2. Digit=2 and isMTPPassingThru2833=0
00028432.002 |12:59:51.808 |AppInfo |SIPCdpc(11) - sendDtmfVia2833: sending sipOutgoingDTMFTone Tone 2 for digit 2
00028436.000 |12:59:51.808 |SdlSig |MXOutgoingDTMFTone |waiting |MediaTerminationPointControl(1,100,130,1) |MTPAgenaInterface(1,100,233,6) |1,100,13,79.27^192.168.131.60^SEP001BD584B00D |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] tone=2 CI=27034351 confId=16779219 passthruPartyID=0x1000013 isMTPPassingThru2833=F
00028436.001 |12:59:51.808 |AppInfo |MediaTerminationPointControl(1)::star_MediaExchangeOutgoingDTMFTone tone=2, conferenceID=16779219, passthruID=16777235
00028436.002 |12:59:51.808 |AppInfo |MediaTerminationPointControl(1)::star_MediaExchangeOutgoingDTMFTone TCPPid = [1.100.13.4] myIP: 0xb83a8c0 (192.168.131.11) conferenceID=16779219, passthruPartyID=16777235, tone=2
We can also take wiresshark captures from CUCM and we will see the actual rtpevent sent out and the digits sent. The screen shot below shows the wireshark cpatures taking from CUCM and the RFC2833 formatted digits sent out to exchange.
From the wireshark traces, we can see the digit been sent out by the MTP to the exchange server.
jabber4windows----sip----CUCM--SIP---Gateway---E1--PSTN
dial-peer voice 3 voip
incoming called number .
no vad
dtmf-relay sip-kpml rtp-nte
14:53:48.445 |setEndpointsDtmfCaps: KPML Supported.|*^*^*
14:53:48.445 |setEndpointsDtmfCaps: Detected inband DTMF support.|*^*^*
14:53:48.445 |SIP DTMF Info: mLocalDtmfCaps...UNSOL=1, KPML=1, Inband=1(101) mEndppointsDtmfCaps...UNSOL=0, KPML=1, Inband=1(101) mDefaultTelephonyEvent=101, mDtmfPreference=1, mMtpAllocated=0|*^*^*
Since both endpoints support both method CUCM will use rtp-nte, this is always the preffered DTMF method. The trace below confirms this
++ digit=0 ++
14:53:58.898 |//SIP/SIPD(22,73,33)/ccbId=0/scbId=0/getCdpcPid: found Cdpc Pid (22,100,74,286) for mapKey 544627160|23,100,63,1.1271^172.10.40.190^*
14:53:58.898 |//SIP/SIPCdpc(22,74,286)/ci=544627160/ccbId=155570/scbId=0/star_CcUserInfoReq: Outbound DTMF method selected is 1. Digit=0 and isMTPPassingThru2833=0|23,100,63,1.1271^172.10.40.190^*
++ digit=2 ++
14:54:01.948 |//SIP/SIPD(22,73,33)/ccbId=0/scbId=0/getCdpcPid: found Cdpc Pid (22,100,74,286) for mapKey 544627160|23,100,63,1.1272^172.10.40.190^*
14:54:01.948 |//SIP/SIPCdpc(22,74,286)/ci=544627160/ccbId=155570/scbId=0/star_CcUserInfoReq: Outbound DTMF method selected is 1. Digit=2 and isMTPPassingThru2833=0|23,100,63,1.1272^172.10.40.190^*
082055: May 24 14:53:58.743 BST: s=VoIP d=DSP payload 0x65 ssrc 0xDCC07A11 sequence 0x3B6B timestamp 0xA892DC55
082056: May 24 14:53:58.743 BST: <<<Rcv> Pt:101 Evt:0 Pkt:0A 01 90
082057: May 24 14:53:58.793 BST: s=VoIP d=DSP payload 0x65 ssrc 0xDCC07A11 sequence 0x3B6C timestamp 0xA892DC55
082058: May 24 14:53:58.793 BST: <<<Rcv> Pt:101 Evt:0 Pkt:0A 01 90
082059: May 24 14:53:58.843 BST: s=VoIP d=DSP payload 0x65 ssrc 0xDCC07A11 sequence 0x3B6D timestamp 0xA892DC55
082060: May 24 14:53:58.843 BST: <<<Rcv> Pt:101 Evt:0 Pkt:0A 03 20
082061: May 24 14:53:58.893 BST: s=VoIP d=DSP payload 0x65 ssrc 0xDCC07A11 sequence 0x3B6E timestamp 0xA892DC55
082062: May 24 14:53:58.893 BST: <<<Rcv> Pt:101 Evt:0 Pkt:0A 04 B0
082063: May 24 14:53:58.943 BST: s=VoIP d=DSP payload 0x65 ssrc 0xDCC07A11 sequence 0x3B6F timestamp 0xA892DC55
082064: May 24 14:53:58.943 BST: <<<Rcv> Pt:101 Evt:0 Pkt:0A 06 40
082065: May 24 14:53:58.993 BST: s=VoIP d=DSP payload 0x65 ssrc 0xDCC07A11 sequence 0x3B70 timestamp 0xA892DC55
082066: May 24 14:53:58.993 BST: <<<Rcv> Pt:101 Evt:0 Pkt:8A 07 D0
082067: May 24 14:54:01.800 BST: s=VoIP d=DSP payload 0x65 ssrc 0xDCC07A11 sequence 0x3BFB timestamp 0xA8933BD5
082068: May 24 14:54:01.800 BST: <<<Rcv> Pt:101 Evt:2 Pkt:0A 01 90
082069: May 24 14:54:01.848 BST: s=VoIP d=DSP payload 0x65 ssrc 0xDCC07A11 sequence 0x3BFC timestamp 0xA8933BD5
082070: May 24 14:54:01.848 BST: <<<Rcv> Pt:101 Evt:2 Pkt:0A 01 90
082071: May 24 14:54:01.900 BST: s=VoIP d=DSP payload 0x65 ssrc 0xDCC07A11 sequence 0x3BFD timestamp 0xA8933BD5
082072: May 24 14:54:01.900 BST: <<<Rcv> Pt:101 Evt:2 Pkt:0A 03 20
082073: May 24 14:54:01.950 BST: s=VoIP d=DSP payload 0x65 ssrc 0xDCC07A11 sequence 0x3BFE timestamp 0xA8933BD5
082074: May 24 14:54:01.950 BST: <<<Rcv> Pt:101 Evt:2 Pkt:0A 04 B0
082075: May 24 14:54:02.000 BST: s=VoIP d=DSP payload 0x65 ssrc 0xDCC07A11 sequence 0x3BFF timestamp 0xA8933BD5
082076: May 24 14:54:02.000 BST: <<<Rcv> Pt:101 Evt:2 Pkt:0A 06 40
082077: May 24 14:54:02.050 BST: s=VoIP d=DSP payload 0x65 ssrc 0xDCC07A11 sequence 0x3C00 timestamp 0xA8933BD5
082078: May 24 14:54:02.050 BST: <<<Rcv> Pt:101 Evt:2 Pkt:8A 07 D0
Here we see that even though sip-kpml was the preffered method on the dial-peer rtp-nte was used..As long as both endpoints support it, it will be used
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: