[Home]

Summary:ASTERISK-28843: res_rtp_asterisk: Duplicate detection of DTMF - Wideband codec / MS customisation
Reporter:David Herselman (bbs2web)Labels:
Date Opened:2020-04-19 04:59:19Date Closed:
Priority:MinorRegression?
Status:Open/NewComponents:Resources/res_rtp_asterisk
Versions:16.9.0 Frequency of
Occurrence		Constant
Related
Issues:
Environment:CentOS 7.5 Sangoma 7 FreePBX Distro on KVM guest PJSIP trunk to Microsoft Teams IAX2 trunk to Office PBXAttachments:( 0) [MS-DTMF].pdf
( 1) compare_rtp_asterisk.png
( 2) iax2_forwarded.png
( 3) out-1980-27117211904-20200419-093244-1587281564.10.mp3
( 4) teams_silk16.zip
( 5) teams-dtmf-g729-compact-nodebug.txt
( 6) teams-dtmf-g729-debug.txt
( 7) teams-dtmf-silk16-compact-nodebug.txt
( 8) teams-dtmf-silk16-debug.txt
( 9) Wireshark_screenshot.png
Description:Asterisk interprets double DTMF rfc2833 key presses, only when using a wide band (16 KHz) audio codec such as silk16. A comparative narrow band (8 KHz) g729 call works perfectly.
\\
\\
I couldn't find an existing bug report in JIRA but did find the following discussion on the IETF mailing list back in 2006. It appears to debates some of the nuances around handling calls where audio and telephone-event messages negotiate different timestamp frequencies, mainly relating to packet loss in those situations:
 https://mailarchive.ietf.org/arch/msg/avt/Hx8rEwIQr9FYrTjP8D-TK41XCag/
\\
\\
Microsoft's implementation amends rfc4733 but I couldn't discern anything in the document which explains why digits would get recognised twice. I've uploaded Microsoft's documentation as part of this report.
\\
\\
One possible clue in the debug log may be that encoding is trying to run at 320 samples/second instead of 160 and therefor may interpret a single dtmf tone as two events.
\\
\\
\\
Problem summary:
{quote}
Duplicate rfc2833 DTMF events detected when using wideband codec {{SILK/16000}} together with {{telephone-event/8000}}
{quote}
\\
\\
In both of the following examples an incoming Teams Direct Route call from +27115551904 arrives on Asterisk for a destination of 1980 which is reachable via IAX2. A single '8' key press is sent a couple seconds after call establishment.
\\
\\
{panel:title=Duplicate DTMF with wide band codec}
{noformat}
SIP/2.0 200 OK
Via: SIP/2.0/TLS 52.114.76.76:5061;rport=8256;received=52.114.76.76;branch=z9hG4bK7bd2d1d3
Call-ID: 10b73fc68209572abdd9757dfc509e5f
From: "David Herselman" <sip:+27115551904@sip.pstnhub.microsoft.com;user=phone>;tag=7ac926eb533041e79123af4a702621b6
To: <sip:1980@asterisk.company.co.za>;tag=1ff1ddc8-3608-46ec-a353-9cac40ca8098;user=phone
CSeq: 2 INVITE
Contact: <sip:asterisk.company.co.za:5061;transport=TLS>
Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER
Supported: 100rel, timer, replaces, norefersub
Server: FPBX-15.0.16.49(16.9.0)
Content-Type: application/sdp
Content-Length:   826

v=0
o=- 0 3 IN IP4 196.1.1.1
s=Asterisk
c=IN IP4 196.1.1.1
t=0 0
m=audio 13124 RTP/SAVP 104 18 0 8 101
a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:lnIADcidXdqNLxecqAZc/5LUEGleofDQ1x951fe6
a=ice-ufrag:40c679ae5ecfef5e43f0fb86063d6fed
a=ice-pwd:2349eab80869ed7f7be1d42f3eff26d8
a=candidate:Hc0a81407 1 UDP 2130706431 192.168.20.7 13124 typ host
a=candidate:S294f175b 1 UDP 1694498815 196.1.1.1 13124 typ srflx raddr 192.168.20.7 rport 13124
a=candidate:Hc0a81407 2 UDP 2130706430 192.168.20.7 13125 typ host
a=candidate:S294f175b 2 UDP 1694498814 196.1.1.1 13125 typ srflx raddr 192.168.20.7 rport 13125
a=rtpmap:104 SILK/16000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:100
a=sendrecv

Lots of these:
[2020-04-19 09:12:49] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50010 (type 104, seq 015233, ts 48369872, len 000064)
[2020-04-19 09:12:49] DEBUG[22953][C-00000004] audiohook.c: Failed to get 320 samples from write factory 0x7fa6800729c8
[2020-04-19 09:12:49] DEBUG[22953][C-00000004] audiohook.c: Read factory 0x7fa680071f88 and write factory 0x7fa6800729c8 both fail to provide 320 samples
[2020-04-19 09:12:49] DEBUG[22954][C-00000004] translate.c: Sample size different 320 vs 160

Makes it super confusing that debug messages appear twice but the RTP type 101 packets are detected twice as well:
[davidh@sipteams ~]# grep -e 'type 101' -e 2833 -e DTMF teams-dtmf-silk16-debug.txt;
[2020-04-19 09:12:48] DEBUG[22952][C-00000004] dahdi/bridge_native_dahdi.c: Channel 'IAX2/Office-28115' has DTMF hooks.
[2020-04-19 09:12:49] DEBUG[22952][C-00000004] dahdi/bridge_native_dahdi.c: Channel 'IAX2/Office-28115' has DTMF hooks.
[2020-04-19 09:12:49] DEBUG[22952][C-00000004] dahdi/bridge_native_dahdi.c: Channel 'IAX2/Office-28115' has DTMF hooks.
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50010 (type 101, seq 015285, ts 48386209, len 000008)
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50010 (type 101, seq 015285, ts 48386209, len 000004, mark 1, event 00000008, end 0, duration 00160)
[2020-04-19 09:12:50] DEBUG[22952][C-00000004] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:12:50] DEBUG[22952][C-00000004] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 56 (8), at 192.168.10.53:50010
[2020-04-19 09:12:50] DTMF[22952][C-00000004] channel.c: DTMF begin '8' received on PJSIP/msteams_sip1-00000003
[2020-04-19 09:12:50] DTMF[22952][C-00000004] channel.c: DTMF begin '8' received on PJSIP/msteams_sip1-00000003
[2020-04-19 09:12:50] DTMF[22952][C-00000004] channel.c: DTMF begin passthrough '8' on PJSIP/msteams_sip1-00000003
[2020-04-19 09:12:50] DTMF[22952][C-00000004] channel.c: DTMF begin passthrough '8' on PJSIP/msteams_sip1-00000003
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50010 (type 101, seq 015287, ts 48386209, len 000008)
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50010 (type 101, seq 015287, ts 48386209, len 000004, mark 0, event 00000008, end 0, duration 00320)
[2020-04-19 09:12:50] DEBUG[22952][C-00000004] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50010 (type 101, seq 015288, ts 48386209, len 000008)
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50010 (type 101, seq 015288, ts 48386209, len 000004, mark 0, event 00000008, end 0, duration 00480)
[2020-04-19 09:12:50] DEBUG[22952][C-00000004] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50010 (type 101, seq 015290, ts 48386209, len 000008)
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50010 (type 101, seq 015290, ts 48386209, len 000004, mark 0, event 00000008, end 0, duration 00640)
[2020-04-19 09:12:50] DEBUG[22952][C-00000004] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50010 (type 101, seq 015293, ts 48386209, len 000008)
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50010 (type 101, seq 015293, ts 48386209, len 000004, mark 0, event 00000008, end 0, duration 00800)
[2020-04-19 09:12:50] DEBUG[22952][C-00000004] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50010 (type 101, seq 015294, ts 48386209, len 000008)
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50010 (type 101, seq 015294, ts 48386209, len 000004, mark 0, event 00000008, end 0, duration 00960)
[2020-04-19 09:12:50] DEBUG[22952][C-00000004] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50010 (type 101, seq 015297, ts 48386209, len 000008)
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50010 (type 101, seq 015297, ts 48386209, len 000004, mark 0, event 00000008, end 0, duration 01120)
[2020-04-19 09:12:50] DEBUG[22952][C-00000004] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50010 (type 101, seq 015298, ts 48386209, len 000008)
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50010 (type 101, seq 015298, ts 48386209, len 000004, mark 0, event 00000008, end 0, duration 01280)
[2020-04-19 09:12:50] DEBUG[22952][C-00000004] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:12:50] DEBUG[22952][C-00000004] res_rtp_asterisk.c: Creating END DTMF Frame: 56 (8), at 192.168.10.53:50010
[2020-04-19 09:12:50] DTMF[22952][C-00000004] channel.c: DTMF end '8' received on PJSIP/msteams_sip1-00000003, duration 80 ms
[2020-04-19 09:12:50] DTMF[22952][C-00000004] channel.c: DTMF end '8' received on PJSIP/msteams_sip1-00000003, duration 80 ms
[2020-04-19 09:12:50] DTMF[22952][C-00000004] channel.c: DTMF end accepted with begin '8' on PJSIP/msteams_sip1-00000003
[2020-04-19 09:12:50] DTMF[22952][C-00000004] channel.c: DTMF end accepted with begin '8' on PJSIP/msteams_sip1-00000003
[2020-04-19 09:12:50] DTMF[22952][C-00000004] channel.c: DTMF end passthrough '8' on PJSIP/msteams_sip1-00000003
[2020-04-19 09:12:50] DTMF[22952][C-00000004] channel.c: DTMF end passthrough '8' on PJSIP/msteams_sip1-00000003
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50010 (type 101, seq 015301, ts 48386209, len 000008)
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50010 (type 101, seq 015301, ts 48386209, len 000004, mark 0, event 00000008, end 0, duration 01440)
[2020-04-19 09:12:50] DEBUG[22952][C-00000004] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:12:50] DEBUG[22952][C-00000004] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 56 (8), at 192.168.10.53:50010
[2020-04-19 09:12:50] DTMF[22952][C-00000004] channel.c: DTMF begin '8' received on PJSIP/msteams_sip1-00000003
[2020-04-19 09:12:50] DTMF[22952][C-00000004] channel.c: DTMF begin '8' received on PJSIP/msteams_sip1-00000003
[2020-04-19 09:12:50] DTMF[22952][C-00000004] channel.c: DTMF begin ignored '8' on PJSIP/msteams_sip1-00000003
[2020-04-19 09:12:50] DTMF[22952][C-00000004] channel.c: DTMF begin ignored '8' on PJSIP/msteams_sip1-00000003
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50010 (type 101, seq 015302, ts 48386209, len 000008)
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50010 (type 101, seq 015302, ts 48386209, len 000004, mark 0, event 00000008, end 1, duration 01600)
[2020-04-19 09:12:50] DEBUG[22952][C-00000004] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:12:50] DEBUG[22952][C-00000004] res_rtp_asterisk.c: Creating END DTMF Frame: 56 (8), at 192.168.10.53:50010
[2020-04-19 09:12:50] DTMF[22952][C-00000004] channel.c: DTMF end '8' received on PJSIP/msteams_sip1-00000003, duration 100 ms
[2020-04-19 09:12:50] DTMF[22952][C-00000004] channel.c: DTMF end '8' received on PJSIP/msteams_sip1-00000003, duration 100 ms
[2020-04-19 09:12:50] DTMF[22952][C-00000004] channel.c: DTMF end '8' received on PJSIP/msteams_sip1-00000003, duration 100 ms
[2020-04-19 09:12:50] DTMF[22952][C-00000004] channel.c: DTMF end '8' received on PJSIP/msteams_sip1-00000003, duration 100 ms
[2020-04-19 09:12:50] DTMF[22952][C-00000004] channel.c: DTMF begin emulation of '8' with duration 100 queued on PJSIP/msteams_sip1-00000003
[2020-04-19 09:12:50] DTMF[22952][C-00000004] channel.c: DTMF begin emulation of '8' with duration 100 queued on PJSIP/msteams_sip1-00000003
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50010 (type 101, seq 015303, ts 48386209, len 000008)
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50010 (type 101, seq 015303, ts 48386209, len 000004, mark 0, event 00000008, end 1, duration 01600)
[2020-04-19 09:12:50] DEBUG[22952][C-00000004] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:12:50] DEBUG[22952][C-00000004] res_rtp_asterisk.c: Dropping duplicate or out of order DTMF END frame (seqno: 15303, ts 48386209, digit 8)
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50010 (type 101, seq 015304, ts 48386209, len 000008)
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50010 (type 101, seq 015304, ts 48386209, len 000004, mark 0, event 00000008, end 1, duration 01600)
[2020-04-19 09:12:50] DEBUG[22952][C-00000004] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:12:50] DEBUG[22952][C-00000004] res_rtp_asterisk.c: Dropping duplicate or out of order DTMF END frame (seqno: 15304, ts 48386209, digit 8)
[2020-04-19 09:12:51] DTMF[22952][C-00000004] channel.c: DTMF end emulation of '8' queued on PJSIP/msteams_sip1-00000003
[2020-04-19 09:12:51] DTMF[22952][C-00000004] channel.c: DTMF end emulation of '8' queued on PJSIP/msteams_sip1-00000003
{noformat}
{panel}
\\
{panel:title=Normal DTMF with narrow band codec}
{noformat}
SIP/2.0 200 OK
Via: SIP/2.0/TLS 52.114.76.76:5061;rport=5128;received=52.114.76.76;branch=z9hG4bKc8bff66f
Call-ID: dd815213b70b54f089971b041274c997
From: "David Herselman" <sip:+27115551904@sip.pstnhub.microsoft.com;user=phone>;tag=61b1845891d0438eaee84bc79a046d45
To: <sip:1980@asterisk.company.co.za>;tag=6c64f330-1893-4017-9bc7-873c17c91ffd;user=phone
CSeq: 2 INVITE
Contact: <sip:asterisk.company.co.za:5061;transport=TLS>
Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER
Supported: 100rel, timer, replaces, norefersub
Server: FPBX-15.0.16.49(16.9.0)
Content-Type: application/sdp
Content-Length:   797

