That’s for the suggestions. But, there are no AMI scripts running which execute playDTMF.
This is something that I can reproduce always, which may help.
A Dahdi channel calls a SIP provider (callcentric in this case). On the Dahdi device, I press the #1 key. On the other end, they hear a constant tone for about 30 seconds. This is what the logs shows:
[Jan 13 14:57:42] DTMF[23851] channel.c: DTMF end ‘1’ received on DAHDI/1-1, duration 0 ms
[Jan 13 14:57:42] DTMF[23851] channel.c: DTMF begin emulation of ‘1’ with duration 100 queued on DAHDI/1-1
[Jan 13 14:57:42] DTMF[23851] channel.c: DTMF end emulation of ‘1’ queued on DAHDI/1-
which seems right… This is what rtp debug shows. Can anyone explain why the RTP DTMF packets gets sent 11 times? I think this would be OK if all the TS’s were the same, but they are not.
…
[Jan 13 14:59:22] DTMF[23851] channel.c: DTMF end ‘1’ received on DAHDI/1-1, duration 0 ms
[Jan 13 14:59:22] DTMF[23851] channel.c: DTMF begin emulation of ‘1’ with duration 100 queued on DAHDI/1-1
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Got RTP packet from 204.11.192.37:57908 (type 18, seq 048376, ts 890733, len 000020)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Got RTP packet from 204.11.192.37:57908 (type 18, seq 048377, ts 890893, len 000020)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Got RTP packet from 204.11.192.37:57908 (type 18, seq 048378, ts 891053, len 000020)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Got RTP packet from 204.11.192.37:57908 (type 18, seq 048379, ts 891213, len 000020)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Got RTP packet from 204.11.192.37:57908 (type 18, seq 048380, ts 891373, len 000020)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Got RTP packet from 204.11.192.37:57908 (type 18, seq 048381, ts 891533, len 000020)
[Jan 13 14:59:22] DTMF[23851] channel.c: DTMF end emulation of ‘1’ queued on DAHDI/1-1
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Sent RTP DTMF packet to 204.11.192.37:57908 (type 101, seq 050670, ts 826992, len 000004)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Sent RTP DTMF packet to 204.11.192.37:57908 (type 101, seq 050671, ts 826992, len 000004)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Sent RTP DTMF packet to 204.11.192.37:57908 (type 101, seq 050672, ts 826992, len 000004)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Got RTP packet from 204.11.192.37:57908 (type 18, seq 048382, ts 891693, len 000020)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Sent RTP packet to 204.11.192.37:57908 (type 18, seq 050673, ts 828200, len 000020)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Sent RTP DTMF packet to 204.11.192.37:57908 (type 101, seq 050674, ts 828200, len 000004)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Got RTP packet from 204.11.192.37:57908 (type 18, seq 048383, ts 891853, len 000020)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Sent RTP packet to 204.11.192.37:57908 (type 18, seq 050675, ts 828360, len 000020)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Sent RTP DTMF packet to 204.11.192.37:57908 (type 101, seq 050676, ts 828360, len 000004)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Got RTP packet from 204.11.192.37:57908 (type 18, seq 048384, ts 892013, len 000020)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Sent RTP packet to 204.11.192.37:57908 (type 18, seq 050677, ts 828520, len 000020)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Sent RTP DTMF packet to 204.11.192.37:57908 (type 101, seq 050678, ts 828520, len 000004)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Got RTP packet from 204.11.192.37:57908 (type 18, seq 048385, ts 892173, len 000020)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Sent RTP packet to 204.11.192.37:57908 (type 18, seq 050679, ts 828680, len 000020)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Sent RTP DTMF packet to 204.11.192.37:57908 (type 101, seq 050680, ts 828680, len 000004)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Got RTP packet from 204.11.192.37:57908 (type 18, seq 048386, ts 892333, len 000020)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Sent RTP packet to 204.11.192.37:57908 (type 18, seq 050681, ts 828840, len 000020)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Sent RTP DTMF packet to 204.11.192.37:57908 (type 101, seq 050682, ts 828840, len 000004)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Got RTP packet from 204.11.192.37:57908 (type 18, seq 048387, ts 892493, len 000020)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Sent RTP packet to 204.11.192.37:57908 (type 18, seq 050683, ts 829000, len 000020)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Sent RTP DTMF packet to 204.11.192.37:57908 (type 101, seq 050684, ts 829000, len 000004)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Sent RTP DTMF packet to 204.11.192.37:57908 (type 101, seq 050684, ts 829000, len 000004)
[Jan 13 14:59:22] VERBOSE[23851] logger.c: Sent RTP DTMF packet to 204.11.192.37:57908 (type 101, seq 050684, ts 829000, len 000004)
…
Here is an example when the using the local SIP device (192.168.0.61): Notice the local sip device sends the RTP DTMF multiple times, but all with the same TS. Asterisk replays it on the other channels, but w/multiple TS’s.
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP RFC2833 from 192.168.0.61:31328 (type 101, seq 008374, ts 111806120, len 000004, mark 1, event 00000001, end 0, duration 00000)
[Jan 13 15:10:07] DEBUG[23893] rtp.c: - RTP 2833 Event: 00000001 (len = 4)
[Jan 13 15:10:07] DTMF[23893] channel.c: DTMF end ‘1’ received on SIP/15-00b33e50, duration 0 ms
[Jan 13 15:10:07] DTMF[23893] channel.c: DTMF begin emulation of ‘1’ with duration 100 queued on SIP/15-00b33e50
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP packet from 204.11.192.37:59410 (type 18, seq 015938, ts 084415, len 000020)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Sent RTP packet to 192.168.0.61:31328 (type 00, seq 017767, ts 084408, len 000160)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP packet from 192.168.0.61:31328 (type 00, seq 008375, ts 111806160, len 000160)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP packet from 192.168.0.61:31328 (type 101, seq 008376, ts 111806120, len 000004)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP RFC2833 from 192.168.0.61:31328 (type 101, seq 008376, ts 111806120, len 000004, mark 0, event 00000001, end 0, duration 00160)
[Jan 13 15:10:07] DEBUG[23893] rtp.c: - RTP 2833 Event: 00000001 (len = 4)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP packet from 204.11.192.37:59410 (type 18, seq 015939, ts 084575, len 000020)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Sent RTP packet to 192.168.0.61:31328 (type 00, seq 017768, ts 084568, len 000160)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP packet from 192.168.0.61:31328 (type 00, seq 008377, ts 111806320, len 000160)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP packet from 192.168.0.61:31328 (type 101, seq 008378, ts 111806120, len 000004)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP RFC2833 from 192.168.0.61:31328 (type 101, seq 008378, ts 111806120, len 000004, mark 0, event 00000001, end 0, duration 00320)
[Jan 13 15:10:07] DEBUG[23893] rtp.c: - RTP 2833 Event: 00000001 (len = 4)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP packet from 204.11.192.37:59410 (type 18, seq 015940, ts 084735, len 000020)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Sent RTP packet to 192.168.0.61:31328 (type 00, seq 017769, ts 084728, len 000160)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP packet from 192.168.0.61:31328 (type 00, seq 008379, ts 111806480, len 000160)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP packet from 192.168.0.61:31328 (type 101, seq 008380, ts 111806120, len 000004)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP RFC2833 from 192.168.0.61:31328 (type 101, seq 008380, ts 111806120, len 000004, mark 0, event 00000001, end 0, duration 00480)
[Jan 13 15:10:07] DEBUG[23893] rtp.c: - RTP 2833 Event: 00000001 (len = 4)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP packet from 204.11.192.37:59410 (type 18, seq 015941, ts 084895, len 000020)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Sent RTP packet to 192.168.0.61:31328 (type 00, seq 017770, ts 084888, len 000160)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP packet from 192.168.0.61:31328 (type 00, seq 008381, ts 111806640, len 000160)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP packet from 192.168.0.61:31328 (type 101, seq 008382, ts 111806120, len 000004)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP RFC2833 from 192.168.0.61:31328 (type 101, seq 008382, ts 111806120, len 000004, mark 0, event 00000001, end 0, duration 00640)
[Jan 13 15:10:07] DEBUG[23893] rtp.c: - RTP 2833 Event: 00000001 (len = 4)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP packet from 204.11.192.37:59410 (type 18, seq 015942, ts 085055, len 000020)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Sent RTP packet to 192.168.0.61:31328 (type 00, seq 017771, ts 085048, len 000160)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP packet from 192.168.0.61:31328 (type 00, seq 008383, ts 111806800, len 000160)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP packet from 192.168.0.61:31328 (type 101, seq 008384, ts 111806120, len 000004)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP RFC2833 from 192.168.0.61:31328 (type 101, seq 008384, ts 111806120, len 000004, mark 0, event 00000001, end 0, duration 00800)
[Jan 13 15:10:07] DEBUG[23893] rtp.c: - RTP 2833 Event: 00000001 (len = 4)
[Jan 13 15:10:07] DTMF[23893] channel.c: DTMF end emulation of ‘1’ queued on SIP/15-00b33e50
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Sent RTP DTMF packet to 204.11.192.37:59410 (type 101, seq 007632, ts 111805920, len 000004)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Sent RTP DTMF packet to 204.11.192.37:59410 (type 101, seq 007633, ts 111805920, len 000004)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Sent RTP DTMF packet to 204.11.192.37:59410 (type 101, seq 007634, ts 111805920, len 000004)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP packet from 204.11.192.37:59410 (type 18, seq 015943, ts 085215, len 000020)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Sent RTP packet to 204.11.192.37:59410 (type 18, seq 007635, ts 111806928, len 000020)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP packet from 192.168.0.61:31328 (type 00, seq 008385, ts 111806960, len 000160)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP packet from 192.168.0.61:31328 (type 101, seq 008386, ts 111806120, len 000004)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP RFC2833 from 192.168.0.61:31328 (type 101, seq 008386, ts 111806120, len 000004, mark 0, event 00000001, end 0, duration 00960)
[Jan 13 15:10:07] DEBUG[23729] rtp.c: - RTP 2833 Event: 00000001 (len = 4)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Sent RTP DTMF packet to 204.11.192.37:59410 (type 101, seq 007636, ts 111806928, len 000004)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP packet from 204.11.192.37:59410 (type 18, seq 015944, ts 085375, len 000020)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Sent RTP packet to 204.11.192.37:59410 (type 18, seq 007637, ts 111807088, len 000020)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP packet from 192.168.0.61:31328 (type 00, seq 008387, ts 111807120, len 000160)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP packet from 192.168.0.61:31328 (type 101, seq 008388, ts 111806120, len 000004)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP RFC2833 from 192.168.0.61:31328 (type 101, seq 008388, ts 111806120, len 000004, mark 0, event 00000001, end 0, duration 01120)
[Jan 13 15:10:07] DEBUG[23729] rtp.c: - RTP 2833 Event: 00000001 (len = 4)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Sent RTP DTMF packet to 204.11.192.37:59410 (type 101, seq 007638, ts 111807088, len 000004)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP packet from 204.11.192.37:59410 (type 18, seq 015945, ts 085535, len 000020)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Sent RTP packet to 204.11.192.37:59410 (type 18, seq 007639, ts 111807248, len 000020)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP packet from 192.168.0.61:31328 (type 00, seq 008389, ts 111807280, len 000160)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP packet from 192.168.0.61:31328 (type 101, seq 008390, ts 111806120, len 000004)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP RFC2833 from 192.168.0.61:31328 (type 101, seq 008390, ts 111806120, len 000004, mark 0, event 00000001, end 0, duration 01280)
[Jan 13 15:10:07] DEBUG[23729] rtp.c: - RTP 2833 Event: 00000001 (len = 4)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Sent RTP DTMF packet to 204.11.192.37:59410 (type 101, seq 007640, ts 111807248, len 000004)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP packet from 204.11.192.37:59410 (type 18, seq 015946, ts 085695, len 000020)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Sent RTP packet to 204.11.192.37:59410 (type 18, seq 007641, ts 111807408, len 000020)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP packet from 192.168.0.61:31328 (type 00, seq 008391, ts 111807440, len 000160)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP packet from 192.168.0.61:31328 (type 101, seq 008392, ts 111806120, len 000004)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP RFC2833 from 192.168.0.61:31328 (type 101, seq 008392, ts 111806120, len 000004, mark 0, event 00000001, end 0, duration 01440)
[Jan 13 15:10:07] DEBUG[23729] rtp.c: - RTP 2833 Event: 00000001 (len = 4)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Sent RTP DTMF packet to 204.11.192.37:59410 (type 101, seq 007642, ts 111807408, len 000004)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP packet from 204.11.192.37:59410 (type 18, seq 015947, ts 085855, len 000020)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Sent RTP packet to 204.11.192.37:59410 (type 18, seq 007643, ts 111807568, len 000020)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP packet from 192.168.0.61:31328 (type 00, seq 008393, ts 111807600, len 000160)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP packet from 192.168.0.61:31328 (type 101, seq 008394, ts 111806120, len 000004)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP RFC2833 from 192.168.0.61:31328 (type 101, seq 008394, ts 111806120, len 000004, mark 0, event 00000001, end 0, duration 01600)
[Jan 13 15:10:07] DEBUG[23729] rtp.c: - RTP 2833 Event: 00000001 (len = 4)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Sent RTP DTMF packet to 204.11.192.37:59410 (type 101, seq 007644, ts 111807568, len 000004)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP packet from 204.11.192.37:59410 (type 18, seq 015948, ts 086015, len 000020)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Sent RTP packet to 204.11.192.37:59410 (type 18, seq 007645, ts 111807728, len 000020)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP packet from 192.168.0.61:31328 (type 00, seq 008395, ts 111807760, len 000160)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP packet from 192.168.0.61:31328 (type 101, seq 008396, ts 111806120, len 000004)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP RFC2833 from 192.168.0.61:31328 (type 101, seq 008396, ts 111806120, len 000004, mark 0, event 00000001, end 0, duration 01760)
[Jan 13 15:10:07] DEBUG[23729] rtp.c: - RTP 2833 Event: 00000001 (len = 4)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP packet from 192.168.0.61:31328 (type 101, seq 008397, ts 111806120, len 000004)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP RFC2833 from 192.168.0.61:31328 (type 101, seq 008397, ts 111806120, len 000004, mark 0, event 00000001, end 1, duration 01800)
[Jan 13 15:10:07] DEBUG[23729] rtp.c: - RTP 2833 Event: 00000001 (len = 4)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP packet from 192.168.0.61:31328 (type 101, seq 008398, ts 111806120, len 000004)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP RFC2833 from 192.168.0.61:31328 (type 101, seq 008398, ts 111806120, len 000004, mark 0, event 00000001, end 1, duration 01800)
[Jan 13 15:10:07] DEBUG[23729] rtp.c: - RTP 2833 Event: 00000001 (len = 4)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP packet from 192.168.0.61:31328 (type 101, seq 008399, ts 111806120, len 000004)
[Jan 13 15:10:07] VERBOSE[23729] logger.c: Got RTP RFC2833 from 192.168.0.61:31328 (type 101, seq 008399, ts 111806120, len 000004, mark 0, event 00000001, end 1, duration 01800)
[Jan 13 15:10:07] DEBUG[23729] rtp.c: - RTP 2833 Event: 00000001 (len = 4)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Sent RTP DTMF packet to 204.11.192.37:59410 (type 101, seq 007646, ts 111807728, len 000004)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Sent RTP DTMF packet to 204.11.192.37:59410 (type 101, seq 007646, ts 111807728, len 000004)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Sent RTP DTMF packet to 204.11.192.37:59410 (type 101, seq 007646, ts 111807728, len 000004)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Got RTP packet from 204.11.192.37:59410 (type 18, seq 015949, ts 086175, len 000020)
[Jan 13 15:10:07] VERBOSE[23893] logger.c: Sent RTP packet to 204.11.192.37:59410 (type 18, seq 007647, ts 111807888, len 000020)