07-04-2011 09:34 AM - edited 03-16-2019 05:46 AM
Hi, I have been working on an intermitent DTMF problem for some days for one of our sites. I read about some set up that deny it working right away but this site has two gateways deployed for 6 months already and people started complaining about it last week. There is a second site using similar gateway and setup always working, so a phone with two DNs will help discard phones problems (not completing discarding phone issue, but very low probability of it).
The site which is presenting this has 7 E1s from same carrier, 4 in the 1st GW, 3 on the 2nd one. I tested with DTMF failing over the two gateways so I assume same problem affect both and I am copying one of them config.
Gateways runs IOS 15.(0)M3 where DTMF sometimes works, sometimes does not.
The other office runs 15.1(3)T and voice setup should be similar, althought I can copy config if usefull.
By this setup, does someone know if it could be a carrier problem causing this? Besides H.245 setup checking or IOS matching for this, is this something else I could verify?
Thanks a lot.
Solved! Go to Solution.
07-05-2011 08:17 AM
The best way to see if CUCM is sending digits is to get 'debug h245 asn1'. If you see ALL of the digits you press AFTER the call is connected, then the issue is likely either the telco, or the PRI circuit.
07-04-2011 06:14 PM
Is the issue noticed on inbound calls (in to Unity, for example), or outbound (to a bank IVR)? The first thing is to make sure you are matching the correct dial peers. Your voip dial peers have h245-alpha, but are you sure you are hitting these peers for all calls? If you place an outbound call, for example, that does not make an explicite match, you will default to dial-peer 0 with default capabilities....of which dtmf is not listed. You can check your dial peer matching with 'debug voip ccapi inout'
Another possible cause of in intermittent dtmf issue is packet loss. If you place a call, and enter 'show call active voice br', you can see a line containing "lost:x/x/x". x/x/x is dropped/early/late packets. If you have packet loss, you could be dropping the h245 packets containing dtmf.
Finally....it could be a telco issue. If the issue is inbound, for example, you can get a pcm capture off of the b channel the call is on an actually hear dtmf tones coming inbound. You'll need TAC to decode the PCM file, though. If you don't hear dtmf, or it's low, hot, or otherwise garbled...this is your issue.
Hope this gives you a few options of where to look
07-05-2011 04:53 AM
Thanks for the info. Those are outbound calls to banks and other IVRs. Tried number 40044828 which takes an outbound dial-peer 2010. I am going to retry a few calls (some of them work, some do not, to same numbers in differente times) and monitor them with 'show call active voice br'.
R3-BRSAO-JU18-05-RTR-01#show voice call status
CallID CID ccVdb Port Slot/DSP:Ch Called # Codec MLPP Dial-peers
0xCA779 34ED 0x0219460C 0/0/0:15.1 0/1:2 *070952396 g711ulaw 1000/2010
0xCA864 39EE 0x0224EDFC 0/0/1:15.1 0/1:1 *088898487 g711ulaw 1000/2010
0xCA866 3AEE 0x0230B5D8 0/1/0:15.1 0/1:3 *073369158 g711ulaw 1000/2010
0xCA870 E1F 0x023C717C 0/1/1:15.1 0/1:4 33026 g711ulaw 1500/1000
0xCA876 E21 0x023C717C 0/1/1:15.3 0/1:5 33000 g711ulaw 1500/1000
0xCA87D EE 0x0224EDFC 0/0/1:15.2 0/1:8 *035491000 g711ulaw 1000/2010
0xCA881 2EE 0x0219460C 0/0/0:15.2 0/1:6 *040044828 g711ulaw 1000/2010
7 active calls found
It is a local call and only dial-peer for it. Basically it will strip zero prefix for external local calls.
dial-peer voice 2010 pots
trunkgroup 1
description ## PSTN ##
destination-pattern 0[2-9].......
direct-inward-dial
!
R3-BRSAO-JU18-05-RTR-01#show dial-peer voice 2010
VoiceEncapPeer2010
peer type = voice, system default peer = FALSE, information type = voice,
description = `## PSTN ##',
tag = 2010, destination-pattern = `0[2-9].......',
voice reg type = 0, corresponding tag = 0,
allow watch = FALSE
answer-address = `', preference=0,
CLID Restriction = None
CLID Network Number = `'
CLID Second Number sent
CLID Override RDNIS = disabled,
rtp-ssrc mux = system
source carrier-id = `', target carrier-id = `',
source trunk-group-label = `', target trunk-group-label = `',
numbering Type = `unknown'
group = 2010, Admin state is up, Operation state is up,
Outbound state is up,
incoming called-number = `', connections/maximum = 4/unlimited,
DTMF Relay = disabled,
URI classes:
Destination =
huntstop = disabled,
in bound application associated: 'DEFAULT'
out bound application associated: ''
dnis-map =
permission :both
incoming COR list:maximum capability
outgoing COR list:minimum requirement
Translation profile (Incoming):
Translation profile (Outgoing):
incoming call blocking:
translation-profile = `'
disconnect-cause = `no-service'
advertise 0x40 capacity_update_timer 25 addrFamily 4 oldAddrFamily 4
mailbox selection policy: none
trunk-group:
id = `1', preference = `'
type = pots, prefix = `',
forward-digits default
session-target = `', voice-port = `',
direct-inward-dial = enabled,
digit_strip = enabled,
register E.164 number with H323 GK and/or SIP Registrar = TRUE
fax rate = system, payload size = 20 bytes
supported-language = ''
preemption level = `routine'
bandwidth:
maximum = 64 KBits/sec, minimum = 64 KBits/sec
voice class called-number:
inbound = `', outbound = `'
dial tone generation after remote onhook = enabled
mobility=0, snr=, snr_noan=, snr_delay=0, snr_timeout=0
Time elapsed since last clearing of voice call statistics never
Connect Time = 309618925, Charged Units = 0,
Successful Calls = 161310, Failed Calls = 16730, Incomplete Calls = 8190
Accepted Calls = 0, Refused Calls = 0,
Last Disconnect Cause is "10 ",
Last Disconnect Text is "normal call clearing (16)",
Last Setup Time = 1172289947.
Last Disconnect Time = 1172292592.
R3-BRSAO-JU18-05-RTR-01#
Thanks.
07-05-2011 05:08 AM
Some info on the outgoing call
EE : 717207 09:06:58.433 gmt Tue Jul 5 2011.1 +1770 pid:2010 Originate 040044828 active
dur 00:00:42 tx:2206/370608 rx:1356/213775
Tele 0/0/0:15 (717207) [0/0/0.4] tx:44170/26720/0ms g711ulaw noise:-83 acom:51 i/0:-23/-41 dBm
07-05-2011 05:50 AM
It's not the pots dial peer you need to worry about for dtmf. On an outbound call, you should match an INBOUND voip dial peer before matching the outbound pots dial peer. The voip dial peer will negotiate the dtmf to CUCM on the voip side.
07-05-2011 07:41 AM
Thanks for the info. This is sample dial-peer to inbound calls to CUCM. The H.245 DTMF method is used in 8 other similar sites (same carrier, ISDN).
dial-peer voice 1000 voip
description ## To CUCM ##
preference 1
destination-pattern 3[3-7]...
session target ipv4:10.22.10.12
voice-class codec 1
voice-class h323 1
dtmf-relay h245-alphanumeric
!
dial-peer voice 1001 voip
description ## To CUCM ##
preference 2
destination-pattern 3[3-7]...
session target ipv4:10.22.10.11
voice-class codec 1
voice-class h323 1
dtmf-relay h245-alphanumeric
!
Some 'debug voice ccapi inout' provided some info I cannot see in sites working fine, just on this presenting DTMF failure.
R3-BRSAO-JU18-05-RTR-02#Consume mask is not set. Relaying Digit 4 to dstCallId 0xAF1E9
Jul 5 09:20:34.586 gmt: //717288/80575EF5790D/CCAPI/cc_relay_digit_begin_for_3way_conference:
Check DTMF relay digit begin for 3way conf
Jul 5 09:20:34.686 gmt: //717288/80575EF5790D/CCAPI/cc_api_call_digit_end:
Consume mask is not set. Relaying Digit 4 to dstCallId 0xAF1E9
Jul 5 09:20:34.686 gmt: //717288/80575EF5790D/CCAPI/cc_relay_digit_end_for_3way_conference:
Check DTMF relay digit end for 3way conf
R3-BRSAO-JU18-05-RTR-02#
Jul 5 09:20:38.666 gmt: //717288/80575EF5790D/CCAPI/cc_api_call_digit_begin:
Consume mask is not set. Relaying Digit 4 to dstCallId 0xAF1E9
Jul 5 09:20:38.666 gmt: //717288/80575EF5790D/CCAPI/cc_relay_digit_begin_for_3way_conference:
Check DTMF relay digit begin for 3way conf
Jul 5 09:20:38.766 gmt: //717288/80575EF5790D/CCAPI/cc_api_call_digit_end:
Consume mask is not set. Relaying Digit 4 to dstCallId 0xAF1E9
Jul 5 09:20:38.766 gmt: //717288/80575EF5790D/CCAPI/cc_relay_digit_end_for_3way_conference:
Check DTMF relay digit end for 3way conf
I am trying to learn better of this event.
07-05-2011 08:17 AM
The best way to see if CUCM is sending digits is to get 'debug h245 asn1'. If you see ALL of the digits you press AFTER the call is connected, then the issue is likely either the telco, or the PRI circuit.
07-05-2011 05:59 PM
Thanks again, makes sense. Debug shows H.245 msgs being received. During a call which does not transmit DTMF:
R3-BRSAO-JU18-05-RTR-02#debug h245 asn1
H.245 ASN1 Messages debugging is on
R3-BRSAO-JU18-05-RTR-02#term mon
R3-BRSAO-JU18-05-RTR-02#
Jul 5 21:54:05.809 gmt: h245_decode_one_pdu: more_pdus = 0, bytesLeftToDecode = 7
Jul 5 21:54:05.809 gmt: H245 MSC INCOMING ENCODE BUFFER::= 6D810446200063
Jul 5 21:54:05.809 gmt:
Jul 5 21:54:05.809 gmt: H245 MSC INCOMING PDU ::=
value MultimediaSystemControlMessage ::= indication : userInput : signal :
{
signalType "1"
duration 100
}
Jul 5 21:54:05.809 gmt: h245_decode_one_pdu: H245ASNDecodePdu rc = 0, bytesLeftToDecode = 0
Jul 5 21:54:05.809 gmt: h245_decode_one_pdu: Read Pkt body: more_pdus:0 rc:0 asn_rc:0
R3-BRSAO-JU18-05-RTR-02#
Jul 5 21:54:13.493 gmt: h245_decode_one_pdu: more_pdus = 0, bytesLeftToDecode = 7
Jul 5 21:54:13.493 gmt: H245 MSC INCOMING ENCODE BUFFER::= 6D810446400063
Jul 5 21:54:13.493 gmt:
Jul 5 21:54:13.493 gmt: H245 MSC INCOMING PDU ::=
value MultimediaSystemControlMessage ::= indication : userInput : signal :
{
signalType "2"
duration 100
}
Now, retry to one call that works to compare, but I believe there won't be any differences. Probably a carrier problem, unfortunately. There are more than 10 issues in last 2 months...
07-05-2011 06:09 PM
That is a call the DTMF works
R3-BRSAO-JU18-05-RTR-01#show voice call status
CallID CID ccVdb Port Slot/DSP:Ch Called # Codec MLPP Dial-peers
0xCC461 2AE7 0x023C717C 0/1/1:15.1 0/1:9 *063860533 g711ulaw 0/2010
0xCC4AE 3BE8 0x0224EDFC 0/0/1:15.1 0/1:3 *061592413 g711ulaw 1000/2010
0xCC543 1FE8 0x023C717C 0/1/1:15.2 0/1:10 *075431674 g711ulaw 1000/2010
0xCC552 23E8 0x023C717C 0/1/1:15.3 0/1:7 *072171332 g711ulaw 1000/2010
0xCC61A 20E8 0x0219460C 0/0/0:15.1 0/1:1 *040040001 g729r8 1000/2010
5 active calls found
R3-BRSAO-JU18-05-RTR-01#
Jul 5 22:08:11.515 gmt: h245_decode_one_pdu: more_pdus = 0, bytesLeftToDecode = 7
Jul 5 22:08:11.515 gmt: H245 MSC INCOMING ENCODE BUFFER::= 6D810446800063
Jul 5 22:08:11.515 gmt:
Jul 5 22:08:11.515 gmt: H245 MSC INCOMING PDU ::=
value MultimediaSystemControlMessage ::= indication : userInput : signal :
{
signalType "4"
duration 100
}
Jul 5 22:08:11.515 gmt: h245_decode_one_pdu: H245ASNDecodePdu rc = 0, bytesLeftToDecode = 0
Jul 5 22:08:11.515 gmt: h245_decode_one_pdu: Read Pkt body: more_pdus:0 rc:0 asn_rc:0
R3-BRSAO-JU18-05-RTR-01#
Jul 5 22:08:19.483 gmt: h245_decode_one_pdu: more_pdus = 0, bytesLeftToDecode = 7
Jul 5 22:08:19.483 gmt: H245 MSC INCOMING ENCODE BUFFER::= 6D810446800063
Jul 5 22:08:19.483 gmt:
Jul 5 22:08:19.483 gmt: H245 MSC INCOMING PDU ::=
value MultimediaSystemControlMessage ::= indication : userInput : signal :
{
signalType "4"
duration 100
}
Jul 5 22:08:19.483 gmt: h245_decode_one_pdu: H245ASNDecodePdu rc = 0, bytesLeftToDecode = 0
Jul 5 22:08:19.483 gmt: h245_decode_one_pdu: Read Pkt body: more_pdus:0 rc:0 asn_rc:0
R3-BRSAO-JU18-05-RTR-01#
Jul 5 22:08:23.115 gmt: h245_decode_one_pdu: more_pdus = 0, bytesLeftToDecode = 7
Jul 5 22:08:23.115 gmt: H245 MSC INCOMING ENCODE BUFFER::= 6D810444600063
Jul 5 22:08:23.115 gmt:
Jul 5 22:08:23.115 gmt: H245 MSC INCOMING PDU ::=
value MultimediaSystemControlMessage ::= indication : userInput : signal :
{
signalType "#"
duration 100
}
Jul 5 22:08:23.115 gmt: h245_decode_one_pdu: H245ASNDecodePdu rc = 0, bytesLeftToDecode = 0
Jul 5 22:08:23.115 gmt: h245_decode_one_pdu: Read Pkt body: more_pdus:0 rc:0 asn_rc:0
R3-BRSAO-JU18-05-RTR-01#
Jul 5 22:08:26.751 gmt: h245_decode_one_pdu: more_pdus = 0, bytesLeftToDecode = 5
Jul 5 22:08:26.751 gmt: H245 MSC INCOMING ENCODE BUFFER::= 0400000000
Jul 5 22:08:26.751 gmt:
Jul 5 22:08:26.751 gmt: H245 MSC INCOMING PDU ::=
value MultimediaSystemControlMessage ::= request : closeLogicalChannel :
{
forwardLogicalChannelNumber 1
source user : NULL
}
Jul 5 22:08:26.751 gmt: h245_decode_one_pdu: H245ASNDecodePdu rc = 0, bytesLeftToDecode = 0
Jul 5 22:08:26.751 gmt: h245_decode_one_pdu: Read Pkt body: more_pdus:0 rc:0 asn_rc:0
Jul 5 22:08:26.751 gmt: H245 MSC OUTGOING PDU ::=
value MultimediaSystemControlMessage ::= response : closeLogicalChannelAck :
{
forwardLogicalChannelNumber 1
}
Jul 5 22:08:26.751 gmt: H245 MSC OUTGOING ENCODE BUFFER::= 23800000
Jul 5 22:08:26.751 gmt:
Jul 5 22:08:26.755 gmt: h245_decode_one_pdu: more_pdus = 0, bytesLeftToDecode = 2
Jul 5 22:08:26.755 gmt: H245 MSC INCOMING ENCODE BUFFER::= 4A40
Jul 5 22:08:26.755 gmt:
Jul 5 22:08:26.755 gmt: H245 MSC INCOMING PDU ::=
value MultimediaSystemControlMessage ::= command : endSessionCommand : disconnect : NULL
Jul 5 22:08:26.755 gmt: h245_decode_one_pdu: H245ASNDecodePdu rc = 0, bytesLeftToDecode = 0
Jul 5 22:08:26.755 gmt: h245_decode_one_pdu: Read Pkt body: more_pdus:0 rc:0 asn_rc:0
Jul 5 22:08:26.755 gmt: H245 MSC OUTGOING PDU ::=
value MultimediaSystemControlMessage ::= command : endSessionCommand : disconnect : NULL
Jul 5 22:08:26.755 gmt: H245 MSC OUTGOING ENCODE BUFFER::= 4A40
Jul 5 22:08:26.755 gmt:
R3-BRSAO-JU18-05-RTR-01#
Jul 5 22:08:26.779 gmt: %ISDN-6-DISCONNECT: Interface Serial0/0/0:0 disconnected from 40040001 , call lasted 31 seconds
R3-BRSAO-JU18-05-RTR-01#
R3-BRSAO-JU18-05-RTR-01#
07-07-2011 11:45 AM
Christopher, thank you very much for the help. Issue still pending to check with PSTN carrier. I will open an incident with them. It's hard to make they work on intermitent issues but there is very low chance the gateway is not fowarding DTMF in ISDN. In paralel, I'll ask our support provider in NY to take a look at.
Discover and save your favorite ideas. Come back to expert answers, step-by-step guides, recent topics, and more.
New here? Get started with these tips. How to use Community New member guide