v=0
o=- 0 3 IN IP4 196.1.1.1
s=Asterisk
c=IN IP4 196.1.1.1
t=0 0
m=audio 13458 RTP/SAVP 18 0 8 101
a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:2/fmRbQY0aix4uUxrTe8KqtxP6R/JJaUUGBNMuvP
a=ice-ufrag:416688807842f6a42f605d0975eeae8a
a=ice-pwd:3420f1fc1acc461f1c018dc41640f589
a=candidate:Hc0a81407 1 UDP 2130706431 192.168.20.7 13458 typ host
a=candidate:S294f175b 1 UDP 1694498815 196.1.1.1 13458 typ srflx raddr 192.168.20.7 rport 13458
a=candidate:Hc0a81407 2 UDP 2130706430 192.168.20.7 13459 typ host
a=candidate:S294f175b 2 UDP 1694498814 196.1.1.1 13459 typ srflx raddr 192.168.20.7 rport 13459
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:150
a=sendrecv

DTMF works perfectly and isn't detected twice, although debug lines still print things twice:
[davidh@sipteams ~]# grep -e 'type 101' -e 2833 -e DTMF teams-dtmf-g729-debug.txt;
[2020-04-19 09:32:45] DEBUG[26873][C-00000006] dahdi/bridge_native_dahdi.c: Channel 'IAX2/Office-28327' has DTMF hooks.
[2020-04-19 09:32:45] DEBUG[26873][C-00000006] dahdi/bridge_native_dahdi.c: Channel 'IAX2/Office-28327' has DTMF hooks.
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50006 (type 101, seq 012003, ts 480000275, len 000008)
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50006 (type 101, seq 012003, ts 480000275, len 000004, mark 1, event 00000008, end 0, duration 00160)
[2020-04-19 09:32:47] DEBUG[26873][C-00000006] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:32:47] DEBUG[26873][C-00000006] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 56 (8), at 192.168.10.53:50006
[2020-04-19 09:32:47] DTMF[26873][C-00000006] channel.c: DTMF begin '8' received on PJSIP/msteams_sip1-00000005
[2020-04-19 09:32:47] DTMF[26873][C-00000006] channel.c: DTMF begin '8' received on PJSIP/msteams_sip1-00000005
[2020-04-19 09:32:47] DTMF[26873][C-00000006] channel.c: DTMF begin passthrough '8' on PJSIP/msteams_sip1-00000005
[2020-04-19 09:32:47] DTMF[26873][C-00000006] channel.c: DTMF begin passthrough '8' on PJSIP/msteams_sip1-00000005
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50006 (type 101, seq 012005, ts 480000275, len 000008)
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50006 (type 101, seq 012005, ts 480000275, len 000004, mark 0, event 00000008, end 0, duration 00320)
[2020-04-19 09:32:47] DEBUG[26873][C-00000006] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50006 (type 101, seq 012007, ts 480000275, len 000008)
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50006 (type 101, seq 012007, ts 480000275, len 000004, mark 0, event 00000008, end 0, duration 00480)
[2020-04-19 09:32:47] DEBUG[26873][C-00000006] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50006 (type 101, seq 012009, ts 480000275, len 000008)
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50006 (type 101, seq 012009, ts 480000275, len 000004, mark 0, event 00000008, end 0, duration 00640)
[2020-04-19 09:32:47] DEBUG[26873][C-00000006] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50006 (type 101, seq 012011, ts 480000275, len 000008)
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50006 (type 101, seq 012011, ts 480000275, len 000004, mark 0, event 00000008, end 0, duration 00800)
[2020-04-19 09:32:47] DEBUG[26873][C-00000006] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50006 (type 101, seq 012013, ts 480000275, len 000008)
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50006 (type 101, seq 012013, ts 480000275, len 000004, mark 0, event 00000008, end 0, duration 00960)
[2020-04-19 09:32:47] DEBUG[26873][C-00000006] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50006 (type 101, seq 012015, ts 480000275, len 000008)
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50006 (type 101, seq 012015, ts 480000275, len 000004, mark 0, event 00000008, end 0, duration 01120)
[2020-04-19 09:32:47] DEBUG[26873][C-00000006] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50006 (type 101, seq 012017, ts 480000275, len 000008)
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50006 (type 101, seq 012017, ts 480000275, len 000004, mark 0, event 00000008, end 0, duration 01280)
[2020-04-19 09:32:47] DEBUG[26873][C-00000006] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50006 (type 101, seq 012019, ts 480000275, len 000008)
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50006 (type 101, seq 012019, ts 480000275, len 000004, mark 0, event 00000008, end 0, duration 01440)
[2020-04-19 09:32:47] DEBUG[26873][C-00000006] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50006 (type 101, seq 012021, ts 480000275, len 000008)
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50006 (type 101, seq 012021, ts 480000275, len 000004, mark 0, event 00000008, end 1, duration 01600)
[2020-04-19 09:32:47] DEBUG[26873][C-00000006] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:32:47] DEBUG[26873][C-00000006] res_rtp_asterisk.c: Creating END DTMF Frame: 56 (8), at 192.168.10.53:50006
[2020-04-19 09:32:47] DTMF[26873][C-00000006] channel.c: DTMF end '8' received on PJSIP/msteams_sip1-00000005, duration 200 ms
[2020-04-19 09:32:47] DTMF[26873][C-00000006] channel.c: DTMF end '8' received on PJSIP/msteams_sip1-00000005, duration 200 ms
[2020-04-19 09:32:47] DTMF[26873][C-00000006] channel.c: DTMF end accepted with begin '8' on PJSIP/msteams_sip1-00000005
[2020-04-19 09:32:47] DTMF[26873][C-00000006] channel.c: DTMF end accepted with begin '8' on PJSIP/msteams_sip1-00000005
[2020-04-19 09:32:47] DTMF[26873][C-00000006] channel.c: DTMF end passthrough '8' on PJSIP/msteams_sip1-00000005
[2020-04-19 09:32:47] DTMF[26873][C-00000006] channel.c: DTMF end passthrough '8' on PJSIP/msteams_sip1-00000005
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50006 (type 101, seq 012022, ts 480000275, len 000008)
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50006 (type 101, seq 012022, ts 480000275, len 000004, mark 0, event 00000008, end 1, duration 01600)
[2020-04-19 09:32:47] DEBUG[26873][C-00000006] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:32:47] DEBUG[26873][C-00000006] res_rtp_asterisk.c: Dropping duplicate or out of order DTMF END frame (seqno: 12022, ts 480000275, digit 8)
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.53:50006 (type 101, seq 012023, ts 480000275, len 000008)
[2020-04-19 09:32:47] VERBOSE[26873][C-00000006] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50006 (type 101, seq 012023, ts 480000275, len 000004, mark 0, event 00000008, end 1, duration 01600)
[2020-04-19 09:32:47] DEBUG[26873][C-00000006] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:32:47] DEBUG[26873][C-00000006] res_rtp_asterisk.c: Dropping duplicate or out of order DTMF END frame (seqno: 12023, ts 480000275, digit 8)
{noformat}
{panel}
Comments:By: Asterisk Team (asteriskteam) 2020-04-19 04:59:20.406-0500

Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution.

