VoIP Mailing List Archives
Mailing list archives for the VoIP community |
|
| View previous topic :: View next topic |
| Author |
Message |
andynewlands at gmail.com
Guest
|
 Posted: Fri Apr 08, 2022 6:09 am Post subject: [Freeswitch-users] Spurious DTMF characters when using RFC28 |
 |
|
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@gmail.com (andynewlands@gmail.com)> wrote:
| Quote: | 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
|
|
|
| Back to top |
|
 |
dragos at freeswitch.org
Guest
|
| Posted: Tue Apr 12, 2022 10:33 am Post subject: [Freeswitch-users] Spurious DTMF characters when using RFC28 |
|
|
You could open a github issue.
On Fri, Apr 8, 2022 at 1:40 PM Andy Newlands <andynewlands@gmail.com (andynewlands@gmail.com)> wrote:
| Quote: | 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@gmail.com (andynewlands@gmail.com)> wrote:
| Quote: | 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
|
_________________________________________________________________________
The FreeSWITCH project is sponsored by SignalWire https://signalwire.com
Enhance your FreeSWITCH install with disruptive priced SMS and PSTN services.
Build your next product on our scalable cloud platform.
Join our online community to chat in real time https://signalwire.community
Professional FreeSWITCH Services
sales@freeswitch.com (sales@freeswitch.com)
https://freeswitch.com
Official FreeSWITCH Sites
https://freeswitch.com/oss
https://freeswitch.org/confluence
https://cluecon.com
FreeSWITCH-users mailing list
FreeSWITCH-users@lists.freeswitch.org (FreeSWITCH-users@lists.freeswitch.org)
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
https://freeswitch.com |
|
|
| Back to top |
|
|
mike at freeswitch.org
Guest
|
| Posted: Tue Apr 12, 2022 4:33 pm Post subject: [Freeswitch-users] Spurious DTMF characters when using RFC28 |
|
|
If you understand the conditions that trigger this, a unit test that reproduces it would be very helpful as well. We look forward to see your pull requests on this issue. Thanks for all your hard work and diligence. It is a weird issue that I dont believe I have ever seen in the wild, I will be interested to better understand what is different about your environment that triggers its and what sort of device you are interloping with that causes this issue. | Quote: | On Apr 12, 2022, at 9:05 AM, Dragos Oancea <dragos@freeswitch.org (dragos@freeswitch.org)> wrote:
You could open a github issue.
On Fri, Apr 8, 2022 at 1:40 PM Andy Newlands <andynewlands@gmail.com (andynewlands@gmail.com)> wrote:
| Quote: | 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@gmail.com (andynewlands@gmail.com)> wrote:
| Quote: | 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/10242022-02-28 14:00:56.103665 [INFO] switch_channel.c:522 RECV DTMF 4:24002022-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: 50632022-02-28 14:00:56.383661 [INFO] switch_channel.c:522 RECV DTMF 4:24002022-02-28 14:00:56.583665 [INFO] switch_channel.c:522 RECV DTMF 5:24002022-02-28 14:00:57.063662 [INFO] switch_channel.c:522 RECV DTMF 5:24002022-02-28 14:00:57.123670 [INFO] switch_channel.c:522 RECV DTMF 8:27202022-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: 540882022-02-28 14:00:57.603671 [INFO] switch_channel.c:522 RECV DTMF 9:24002022-02-28 14:00:57.824102 [INFO] switch_channel.c:522 RECV DTMF 8:27202022-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: 570022022-02-28 14:00:58.183668 [INFO] switch_channel.c:522 RECV DTMF 6:24002022-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: 570732022-02-28 14:00:58.503667 [INFO] switch_channel.c:522 RECV DTMF 9:24002022-02-28 14:00:58.643667 [INFO] switch_channel.c:522 RECV DTMF 1:24002022-02-28 14:00:58.963663 [INFO] switch_channel.c:522 RECV DTMF 6:24002022-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).
|
|
|
|
|
| Back to top |
|
|
|
|
|
You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot vote in polls in this forum
|
Powered by phpBB © 2001, 2005 phpBB Group
|
Search
