intermittent DTMF duplicate digit detection
I am running FreeSWITCH Version 1.6.6~64bit ( 64bit) running in a non-virtualized hardware platform. I am using it with FusionPBX (roughly 2 weeks since my last git pull) When using a SIP trunk from my CopperCom IP card I get intermittent duplicate DTMF digits specifically causing me trouble using the IVR application. With these options on: dtmf_verbose=true spandsp_dtmf_rx_threshold=-42 spandsp_dtmf_rx_twist=8 spandsp_dtmf_rx_reverse_twist=6 min_dup_digit_spacing_ms=50 (I have adjusted this from 0 to values of upwards of 2000...not sure it applies in this case as I think the duplicate digits might not be impacted by this value as I think two different systems are detecting the DTMF). In the following logs the min_dup_digit_spacing_ms might have been any number of values I was testing. So...on a properly recognized DTMF digit the logs look like this when I placed a test call to the IVR and dialed 9 as a menu option for the company directory then 489 to successfully to search for a name...in this call all worked as expected: b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.113751 [DEBUG] switch_core_media.c:4485 sofia/internal/541xxxyyyy@a.b.c.d Set 2833 dtmf send payload to 101 recv payload to 101 b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d parsing [public->dtmf-type] continue=true b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Regex (PASS) [dtmf-type] () =~ // break=on-false b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(dtmf_verbose=true) b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(spandsp_dtmf_rx_threshold=-42) b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(spandsp_dtmf_rx_twist=8) b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(spandsp_dtmf_rx_reverse_twist=6) b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action spandsp_start_dtmf() b6fe5cc0-717e-11e6-a586-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(dtmf_verbose=true) b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [dtmf_verbose]=[true] b6fe5cc0-717e-11e6-a586-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(spandsp_dtmf_rx_threshold=-42) b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [spandsp_dtmf_rx_threshold]=[-42] b6fe5cc0-717e-11e6-a586-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(spandsp_dtmf_rx_twist=8) b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [spandsp_dtmf_rx_twist]=[8] b6fe5cc0-717e-11e6-a586-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(spandsp_dtmf_rx_reverse_twist=6) b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [spandsp_dtmf_rx_reverse_twist]=[6] b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] switch_core_session.c:2628 Application spandsp_start_dtmf Requires media! pre_answering channel sofia/internal/541xxxyyyy@a.b.c.d b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] switch_core_media.c:6332 sofia/internal/541xxxyyyy@a.b.c.d Set 2833 dtmf send payload to 101 b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] switch_core_media.c:6339 sofia/internal/541xxxyyyy@a.b.c.d Set 2833 dtmf receive payload to 101 b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] switch_core_media.c:6362 sofia/internal/541xxxyyyy@a.b.c.d Set rtp dtmf delay to 40 b6fe5cc0-717e-11e6-a586-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d spandsp_start_dtmf() b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:00.973723 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially D - total -18.52dB, row -35.24dB, col -32.15dB, duration 62628 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:00.993716 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.97dB, row -5.18dB, col -5.09dB, duration 62730 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:00.993716 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.94dB, row -5.03dB, col -5.06dB, duration 62832 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:00.993716 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [9] b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:00.993716 [INFO] switch_channel.c:512 RECV DTMF 9:2000 b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.013719 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -3.03dB, row -5.21dB, col -5.28dB, duration 102 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.013719 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -3.02dB, row -5.29dB, col -5.13dB, duration 204 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.033720 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.92dB, row -5.03dB, col -5.03dB, duration 306 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.053716 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.97dB, row -5.08dB, col -5.22dB, duration 408 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.053716 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -9.02dB, row -17.52dB, col -16.96dB, duration 510 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.073716 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [9], duration = 76 ms b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.093756 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially D - total -19.84dB, row -34.97dB, col -34.04dB, duration 48144 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.113726 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.80dB, row -4.77dB, col -4.77dB, duration 48246 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.113726 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.92dB, row -5.02dB, col -5.03dB, duration 48348 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.113726 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [4] b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.113726 [INFO] switch_channel.c:512 RECV DTMF 4:2000 b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.133730 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -3.14dB, row -5.55dB, col -5.42dB, duration 102 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.133730 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.77dB, row -4.66dB, col -4.80dB, duration 204 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.153730 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -3.25dB, row -5.70dB, col -5.63dB, duration 306 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.173727 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.79dB, row -4.84dB, col -4.70dB, duration 408 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.173727 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.92dB, row -5.00dB, col -5.05dB, duration 510 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.193720 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -4.11dB, row -7.36dB, col -7.35dB, duration 612 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.213719 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [4], duration = 89 ms b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.313724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -3.95dB, row -7.12dB, col -7.00dB, duration 918 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.333719 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -3.10dB, row -5.44dB, col -5.32dB, duration 1020 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.353724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -2.99dB, row -5.15dB, col -5.16dB, duration 1122 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.353724 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [8] b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.353724 [INFO] switch_channel.c:512 RECV DTMF 8:2000 b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.353724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -2.85dB, row -4.84dB, col -4.94dB, duration 102 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.373724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -2.90dB, row -5.02dB, col -4.93dB, duration 204 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.393724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -2.98dB, row -5.22dB, col -5.11dB, duration 306 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.393724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -3.11dB, row -5.32dB, col -5.43dB, duration 408 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.413724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -3.09dB, row -5.33dB, col -5.39dB, duration 510 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.413724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially * - total -13.19dB, row -24.69dB, col -24.21dB, duration 612 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.433724 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [8], duration = 89 ms b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.473724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -9.05dB, row -17.46dB, col -17.13dB, duration 306 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.493719 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.97dB, row -5.12dB, col -5.12dB, duration 408 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.493719 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.96dB, row -5.16dB, col -5.06dB, duration 510 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.493719 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [9] b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.493719 [INFO] switch_channel.c:512 RECV DTMF 9:2000 b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.513724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -8.91dB, row -16.92dB, col -17.15dB, duration 102 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.533724 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [9], duration = 25 ms b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.553724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -5.06dB, row -9.31dB, col -9.33dB, duration 204 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.573734 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.98dB, row -5.04dB, col -5.19dB, duration 306 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.573734 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.93dB, row -5.14dB, col -4.99dB, duration 408 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.573734 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [9] b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.573734 [INFO] switch_channel.c:512 RECV DTMF 9:2000 b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.593730 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -3.02dB, row -5.28dB, col -5.20dB, duration 102 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.593730 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -11.08dB, row -21.34dB, col -21.19dB, duration 204 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.613728 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [9], duration = 38 ms this time I dialed the same menu and dialed 4 and got invalid entry (which digit I dial to cause the intermittent failure seems to be nearly any digit): 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] switch_core_media.c:4485 sofia/internal/541xxxyyyy@a.b.c.d Set 2833 dtmf send payload to 101 recv payload to 101 0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d parsing [public->dtmf-type] continue=true 0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Regex (PASS) [dtmf-type] () =~ // break=on-false 0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(dtmf_verbose=true) 0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(spandsp_dtmf_rx_threshold=-42) 0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(spandsp_dtmf_rx_twist=8) 0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(spandsp_dtmf_rx_reverse_twist=6) 0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action spandsp_start_dtmf() 0da6c076-717f-11e6-a732-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(dtmf_verbose=true) 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [dtmf_verbose]=[true] 0da6c076-717f-11e6-a732-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(spandsp_dtmf_rx_threshold=-42) 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [spandsp_dtmf_rx_threshold]=[-42] 0da6c076-717f-11e6-a732-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(spandsp_dtmf_rx_twist=8) 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [spandsp_dtmf_rx_twist]=[8] 0da6c076-717f-11e6-a732-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(spandsp_dtmf_rx_reverse_twist=6) 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [spandsp_dtmf_rx_reverse_twist]=[6] 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] switch_core_session.c:2628 Application spandsp_start_dtmf Requires media! pre_answering channel sofia/internal/541xxxyyyy@a.b.c.d 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.533724 [DEBUG] switch_core_media.c:6332 sofia/internal/541xxxyyyy@a.b.c.d Set 2833 dtmf send payload to 101 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.533724 [DEBUG] switch_core_media.c:6339 sofia/internal/541xxxyyyy@a.b.c.d Set 2833 dtmf receive payload to 101 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.533724 [DEBUG] switch_core_media.c:6362 sofia/internal/541xxxyyyy@a.b.c.d Set rtp dtmf delay to 40 0da6c076-717f-11e6-a732-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d spandsp_start_dtmf() 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.593744 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -4.41dB, row -8.03dB, col -8.02dB, duration 32538 - miss 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.593744 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.73dB, row -4.71dB, col -4.59dB, duration 32640 - hit 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.693734 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -4.19dB, row -7.59dB, col -7.55dB, duration 33354 - miss 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.713723 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -3.25dB, row -5.68dB, col -5.62dB, duration 33456 - hit 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.713723 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.76dB, row -4.65dB, col -4.79dB, duration 33558 - hit 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.713723 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [4] 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.713723 [INFO] switch_channel.c:512 RECV DTMF 4:2000 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.733724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -3.18dB, row -5.61dB, col -5.47dB, duration 102 - hit 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.753724 [DEBUG] switch_rtp.c:6874 RTP RECV DTMF 4:800 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.753724 [INFO] switch_channel.c:512 RECV DTMF 4:800 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.753724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -3.76dB, row -6.65dB, col -6.69dB, duration 204 - hit 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.793718 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [4], duration = 51 ms Whenever I have problems with duplicate digits as in the later example above I always get a line with switch_rtp.c like this: 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.753724 [DEBUG] switch_rtp.c:6874 RTP RECV DTMF 4:800 If one of the switch_rtp lines does not show up in the output put that it RECV DTMF the DTMF is recognized properly. Is there an option that I can set to tell the switch_rtp.c to ignore receiving DTMF? I do not know happens that causes some calls to work and some calls to not work. I was not sure if when it is intermittent (sometimes 80% get duplicate DTMF, sometimes only 20% get duplicate DTMF) what else to try. I saw this: https://freeswitch.org/confluence/display/FREESWITCH/RTP+Issues and was not sure if this applied...or where options like: <param name="auto-rtp-bugs" value="clear"/> Were supposed to be placed in the dial plan to get these in the right place. Is this part of the options before you invoke action=spandsp_start_dtmf Thanks in advance for any help you can provide. Jeff -.-. --.- -.. . -.- . --... --.- -.-- ..-
Can you try with RFC-2833 inste as of inband? Guillermo Sent from my iPhone
On Sep 3, 2016, at 01:20, Jeff Crews <jeff@eoni.com> wrote:
I am running FreeSWITCH Version 1.6.6~64bit ( 64bit) running in a non-virtualized hardware platform. I am using it with FusionPBX (roughly 2 weeks since my last git pull)
When using a SIP trunk from my CopperCom IP card I get intermittent duplicate DTMF digits specifically causing me trouble using the IVR application.
With these options on:
dtmf_verbose=true
spandsp_dtmf_rx_threshold=-42
spandsp_dtmf_rx_twist=8
spandsp_dtmf_rx_reverse_twist=6
min_dup_digit_spacing_ms=50 (I have adjusted this from 0 to values of upwards of 2000…not sure it applies in this case as I think the duplicate digits might not be impacted by this value as I think two different systems are detecting the DTMF).
In the following logs the min_dup_digit_spacing_ms might have been any number of values I was testing.
So…on a properly recognized DTMF digit the logs look like this when I placed a test call to the IVR and dialed 9 as a menu option for the company directory then 489 to successfully to search for a name…in this call all worked as expected:
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.113751 [DEBUG] switch_core_media.c:4485 sofia/internal/541xxxyyyy@a.b.c.d Set 2833 dtmf send payload to 101 recv payload to 101 b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d parsing [public->dtmf-type] continue=true b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Regex (PASS) [dtmf-type] () =~ // break=on-false b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(dtmf_verbose=true) b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(spandsp_dtmf_rx_threshold=-42) b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(spandsp_dtmf_rx_twist=8) b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(spandsp_dtmf_rx_reverse_twist=6) b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action spandsp_start_dtmf() b6fe5cc0-717e-11e6-a586-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(dtmf_verbose=true) b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [dtmf_verbose]=[true] b6fe5cc0-717e-11e6-a586-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(spandsp_dtmf_rx_threshold=-42) b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [spandsp_dtmf_rx_threshold]=[-42] b6fe5cc0-717e-11e6-a586-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(spandsp_dtmf_rx_twist=8) b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [spandsp_dtmf_rx_twist]=[8] b6fe5cc0-717e-11e6-a586-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(spandsp_dtmf_rx_reverse_twist=6) b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [spandsp_dtmf_rx_reverse_twist]=[6] b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] switch_core_session.c:2628 Application spandsp_start_dtmf Requires media! pre_answering channel sofia/internal/541xxxyyyy@a.b.c.d b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] switch_core_media.c:6332 sofia/internal/541xxxyyyy@a.b.c.d Set 2833 dtmf send payload to 101 b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] switch_core_media.c:6339 sofia/internal/541xxxyyyy@a.b.c.d Set 2833 dtmf receive payload to 101 b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] switch_core_media.c:6362 sofia/internal/541xxxyyyy@a.b.c.d Set rtp dtmf delay to 40 b6fe5cc0-717e-11e6-a586-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d spandsp_start_dtmf() b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:00.973723 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially D - total -18.52dB, row -35.24dB, col -32.15dB, duration 62628 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:00.993716 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.97dB, row -5.18dB, col -5.09dB, duration 62730 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:00.993716 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.94dB, row -5.03dB, col -5.06dB, duration 62832 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:00.993716 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [9] b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:00.993716 [INFO] switch_channel.c:512 RECV DTMF 9:2000 b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.013719 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -3.03dB, row -5.21dB, col -5.28dB, duration 102 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.013719 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -3.02dB, row -5.29dB, col -5.13dB, duration 204 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.033720 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.92dB, row -5.03dB, col -5.03dB, duration 306 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.053716 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.97dB, row -5.08dB, col -5.22dB, duration 408 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.053716 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -9.02dB, row -17.52dB, col -16.96dB, duration 510 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.073716 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [9], duration = 76 ms b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.093756 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially D - total -19.84dB, row -34.97dB, col -34.04dB, duration 48144 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.113726 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.80dB, row -4.77dB, col -4.77dB, duration 48246 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.113726 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.92dB, row -5.02dB, col -5.03dB, duration 48348 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.113726 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [4] b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.113726 [INFO] switch_channel.c:512 RECV DTMF 4:2000 b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.133730 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -3.14dB, row -5.55dB, col -5.42dB, duration 102 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.133730 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.77dB, row -4.66dB, col -4.80dB, duration 204 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.153730 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -3.25dB, row -5.70dB, col -5.63dB, duration 306 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.173727 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.79dB, row -4.84dB, col -4.70dB, duration 408 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.173727 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.92dB, row -5.00dB, col -5.05dB, duration 510 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.193720 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -4.11dB, row -7.36dB, col -7.35dB, duration 612 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.213719 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [4], duration = 89 ms b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.313724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -3.95dB, row -7.12dB, col -7.00dB, duration 918 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.333719 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -3.10dB, row -5.44dB, col -5.32dB, duration 1020 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.353724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -2.99dB, row -5.15dB, col -5.16dB, duration 1122 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.353724 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [8] b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.353724 [INFO] switch_channel.c:512 RECV DTMF 8:2000 b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.353724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -2.85dB, row -4.84dB, col -4.94dB, duration 102 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.373724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -2.90dB, row -5.02dB, col -4.93dB, duration 204 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.393724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -2.98dB, row -5.22dB, col -5.11dB, duration 306 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.393724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -3.11dB, row -5.32dB, col -5.43dB, duration 408 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.413724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -3.09dB, row -5.33dB, col -5.39dB, duration 510 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.413724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially * - total -13.19dB, row -24.69dB, col -24.21dB, duration 612 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.433724 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [8], duration = 89 ms b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.473724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -9.05dB, row -17.46dB, col -17.13dB, duration 306 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.493719 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.97dB, row -5.12dB, col -5.12dB, duration 408 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.493719 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.96dB, row -5.16dB, col -5.06dB, duration 510 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.493719 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [9] b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.493719 [INFO] switch_channel.c:512 RECV DTMF 9:2000 b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.513724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -8.91dB, row -16.92dB, col -17.15dB, duration 102 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.533724 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [9], duration = 25 ms b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.553724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -5.06dB, row -9.31dB, col -9.33dB, duration 204 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.573734 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.98dB, row -5.04dB, col -5.19dB, duration 306 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.573734 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.93dB, row -5.14dB, col -4.99dB, duration 408 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.573734 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [9] b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.573734 [INFO] switch_channel.c:512 RECV DTMF 9:2000 b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.593730 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -3.02dB, row -5.28dB, col -5.20dB, duration 102 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.593730 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -11.08dB, row -21.34dB, col -21.19dB, duration 204 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.613728 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [9], duration = 38 ms
this time I dialed the same menu and dialed 4 and got invalid entry (which digit I dial to cause the intermittent failure seems to be nearly any digit): 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] switch_core_media.c:4485 sofia/internal/541xxxyyyy@a.b.c.d Set 2833 dtmf send payload to 101 recv payload to 101 0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d parsing [public->dtmf-type] continue=true 0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Regex (PASS) [dtmf-type] () =~ // break=on-false 0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(dtmf_verbose=true) 0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(spandsp_dtmf_rx_threshold=-42) 0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(spandsp_dtmf_rx_twist=8) 0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(spandsp_dtmf_rx_reverse_twist=6) 0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action spandsp_start_dtmf() 0da6c076-717f-11e6-a732-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(dtmf_verbose=true) 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [dtmf_verbose]=[true] 0da6c076-717f-11e6-a732-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(spandsp_dtmf_rx_threshold=-42) 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [spandsp_dtmf_rx_threshold]=[-42] 0da6c076-717f-11e6-a732-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(spandsp_dtmf_rx_twist=8) 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [spandsp_dtmf_rx_twist]=[8] 0da6c076-717f-11e6-a732-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(spandsp_dtmf_rx_reverse_twist=6) 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [spandsp_dtmf_rx_reverse_twist]=[6] 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] switch_core_session.c:2628 Application spandsp_start_dtmf Requires media! pre_answering channel sofia/internal/541xxxyyyy@a.b.c.d 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.533724 [DEBUG] switch_core_media.c:6332 sofia/internal/541xxxyyyy@a.b.c.d Set 2833 dtmf send payload to 101 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.533724 [DEBUG] switch_core_media.c:6339 sofia/internal/541xxxyyyy@a.b.c.d Set 2833 dtmf receive payload to 101 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.533724 [DEBUG] switch_core_media.c:6362 sofia/internal/541xxxyyyy@a.b.c.d Set rtp dtmf delay to 40 0da6c076-717f-11e6-a732-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d spandsp_start_dtmf() 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.593744 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -4.41dB, row -8.03dB, col -8.02dB, duration 32538 - miss 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.593744 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.73dB, row -4.71dB, col -4.59dB, duration 32640 - hit 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.693734 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -4.19dB, row -7.59dB, col -7.55dB, duration 33354 - miss 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.713723 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -3.25dB, row -5.68dB, col -5.62dB, duration 33456 - hit 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.713723 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.76dB, row -4.65dB, col -4.79dB, duration 33558 - hit 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.713723 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [4] 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.713723 [INFO] switch_channel.c:512 RECV DTMF 4:2000 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.733724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -3.18dB, row -5.61dB, col -5.47dB, duration 102 - hit 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.753724 [DEBUG] switch_rtp.c:6874 RTP RECV DTMF 4:800 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.753724 [INFO] switch_channel.c:512 RECV DTMF 4:800 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.753724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -3.76dB, row -6.65dB, col -6.69dB, duration 204 - hit 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.793718 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [4], duration = 51 ms
Whenever I have problems with duplicate digits as in the later example above I always get a line with switch_rtp.c like this:
0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.753724 [DEBUG] switch_rtp.c:6874 RTP RECV DTMF 4:800
If one of the switch_rtp lines does not show up in the output put that it RECV DTMF the DTMF is recognized properly.
Is there an option that I can set to tell the switch_rtp.c to ignore receiving DTMF?
I do not know happens that causes some calls to work and some calls to not work.
I was not sure if when it is intermittent (sometimes 80% get duplicate DTMF, sometimes only 20% get duplicate DTMF) what else to try.
I saw this: https://freeswitch.org/confluence/display/FREESWITCH/RTP+Issues and was not sure if this applied…or where options like: <param name="auto-rtp-bugs" value="clear"/> Were supposed to be placed in the dial plan to get these in the right place. Is this part of the options before you invoke action=spandsp_start_dtmf
Thanks in advance for any help you can provide.
Jeff -.-. --.- -.. . -.- . --... --.- -.-- ..-
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
Sorry my original email had so many typos. Thanks for this suggestion. I was trying to figure out how to do this exact change to use rfc2833, none or inband to see if it impacted this issue…I was not sure where to make this change…are you suggesting I remove the line to “spandsp_start_dtmf” or is dtmf-type an option for spandsp? I did not see any options for spandsp that mention 2833 so I figured this was something someplace else. I have tried removing the spandsp_start_dtmf and adding setting dtmf-type=rfc2833 followed by start_dtmf and I still see my dialed DTMF digits receiving twice and sometimes three times…sometimes I only get the digit once (what I would expect when I only press the button once). I have tried removing start_dtmf and leaving the dtmf-type=rfc2833 I also tried dtmf-type=inband but so no improvement. I have tried setting dtmf-type=junk to see if I would get an error message or something to indicate I am putting the parameter in the correct place…but do not see any error…this seems to get submitted as the call processes and does not seem to change anything. Is there a debug level or log setting that would confirm if I switch to rfc2833 or inband that freeswitch is indeed working as rfc2833 or inband? If I could figure out how to disable whatever the switch_rtp.c message indicates on the log DTMF processing…that would seem to address my issue. Thanks in advance for any help you can provide. From: freeswitch-users-bounces@lists.freeswitch.org [mailto:freeswitch-users-bounces@lists.freeswitch.org] On Behalf Of Guillermo Ruiz Camauer Sent: Saturday, September 03, 2016 09:14 To: FreeSWITCH Users Help Subject: Re: [Freeswitch-users] intermittent DTMF duplicate digit detection Can you try with RFC-2833 inste as of inband? Guillermo Sent from my iPhone On Sep 3, 2016, at 01:20, Jeff Crews <jeff@eoni.com<mailto:jeff@eoni.com>> wrote: I am running FreeSWITCH Version 1.6.6~64bit ( 64bit) running in a non-virtualized hardware platform. I am using it with FusionPBX (roughly 2 weeks since my last git pull) When using a SIP trunk from my CopperCom IP card I get intermittent duplicate DTMF digits specifically causing me trouble using the IVR application. With these options on: dtmf_verbose=true spandsp_dtmf_rx_threshold=-42 spandsp_dtmf_rx_twist=8 spandsp_dtmf_rx_reverse_twist=6 min_dup_digit_spacing_ms=50 (I have adjusted this from 0 to values of upwards of 2000…not sure it applies in this case as I think the duplicate digits might not be impacted by this value as I think two different systems are detecting the DTMF). In the following logs the min_dup_digit_spacing_ms might have been any number of values I was testing. So…on a properly recognized DTMF digit the logs look like this when I placed a test call to the IVR and dialed 9 as a menu option for the company directory then 489 to successfully to search for a name…in this call all worked as expected: b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.113751 [DEBUG] switch_core_media.c:4485 sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> Set 2833 dtmf send payload to 101 recv payload to 101 b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> parsing [public->dtmf-type] continue=true b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> Regex (PASS) [dtmf-type] () =~ // break=on-false b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> Action set(dtmf_verbose=true) b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> Action set(spandsp_dtmf_rx_threshold=-42) b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> Action set(spandsp_dtmf_rx_twist=8) b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> Action set(spandsp_dtmf_rx_reverse_twist=6) b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> Action spandsp_start_dtmf() b6fe5cc0-717e-11e6-a586-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> set(dtmf_verbose=true) b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> [dtmf_verbose]=[true] b6fe5cc0-717e-11e6-a586-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> set(spandsp_dtmf_rx_threshold=-42) b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> [spandsp_dtmf_rx_threshold]=[-42] b6fe5cc0-717e-11e6-a586-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> set(spandsp_dtmf_rx_twist=8) b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> [spandsp_dtmf_rx_twist]=[8] b6fe5cc0-717e-11e6-a586-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> set(spandsp_dtmf_rx_reverse_twist=6) b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> [spandsp_dtmf_rx_reverse_twist]=[6] b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] switch_core_session.c:2628 Application spandsp_start_dtmf Requires media! pre_answering channel sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] switch_core_media.c:6332 sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> Set 2833 dtmf send payload to 101 b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] switch_core_media.c:6339 sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> Set 2833 dtmf receive payload to 101 b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] switch_core_media.c:6362 sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> Set rtp dtmf delay to 40 b6fe5cc0-717e-11e6-a586-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> spandsp_start_dtmf() b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:00.973723 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially D - total -18.52dB, row -35.24dB, col -32.15dB, duration 62628 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:00.993716 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.97dB, row -5.18dB, col -5.09dB, duration 62730 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:00.993716 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.94dB, row -5.03dB, col -5.06dB, duration 62832 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:00.993716 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [9] b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:00.993716 [INFO] switch_channel.c:512 RECV DTMF 9:2000 b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.013719 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -3.03dB, row -5.21dB, col -5.28dB, duration 102 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.013719 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -3.02dB, row -5.29dB, col -5.13dB, duration 204 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.033720 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.92dB, row -5.03dB, col -5.03dB, duration 306 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.053716 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.97dB, row -5.08dB, col -5.22dB, duration 408 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.053716 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -9.02dB, row -17.52dB, col -16.96dB, duration 510 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.073716 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [9], duration = 76 ms b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.093756 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially D - total -19.84dB, row -34.97dB, col -34.04dB, duration 48144 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.113726 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.80dB, row -4.77dB, col -4.77dB, duration 48246 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.113726 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.92dB, row -5.02dB, col -5.03dB, duration 48348 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.113726 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [4] b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.113726 [INFO] switch_channel.c:512 RECV DTMF 4:2000 b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.133730 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -3.14dB, row -5.55dB, col -5.42dB, duration 102 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.133730 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.77dB, row -4.66dB, col -4.80dB, duration 204 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.153730 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -3.25dB, row -5.70dB, col -5.63dB, duration 306 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.173727 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.79dB, row -4.84dB, col -4.70dB, duration 408 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.173727 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.92dB, row -5.00dB, col -5.05dB, duration 510 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.193720 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -4.11dB, row -7.36dB, col -7.35dB, duration 612 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.213719 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [4], duration = 89 ms b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.313724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -3.95dB, row -7.12dB, col -7.00dB, duration 918 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.333719 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -3.10dB, row -5.44dB, col -5.32dB, duration 1020 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.353724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -2.99dB, row -5.15dB, col -5.16dB, duration 1122 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.353724 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [8] b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.353724 [INFO] switch_channel.c:512 RECV DTMF 8:2000 b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.353724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -2.85dB, row -4.84dB, col -4.94dB, duration 102 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.373724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -2.90dB, row -5.02dB, col -4.93dB, duration 204 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.393724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -2.98dB, row -5.22dB, col -5.11dB, duration 306 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.393724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -3.11dB, row -5.32dB, col -5.43dB, duration 408 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.413724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -3.09dB, row -5.33dB, col -5.39dB, duration 510 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.413724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially * - total -13.19dB, row -24.69dB, col -24.21dB, duration 612 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.433724 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [8], duration = 89 ms b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.473724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -9.05dB, row -17.46dB, col -17.13dB, duration 306 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.493719 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.97dB, row -5.12dB, col -5.12dB, duration 408 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.493719 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.96dB, row -5.16dB, col -5.06dB, duration 510 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.493719 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [9] b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.493719 [INFO] switch_channel.c:512 RECV DTMF 9:2000 b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.513724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -8.91dB, row -16.92dB, col -17.15dB, duration 102 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.533724 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [9], duration = 25 ms b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.553724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -5.06dB, row -9.31dB, col -9.33dB, duration 204 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.573734 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.98dB, row -5.04dB, col -5.19dB, duration 306 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.573734 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.93dB, row -5.14dB, col -4.99dB, duration 408 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.573734 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [9] b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.573734 [INFO] switch_channel.c:512 RECV DTMF 9:2000 b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.593730 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -3.02dB, row -5.28dB, col -5.20dB, duration 102 - hit b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.593730 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -11.08dB, row -21.34dB, col -21.19dB, duration 204 - miss b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.613728 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [9], duration = 38 ms this time I dialed the same menu and dialed 4 and got invalid entry (which digit I dial to cause the intermittent failure seems to be nearly any digit): 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] switch_core_media.c:4485 sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> Set 2833 dtmf send payload to 101 recv payload to 101 0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> parsing [public->dtmf-type] continue=true 0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> Regex (PASS) [dtmf-type] () =~ // break=on-false 0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> Action set(dtmf_verbose=true) 0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> Action set(spandsp_dtmf_rx_threshold=-42) 0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> Action set(spandsp_dtmf_rx_twist=8) 0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> Action set(spandsp_dtmf_rx_reverse_twist=6) 0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> Action spandsp_start_dtmf() 0da6c076-717f-11e6-a732-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> set(dtmf_verbose=true) 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> [dtmf_verbose]=[true] 0da6c076-717f-11e6-a732-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> set(spandsp_dtmf_rx_threshold=-42) 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> [spandsp_dtmf_rx_threshold]=[-42] 0da6c076-717f-11e6-a732-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> set(spandsp_dtmf_rx_twist=8) 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> [spandsp_dtmf_rx_twist]=[8] 0da6c076-717f-11e6-a732-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> set(spandsp_dtmf_rx_reverse_twist=6) 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> [spandsp_dtmf_rx_reverse_twist]=[6] 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] switch_core_session.c:2628 Application spandsp_start_dtmf Requires media! pre_answering channel sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.533724 [DEBUG] switch_core_media.c:6332 sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> Set 2833 dtmf send payload to 101 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.533724 [DEBUG] switch_core_media.c:6339 sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> Set 2833 dtmf receive payload to 101 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.533724 [DEBUG] switch_core_media.c:6362 sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> Set rtp dtmf delay to 40 0da6c076-717f-11e6-a732-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d<mailto:sofia/internal/541xxxyyyy@a.b.c.d> spandsp_start_dtmf() 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.593744 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -4.41dB, row -8.03dB, col -8.02dB, duration 32538 - miss 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.593744 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.73dB, row -4.71dB, col -4.59dB, duration 32640 - hit 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.693734 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -4.19dB, row -7.59dB, col -7.55dB, duration 33354 - miss 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.713723 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -3.25dB, row -5.68dB, col -5.62dB, duration 33456 - hit 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.713723 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.76dB, row -4.65dB, col -4.79dB, duration 33558 - hit 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.713723 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [4] 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.713723 [INFO] switch_channel.c:512 RECV DTMF 4:2000 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.733724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -3.18dB, row -5.61dB, col -5.47dB, duration 102 - hit 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.753724 [DEBUG] switch_rtp.c:6874 RTP RECV DTMF 4:800 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.753724 [INFO] switch_channel.c:512 RECV DTMF 4:800 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.753724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -3.76dB, row -6.65dB, col -6.69dB, duration 204 - hit 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.793718 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [4], duration = 51 ms Whenever I have problems with duplicate digits as in the later example above I always get a line with switch_rtp.c like this: 0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.753724 [DEBUG] switch_rtp.c:6874 RTP RECV DTMF 4:800 If one of the switch_rtp lines does not show up in the output put that it RECV DTMF the DTMF is recognized properly. Is there an option that I can set to tell the switch_rtp.c to ignore receiving DTMF? I do not know happens that causes some calls to work and some calls to not work. I was not sure if when it is intermittent (sometimes 80% get duplicate DTMF, sometimes only 20% get duplicate DTMF) what else to try. I saw this: https://freeswitch.org/confluence/display/FREESWITCH/RTP+Issues and was not sure if this applied…or where options like: <param name="auto-rtp-bugs" value="clear"/> Were supposed to be placed in the dial plan to get these in the right place. Is this part of the options before you invoke action=spandsp_start_dtmf Thanks in advance for any help you can provide. Jeff -.-. --.- -.. . -.- . --... --.- -.-- ..- _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org<mailto:consulting@freeswitch.org> http://www.freeswitchsolutions.com Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org<mailto:FreeSWITCH-users@lists.freeswitch.org> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users<http://lists.freeswitch.org/mailman/options/freeswitch-users> http://www.freeswitch.org
Jeff, Just a couple of pointers. Inband DTMF detection is handled by spandsp and only really works if you are using PCMU or PCMA codecs (it does NOT work if you use codecs that compress like G.729, etc.) Spandsp analyses the tone frequencies received and tries to determine which DTMF was sent. RFC2833 works by sending a special packet in the RTP stream, no analysis needed. You should only specify ONE DTMF method for a channel if you don't want to have duplication problems. You should set <param name="dtmf-type" value="rfc2833"/> and <param name="liberal-dtmf" value="false"/> in the sip profile so that it only accepts RFC2833. Regards, Guillermo On Wed, Sep 7, 2016 at 9:15 AM, Jeff Crews <jeff@eoni.com> wrote:
Sorry my original email had so many typos.
Thanks for this suggestion.
I was trying to figure out how to do this exact change to use rfc2833, none or inband to see if it impacted this issue…I was not sure where to make this change…are you suggesting I remove the line to “spandsp_start_dtmf” or is dtmf-type an option for spandsp? I did not see any options for spandsp that mention 2833 so I figured this was something someplace else.
I have tried removing the spandsp_start_dtmf and adding setting dtmf-type=rfc2833 followed by start_dtmf and I still see my dialed DTMF digits receiving twice and sometimes three times…sometimes I only get the digit once (what I would expect when I only press the button once). I have tried removing start_dtmf and leaving the dtmf-type=rfc2833
I also tried dtmf-type=inband but so no improvement.
I have tried setting dtmf-type=junk to see if I would get an error message or something to indicate I am putting the parameter in the correct place…but do not see any error…this seems to get submitted as the call processes and does not seem to change anything.
Is there a debug level or log setting that would confirm if I switch to rfc2833 or inband that freeswitch is indeed working as rfc2833 or inband?
If I could figure out how to disable whatever the switch_rtp.c message indicates on the log DTMF processing…that would seem to address my issue.
Thanks in advance for any help you can provide.
*From:* freeswitch-users-bounces@lists.freeswitch.org [mailto: freeswitch-users-bounces@lists.freeswitch.org] *On Behalf Of *Guillermo Ruiz Camauer *Sent:* Saturday, September 03, 2016 09:14 *To:* FreeSWITCH Users Help *Subject:* Re: [Freeswitch-users] intermittent DTMF duplicate digit detection
Can you try with RFC-2833 inste as of inband?
Guillermo
Sent from my iPhone
On Sep 3, 2016, at 01:20, Jeff Crews <jeff@eoni.com> wrote:
I am running
FreeSWITCH Version 1.6.6~64bit ( 64bit) running in a non-virtualized hardware platform. I am using it with FusionPBX (roughly 2 weeks since my last git pull)
When using a SIP trunk from my CopperCom IP card I get intermittent duplicate DTMF digits specifically causing me trouble using the IVR application.
With these options on:
dtmf_verbose=true
spandsp_dtmf_rx_threshold=-42
spandsp_dtmf_rx_twist=8
spandsp_dtmf_rx_reverse_twist=6
min_dup_digit_spacing_ms=50
(I have adjusted this from 0 to values of upwards of 2000…not sure it applies in this case as I think the duplicate digits might not be impacted by this value as I think two different systems are detecting the DTMF).
In the following logs the min_dup_digit_spacing_ms might have been any number of values I was testing.
So…on a properly recognized DTMF digit the logs look like this when I placed a test call to the IVR and dialed 9 as a menu option for the company directory then 489 to successfully to search for a name…in this call all worked as expected:
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.113751 [DEBUG] switch_core_media.c:4485 sofia/internal/541xxxyyyy@a.b.c.d Set 2833 dtmf send payload to 101 recv payload to 101
b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d parsing [public->dtmf-type] continue=true
b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Regex (PASS) [dtmf-type] () =~ // break=on-false
b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(dtmf_verbose=true)
b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(spandsp_dtmf_rx_threshold= -42)
b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(spandsp_dtmf_rx_twist=8)
b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(spandsp_dtmf_rx_reverse_ twist=6)
b6fe5cc0-717e-11e6-a586-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action spandsp_start_dtmf()
b6fe5cc0-717e-11e6-a586-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(dtmf_verbose=true)
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [dtmf_verbose]=[true]
b6fe5cc0-717e-11e6-a586-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(spandsp_dtmf_rx_threshold=-42)
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [spandsp_dtmf_rx_threshold]=[-42]
b6fe5cc0-717e-11e6-a586-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(spandsp_dtmf_rx_twist=8)
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [spandsp_dtmf_rx_twist]=[8]
b6fe5cc0-717e-11e6-a586-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(spandsp_dtmf_rx_reverse_twist=6)
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [spandsp_dtmf_rx_reverse_twist]=[6]
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] switch_core_session.c:2628 Application spandsp_start_dtmf Requires media! pre_answering channel sofia/internal/541xxxyyyy@a.b.c.d
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] switch_core_media.c:6332 sofia/internal/541xxxyyyy@a.b.c.d Set 2833 dtmf send payload to 101
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] switch_core_media.c:6339 sofia/internal/541xxxyyyy@a.b.c.d Set 2833 dtmf receive payload to 101
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:32:53.133718 [DEBUG] switch_core_media.c:6362 sofia/internal/541xxxyyyy@a.b.c.d Set rtp dtmf delay to 40
b6fe5cc0-717e-11e6-a586-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d spandsp_start_dtmf()
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:00.973723 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially D - total -18.52dB, row -35.24dB, col -32.15dB, duration 62628 - miss
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:00.993716 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.97dB, row -5.18dB, col -5.09dB, duration 62730 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:00.993716 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.94dB, row -5.03dB, col -5.06dB, duration 62832 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:00.993716 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [9]
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:00.993716 [INFO] switch_channel.c:512 RECV DTMF 9:2000
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.013719 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -3.03dB, row -5.21dB, col -5.28dB, duration 102 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.013719 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -3.02dB, row -5.29dB, col -5.13dB, duration 204 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.033720 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.92dB, row -5.03dB, col -5.03dB, duration 306 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.053716 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.97dB, row -5.08dB, col -5.22dB, duration 408 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.053716 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -9.02dB, row -17.52dB, col -16.96dB, duration 510 - miss
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:01.073716 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [9], duration = 76 ms
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.093756 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially D - total -19.84dB, row -34.97dB, col -34.04dB, duration 48144 - miss
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.113726 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.80dB, row -4.77dB, col -4.77dB, duration 48246 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.113726 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.92dB, row -5.02dB, col -5.03dB, duration 48348 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.113726 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [4]
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.113726 [INFO] switch_channel.c:512 RECV DTMF 4:2000
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.133730 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -3.14dB, row -5.55dB, col -5.42dB, duration 102 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.133730 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.77dB, row -4.66dB, col -4.80dB, duration 204 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.153730 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -3.25dB, row -5.70dB, col -5.63dB, duration 306 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.173727 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.79dB, row -4.84dB, col -4.70dB, duration 408 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.173727 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.92dB, row -5.00dB, col -5.05dB, duration 510 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.193720 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -4.11dB, row -7.36dB, col -7.35dB, duration 612 - miss
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.213719 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [4], duration = 89 ms
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.313724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -3.95dB, row -7.12dB, col -7.00dB, duration 918 - miss
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.333719 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -3.10dB, row -5.44dB, col -5.32dB, duration 1020 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.353724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -2.99dB, row -5.15dB, col -5.16dB, duration 1122 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.353724 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [8]
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.353724 [INFO] switch_channel.c:512 RECV DTMF 8:2000
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.353724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -2.85dB, row -4.84dB, col -4.94dB, duration 102 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.373724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -2.90dB, row -5.02dB, col -4.93dB, duration 204 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.393724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -2.98dB, row -5.22dB, col -5.11dB, duration 306 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.393724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -3.11dB, row -5.32dB, col -5.43dB, duration 408 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.413724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 8 - total -3.09dB, row -5.33dB, col -5.39dB, duration 510 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.413724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially * - total -13.19dB, row -24.69dB, col -24.21dB, duration 612 - miss
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.433724 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [8], duration = 89 ms
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.473724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -9.05dB, row -17.46dB, col -17.13dB, duration 306 - miss
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.493719 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.97dB, row -5.12dB, col -5.12dB, duration 408 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.493719 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.96dB, row -5.16dB, col -5.06dB, duration 510 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.493719 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [9]
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.493719 [INFO] switch_channel.c:512 RECV DTMF 9:2000
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.513724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -8.91dB, row -16.92dB, col -17.15dB, duration 102 - miss
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.533724 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [9], duration = 25 ms
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.553724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -5.06dB, row -9.31dB, col -9.33dB, duration 204 - miss
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.573734 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.98dB, row -5.04dB, col -5.19dB, duration 306 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.573734 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -2.93dB, row -5.14dB, col -4.99dB, duration 408 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.573734 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [9]
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.573734 [INFO] switch_channel.c:512 RECV DTMF 9:2000
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.593730 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -3.02dB, row -5.28dB, col -5.20dB, duration 102 - hit
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.593730 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 9 - total -11.08dB, row -21.34dB, col -21.19dB, duration 204 - miss
b6fe5cc0-717e-11e6-a586-0360625ff113 2016-09-02 19:33:07.613728 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [9], duration = 38 ms
this time I dialed the same menu and dialed 4 and got invalid entry (which digit I dial to cause the intermittent failure seems to be nearly any digit):
0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] switch_core_media.c:4485 sofia/internal/541xxxyyyy@a.b.c.d Set 2833 dtmf send payload to 101 recv payload to 101
0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d parsing [public->dtmf-type] continue=true
0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Regex (PASS) [dtmf-type] () =~ // break=on-false
0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(dtmf_verbose=true)
0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(spandsp_dtmf_rx_threshold= -42)
0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(spandsp_dtmf_rx_twist=8)
0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action set(spandsp_dtmf_rx_reverse_ twist=6)
0da6c076-717f-11e6-a732-0360625ff113 Dialplan: sofia/internal/541xxxyyyy@a.b.c.d Action spandsp_start_dtmf()
0da6c076-717f-11e6-a732-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(dtmf_verbose=true)
0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [dtmf_verbose]=[true]
0da6c076-717f-11e6-a732-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(spandsp_dtmf_rx_threshold=-42)
0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [spandsp_dtmf_rx_threshold]=[-42]
0da6c076-717f-11e6-a732-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(spandsp_dtmf_rx_twist=8)
0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [spandsp_dtmf_rx_twist]=[8]
0da6c076-717f-11e6-a732-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d set(spandsp_dtmf_rx_reverse_twist=6)
0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] mod_dptools.c:1498 SET sofia/internal/541xxxyyyy@a.b.c.d [spandsp_dtmf_rx_reverse_twist]=[6]
0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.513757 [DEBUG] switch_core_session.c:2628 Application spandsp_start_dtmf Requires media! pre_answering channel sofia/internal/541xxxyyyy@a.b.c.d
0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.533724 [DEBUG] switch_core_media.c:6332 sofia/internal/541xxxyyyy@a.b.c.d Set 2833 dtmf send payload to 101
0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.533724 [DEBUG] switch_core_media.c:6339 sofia/internal/541xxxyyyy@a.b.c.d Set 2833 dtmf receive payload to 101
0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:18.533724 [DEBUG] switch_core_media.c:6362 sofia/internal/541xxxyyyy@a.b.c.d Set rtp dtmf delay to 40
0da6c076-717f-11e6-a732-0360625ff113 EXECUTE sofia/internal/541xxxyyyy@a.b.c.d spandsp_start_dtmf()
0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.593744 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -4.41dB, row -8.03dB, col -8.02dB, duration 32538 - miss
0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.593744 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.73dB, row -4.71dB, col -4.59dB, duration 32640 - hit
0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.693734 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -4.19dB, row -7.59dB, col -7.55dB, duration 33354 - miss
0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.713723 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -3.25dB, row -5.68dB, col -5.62dB, duration 33456 - hit
0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.713723 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -2.76dB, row -4.65dB, col -4.79dB, duration 33558 - hit
0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.713723 [DEBUG] mod_spandsp_dsp.c:375 DTMF BEGIN DETECTED: [4]
0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.713723 [INFO] switch_channel.c:512 RECV DTMF 4:2000
0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.733724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -3.18dB, row -5.61dB, col -5.47dB, duration 102 - hit
0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.753724 [DEBUG] switch_rtp.c:6874 RTP RECV DTMF 4:800
0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.753724 [INFO] switch_channel.c:512 RECV DTMF 4:800
0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.753724 [DEBUG] mod_spandsp_fax.c:276 FLOW DTMF Potentially 4 - total -3.76dB, row -6.65dB, col -6.69dB, duration 204 - hit
0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.793718 [DEBUG] mod_spandsp_dsp.c:387 DTMF END DETECTED: [4], duration = 51 ms
Whenever I have problems with duplicate digits as in the later example above I always get a line with switch_rtp.c like this:
0da6c076-717f-11e6-a732-0360625ff113 2016-09-02 19:35:22.753724 [DEBUG] switch_rtp.c:6874 RTP RECV DTMF 4:800
If one of the switch_rtp lines does not show up in the output put that it RECV DTMF the DTMF is recognized properly.
Is there an option that I can set to tell the switch_rtp.c to ignore receiving DTMF?
I do not know happens that causes some calls to work and some calls to not work.
I was not sure if when it is intermittent (sometimes 80% get duplicate DTMF, sometimes only 20% get duplicate DTMF) what else to try.
I saw this:
https://freeswitch.org/confluence/display/FREESWITCH/RTP+Issues
and was not sure if this applied…or where options like:
<param name="auto-rtp-bugs" value="clear"/>
Were supposed to be placed in the dial plan to get these in the right place. Is this part of the options before you invoke action=spandsp_start_dtmf
Thanks in advance for any help you can provide.
Jeff
-.-. --.- -.. . -.- . --... --.- -.-- ..-
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Guillermo Ruiz Camauer
Thank you very much. Those descriptions help understand the relationship much better. So I am only using PCMU and PCMA codecs. My only active SIP profile was already on: dtmf-type=rfc2833 with liberal-dtmf not specified…however I added liberal-dtmf=false anyway just to be sure. Then I made sure anything with start_dtmf or start_spandsp were disabled and made a test call to the IVR. I made three test calls and dialed a signal digit of 9 on the IVR menu and each of the three times…it routed perfectly with log entries like this: 2016-09-08 05:09:33.086731 [DEBUG] switch_ivr_menu.c:424 digits 9 Then on my fourth call…I dialed the same numbers and the IVR menu kept playing as it was as if no digits were detected at all. This is the symptom that led me to a person suggesting I place the “start_dtmf” at the beginning of my inbound routes for my user needing the IVR menu. After placing 10 calls using the same Verizon Droid Turbo mobile phone, on 10 calls, 50% of the calls resulting in the IVR not hearing the DTMF and the IVR recording played on. I tried dialing several times the 9 digit…and no improvement. In running a: tail freeswitch.log | grep –i dtmf I see nothing with the text dtmf in the log when the DTMF is not detected. Then I tried 10 more and all failed to recognize DTMF dialed while the IVR menu was played. Then I added back start_dtmf on the inbound route for this customer. Then I could consistently get the DTMF to be recognized. I started two SSH sessions tailing the freeswitch.log to look for “digits” in one and case-insensitive “dtmf” in the other. I did 20 test calls from the same mobile phone, no speakerphone, dialing 9 each time. In 20 calls only 1 call got double digits received by the switch_ivr_menu.c. When I did see double digits…I got an entry like this: 2016-09-08 05:49:15.846749 [DEBUG] switch_rtp.c:6874 RTP RECV DTMF 9:1280 I placed 30 more test calls 8 had double digit 9, 2 had triple digit 9 and the other 10 were good with only single digit received. Again when duplicate digits occurred I got entries in the log from switch_rtp.c Last week when I noticed duplicate digits were received I added IVR menu options for each menu entry so that if 2=sales I added 2, 22 and 222 to all go to sales to keep calls flowing until I can figure this out. Does anyone know exactly what does “RTP RECV DTMF” indicates? Would packet capture in wireshark show something? Jeff From: freeswitch-users-bounces@lists.freeswitch.org [mailto:freeswitch-users-bounces@lists.freeswitch.org] On Behalf Of Guillermo Ruiz Camauer Sent: Wednesday, September 07, 2016 10:43 To: FreeSWITCH Users Help Subject: Re: [Freeswitch-users] intermittent DTMF duplicate digit detection Jeff, Just a couple of pointers. Inband DTMF detection is handled by spandsp and only really works if you are using PCMU or PCMA codecs (it does NOT work if you use codecs that compress like G.729, etc.) Spandsp analyses the tone frequencies received and tries to determine which DTMF was sent. RFC2833 works by sending a special packet in the RTP stream, no analysis needed. You should only specify ONE DTMF method for a channel if you don't want to have duplication problems. You should set <param name="dtmf-type" value="rfc2833"/> and <param name="liberal-dtmf" value="false"/> in the sip profile so that it only accepts RFC2833. Regards, Guillermo
start_dtmf you need to start only if you receive in-band (tone) dtmf. If you are receiving rfc2833 then it should be rtp event packed picked up by FS by default, so RTP RECV DTMF 9:1280 means you got RTP EVENT with duration 1280 sent by source like that. This you should be able to see if you tcpdump/ngrep on that server. So I suggest disable start_dtmf and do the tcpdump to see if you will receive RTP EVENT when dtmf is ignored. mirko On Thu, Sep 8, 2016 at 3:01 PM, Jeff Crews <jeff@eoni.com> wrote:
Thank you very much.
Those descriptions help understand the relationship much better.
So I am only using PCMU and PCMA codecs.
My only active SIP profile was already on: dtmf-type=rfc2833 with liberal-dtmf not specified…however I added liberal-dtmf=false anyway just to be sure.
Then I made sure anything with start_dtmf or start_spandsp were disabled and made a test call to the IVR.
I made three test calls and dialed a signal digit of 9 on the IVR menu and each of the three times…it routed perfectly with log entries like this:
2016-09-08 05:09:33.086731 [DEBUG] switch_ivr_menu.c:424 digits 9
Then on my fourth call…I dialed the same numbers and the IVR menu kept playing as it was as if no digits were detected at all. This is the symptom that led me to a person suggesting I place the “start_dtmf” at the beginning of my inbound routes for my user needing the IVR menu. After placing 10 calls using the same Verizon Droid Turbo mobile phone, on 10 calls, 50% of the calls resulting in the IVR not hearing the DTMF and the IVR recording played on. I tried dialing several times the 9 digit…and no improvement.
In running a: tail freeswitch.log | grep –i dtmf
I see nothing with the text dtmf in the log when the DTMF is not detected.
Then I tried 10 more and all failed to recognize DTMF dialed while the IVR menu was played.
Then I added back start_dtmf on the inbound route for this customer.
Then I could consistently get the DTMF to be recognized.
I started two SSH sessions tailing the freeswitch.log to look for “digits” in one and case-insensitive “dtmf” in the other.
I did 20 test calls from the same mobile phone, no speakerphone, dialing 9 each time.
In 20 calls only 1 call got double digits received by the switch_ivr_menu.c.
When I did see double digits…I got an entry like this:
2016-09-08 05:49:15.846749 [DEBUG] switch_rtp.c:6874 RTP RECV DTMF 9:1280
I placed 30 more test calls
8 had double digit 9, 2 had triple digit 9 and the other 10 were good with only single digit received.
Again when duplicate digits occurred I got entries in the log from switch_rtp.c
Last week when I noticed duplicate digits were received I added IVR menu options for each menu entry so that if 2=sales I added 2, 22 and 222 to all go to sales to keep calls flowing until I can figure this out.
Does anyone know exactly what does “RTP RECV DTMF” indicates?
Would packet capture in wireshark show something?
Jeff
*From:* freeswitch-users-bounces@lists.freeswitch.org [mailto: freeswitch-users-bounces@lists.freeswitch.org] *On Behalf Of *Guillermo Ruiz Camauer *Sent:* Wednesday, September 07, 2016 10:43 *To:* FreeSWITCH Users Help *Subject:* Re: [Freeswitch-users] intermittent DTMF duplicate digit detection
Jeff,
Just a couple of pointers. Inband DTMF detection is handled by spandsp and only really works if you are using PCMU or PCMA codecs (it does NOT work if you use codecs that compress like G.729, etc.) Spandsp analyses the tone frequencies received and tries to determine which DTMF was sent.
RFC2833 works by sending a special packet in the RTP stream, no analysis needed. You should only specify ONE DTMF method for a channel if you don't want to have duplication problems.
You should set <param name="dtmf-type" value="rfc2833"/> and <param name="liberal-dtmf" value="false"/> in the sip profile so that it only accepts RFC2833.
Regards,
Guillermo
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Regards, Mirko
I see that you are using a CopperCom IP card. What exactly is that (I cannot find any info, have they gone out of business?) If it is a T1/E1 card, then you will only be able to use INBAND signalling, unless the card generates RFC2833 for you. Have you checked the settings/parameters for this card? Does this happen to you if you use a plain SIP provider or from a SIP phone? Guillermo On Thu, Sep 8, 2016 at 10:33 AM, Mirko Brankovic <mirkobrankovic@gmail.com> wrote:
start_dtmf you need to start only if you receive in-band (tone) dtmf. If you are receiving rfc2833 then it should be rtp event packed picked up by FS by default, so RTP RECV DTMF 9:1280 means you got RTP EVENT with duration 1280 sent by source like that. This you should be able to see if you tcpdump/ngrep on that server.
So I suggest disable start_dtmf and do the tcpdump to see if you will receive RTP EVENT when dtmf is ignored.
mirko
On Thu, Sep 8, 2016 at 3:01 PM, Jeff Crews <jeff@eoni.com> wrote:
Thank you very much.
Those descriptions help understand the relationship much better.
So I am only using PCMU and PCMA codecs.
My only active SIP profile was already on: dtmf-type=rfc2833 with liberal-dtmf not specified…however I added liberal-dtmf=false anyway just to be sure.
Then I made sure anything with start_dtmf or start_spandsp were disabled and made a test call to the IVR.
I made three test calls and dialed a signal digit of 9 on the IVR menu and each of the three times…it routed perfectly with log entries like this:
2016-09-08 05:09:33.086731 [DEBUG] switch_ivr_menu.c:424 digits 9
Then on my fourth call…I dialed the same numbers and the IVR menu kept playing as it was as if no digits were detected at all. This is the symptom that led me to a person suggesting I place the “start_dtmf” at the beginning of my inbound routes for my user needing the IVR menu. After placing 10 calls using the same Verizon Droid Turbo mobile phone, on 10 calls, 50% of the calls resulting in the IVR not hearing the DTMF and the IVR recording played on. I tried dialing several times the 9 digit…and no improvement.
In running a: tail freeswitch.log | grep –i dtmf
I see nothing with the text dtmf in the log when the DTMF is not detected.
Then I tried 10 more and all failed to recognize DTMF dialed while the IVR menu was played.
Then I added back start_dtmf on the inbound route for this customer.
Then I could consistently get the DTMF to be recognized.
I started two SSH sessions tailing the freeswitch.log to look for “digits” in one and case-insensitive “dtmf” in the other.
I did 20 test calls from the same mobile phone, no speakerphone, dialing 9 each time.
In 20 calls only 1 call got double digits received by the switch_ivr_menu.c.
When I did see double digits…I got an entry like this:
2016-09-08 05:49:15.846749 [DEBUG] switch_rtp.c:6874 RTP RECV DTMF 9:1280
I placed 30 more test calls
8 had double digit 9, 2 had triple digit 9 and the other 10 were good with only single digit received.
Again when duplicate digits occurred I got entries in the log from switch_rtp.c
Last week when I noticed duplicate digits were received I added IVR menu options for each menu entry so that if 2=sales I added 2, 22 and 222 to all go to sales to keep calls flowing until I can figure this out.
Does anyone know exactly what does “RTP RECV DTMF” indicates?
Would packet capture in wireshark show something?
Jeff
*From:* freeswitch-users-bounces@lists.freeswitch.org [mailto: freeswitch-users-bounces@lists.freeswitch.org] *On Behalf Of *Guillermo Ruiz Camauer *Sent:* Wednesday, September 07, 2016 10:43 *To:* FreeSWITCH Users Help *Subject:* Re: [Freeswitch-users] intermittent DTMF duplicate digit detection
Jeff,
Just a couple of pointers. Inband DTMF detection is handled by spandsp and only really works if you are using PCMU or PCMA codecs (it does NOT work if you use codecs that compress like G.729, etc.) Spandsp analyses the tone frequencies received and tries to determine which DTMF was sent.
RFC2833 works by sending a special packet in the RTP stream, no analysis needed. You should only specify ONE DTMF method for a channel if you don't want to have duplication problems.
You should set <param name="dtmf-type" value="rfc2833"/> and <param name="liberal-dtmf" value="false"/> in the sip profile so that it only accepts RFC2833.
Regards,
Guillermo
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Regards, Mirko
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Guillermo Ruiz Camauer
participants (3)
-
Guillermo Ruiz Camauer
-
Jeff Crews
-
Mirko Brankovic