A good first step is for you to review the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] if you haven't already. The guidelines detail what is expected from an Asterisk issue report.

Then, if you are submitting a patch, please review the [Patch Contribution Process|https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process].

Please note that once your issue enters an open state it has been accepted. As Asterisk is an open source project there is no guarantee or timeframe on when your issue will be looked into. If you need expedient resolution you will need to find and pay a suitable developer. Asking for an update on your issue will not yield any progress on it and will not result in a response. All updates are posted to the issue when they occur.
By: David Herselman (bbs2web) 2020-04-19 05:00:59.816-0500

Microsoft amendments to rfc4733
By: David Herselman (bbs2web) 2020-04-19 05:02:51.598-0500

Normal DTMF - narrow band g729 codec where timestamp frequency matches telephone-events
By: David Herselman (bbs2web) 2020-04-19 05:03:31.903-0500

Duplicate DTMF - wide band silk16 codec where timestamp frequency does not match telephone-events
By: David Herselman (bbs2web) 2020-04-19 05:04:11.460-0500

Normal DTMF - narrow band g729 codec where timestamp frequency matches telephone-events - debug level
By: David Herselman (bbs2web) 2020-04-19 05:04:41.641-0500

Duplicate DTMF - wide band silk16 codec where timestamp frequency does not match telephone-events - debug level
By: David Herselman (bbs2web) 2020-04-19 05:07:56.195-0500

