[Home]

Summary:ASTERISK-14118: DTMF occurs in every calls without user press keyboard of telephone
Reporter:Rodrigo R Passos (rodrigopassos)Labels:
Date Opened:2009-05-13 10:29:20Date Closed:2009-06-24 13:25:48
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Core/PBX
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) 557135556180_dtmf.debug
( 1) 557135556180_rtp.zip
( 2) chan_dahdi.conf
( 3) Dump_Fidelity.pdf
( 4) extconfig.conf
( 5) extensions.ael
( 6) modules.conf
( 7) res_odbc.conf
( 8) rtp.conf
( 9) sip.conf
Description:When a call is in progress in my PBX Server, all side of that call, listen one beep. This beep is a dtmf.  This DTMF is aleatory, and when PBX stay over demand, this problem occurs with more frequence. All devices, IP Phone, ATA and TE420P can listen this DTMF, and when a do call, the problem occurs when this call is between sip to sip, sip to pstn and pstn to sip.

****** ADDITIONAL INFORMATION ******

This is a log, where can i saw that my problem is a DTMF.
[May  6 12:02:18] VERBOSE[17952] logger.c:     -- Executing [08008881784@ramais:1] DeadAGI("SIP/557135556760-b58450c8", "dial_out.php|557135556760|08008881784|60") in new stack
[May  6 12:02:18] WARNING[17952] res_agi.c: Running DeadAGI on a live channel will cause problems, please use AGI
[May  6 12:02:18] VERBOSE[17952] logger.c:     -- Launched AGI Script /var/lib/asterisk/agi-bin/dial_out.php
[May  6 12:02:18] VERBOSE[17952] logger.c:     -- AGI Script Executing Application: (DIAL) Options: (DAHDI/g11/08008881784|60|)
[May  6 12:02:18] DEBUG[17952] dsp.c: dsp busy pattern set to 0,0
[May  6 12:02:18] VERBOSE[17952] logger.c:     -- Requested transfer capability: 0x00 - SPEECH
[May  6 12:02:18] VERBOSE[17952] logger.c:     -- Called g11/08008881784
[May  6 12:02:18] VERBOSE[17952] logger.c:     -- DAHDI/68-1 is proceeding passing it to SIP/557135556760-b58450c8
[May  6 12:02:18] VERBOSE[17952] logger.c:     -- DAHDI/68-1 is making progress passing it to SIP/557135556760-b58450c8
[May  6 12:02:20] VERBOSE[17952] logger.c:     -- DAHDI/68-1 is ringing
[May  6 12:02:20] VERBOSE[17952] logger.c:     -- DAHDI/68-1 answered SIP/557135556760-b58450c8
[May  6 12:02:21] WARNING[17952] abstract_jb.c: Failed to put first frame in the jitterbuffer on channel 'DAHDI/68-1'
[May  6 12:02:21] VERBOSE[17952] logger.c:     -- adaptive jitterbuffer created on channel DAHDI/68-1
[May  6 12:02:28] WARNING[17952] rtp.c: RTCP Read too short
[May  6 12:02:28] DEBUG[17952] chan_dahdi.c: Set option AUDIO MODE, value: ON(1) on DAHDI/68-1
[May  6 12:02:28] DEBUG[17952] chan_dahdi.c: Not yet hungup...  Calling hangup once with icause, and clearing call
[May  6 12:02:28] DEBUG[17952] chan_dahdi.c: Set option AUDIO MODE, value: OFF(0) on DAHDI/68-1
[May  6 12:02:28] VERBOSE[17952] logger.c:     -- Hungup 'DAHDI/68-1'
[May  6 12:02:28] VERBOSE[17952] logger.c:     -- adaptive jitterbuffer destroyed on channel DAHDI/68-1
[May  6 12:02:29] VERBOSE[17952] logger.c:     -- AGI Script dial_out.php completed, returning 0
[May  8 07:52:37] VERBOSE[17952] logger.c:     -- Executing [32642337@ramais:1] DeadAGI("SIP/557135556770-09246710", "dial_out.php|557135556770|32642337|60") in new stack
[May  8 07:52:37] WARNING[17952] res_agi.c: Running DeadAGI on a live channel will cause problems, please use AGI
[May  8 07:52:37] VERBOSE[17952] logger.c:     -- Launched AGI Script /var/lib/asterisk/agi-bin/dial_out.php
[May  8 07:52:37] VERBOSE[17952] logger.c:     -- AGI Script Executing Application: (DIAL) Options: (DAHDI/g11/32642337|60|)
[May  8 07:52:37] DEBUG[17952] dsp.c: dsp busy pattern set to 0,0
[May  8 07:52:37] VERBOSE[17952] logger.c:     -- Requested transfer capability: 0x00 - SPEECH
[May  8 07:52:37] VERBOSE[17952] logger.c:     -- Called g11/32642337
[May  8 07:52:37] DEBUG[17952] chan_dahdi.c: Set option AUDIO MODE, value: ON(1) on DAHDI/63-1
[May  8 07:52:37] DEBUG[17952] chan_dahdi.c: Already hungup...  Calling hangup once, and clearing call
[May  8 07:52:37] DEBUG[17952] chan_dahdi.c: Set option AUDIO MODE, value: OFF(0) on DAHDI/63-1
[May  8 07:52:37] VERBOSE[17952] logger.c:     -- Hungup 'DAHDI/63-1'
[May  8 07:52:37] VERBOSE[17952] logger.c:   == Everyone is busy/congested at this time (1:0/0/1)
[May  8 07:52:37] VERBOSE[17952] logger.c:     -- AGI Script dial_out.php completed, returning 0
[May  9 12:26:16] VERBOSE[17952] logger.c:     -- Executing DeadAgi("SIP/557135557713-b349ba38", "dial_in.php|557135556180|SIP/557135556180|60|SIP||")
[May  9 12:26:16] WARNING[17952] res_agi.c: Running DeadAGI on a live channel will cause problems, please use AGI
[May  9 12:26:16] VERBOSE[17952] logger.c:     -- Launched AGI Script /var/lib/asterisk/agi-bin/dial_in.php
[May  9 12:26:16] VERBOSE[17952] logger.c:     -- AGI Script Executing Application: (DIAL) Options: (SIP/557135556180|60|oft)
[May  9 12:26:16] VERBOSE[17952] logger.c:     -- Called 557135556180
[May  9 12:26:17] VERBOSE[17952] logger.c:     -- SIP/557135556180-091fe030 is ringing
[May  9 12:26:25] VERBOSE[17952] logger.c:     -- SIP/557135556180-091fe030 answered SIP/557135557713-b349ba38
[May  9 12:26:47] DTMF[17952] channel.c: DTMF begin '2' received on SIP/557135556180-091fe030
[May  9 12:26:47] DTMF[17952] channel.c: DTMF begin passthrough '2' on SIP/557135556180-091fe030
[May  9 12:26:47] DTMF[17952] channel.c: DTMF end '2' received on SIP/557135556180-091fe030, duration 30 ms
[May  9 12:26:47] DTMF[17952] channel.c: DTMF end accepted with begin '2' on SIP/557135556180-091fe030
[May  9 12:26:47] DTMF[17952] channel.c: DTMF end '2' has duration 30 but want minimum 80, emulating on SIP/557135556180-091fe030
[May  9 12:26:47] DTMF[17952] channel.c: DTMF end emulation of '2' queued on SIP/557135556180-091fe030
[May  9 12:26:51] DTMF[17952] channel.c: DTMF begin '1' received on SIP/557135556180-091fe030
[May  9 12:26:51] DTMF[17952] channel.c: DTMF begin passthrough '1' on SIP/557135556180-091fe030
[May  9 12:26:52] DTMF[17952] channel.c: DTMF end '1' received on SIP/557135556180-091fe030, duration 30 ms
[May  9 12:26:52] DTMF[17952] channel.c: DTMF end accepted with begin '1' on SIP/557135556180-091fe030
[May  9 12:26:52] DTMF[17952] channel.c: DTMF end '1' has duration 30 but want minimum 80, emulating on SIP/557135556180-091fe030
[May  9 12:26:52] DTMF[17952] channel.c: DTMF end emulation of '1' queued on SIP/557135556180-091fe030
[May  9 12:27:09] DTMF[17952] channel.c: DTMF begin '6' received on SIP/557135556180-091fe030
[May  9 12:27:09] DTMF[17952] channel.c: DTMF begin passthrough '6' on SIP/557135556180-091fe030
[May  9 12:27:09] DTMF[17952] channel.c: DTMF end '6' received on SIP/557135556180-091fe030, duration 30 ms
[May  9 12:27:09] DTMF[17952] channel.c: DTMF end accepted with begin '6' on SIP/557135556180-091fe030
[May  9 12:27:09] DTMF[17952] channel.c: DTMF end '6' has duration 30 but want minimum 80, emulating on SIP/557135556180-091fe030
[May  9 12:27:09] DTMF[17952] channel.c: DTMF end emulation of '6' queued on SIP/557135556180-091fe030
[May  9 12:27:17] DTMF[17952] channel.c: DTMF begin '5' received on SIP/557135556180-091fe030
[May  9 12:27:17] DTMF[17952] channel.c: DTMF begin passthrough '5' on SIP/557135556180-091fe030
[May  9 12:27:17] DTMF[17952] channel.c: DTMF end '5' received on SIP/557135556180-091fe030, duration 30 ms
[May  9 12:27:17] DTMF[17952] channel.c: DTMF end accepted with begin '5' on SIP/557135556180-091fe030
[May  9 12:27:17] DTMF[17952] channel.c: DTMF end '5' has duration 30 but want minimum 80, emulating on SIP/557135556180-091fe030
[May  9 12:27:17] DTMF[17952] channel.c: DTMF end emulation of '5' queued on SIP/557135556180-091fe030
[May  9 12:27:37] DTMF[17952] channel.c: DTMF begin '4' received on SIP/557135556180-091fe030
[May  9 12:27:37] DTMF[17952] channel.c: DTMF begin passthrough '4' on SIP/557135556180-091fe030
[May  9 12:27:37] DTMF[17952] channel.c: DTMF end '4' received on SIP/557135556180-091fe030, duration 30 ms
[May  9 12:27:37] DTMF[17952] channel.c: DTMF end accepted with begin '4' on SIP/557135556180-091fe030
[May  9 12:27:37] DTMF[17952] channel.c: DTMF end '4' has duration 30 but want minimum 80, emulating on SIP/557135556180-091fe030
[May  9 12:27:37] DTMF[17952] channel.c: DTMF end emulation of '4' queued on SIP/557135556180-091fe030
[May  9 12:27:37] DTMF[17952] channel.c: DTMF begin 'A' received on SIP/557135556180-091fe030
[May  9 12:27:37] DTMF[17952] channel.c: DTMF begin passthrough 'A' on SIP/557135556180-091fe030
[May  9 12:27:37] DTMF[17952] channel.c: DTMF end 'A' received on SIP/557135556180-091fe030, duration 30 ms
[May  9 12:27:37] DTMF[17952] channel.c: DTMF end accepted with begin 'A' on SIP/557135556180-091fe030
[May  9 12:27:37] DTMF[17952] channel.c: DTMF end 'A' has duration 30 but want minimum 80, emulating on SIP/557135556180-091fe030
[May  9 12:27:37] DTMF[17952] channel.c: DTMF end emulation of 'A' queued on SIP/557135556180-091fe030
[May  9 12:27:47] DTMF[17952] channel.c: DTMF begin '*' received on SIP/557135556180-091fe030
[May  9 12:27:47] DTMF[17952] channel.c: DTMF begin passthrough '*' on SIP/557135556180-091fe030
[May  9 12:27:47] DTMF[17952] channel.c: DTMF end '*' received on SIP/557135556180-091fe030, duration 240 ms
[May  9 12:27:47] DTMF[17952] channel.c: DTMF end accepted with begin '*' on SIP/557135556180-091fe030
[May  9 12:27:47] DTMF[17952] channel.c: DTMF end passthrough '*' on SIP/557135556180-091fe030
[May  9 12:27:48] DTMF[17952] channel.c: DTMF begin '2' received on SIP/557135556180-091fe030
[May  9 12:27:48] DTMF[17952] channel.c: DTMF begin passthrough '2' on SIP/557135556180-091fe030
[May  9 12:27:48] DTMF[17952] channel.c: DTMF end '2' received on SIP/557135556180-091fe030, duration 200 ms
[May  9 12:27:48] DTMF[17952] channel.c: DTMF end accepted with begin '2' on SIP/557135556180-091fe030
[May  9 12:27:48] DTMF[17952] channel.c: DTMF end passthrough '2' on SIP/557135556180-091fe030
[May  9 12:27:48] VERBOSE[17952] logger.c:     -- Started music on hold, class 'default', on SIP/557135557713-b349ba38
[May  9 12:27:48] VERBOSE[17952] logger.c:     -- <SIP/557135556180-091fe030> Playing 'pbx-transfer' (language 'pt_BR')
[May  9 12:27:53] WARNING[17952] res_features.c: Did not read data.
[May  9 12:27:53] VERBOSE[17952] logger.c:     -- Stopped music on hold on SIP/557135557713-b349ba38
[May  9 12:27:53] VERBOSE[17952] logger.c:     -- <SIP/557135556180-091fe030> Playing 'beeperr' (language 'pt_BR')
[May  9 12:27:55] DTMF[17952] channel.c: DTMF begin '6' received on SIP/557135556180-091fe030
[May  9 12:27:55] DTMF[17952] channel.c: DTMF begin passthrough '6' on SIP/557135556180-091fe030
[May  9 12:27:55] DTMF[17952] channel.c: DTMF end '6' received on SIP/557135556180-091fe030, duration 310 ms
[May  9 12:27:55] DTMF[17952] channel.c: DTMF end accepted with begin '6' on SIP/557135556180-091fe030
[May  9 12:27:55] DTMF[17952] channel.c: DTMF end passthrough '6' on SIP/557135556180-091fe030
[May  9 12:27:56] DTMF[17952] channel.c: DTMF begin '1' received on SIP/557135556180-091fe030
[May  9 12:27:56] DTMF[17952] channel.c: DTMF begin passthrough '1' on SIP/557135556180-091fe030
[May  9 12:27:56] DTMF[17952] channel.c: DTMF end '1' received on SIP/557135556180-091fe030, duration 180 ms
[May  9 12:27:56] DTMF[17952] channel.c: DTMF end accepted with begin '1' on SIP/557135556180-091fe030
[May  9 12:27:56] DTMF[17952] channel.c: DTMF end passthrough '1' on SIP/557135556180-091fe030
[May  9 12:27:58] DTMF[17952] channel.c: DTMF begin '8' received on SIP/557135556180-091fe030
[May  9 12:27:58] DTMF[17952] channel.c: DTMF begin passthrough '8' on SIP/557135556180-091fe030
[May  9 12:27:58] DTMF[17952] channel.c: DTMF end '8' received on SIP/557135556180-091fe030, duration 190 ms
[May  9 12:27:58] DTMF[17952] channel.c: DTMF end accepted with begin '8' on SIP/557135556180-091fe030
[May  9 12:27:58] DTMF[17952] channel.c: DTMF end passthrough '8' on SIP/557135556180-091fe030
[May  9 12:28:01] DTMF[17952] channel.c: DTMF begin '2' received on SIP/557135556180-091fe030
[May  9 12:28:01] DTMF[17952] channel.c: DTMF begin passthrough '2' on SIP/557135556180-091fe030
[May  9 12:28:01] DTMF[17952] channel.c: DTMF end '2' received on SIP/557135556180-091fe030, duration 130 ms
[May  9 12:28:01] DTMF[17952] channel.c: DTMF end accepted with begin '2' on SIP/557135556180-091fe030
[May  9 12:28:01] DTMF[17952] channel.c: DTMF end passthrough '2' on SIP/557135556180-091fe030
[May  9 12:28:02] DTMF[17952] channel.c: DTMF begin '9' received on SIP/557135556180-091fe030
[May  9 12:28:02] DTMF[17952] channel.c: DTMF begin passthrough '9' on SIP/557135556180-091fe030
[May  9 12:28:02] DTMF[17952] channel.c: DTMF end '9' received on SIP/557135556180-091fe030, duration 30 ms
[May  9 12:28:02] DTMF[17952] channel.c: DTMF end accepted with begin '9' on SIP/557135556180-091fe030
[May  9 12:28:02] DTMF[17952] channel.c: DTMF end '9' has duration 30 but want minimum 80, emulating on SIP/557135556180-091fe030
[May  9 12:28:02] DTMF[17952] channel.c: DTMF end emulation of '9' queued on SIP/557135556180-091fe030
[May  9 12:28:36] DTMF[17952] channel.c: DTMF begin '*' received on SIP/557135556180-091fe030
[May  9 12:28:36] DTMF[17952] channel.c: DTMF begin passthrough '*' on SIP/557135556180-091fe030
[May  9 12:28:36] DTMF[17952] channel.c: DTMF end '*' received on SIP/557135556180-091fe030, duration 200 ms
[May  9 12:28:36] DTMF[17952] channel.c: DTMF end accepted with begin '*' on SIP/557135556180-091fe030
[May  9 12:28:36] DTMF[17952] channel.c: DTMF end passthrough '*' on SIP/557135556180-091fe030
[May  9 12:28:37] DTMF[17952] channel.c: DTMF begin '2' received on SIP/557135556180-091fe030
[May  9 12:28:37] DTMF[17952] channel.c: DTMF begin passthrough '2' on SIP/557135556180-091fe030
[May  9 12:28:37] DTMF[17952] channel.c: DTMF end '2' received on SIP/557135556180-091fe030, duration 160 ms
[May  9 12:28:37] DTMF[17952] channel.c: DTMF end accepted with begin '2' on SIP/557135556180-091fe030
[May  9 12:28:37] DTMF[17952] channel.c: DTMF end passthrough '2' on SIP/557135556180-091fe030
[May  9 12:28:37] VERBOSE[17952] logger.c:     -- Started music on hold, class 'default', on SIP/557135557713-b349ba38
[May  9 12:28:37] VERBOSE[17952] logger.c:     -- <SIP/557135556180-091fe030> Playing 'pbx-transfer' (language 'pt_BR')
[May  9 12:28:39] DTMF[17952] channel.c: DTMF begin '7' received on SIP/557135556180-091fe030
[May  9 12:28:39] DTMF[17952] channel.c: DTMF begin ignored '7' on SIP/557135556180-091fe030
[May  9 12:28:40] DTMF[17952] channel.c: DTMF end '7' received on SIP/557135556180-091fe030, duration 150 ms
[May  9 12:28:40] DTMF[17952] channel.c: DTMF end passthrough '7' on SIP/557135556180-091fe030
[May  9 12:28:40] DTMF[17952] channel.c: DTMF begin '7' received on SIP/557135556180-091fe030
[May  9 12:28:40] DTMF[17952] channel.c: DTMF begin ignored '7' on SIP/557135556180-091fe030
[May  9 12:28:40] DTMF[17952] channel.c: DTMF end '7' received on SIP/557135556180-091fe030, duration 150 ms
[May  9 12:28:40] DTMF[17952] channel.c: DTMF end passthrough '7' on SIP/557135556180-091fe030
[May  9 12:28:40] DTMF[17952] channel.c: DTMF begin '1' received on SIP/557135556180-091fe030
[May  9 12:28:40] DTMF[17952] channel.c: DTMF begin ignored '1' on SIP/557135556180-091fe030
[May  9 12:28:40] DTMF[17952] channel.c: DTMF end '1' received on SIP/557135556180-091fe030, duration 120 ms
[May  9 12:28:40] DTMF[17952] channel.c: DTMF end passthrough '1' on SIP/557135556180-091fe030
[May  9 12:28:41] DTMF[17952] channel.c: DTMF begin '2' received on SIP/557135556180-091fe030
[May  9 12:28:41] DTMF[17952] channel.c: DTMF begin ignored '2' on SIP/557135556180-091fe030
[May  9 12:28:41] DTMF[17952] channel.c: DTMF end '2' received on SIP/557135556180-091fe030, duration 130 ms
[May  9 12:28:41] DTMF[17952] channel.c: DTMF end passthrough '2' on SIP/557135556180-091fe030
[May  9 12:28:44] VERBOSE[17952] logger.c:     -- Local/7712@ramais-d6ac,1 is ringing
[May  9 12:28:46] DTMF[17952] channel.c: DTMF begin '4' received on SIP/557135556180-091fe030
[May  9 12:28:46] DTMF[17952] channel.c: DTMF begin passthrough '4' on SIP/557135556180-091fe030
[May  9 12:28:46] DTMF[17952] channel.c: DTMF end '4' received on SIP/557135556180-091fe030, duration 50 ms
[May  9 12:28:46] DTMF[17952] channel.c: DTMF end accepted with begin '4' on SIP/557135556180-091fe030
[May  9 12:28:46] DTMF[17952] channel.c: DTMF end '4' has duration 50 but want minimum 80, emulating on SIP/557135556180-091fe030
[May  9 12:28:46] DTMF[17952] channel.c: DTMF end emulation of '4' queued on SIP/557135556180-091fe030
[May  9 12:28:47] DTMF[17952] channel.c: DTMF begin '4' received on SIP/557135556180-091fe030
[May  9 12:28:47] DTMF[17952] channel.c: DTMF begin passthrough '4' on SIP/557135556180-091fe030
[May  9 12:28:47] DTMF[17952] channel.c: DTMF end '4' received on SIP/557135556180-091fe030, duration 30 ms
[May  9 12:28:47] DTMF[17952] channel.c: DTMF end accepted with begin '4' on SIP/557135556180-091fe030
[May  9 12:28:47] DTMF[17952] channel.c: DTMF end '4' has duration 30 but want minimum 80, emulating on SIP/557135556180-091fe030
[May  9 12:28:47] DTMF[17952] channel.c: DTMF end emulation of '4' queued on SIP/557135556180-091fe030
[May  9 12:29:00] WARNING[17952] rtp.c: RTCP Read too short
[May  9 12:29:00] VERBOSE[17952] logger.c:     -- Stopped music on hold on SIP/557135557713-b349ba38
[May  9 12:29:01] VERBOSE[17952] logger.c:     -- <SIP/557135557712-095f4bb0> Playing 'beep' (language 'pt_BR')
[May  9 12:29:01] WARNING[17952] chan_sip.c: This function can only be used on SIP channels.
[May  9 12:29:01] ERROR[17952] utils.c: write() returned error: Broken pipe
[May  9 12:29:01] VERBOSE[17952] logger.c:     -- AGI Script dial_in.php completed, returning 0
Comments:By: Rodrigo R Passos (rodrigopassos) 2009-05-13 12:19:34

