[asterisk-bugs] [JIRA] Updated: (ASTERISK-18404) out-of-order RTP causes DTMF loss
Matt Jordan (JIRA)
noreply at issues.asterisk.org
Mon Jul 16 13:22:20 CDT 2012
[ https://issues.asterisk.org/jira/browse/ASTERISK-18404?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Matt Jordan updated ASTERISK-18404:
-----------------------------------
Reviewboard Link: https://reviewboard.asterisk.org/r/2033/
> out-of-order RTP causes DTMF loss
> ---------------------------------
>
> Key: ASTERISK-18404
> URL: https://issues.asterisk.org/jira/browse/ASTERISK-18404
> Project: Asterisk
> Issue Type: Bug
> Security Level: None
> Components: Core/RTP
> Affects Versions: 1.8.4
> Environment: debian amd64
> {code}
> # dpkg -l | grep asterisk
> ii asterisk 1:1.8.4.4~dfsg-2 Open Source Private Branch Exchange (PBX)
> ii asterisk-config 1:1.8.4.4~dfsg-2 Configuration files for Asterisk
> ii asterisk-core-sounds-en-gsm 1.4.19-1 asterisk PBX sound files - English/gsm
> ii asterisk-dahdi 1:1.8.4.4~dfsg-2 DAHDI devices support for the Asterisk PBX
> ii asterisk-doc 1:1.6.2.9-2+squeeze2 Source code documentation for Asterisk
> ii asterisk-modules 1:1.8.4.4~dfsg-2 loadable modules for the Asterisk PBX
> ii asterisk-moh-opsound-gsm 2.03-1 asterisk extra sound files - English/gsm
> ii asterisk-mysql 1:1.8.4.4~dfsg-2 MySQL database protocol support for the Asterisk PBX
> ii asterisk-sounds-extra 1.4.9-1 Additional sound files for the Asterisk PBX
> ii asterisk-voicemail 1:1.8.4.4~dfsg-2 simple voicemail support for the Asterisk PBX
> ii libasterisk-agi-perl 1.01-2 Collections of Perl modules to be used with Asterisk PBX AGI
> {code}
> Reporter: Stephane Chazelas
> Assignee: Matt Jordan
> Severity: Critical
>
> We're in the process of upgrading our phone system from trixbox 1.4 to 1.8 on debian).
> Many DTMF RTP frames from one of our VOIP providers arrive out-of-order. See for instance:
> {code}
> 3.977152 195.189.173.27 -> 80.193.213.24 RTP EVENT Payload type=RTP Event, DTMF One 1 (end)
> 3.977163 195.189.173.27 -> 80.193.213.24 RTP EVENT Payload type=RTP Event, DTMF One 1 (end)
> 3.977171 195.189.173.27 -> 80.193.213.24 RTP EVENT Payload type=RTP Event, DTMF One 1
> 3.977179 195.189.173.27 -> 80.193.213.24 RTP EVENT Payload type=RTP Event, DTMF One 1 (end)
> 4.669046 195.189.173.27 -> 80.193.213.24 RTP EVENT Payload type=RTP Event, DTMF Four 4
> 4.669056 195.189.173.27 -> 80.193.213.24 RTP EVENT Payload type=RTP Event, DTMF Four 4 (end)
> 4.669065 195.189.173.27 -> 80.193.213.24 RTP EVENT Payload type=RTP Event, DTMF Four 4 (end)
> 4.669073 195.189.173.27 -> 80.193.213.24 RTP EVENT Payload type=RTP Event, DTMF Four 4 (end)
> 5.162105 195.189.173.27 -> 80.193.213.24 RTP EVENT Payload type=RTP Event, DTMF Five 5
> 5.162132 195.189.173.27 -> 80.193.213.24 RTP EVENT Payload type=RTP Event, DTMF Five 5 (end)
> 5.162141 195.189.173.27 -> 80.193.213.24 RTP EVENT Payload type=RTP Event, DTMF Five 5 (end)
> 5.162149 195.189.173.27 -> 80.193.213.24 RTP EVENT Payload type=RTP Event, DTMF Five 5 (end)
> {code}
> The 4 packets for "1" above arrived in the 3-4-1-2 sequence, and that digit was ignored by asterisk (only 4 and 5 were transmitted which caused the wrong extension to be called.
> When that happens the DTMF is just discarded by asterisk (and that also happens for 2-1-3-4 sequences which are more common).
> It doesn't occur in trixbox's 1.4.24, so it would be a regression at some point.
> Here is the corresponding rtpdebug output
> {code}
> [2011-09-01 11:39:41] VERBOSE[5944] res_rtp_asterisk.c: Got RTP packet from 195.189.173.27:28704 (type 101, seq 025103, ts 027992, len 000004)
> [2011-09-01 11:39:41] VERBOSE[5944] res_rtp_asterisk.c: Got RTP RFC2833 from 195.189.173.27:28704 (type 101, seq 025103, ts 027992, len 000004, mark 0, event 00000001, end 1, duration 00800)
> [2011-09-01 11:39:41] VERBOSE[5944] res_rtp_asterisk.c: Got RTP packet from 195.189.173.27:28704 (type 101, seq 025104, ts 027992, len 000004)
> [2011-09-01 11:39:41] VERBOSE[5944] res_rtp_asterisk.c: Got RTP RFC2833 from 195.189.173.27:28704 (type 101, seq 025104, ts 027992, len 000004, mark 0, event 00000001, end 1, duration 00800)
> [2011-09-01 11:39:41] VERBOSE[5944] res_rtp_asterisk.c: Got RTP packet from 195.189.173.27:28704 (type 101, seq 025101, ts 027992, len 000004)
> [2011-09-01 11:39:41] VERBOSE[5944] res_rtp_asterisk.c: Got RTP RFC2833 from 195.189.173.27:28704 (type 101, seq 025101, ts 027992, len 000004, mark 1, event 00000001, end 0, duration 00000)
> [2011-09-01 11:39:41] VERBOSE[5944] res_rtp_asterisk.c: Got RTP packet from 195.189.173.27:28704 (type 101, seq 025102, ts 027992, len 000004)
> [2011-09-01 11:39:41] VERBOSE[5944] res_rtp_asterisk.c: Got RTP RFC2833 from 195.189.173.27:28704 (type 101, seq 025102, ts 027992, len 000004, mark 0, event 00000001, end 1, duration 00800)
> [...]
> [2011-09-01 11:39:42] VERBOSE[5944] res_rtp_asterisk.c: Got RTP packet from 195.189.173.27:28704 (type 101, seq 025128, ts 033032, len 000004)
> [2011-09-01 11:39:42] VERBOSE[5944] res_rtp_asterisk.c: Got RTP RFC2833 from 195.189.173.27:28704 (type 101, seq 025128, ts 033032, len 000004, mark 1, event 00000004, end 0, duration 00000)
> [2011-09-01 11:39:42] DTMF[5944] channel.c: DTMF begin '4' received on SIP/voipfone-200-00000002
> [2011-09-01 11:39:42] DTMF[5944] channel.c: DTMF begin ignored '4' on SIP/voipfone-200-00000002
> [2011-09-01 11:39:42] VERBOSE[5944] res_rtp_asterisk.c: Got RTP packet from 195.189.173.27:28704 (type 101, seq 025129, ts 033032, len 000004)
> [2011-09-01 11:39:42] VERBOSE[5944] res_rtp_asterisk.c: Got RTP RFC2833 from 195.189.173.27:28704 (type 101, seq 025129, ts 033032, len 000004, mark 0, event 00000004, end 1, duration 00800)
> [2011-09-01 11:39:42] DTMF[5944] channel.c: DTMF end '4' received on SIP/voipfone-200-00000002, duration 100 ms
> [2011-09-01 11:39:42] DTMF[5944] channel.c: DTMF end passthrough '4' on SIP/voipfone-200-00000002
> [2011-09-01 11:39:42] VERBOSE[5944] res_rtp_asterisk.c: Got RTP packet from 195.189.173.27:28704 (type 101, seq 025131, ts 033032, len 000004)
> [2011-09-01 11:39:42] VERBOSE[5944] res_rtp_asterisk.c: Got RTP RFC2833 from 195.189.173.27:28704 (type 101, seq 025131, ts 033032, len 000004, mark 0, event 00000004, end 1, duration 00800)
> [2011-09-01 11:39:42] VERBOSE[5944] res_rtp_asterisk.c: Got RTP packet from 195.189.173.27:28704 (type 101, seq 025130, ts 033032, len 000004)
> [2011-09-01 11:39:42] VERBOSE[5944] res_rtp_asterisk.c: Got RTP RFC2833 from 195.189.173.27:28704 (type 101, seq 025130, ts 033032, len 000004, mark 0, event 00000004, end 1, duration 00800)
> [...]
> [2011-09-01 11:39:42] VERBOSE[5944] res_rtp_asterisk.c: Got RTP packet from 195.189.173.27:28704 (type 101, seq 025143, ts 036952, len 000004)
> [2011-09-01 11:39:42] VERBOSE[5944] res_rtp_asterisk.c: Got RTP RFC2833 from 195.189.173.27:28704 (type 101, seq 025143, ts 036952, len 000004, mark 1, event 00000005, end 0, duration 00000)
> [2011-09-01 11:39:42] DTMF[5944] channel.c: DTMF begin '5' received on SIP/voipfone-200-00000002
> [2011-09-01 11:39:42] DTMF[5944] channel.c: DTMF begin passthrough '5' on SIP/voipfone-200-00000002
> [2011-09-01 11:39:42] VERBOSE[5944] res_rtp_asterisk.c: Got RTP packet from 195.189.173.27:28704 (type 101, seq 025144, ts 036952, len 000004)
> [2011-09-01 11:39:42] VERBOSE[5944] res_rtp_asterisk.c: Got RTP RFC2833 from 195.189.173.27:28704 (type 101, seq 025144, ts 036952, len 000004, mark 0, event 00000005, end 1, duration 00800)
> [2011-09-01 11:39:42] DTMF[5944] channel.c: DTMF end '5' received on SIP/voipfone-200-00000002, duration 100 ms
> [2011-09-01 11:39:42] DTMF[5944] channel.c: DTMF end accepted with begin '5' on SIP/voipfone-200-00000002
> [2011-09-01 11:39:42] DTMF[5944] channel.c: DTMF end '5' detected to have actual duration 0 on the wire, emulation will be triggered on SIP/voipfone-200-00000002
> [2011-09-01 11:39:42] DTMF[5944] channel.c: DTMF end '5' has duration 0 but want minimum 80, emulating on SIP/voipfone-200-00000002
> [2011-09-01 11:39:42] VERBOSE[5944] res_rtp_asterisk.c: Got RTP packet from 195.189.173.27:28704 (type 101, seq 025145, ts 036952, len 000004)
> [2011-09-01 11:39:42] VERBOSE[5944] res_rtp_asterisk.c: Got RTP RFC2833 from 195.189.173.27:28704 (type 101, seq 025145, ts 036952, len 000004, mark 0, event 00000005, end 1, duration 00800)
> [2011-09-01 11:39:42] VERBOSE[5944] res_rtp_asterisk.c: Got RTP packet from 195.189.173.27:28704 (type 101, seq 025146, ts 036952, len 000004)
> [2011-09-01 11:39:42] VERBOSE[5944] res_rtp_asterisk.c: Got RTP RFC2833 from 195.189.173.27:28704 (type 101, seq 025146, ts 036952, len 000004, mark 0, event 00000005, end 1, duration 00800)
> [2011-09-01 11:39:43] DTMF[5944] channel.c: DTMF end emulation of '5' queued on SIP/voipfone-200-00000002
> {code}
> Sequences were:
> * '1': 3-4-1-2
> * '4': 1-2-4-3
> * '5': 1-2-3-4
> Although the '5' digit is the only one that was received in order, note the note above about duration 0. In that 4 packet sequence for each digit, the "start" packet has duration 0, and the 3 following end ones have duration 800.
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
More information about the asterisk-bugs
mailing list