Wireshark IAX2 flow sequence shows duplicate DMTF events being forwarded
By: Joshua C. Colp (jcolp) 2020-04-19 08:23:25.786-0500

Please attach a packet capture so the DTMF events can be analyzed before hitting Asterisk.
By: David Herselman (bbs2web) 2020-04-19 08:53:43.886-0500

I have a packet capture but I presume Wireshark can't decode TLS v1.2 as it finds no RTP streams after providing the private certificate key. I presume it would be useless in an unencrypted state.

Comparing the grep output for 'type 101' from the two debug logs shows identical values. I presume an internal timer runs at the voice path sampling rate, times out and generates the incorrect dtmf end.

By: David Herselman (bbs2web) 2020-04-19 08:55:02.073-0500

Comparative telephone-events between the two calls
By: Joshua C. Colp (jcolp) 2020-04-19 08:55:43.460-0500

Media is not within the TLS stream, and with SRTP only the payload is encrypted. The RTP stream is still present and viewable, it just has to be manually set to Decode as RTP.
By: David Herselman (bbs2web) 2020-04-19 08:58:09.660-0500

Snippet of Wireshark showing it being unable to decode SRTP after loading the certificate's private key.
By: David Herselman (bbs2web) 2020-04-19 08:59:57.529-0500

Packet capture of SIP TLS v1.2 with encrypted RTP, presumably useless...
By: Joshua C. Colp (jcolp) 2020-04-19 09:04:56.662-0500