All sip clients are in realtime mode and my extensions.conf call realtime to place input calls.
By: Rodrigo R Passos (rodrigopassos) 2009-05-20 12:03:45

Follow same outputs generated with rtp debug:

Sent RTP DTMF packet to 10.5.13.47:10502 (type 96, seq 027709, ts 907040, len 000004)
Sent RTP DTMF packet to 10.5.13.47:10502 (type 96, seq 027710, ts 907040, len 000004)
Sent RTP DTMF packet to 10.5.13.47:10502 (type 96, seq 027711, ts 907040, len 000004)
Sent RTP DTMF packet to 10.5.13.47:10502 (type 96, seq 027712, ts 907040, len 000004)
Sent RTP DTMF packet to 10.5.13.47:10502 (type 96, seq 027713, ts 907040, len 000004)
Sent RTP DTMF packet to 10.5.13.47:10502 (type 96, seq 027714, ts 907040, len 000004)
Sent RTP DTMF packet to 10.5.13.47:10502 (type 96, seq 027715, ts 907040, len 000004)
Sent RTP DTMF packet to 10.5.13.47:10502 (type 96, seq 027716, ts 907040, len 000004)
Sent RTP DTMF packet to 10.5.13.47:10502 (type 96, seq 027718, ts 907040, len 000004)
Sent RTP DTMF packet to 10.5.13.47:10502 (type 96, seq 027719, ts 907040, len 000004)
Sent RTP DTMF packet to 10.5.13.47:10502 (type 96, seq 027720, ts 907040, len 000004)
Sent RTP DTMF packet to 10.5.13.84:10502 (type 96, seq 000806, ts 995808, len 000004)
Sent RTP DTMF packet to 10.5.13.84:10502 (type 96, seq 000807, ts 995808, len 000004)
Sent RTP DTMF packet to 10.5.13.84:10502 (type 96, seq 000808, ts 995808, len 000004)
Sent RTP DTMF packet to 10.5.13.84:10502 (type 96, seq 000809, ts 995808, len 000004)
Sent RTP DTMF packet to 10.5.13.84:10502 (type 96, seq 000810, ts 995808, len 000004)
Sent RTP DTMF packet to 10.5.13.84:10502 (type 96, seq 000811, ts 995808, len 000004)
Sent RTP DTMF packet to 10.5.13.84:10502 (type 96, seq 000812, ts 995808, len 000004)
Sent RTP DTMF packet to 10.5.13.84:10502 (type 96, seq 000813, ts 995808, len 000004)
Sent RTP DTMF packet to 10.5.13.84:10502 (type 96, seq 000815, ts 995808, len 000004)
Sent RTP DTMF packet to 10.5.13.84:10502 (type 96, seq 000816, ts 995808, len 000004)
Sent RTP DTMF packet to 10.5.13.84:10502 (type 96, seq 000817, ts 995808, len 000004)
Sent RTP DTMF packet to 10.5.13.41:10500 (type 101, seq 055296, ts 1732000, len 000004)
Sent RTP DTMF packet to 10.5.13.41:10500 (type 101, seq 055297, ts 1732000, len 000004)
Sent RTP DTMF packet to 10.5.13.41:10500 (type 101, seq 055298, ts 1732000, len 000004)
Sent RTP DTMF packet to 10.5.13.41:10500 (type 101, seq 055299, ts 1732000, len 000004)
Sent RTP DTMF packet to 10.5.13.41:10500 (type 101, seq 055300, ts 1732000, len 000004)
Sent RTP DTMF packet to 10.5.13.41:10500 (type 101, seq 055301, ts 1732000, len 000004)
Sent RTP DTMF packet to 10.5.13.41:10500 (type 101, seq 055302, ts 1732000, len 000004)
Sent RTP DTMF packet to 10.5.13.41:10500 (type 101, seq 055303, ts 1732000, len 000004)
Sent RTP DTMF packet to 10.5.13.41:10500 (type 101, seq 055305, ts 1732000, len 000004)
Sent RTP DTMF packet to 10.5.13.41:10500 (type 101, seq 055306, ts 1732000, len 000004)
Sent RTP DTMF packet to 10.5.13.41:10500 (type 101, seq 055307, ts 1732000, len 000004)
Sent RTP DTMF packet to 10.5.13.120:10500 (type 101, seq 034637, ts 1942296, len 000004)
Sent RTP DTMF packet to 10.5.13.120:10500 (type 101, seq 034638, ts 1942296, len 000004)
Sent RTP DTMF packet to 10.5.13.120:10500 (type 101, seq 034639, ts 1942296, len 000004)
Sent RTP DTMF packet to 10.5.13.120:10500 (type 101, seq 034640, ts 1942296, len 000004)
Sent RTP DTMF packet to 10.5.13.120:10500 (type 101, seq 034641, ts 1942296, len 000004)
Sent RTP DTMF packet to 10.5.13.120:10500 (type 101, seq 034642, ts 1942296, len 000004)
Sent RTP DTMF packet to 10.5.13.120:10500 (type 101, seq 034643, ts 1942296, len 000004)
Sent RTP DTMF packet to 10.5.13.120:10500 (type 101, seq 034645, ts 1942296, len 000004)
Sent RTP DTMF packet to 10.5.13.120:10500 (type 101, seq 034646, ts 1942296, len 000004)
Sent RTP DTMF packet to 10.5.13.120:10500 (type 101, seq 034647, ts 1942296, len 000004)
Sent RTP DTMF packet to 10.5.13.84:10502 (type 96, seq 004035, ts 1518608, len 000004)


By: Dmitry Andrianov (dimas) 2009-05-21 09:31:01

the log states that DTMFs are received from SIP/557135556180.
The IP of your SIP peer is unknown so it is impossible to match that against RTP debug you are providing.

can you turn DTMF logging on, turn RTP debug for SIP/557135556180 IP address on and attach the log you will get?
By: Rodrigo R Passos (rodrigopassos) 2009-05-21 16:20:51

follows the attached files.
The files are:

557135556180_dtmf.debug and 557135556180_rtp.zip, and can be download for your analysis.
By: Dmitry Andrianov (dimas) 2009-05-21 17:04:26

1. I do not really understand what are you doing exactly. first of all, as you see in the log, asterisk complaints you should NOT use DeadAGI on live channels because this WILL cause problems. I'm not really sure  what kind of problem it may cause but I see no reason to fight with Asterisk about this.

2. Do you always have the problem calling the same number or it happens with different numbers? Is it 100% reproducible? I'm asking because the very first thing I would test is to make the same call with simple Dial(SIP/557135556180|60|oft) instead of running your DeadAGI script. This is good for localizing problems - it is much easier to both report and troubleshoot simple cases then when there is a puzzle of dozen components/scripts involved.

3. it is a bit difficult to match your DTMF and RTP logs - I actually expected it all to be in the same file.
But in any case, if 10.5.13.107 is the SIP peer making the call, then it sending RFC2833 DTMF events for sure:

Got  RTP RFC2833 from   10.5.13.107:10502 (type 96, seq 005750, ts 2809755360, len 000004, mark 1, event 00000000, end 0, duration 00000)
...
Got  RTP RFC2833 from   10.5.13.107:10502 (type 96, seq 037688, ts 2823325120, len 000004, mark 1, event 00000006, end 0, duration 00000)
...
Got  RTP RFC2833 from   10.5.13.107:10502 (type 96, seq 037726, ts 2823329920, len 000004, mark 1, event 00000002, end 0, duration 00000)

... etc

so the SIP sends 006271026182*26182*2...

So I would say - check your phone (or whatever it is) first.
By: Rodrigo R Passos (rodrigopassos) 2009-05-21 21:56:03

This problem occurs in all calls. I have 150 (ATA) of the chinese manufacturer 30 IP Phones Grandtstream BT201 and 5 IP Phones Grandstream BT1200. The DeadAGI is in using alone to solve a problem with Asterisk CDR, becouse the transfer attended transfer and blind transfer has problems in creation of the consistent CDR information.
I did a test to more simple in initial instalation, but the problem persist. From that time to come, I do many, many search in the Internet and i don´t find the solution. The initial instalation, I did in 1.4.23 version, after, I did one downgrade to 1.4.22 and now using 1.4.24. I don´t know what more I do to solve my problem. I did one analysis with tcpdump, and I open this packet captured in Wireshark to see where this DTMF is generated and i can see the DTMF is generate in the packet sent by the ATA to Asterisk, and in the rebuild of the RTP packet, I can listen in the packet sent by the Asterisk to ATA and this is obvious. Do you know if the dmtf rfc2833 could be sent one incorrect information to Asterisk?
The packets captured could be see in Dump_Fidelity.pdf.
By: Dmitry Andrianov (dimas) 2009-05-22 02:27:14

First of all, upgrade to 1.4.25.
Then make simple test case - create an extension which when dialed does simple
Dial(...) somewhere without any AGI things. See if the problem persist. If it is, make a test call capturing everything:
1. Asterisk output including debug and DTMF
2. packet capture with packets between Asterisk and both of the IP phones involved.

Provide these debug information and explain what exactly was wrong.
By: Leif Madsen (lmadsen) 2009-06-24 13:25:48

Closed due to lack of response. I suspect fixing the DeadAGI() / AGI() issue probably resolved the issue.