Uploaded image for project: 'FreeSWITCH'
  1. FreeSWITCH
  2. FS-9739

switch_rtp mistakes "ffffffff" for a new DTMF and Queue's a NULL digit

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Minor
    • Resolution: Fixed
    • Affects Version/s: 1.6.12
    • Fix Version/s: None
    • Component/s: core
    • Security Level: public
    • Labels:
      None
    • Environment:
      Linux qa-fsw-nvaaws-a02 3.10.0-327.18.2.el7.x86_64 #1 SMP Thu May 12 11:03:55 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux

      FreeSWITCH Version 1.6.12+git~20161114T235829Z~2f7fd1e60c~64bit (git 2f7fd1e 2016-11-14 23:58:29Z 64bit)
    • CPU Architecture:
      x86-64
    • Kernel:
      Linux
    • uname:
      Linux qa-fsw-nvaaws-a02 3.10.0-327.18.2.el7.x86_64 #1 SMP Thu May 12 11:03:55 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux
    • Userland:
      GNU/Linux
    • Distribution:
      CentOS
    • Distribution Version:
      CentOS 7
    • lsb_release:
      Hide
      -bash: lsb_release: command not found
      Show
      -bash: lsb_release: command not found
    • Compiler:
      gcc
    • Compiler Version:
      gcc (GCC) 4.8.5 20150623 (Red Hat 4.8.5-4)
    • FreeSWITCH GIT Revision:
      FreeSWITCH Version 1.6.12+git~20161114T235829Z~2f7fd1e60c~64bit (git 2f7fd1e 2016-11-14 23:58:29Z 64bit)
    • GIT Master Revision hash::
      n/a

      Description

      Trying to debug why incoming DTMFs are sometimes dropped.
      Have upgraded to latest v1.6 and tested with DEBUG_2833 on.

      The main symptom we sometimes see in the log is:
      switch_rtp.c:7187 RTP RECV DTMF
      with NO identified digit. (eg line 2343 in attached log)

      This was preceded by an all F's packet:
      packet[160]: ff ff ff ff
      (line 2326 in log)

      As far as I can tell looking at the code, this causes the "key" variable to be set to '\0' at switch_rtp.c:617.
      "duration" is presumably set to 0xffff, and "end" is set to 1 since 0xff & 0x80 is going to be true (line 615).

      The "key" variable then is used to populate dtmf.digit (and maybe other fields...)

      This leads to many "truncated" log statements including:
      line 646 "read: "
      line 711: "done: "
      line 717 "Queuing digit "
      (example lines: 2327 and 2328)

      It seems that this "NULL" dtmf has been mis-identified somehow and should not be "Queued" as a digit.

      I noticed that this was logged:
      switch_rtp.c:690 start with end packet 163360
      Seems to indicate that FS thinks a new DTMF is starting, but is also immediately "done" due to the "end" var being set.


      I see in the log (line 2329) that FS then "drops" the next several packets which are the start of a new "#" dtmf, until line 2346 when a "start" is shown (though we are 50ms into the new dtmf).

      At line 2375 another "ffffffff" is received but this time it is dropped (although the log statement is truncated due to the NULL). Then a couple of "#" packets are also dropped for some reason (2378 and 2382).

      The "#" dtmf then continues until 2413 when the "end" is reached for a duration of 270ms.

      So in this case I don't think anything was "dropped" - but I wanted to submit the issue b/c it seems the falsely identified "NULL" digit does cause some packets to be ignored, and I wonder if this could explain other calls I've had, where the "RECV DTMF$" is NOT followed by a true dtmf detection. Unfortunately I haven't had a call like that with the DEBUG_2833 engaged yet.

      Thanks for your help.



        Attachments

        1. freeswitch.kp.log
          355 kB
        2. fs.pcap.log
          154 kB
        3. pcap.out
          515 kB

          Activity

            People

            • Assignee:
              mikej Mike Jerris
              Reporter:
              kidplug Mitch Chapman
            • Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: