[Home]

Summary:ASTERISK-17640: [patch] Enabled dynamic features swallow DTMF codes (even if no match)
Reporter:Kirill Katsnelson (kkm)Labels:
Date Opened:2011-04-03 23:29:48Date Closed:2013-01-15 10:26:02.000-0600
Priority:MinorRegression?
Status:Closed/CompleteComponents:Features
Versions:Frequency of
Occurrence
Related
Issues:
cannot be resolved before completion ofASTERISK-17914 [regression] Change 310888 (Don't delay DTMF) broke DYNAMIC_FEATURES
is related toASTERISK-17962 a patch to fix bug 18130 breaks sequential emulated rfc2833 dtmf
Environment:Attachments:( 0) dtmf.patch
( 1) dtmffix.patch
Description:With a dynamic feature enabled, DTMF messages, if sent quickly enough, intermittently dropped.

****** STEPS TO REPRODUCE ******

1. Create 2 SIP peers in sip.conf. No special settings necessary.

{code}
[base](!)
 context=from-sip
 type=friend
 host=dynamic
 qualify=no

[250](base)
[252](base)
{code}

2. In features.conf, add a dynamic feature. It is essential for the reproduction that feature DTMF pattern is longer that 1 digit.

{code}
xpeercallee => AA,peer/callee,Noop
xpeercaller => BB,peer/caller,Noop
xselfcallee => CC,self/callee,Noop
xselfcaller => DD,self/caller,Noop
{code}

3. In extension.ael, add
{code}
context from-sip {
 252 => {
   __DYNAMIC_FEATURES="xpeercaller";
//    __DYNAMIC_FEATURES="xselfcaller";
//    __DYNAMIC_FEATURES="xpeercallee";
//    __DYNAMIC_FEATURES="xselfcallee";
   Dial(SIP/252);
  }
}
{code}

4. Reload asterisk, register 2 phones for the peers, and from peer 250 dial 252. Answer 252. Prepare to register DTMF messages on the called device, either by hearing, or logging on a softphone, or capturing RTP traffic. I did all three.

Type a sequence of DTMF digits quickly, like 1/16 notes in quite a fast tempo. I find it convenient to play 4555556. Of that sequence of 7 messages, you will hear between 2 and 4 on the called device, depending on how fast or lucky you are.

5. Repeat with
* xselfcaller only enabled (reproduces);
* peercallee/selfcallee enabled (does not reproduce; which means the bug happens only if a feature is enabled on the controlling channel, the caller in our case)
* none of the dynamic features enabled (does not reproduce)
* With feature codes shortened to one digit (does not reproduce: need at least 2-digit long codes). I. e. this does not repro the problem

{code}
xpeercallee => A,peer/callee,Noop
xpeercaller => B,peer/caller,Noop
xselfcallee => C,self/callee,Noop
xselfcaller => D,self/caller,Noop
{code}

****** ADDITIONAL INFORMATION ******

This is regression, 1.6 did not have the problem.

I do not have a patch, have not been working on one, and currently not looking into the problem.
Comments:By: Derrick Bradbury (snapple42) 2011-05-25 13:27:37

I had the same issue with 1.8.4, so I downgraded to 1.6.2.17.3 and the same problem occurs....

THis is with DYNAMIC_FEATURES enabled:

[May 25 14:22:46] DTMF[14365] channel.c: DTMF begin '4' received on SIP/BFLY-INBOUND-00000006
[May 25 14:22:46] DTMF[14365] channel.c: DTMF begin passthrough '4' on SIP/BFLY-INBOUND-00000006
[May 25 14:22:46] DTMF[14365] channel.c: DTMF end '4' received on SIP/BFLY-INBOUND-00000006, duration 280 ms
[May 25 14:22:46] DTMF[14365] channel.c: DTMF end accepted with begin '4' on SIP/BFLY-INBOUND-00000006
[May 25 14:22:46] DTMF[14365] channel.c: DTMF end passthrough '4' on SIP/BFLY-INBOUND-00000006
[May 25 14:22:47] DTMF[14255] channel.c: DTMF begin '2' received on SIP/BFLY-INBOUND-00000006
[May 25 14:22:47] DTMF[14255] channel.c: DTMF begin ignored '2' on SIP/BFLY-INBOUND-00000006
[May 25 14:22:47] DTMF[14365] channel.c: DTMF end '2' received on SIP/BFLY-INBOUND-00000006, duration 280 ms
[May 25 14:22:47] DTMF[14365] channel.c: DTMF begin emulation of '2' with duration 280 queued on SIP/BFLY-INBOUND-00000006
[May 25 14:22:47] DTMF[14365] channel.c: DTMF begin '4' received on SIP/BFLY-INBOUND-00000006
[May 25 14:22:47] DTMF[14365] channel.c: DTMF begin ignored '4' on SIP/BFLY-INBOUND-00000006
[May 25 14:22:47] DTMF[14365] channel.c: DTMF end emulation of '2' queued on SIP/BFLY-INBOUND-00000006
[May 25 14:22:47] DTMF[14255] channel.c: DTMF end '4' received on SIP/BFLY-INBOUND-00000006, duration 280 ms
[May 25 14:22:47] DTMF[14255] channel.c: DTMF end passthrough '4' on SIP/BFLY-INBOUND-00000006
[May 25 14:22:48] DTMF[14365] channel.c: DTMF begin '2' received on SIP/BFLY-INBOUND-00000006
[May 25 14:22:48] DTMF[14365] channel.c: DTMF begin passthrough '2' on SIP/BFLY-INBOUND-00000006
[May 25 14:22:48] DTMF[14365] channel.c: DTMF end '2' received on SIP/BFLY-INBOUND-00000006, duration 230 ms
[May 25 14:22:48] DTMF[14365] channel.c: DTMF end accepted with begin '2' on SIP/BFLY-INBOUND-00000006
[May 25 14:22:48] DTMF[14365] channel.c: DTMF end passthrough '2' on SIP/BFLY-INBOUND-00000006
[May 25 14:22:48] DTMF[14365] channel.c: DTMF begin '#' received on SIP/BFLY-INBOUND-00000006
[May 25 14:22:48] DTMF[14365] channel.c: DTMF begin passthrough '#' on SIP/BFLY-INBOUND-00000006
[May 25 14:22:48] DTMF[14365] channel.c: DTMF end '#' received on SIP/BFLY-INBOUND-00000006, duration 250 ms
[May 25 14:22:48] DTMF[14365] channel.c: DTMF end accepted with begin '#' on SIP/BFLY-INBOUND-00000006
[May 25 14:22:48] DTMF[14365] channel.c: DTMF end passthrough '#' on SIP/BFLY-INBOUND-00000006

This is what the othend got: 422


Now with DYNAMIC_FEATURES disabled:

[May 25 14:26:41] DTMF[14439] channel.c: DTMF begin '4' received on SIP/BFLY-INBOUND-0000000a
[May 25 14:26:41] DTMF[14439] channel.c: DTMF begin passthrough '4' on SIP/BFLY-INBOUND-0000000a
[May 25 14:26:42] DTMF[14439] channel.c: DTMF end '4' received on SIP/BFLY-INBOUND-0000000a, duration 240 ms
[May 25 14:26:42] DTMF[14439] channel.c: DTMF end accepted with begin '4' on SIP/BFLY-INBOUND-0000000a
[May 25 14:26:42] DTMF[14439] channel.c: DTMF end passthrough '4' on SIP/BFLY-INBOUND-0000000a
[May 25 14:26:42] DTMF[14439] channel.c: DTMF begin '2' received on SIP/BFLY-INBOUND-0000000a
[May 25 14:26:42] DTMF[14439] channel.c: DTMF begin passthrough '2' on SIP/BFLY-INBOUND-0000000a
[May 25 14:26:42] DTMF[14439] channel.c: DTMF end '2' received on SIP/BFLY-INBOUND-0000000a, duration 220 ms
[May 25 14:26:42] DTMF[14439] channel.c: DTMF end accepted with begin '2' on SIP/BFLY-INBOUND-0000000a
[May 25 14:26:42] DTMF[14439] channel.c: DTMF end passthrough '2' on SIP/BFLY-INBOUND-0000000a
[May 25 14:26:42] DTMF[14439] channel.c: DTMF begin '4' received on SIP/BFLY-INBOUND-0000000a
[May 25 14:26:42] DTMF[14439] channel.c: DTMF begin passthrough '4' on SIP/BFLY-INBOUND-0000000a
[May 25 14:26:42] DTMF[14439] channel.c: DTMF end '4' received on SIP/BFLY-INBOUND-0000000a, duration 220 ms
[May 25 14:26:42] DTMF[14439] channel.c: DTMF end accepted with begin '4' on SIP/BFLY-INBOUND-0000000a
[May 25 14:26:42] DTMF[14439] channel.c: DTMF end passthrough '4' on SIP/BFLY-INBOUND-0000000a
[May 25 14:26:42] DTMF[14439] channel.c: DTMF begin '2' received on SIP/BFLY-INBOUND-0000000a
[May 25 14:26:42] DTMF[14439] channel.c: DTMF begin passthrough '2' on SIP/BFLY-INBOUND-0000000a
[May 25 14:26:43] DTMF[14439] channel.c: DTMF end '2' received on SIP/BFLY-INBOUND-0000000a, duration 220 ms
[May 25 14:26:43] DTMF[14439] channel.c: DTMF end accepted with begin '2' on SIP/BFLY-INBOUND-0000000a
[May 25 14:26:43] DTMF[14439] channel.c: DTMF end passthrough '2' on SIP/BFLY-INBOUND-0000000a
[May 25 14:26:43] DTMF[14439] channel.c: DTMF begin '#' received on SIP/BFLY-INBOUND-0000000a
[May 25 14:26:43] DTMF[14439] channel.c: DTMF begin passthrough '#' on SIP/BFLY-INBOUND-0000000a
[May 25 14:26:43] DTMF[14439] channel.c: DTMF end '#' received on SIP/BFLY-INBOUND-0000000a, duration 210 ms
[May 25 14:26:43] DTMF[14439] channel.c: DTMF end accepted with begin '#' on SIP/BFLY-INBOUND-0000000a
[May 25 14:26:43] DTMF[14439] channel.c: DTMF end passthrough '#' on SIP/BFLY-INBOUND-0000000a

and the far end received: 4242


By: Leif Madsen (lmadsen) 2011-05-25 13:43:23

I've marked this as related (potentially) to issue ASTERISK-17914
By: dimitripietro (dimitripietro) 2011-05-25 13:45:59

I can also reproduce the same problem on Asterisk 1.8.4. By disabling Dynamic Features, the problem is gone
By: Gregory Hinton Nietsky (irroot) 2011-05-26 08:48:43

This is a quick blind look / stab the theory i have is i get > 1 begin frames before the end frame ....
By: dimitripietro (dimitripietro) 2011-05-26 08:51:18

I can't apply the patch on 1.8.4 :


Hunk #1 FAILED at 3731.
Hunk #2 FAILED at 3757.
2 out of 2 hunks FAILED -- saving rejects to file main/features.c.rej
By: Gregory Hinton Nietsky (irroot) 2011-05-26 10:00:32

pleaese email me the .rej gregory at distrotech dot co dot za
By: Gregory Hinton Nietsky (irroot) 2011-05-26 10:02:42

the patch was against /branches/1.8
By: Leif Madsen (lmadsen) 2011-05-27 13:20:40

I tested this patch (applies cleanly on my trunk checkout) and it makes no change to the related issue.
By: Gregory Hinton Nietsky (irroot) 2011-05-28 02:57:14

ah well it was worth a shot .. i might look deeper at it.
By: Gregory Hinton Nietsky (irroot) 2011-06-04 03:56:31

ASTERISK-17962 is a duplicate and has a potential solution ill post a patch shortly for testing
By: Leif Madsen (lmadsen) 2011-06-06 14:02:02.364-0500

Patch doesn't resolve issue for me.
By: dimitripietro (dimitripietro) 2011-07-18 11:16:54.333-0500

The second patch did resolved the issue for me on 1.8.4.2
By: Jamuel Starkey (jamuel) 2011-09-23 14:33:06.534-0500

Not that anyone particularly cares about 1.6.2.x any more but I can confirm that this one-line fix (patch #2 above) fixes that issue we see in 1.6.2.19
By: Matt Jordan (mjordan) 2013-01-15 10:26:02.228-0600

This looks to have been a duplicate of ASTERISK-17640. If that is not the case, please contact a bug marshal in #asterisk-bugs and we will be happy to reopen this issue. Thanks!