The problem is that audio is intermingled with the DTMF digits, and there is code which ends the DTMF if a timestamp is reached but that timestamp is based on 8000Hz. Other implementations don't intermingle audio and DTMF, they just send the DTMF.
By: David Herselman (bbs2web) 2020-04-19 09:07:41.556-0500

Dunno how to extract the RTP telephone-event messages out of the packet capture. Would it help to reproduce the issue whilst running Asterisk with a higher debugging level? Uploaded debugs have the following set:
{noformat}
logger add channel debug_log_123456 notice,warning,error,debug,verbose,dtmf
core set verbose 6
core set debug 6
pjsip set logger on
rtp set debug on
{noformat}
By: Joshua C. Colp (jcolp) 2020-04-19 09:09:03.724-0500

There's no need to do anything further, I've already grabbed the info from the pcap.
By: David Herselman (bbs2web) 2020-04-19 09:11:47.208-0500

Microsoft's amendments specifically state that:\\
_While dynamic payload type binding is required, both the sender and receiver of message blocks conforming to this protocol MUST fix the telephony signaling information at 8000 Hertz. Dynamic negotiation of the clock frequency of the DTMF payload MUST NOT be used._\\
\\
The RTP events themselves appear to be identical on the two calls, I presume the expiry timer to reach expiry prematurely when audio is running at 16 KHz?
By: David Herselman (bbs2web) 2020-04-19 09:12:20.292-0500

Thanks, sorry the page only refreshes with your comments when I send mine... ;)
By: David Herselman (bbs2web) 2020-04-22 00:37:12.180-0500

Uploaded call recording (out-1980-27117211904-20200419-093244-1587281564.10.mp3) which doesn't appear to indicate inline audio.
By: David Herselman (bbs2web) 2020-04-22 00:54:28.470-0500

I unfortunately lack programming experience but presume that the audio being negotiated at 16 KHz whilst DTMF is negotiated at 8 KHz is the underlying cause?

https://github.com/asterisk/asterisk/blob/master/res/res_rtp_asterisk.c at around lines 7267 appears to be the place where the DTMF tone is presumed to have continued too long and a DTMF end frame is subsequently generated:

{noformat}
if (rtp->dtmf_timeout && rtp->dtmf_timeout < timestamp) {
rtp->dtmf_timeout = 0;

if (rtp->resp) {
struct ast_frame *f;
f = create_dtmf_frame(instance, AST_FRAME_DTMF_END, 0);
f->len = ast_tvdiff_ms(ast_samp2tv(rtp->dtmf_duration, ast_rtp_get_rate(f->subclass.format)), ast_tv(0, 0));
rtp->resp = 0;
rtp->dtmf_timeout = rtp->dtmf_duration = 0;
AST_LIST_INSERT_TAIL(&frames, f, frame_list);
return AST_LIST_FIRST(&frames);
}
}
{noformat}

I presume ast_rtp_get_rate returns the 16 KHz frequency from the type 104 RTP packets which are running at 16 KHz whilst DTMF was negotiated at 8 KHz. At this time the DTMF tone has been active for only 1280 'ticks'.  1280 / 8000 = 160ms  whereas 1280 / 16000 = 80 ms which matches what the debug indicates:

{noformat}
[2020-04-19 09:12:50] VERBOSE[22952][C-00000004] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.53:50010 (type 101, seq 015298, ts 48386209, len 000004, mark 0, event 00000008, end 0, duration 01280)
[2020-04-19 09:12:50] DEBUG[22952][C-00000004] res_rtp_asterisk.c: - RTP 2833 Event: 00000008 (len = 4)
[2020-04-19 09:12:50] DEBUG[22952][C-00000004] res_rtp_asterisk.c: Creating END DTMF Frame: 56 (8), at 192.168.10.53:50010
[2020-04-19 09:12:50] DTMF[22952][C-00000004] channel.c: DTMF end '8' received on PJSIP/msteams_sip1-00000003, duration 80 ms
{noformat}

