[Freeswitch-users] DTMF not passing from the A Leg to the B Leg

[Keith Croxford]

I'm coming across a strange, intermittent behavior with RFC2833 DTMF
packets. This is occurring in a production environment, and I've been able
to duplicate this with a very minimal FreeSWITCH installation in a virtual
machine.

Details of the problem:

A customer occasionally has a problem report where their callers are unable
to use the IVR menu. From the user's standpoint, the digits are not
detected. Upon further review, we do receive DTMF event packets from the
carrier, however, they do not traverse the bridge from the A leg to the B
leg.

>From the console logs, I see the following with the first digit.
--
2021-02-20 11:28:30.842108 [DEBUG] mod_sofia.c:645 SOFIA EXCHANGE_MEDIA
2021-02-20 11:28:30.881612 [DEBUG] switch_rtp.c:1890 rtcp_stats_init: audio
ssrc[1488669269] base_seq[26830]
2021-02-20 11:28:30.933002 [DEBUG] switch_rtp.c:7550 Correct audio ip/port
confirmed.
2021-02-20 11:28:34.881612 [DEBUG] switch_rtp.c:7550 Correct audio ip/port
confirmed.
2021-02-20 11:28:34.923555 [DEBUG] switch_rtp.c:7789 RTP RECV DTMF 1:400
2021-02-20 11:28:34.923555 [INFO] switch_channel.c:515 RECV DTMF 1:400
2021-02-20 11:28:34.923555 [DEBUG] switch_rtp.c:5424 Send start packet for
[1] ts=160 dur=160/160/400 seq=51938 lw=160
2021-02-20 11:28:34.942196 [DEBUG] switch_rtp.c:5323 Send middle packet for
[1] ts=160 dur=320/320/400 seq=51939 lw=320
2021-02-20 11:28:34.942196 [DEBUG] switch_rtp.c:5323 Send end packet for
[1] ts=160 dur=480/480/400 seq=51940 lw=320
2021-02-20 11:28:34.942196 [DEBUG] switch_rtp.c:5323 Send end packet for
[1] ts=160 dur=480/480/400 seq=51941 lw=320
2021-02-20 11:28:34.942196 [DEBUG] switch_rtp.c:5323 Send end packet for
[1] ts=160 dur=480/480/400 seq=51942 lw=320
2021-02-20 11:28:34.942196 [DEBUG] switch_rtp.c:5271 Queue digit delay of
40ms
2021-02-20 11:28:35.421487 [DEBUG] switch_rtp.c:6985 Correct audio RTCP
ip/port confirmed.
--

However, on the following series of digits, they are detected as seen in
the logs from switch_rtp.c and switch_channel.c. However, they do not
proceed to the "Send start packet" step as seen with the previous digit.
This mirrors what I see on the B leg client, as it only detects the first
digit.

--
2021-02-20 11:28:37.521489 [DEBUG] switch_rtp.c:7789 RTP RECV DTMF 1:400
2021-02-20 11:28:37.521489 [INFO] switch_channel.c:515 RECV DTMF 1:400
2021-02-20 11:28:46.082031 [DEBUG] switch_rtp.c:7789 RTP RECV DTMF 3:400
2021-02-20 11:28:46.082031 [INFO] switch_channel.c:515 RECV DTMF 3:400
2021-02-20 11:28:46.481377 [DEBUG] switch_rtp.c:7789 RTP RECV DTMF 6:400
2021-02-20 11:28:46.481377 [INFO] switch_channel.c:515 RECV DTMF 6:400
2021-02-20 11:28:47.061795 [DEBUG] switch_rtp.c:7789 RTP RECV DTMF 4:400
2021-02-20 11:28:47.061795 [INFO] switch_channel.c:515 RECV DTMF 4:400
2021-02-20 11:28:47.461504 [DEBUG] switch_rtp.c:7789 RTP RECV DTMF 5:400
2021-02-20 11:28:47.461504 [INFO] switch_channel.c:515 RECV DTMF 5:400
2021-02-20 11:28:47.881346 [DEBUG] switch_rtp.c:7789 RTP RECV DTMF 0:400
2021-02-20 11:28:47.881346 [INFO] switch_channel.c:515 RECV DTMF 0:400
2021-02-20 11:28:48.281220 [DEBUG] switch_rtp.c:7789 RTP RECV DTMF 0:400
2021-02-20 11:28:48.281220 [INFO] switch_channel.c:515 RECV DTMF 0:400
2021-02-20 11:28:48.805572 [DEBUG] switch_rtp.c:7789 RTP RECV DTMF #:400
2021-02-20 11:28:48.805572 [INFO] switch_channel.c:515 RECV DTMF #:400
2021-02-20 11:29:04.881294 [NOTICE] sofia.c:1079 Hangup sofia/external/
nobody at 192.168.1.71 [CS_EXECUTE] [NORMAL_CLEARING]
--

Yet, they do arrive on the Freeswitch instances. I've attempted to
add <action application="set"
data="rtp_manual_rtp_bugs=ignore_dtmf_duration"/>  to my inbound dialplan
xml. I'm leaning toward these being a "weird" DTMF packet and not a
FreeSWITCH issue, but I'm curious if anyone has encountered a similar
problem, or has advice of what we could test on the FS side.
--
Supporting Details:
Test Environment:
I took a packet capture from production and filtered it down to the A leg's
RFC2833 packets, and saved this to a new file. I then used this pcap file
in a SIPP UAC scenario which is acting as the A Leg.

Freeswitch sits in the middle and I've configured it following this guide (
https://freeswitch.org/confluence/display/FREESWITCH/SBC+FreeSWITCH+Configuration+Example+2)
as a barebones SBC. Freeswitch is version 1.8.3

The B Leg is a simple pjsua client configured to answer an inbound call.
--
Best Regards,

KC
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20210220/9ec2e556/attachment.html>