[Freeswitch-users] Spurious DTMF characters when using RFC2833 with SRTP

[Andy Newlands]

Further to my earlier quest, and after a lot of pain, I believe I have
figured out the cause of the issue.  It lies with what appears to be a bug
do_flush() in switch_rtp.c - this would certainly manifest as seemingly
random/intermittent behaviour in respect of DTMF handling/processing.

I have amended the code and I am currently testing my fix.

Kind regards,

Andy


On Mon, 28 Feb 2022 at 14:12, Andy Newlands <andynewlands at gmail.com> wrote:

> Hi,
>
> We have a reproducible problem where spurious DTMF characters are
> introduced on calls from Freeswitch to a remote (3rd party) IVR, but ONLY
> when using SRTP (not with RTP)
>
> When the spurious character is generated it is:
>
> 1. Only ever following a valid/legitimate character (one that was
> genuinely keyed)
> 2. Often has a very long duration (see below)
> 3. Appears to be a random character - often 0x00, but sometimes
> 0-9/A-F,#,* (and that's when we get problems with the IVR - FS
> automatically drops the 0x00 values).
>
> We have been able to reproduce this from mobile/cell phones and
> traditional land-lines.
>
> I added some code to: switch_rtp.c, in static handle_rfc2833_result_t
> handle_rfc2833(switch_rtp_t *rtp_session, switch_size_t bytes, int
> *do_cng), to try to address this.
>
> It logs an error (with the character hex value and duration) for DTMF
> characters with "long" durations (over 10000) and then discards them.  As
> you can see, below, this is a fairly frequent occurrence (although most of
> the time, the character value is null, so FS drps it, anyway - but
> sometimes, "real" characters are introduced).
>
> 2022-02-28 14:00:53.743665 [NOTICE] switch_vpx.c:599 VPX encoder reset
> (WxH/BW) from 0x0/0 to 352x288/1024
> 2022-02-28 14:00:56.103665 [INFO] switch_channel.c:522 RECV DTMF 4:2400
> 2022-02-28 14:00:56.303664 [ERR] switch_channel.c:557 Ignored invalid DTMF
> on Call-ID: 3b5d08d3-d898-40b6-ae00-5886713ca6dd, DTMF: 0x0 Duration: 5063
> 2022-02-28 14:00:56.383661 [INFO] switch_channel.c:522 RECV DTMF 4:2400
> 2022-02-28 14:00:56.583665 [INFO] switch_channel.c:522 RECV DTMF 5:2400
> 2022-02-28 14:00:57.063662 [INFO] switch_channel.c:522 RECV DTMF 5:2400
> 2022-02-28 14:00:57.123670 [INFO] switch_channel.c:522 RECV DTMF 8:2720
> 2022-02-28 14:00:57.323673 [ERR] switch_rtp.c:686 Discarded long-duration
> DTMF on Call-ID: 3b5d08d3-d898-40b6-ae00-5886713ca6dd, DTMF: 0x0 Duration:
> 54088
> 2022-02-28 14:00:57.603671 [INFO] switch_channel.c:522 RECV DTMF 9:2400
> 2022-02-28 14:00:57.824102 [INFO] switch_channel.c:522 RECV DTMF 8:2720
> 2022-02-28 14:00:57.903663 [ERR] switch_rtp.c:686 Discarded long-duration
> DTMF on Call-ID: 3b5d08d3-d898-40b6-ae00-5886713ca6dd, DTMF: 0x0 Duration:
> 57002
> 2022-02-28 14:00:58.183668 [INFO] switch_channel.c:522 RECV DTMF 6:2400
> 2022-02-28 14:00:58.363666 [ERR] switch_rtp.c:686 Discarded long-duration
> DTMF on Call-ID: 3b5d08d3-d898-40b6-ae00-5886713ca6dd, DTMF: 0x35 Duration:
> 57073
> 2022-02-28 14:00:58.503667 [INFO] switch_channel.c:522 RECV DTMF 9:2400
> 2022-02-28 14:00:58.643667 [INFO] switch_channel.c:522 RECV DTMF 1:2400
> 2022-02-28 14:00:58.963663 [INFO] switch_channel.c:522 RECV DTMF 6:2400
> 2022-02-28 14:00:59.283665 [INFO] switch_channel.c:522 RECV DTMF 1:2400
>
> The first spurious character is 0x00 (which FS will drop anyway) but this
> could easily be a valid character (and would escape detection because its
> duration is not too long - it's long but not unreasonable).  So, this is an
> imperfect "fix" as we occasionally see a spurious character with a
> legitimate value and a  "sensible" duration - sufficiently often for users
> to complain.  The last [ERR] entry shows a '5' being introduced but this is
> dropped because the duration is "crazy" (57073)
>
> As mentioned, this does not happen with secure media disabled - only with
> SRTP.  So, I am wondering if the code correctly processes a digit then,
> sometimes (somehow) incorrectly attempts to decode part of an audio packet
> as though it were RFC2833.
>
> Has anyone else experienced this?  Does anyone know what may be causing
> the problem and what the fix might be.
>
> I can provide console output and tcp dumps if required, along with any
> other details that may help (I'm also comfortable making code changes - to
> for extra logging/diagnostics etc).
>
> Thank you.
>
> Kind regards,
>
> Andy
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20220408/e1e14ed4/attachment.html>