By: Joshua C. Colp (jcolp) 2020-04-22 04:06:48.109-0500

It's the setting of rtp->dtmf_timeout that is the problem as to why it is triggering.
By: David Herselman (bbs2web) 2020-08-27 02:38:47.761-0500

Hi Joshua,

I've been trying to poke around over the last couple of months and really have no idea what I'm doing. Is the problem fundamentally that Microsoft are doing something non standard or is the problem simply a quirk or bug in Asterisk?
By: Joshua C. Colp (jcolp) 2020-08-27 04:23:51.288-0500

From looking at my past comments, it's specifically a bug in Asterisk.
By: David Herselman (bbs2web) 2023-01-22 08:09:15.336-0600

Is there any likely hood of someone looking at this, with the current JIRA status flags (severity minor)?

I would like contribute in getting this bug fixed but my only apparent recourse is to contact a general development company and inquire if anyone knows C. I would naturally point them at the Coding Guidelines (https://wiki.asterisk.org/wiki/display/AST/Coding+Guidelines), is there any specific information that may be useful in hopefully getting the resulting patch submitted?

As an overview one has to most probably obtain the bitrate of the voice (main?) channel and then adjust the rtp->dtmf_timeout value in relation to the telephone-event bitrate. Would this need to be controlled by a switch somewhere or would this method of adjusting the timeout be accepted in to the codebase?

For what it's worth, this also (predictably) affects calls where PJSIP interfaces to Microsoft Teams Direct Route and negotiates opus:

Asterisk negotiates and sends this:
{noformat}
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1
a=rtpmap:101 telephone-event/8000
{noformat}

Single '4' press results in Asterisk doing the following:
{noformat}
[2023-01-22 15:35:37] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.102:50012 (type 101, seq 027355, ts 416064690, len 000008)
[2023-01-22 15:35:37] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.102:50012 (type 101, seq 027355, ts 416064690, len 000004, mark 1, event 00000004, end 0, duration 00160)
[2023-01-22 15:35:37] DEBUG[30845][C-00000c90] res_rtp_asterisk.c: (0x7f2ca01c9920) RTP creating BEGIN DTMF Frame: 52 (4), at 192.168.10.102:50012
[2023-01-22 15:35:37] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.102:50012 (type 101, seq 027357, ts 416064690, len 000008)
[2023-01-22 15:35:37] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.102:50012 (type 101, seq 027357, ts 416064690, len 000004, mark 0, event 00000004, end 0, duration 00320)
[2023-01-22 15:35:37] DEBUG[30845][C-00000c90] res_rtp_asterisk.c: (0x7f2ca01c9920) RTP creating END DTMF Frame: 52 (4), at 192.168.10.102:50012
[2023-01-22 15:35:37] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.102:50012 (type 101, seq 027360, ts 416064690, len 000008)
[2023-01-22 15:35:37] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.102:50012 (type 101, seq 027360, ts 416064690, len 000004, mark 0, event 00000004, end 0, duration 00480)
[2023-01-22 15:35:37] DEBUG[30845][C-00000c90] res_rtp_asterisk.c: (0x7f2ca01c9920) RTP creating BEGIN DTMF Frame: 52 (4), at 192.168.10.102:50012
[2023-01-22 15:35:37] DEBUG[30845][C-00000c90] res_rtp_asterisk.c: (0x7f2ca01c9920) RTP creating END DTMF Frame: 52 (4), at 192.168.10.102:50012
[2023-01-22 15:35:37] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.102:50012 (type 101, seq 027363, ts 416064690, len 000008)
[2023-01-22 15:35:37] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.102:50012 (type 101, seq 027363, ts 416064690, len 000004, mark 0, event 00000004, end 0, duration 00800)
[2023-01-22 15:35:37] DEBUG[30845][C-00000c90] res_rtp_asterisk.c: (0x7f2ca01c9920) RTP creating BEGIN DTMF Frame: 52 (4), at 192.168.10.102:50012
[2023-01-22 15:35:37] DEBUG[30845][C-00000c90] res_rtp_asterisk.c: (0x7f2ca01c9920) RTP creating END DTMF Frame: 52 (4), at 192.168.10.102:50012
[2023-01-22 15:35:37] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.102:50012 (type 101, seq 027365, ts 416064690, len 000008)
[2023-01-22 15:35:37] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.102:50012 (type 101, seq 027365, ts 416064690, len 000004, mark 0, event 00000004, end 0, duration 00960)
[2023-01-22 15:35:37] DEBUG[30845][C-00000c90] res_rtp_asterisk.c: (0x7f2ca01c9920) RTP creating BEGIN DTMF Frame: 52 (4), at 192.168.10.102:50012
[2023-01-22 15:35:37] DEBUG[30845][C-00000c90] res_rtp_asterisk.c: (0x7f2ca01c9920) RTP creating END DTMF Frame: 52 (4), at 192.168.10.102:50012
[2023-01-22 15:35:38] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Sent RTP packet to      192.168.10.102:50012 (type 102, seq 010892, ts 101760, len 000139)
[2023-01-22 15:35:38] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.102:50012 (type 101, seq 027367, ts 416064690, len 000008)
[2023-01-22 15:35:38] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.102:50012 (type 101, seq 027367, ts 416064690, len 000004, mark 0, event 00000004, end 0, duration 01120)
[2023-01-22 15:35:38] DEBUG[30845][C-00000c90] res_rtp_asterisk.c: (0x7f2ca01c9920) RTP creating BEGIN DTMF Frame: 52 (4), at 192.168.10.102:50012
[2023-01-22 15:35:38] DEBUG[30845][C-00000c90] res_rtp_asterisk.c: (0x7f2ca01c9920) RTP creating END DTMF Frame: 52 (4), at 192.168.10.102:50012
[2023-01-22 15:35:38] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.102:50012 (type 101, seq 027369, ts 416064690, len 000008)
[2023-01-22 15:35:38] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.102:50012 (type 101, seq 027369, ts 416064690, len 000004, mark 0, event 00000004, end 0, duration 01280)
[2023-01-22 15:35:38] DEBUG[30845][C-00000c90] res_rtp_asterisk.c: (0x7f2ca01c9920) RTP creating BEGIN DTMF Frame: 52 (4), at 192.168.10.102:50012
[2023-01-22 15:35:38] DEBUG[30845][C-00000c90] res_rtp_asterisk.c: (0x7f2ca01c9920) RTP creating END DTMF Frame: 52 (4), at 192.168.10.102:50012
[2023-01-22 15:35:38] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.102:50012 (type 101, seq 027371, ts 416064690, len 000008)
[2023-01-22 15:35:38] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.102:50012 (type 101, seq 027371, ts 416064690, len 000004, mark 0, event 00000004, end 0, duration 01440)
[2023-01-22 15:35:38] DEBUG[30845][C-00000c90] res_rtp_asterisk.c: (0x7f2ca01c9920) RTP creating BEGIN DTMF Frame: 52 (4), at 192.168.10.102:50012
[2023-01-22 15:35:38] DEBUG[30845][C-00000c90] res_rtp_asterisk.c: (0x7f2ca01c9920) RTP creating END DTMF Frame: 52 (4), at 192.168.10.102:50012
[2023-01-22 15:35:38] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.102:50012 (type 101, seq 027373, ts 416064690, len 000008)
[2023-01-22 15:35:38] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.102:50012 (type 101, seq 027373, ts 416064690, len 000004, mark 0, event 00000004, end 1, duration 01600)
[2023-01-22 15:35:38] DEBUG[30845][C-00000c90] res_rtp_asterisk.c: (0x7f2ca01c9920) RTP creating END DTMF Frame: 52 (4), at 192.168.10.102:50012
[2023-01-22 15:35:38] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.102:50012 (type 101, seq 027374, ts 416064690, len 000008)
[2023-01-22 15:35:38] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.102:50012 (type 101, seq 027374, ts 416064690, len 000004, mark 0, event 00000004, end 1, duration 01600)
[2023-01-22 15:35:38] DEBUG[30845][C-00000c90] res_rtp_asterisk.c: (0x7f2ca01c9920) RTP dropping duplicate or out of order DTMF END frame (seqno: 27374, ts 416064690, digit 4)
[2023-01-22 15:35:38] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.102:50012 (type 101, seq 027375, ts 416064690, len 000008)
[2023-01-22 15:35:38] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Got  RTP RFC2833 from   192.168.10.102:50012 (type 101, seq 027375, ts 416064690, len 000004, mark 0, event 00000004, end 1, duration 01600)
[2023-01-22 15:35:38] DEBUG[30845][C-00000c90] res_rtp_asterisk.c: (0x7f2ca01c9920) RTP dropping duplicate or out of order DTMF END frame (seqno: 27375, ts 416064690, digit 4)
[2023-01-22 15:35:38] VERBOSE[30845][C-00000c90] res_rtp_asterisk.c: Got  RTP packet from    192.168.10.102:50012 (type 102, seq 027404, ts 416101045, len 000012)
{noformat}
By: Joshua C. Colp (jcolp) 2023-01-22 12:38:58.471-0600

The severity doesn't dictate whether someone will or will not look at this. It's ultimately whether they want to. The patch contribution process is on the wiki as well[1]. I don't have any answers regarding the implementation, or the repercussions of such changes.

[1] https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process