DTMF duplicated when Waitexten

Asterisk Asterisk Support
1

Hello,

I have a problem of DTMF duplication.

I receive call from my provider with SIP protocol. These calls pass
through an interactive voice menu, using the application Waitexten to
enter a client code. The menu works fine, but sometimes I have DTMF
duplication that prevent proper code entry. All DTMF come twice.

my sip.conf

[general]
context=default
allowguest=no
allowoverlap=no
allowtransfer=yes
udpbindaddr=0.0.0.0
tcpenable=no
tlsenable=no
srvlookup=yes
maxexpiry=3600
minexpiry=60
defaultexpiry=120
qualifyfreq=60
disallow=all
allow=alaw
language=fr
relaxdtmf=no
dtmfmode=rfc2833
videosupport=no
dynamic_exclude_static=yes
canreinvite=no
rtcachefriends=yes
rtsavesysname=yes
rtupdate=yes
rtautoclear=yes
ignoreregexpire=no
 
[xxxxx]
type=peer
host=xxxxxx.xxxxxxx.com
secret=XxXxXxXxXxX
call-limit=128
defaultuser=00XXXXXXXXXXX
fromuser=00XXXXXXXXXXX
disallow=all
allow=ulaw
nat=yes
context=trunk
qualify=50
insecure=invite
restrictcid=no
dtmfmode=rfc2833
rfc2833compensate=yes
canreinvite=no

my extensions.conf

[code][general]
static=yes
writeprotect=no
autofallthrough=yes
extenpatternmatchnew=yes
clearglobalvars=no

[vm-xxx]
exten => s,1,Answer
exten => s,n,Set(TIMEOUT(response)=3)
exten => s,n,Set(TIMEOUT(digit)=5)
exten => s,n,Playback(xxxxx)
exten => s,n,Playback(xxxxx)
exten => s,n,Playback(xxxxx)
exten => s,n,Set(MAX=0)
exten => s,n(menu),Background(xxxx_menu)
exten => s,n,WaitExten

exten => _NXNXXXXXX#,1,Agi(xxxxxx)
exten => _NXNXXXXXX#,n,Macro(xxxxx)

exten => t,1,Set(CALLERID(name)=******* - xxxxxxx})
exten => t,n(noid),Playback(xxxxxxx)
exten => t,n,Playback(xxxxxxx)
exten => t,n,Macro(xxxxxxx)

exten => i,1,Playback(xxxxxxxx)
exten => i,n,Set(MAX=$[${MAX} + 1])
exten => i,n,GotoIf($[${MAX} = 3]?t,1)
exten => i,n,Goto(s,menu)[/code]

my full log on 1 example

[Aug 25 15:29:53] VERBOSE[16029] pbx.c: [Aug 25 15:29:53] -- Executing [s@vm-xxxxx:1] Answer("SIP/provider-xxxxxxx", "") in new stack [Aug 25 15:29:53] DEBUG[16029] chan_sip.c: SIP answering channel: SIP/provider-xxxxxxx [Aug 25 15:29:53] DEBUG[16029] channel.c: Didn't receive a media frame from SIP/provider-xxxxxxx within 500 ms of answering. Continuing anyway [Aug 25 15:29:53] VERBOSE[16029] pbx.c: [Aug 25 15:29:53] -- Executing [s@vm-xxxxx:2] Set("SIP/provider-xxxxxxx", "TIMEOUT(response)=3") in new stack [Aug 25 15:29:53] VERBOSE[16029] pbx.c: [Aug 25 15:29:53] -- Executing [s@vm-xxxxx:3] Set("SIP/provider-xxxxxxx", "TIMEOUT(digit)=5") in new stack [Aug 25 15:29:53] VERBOSE[16029] pbx.c: [Aug 25 15:29:53] -- Executing [s@vm-xxxxx:4] Playback("SIP/provider-xxxxxxx", "xxxxxxxxxx") in new stack [Aug 25 15:29:53] VERBOSE[16029] file.c: [Aug 25 15:29:53] -- <SIP/provider-xxxxxxx> Playing 'xxxxxxxxxx.ulaw' (language 'fr') [Aug 25 15:29:56] VERBOSE[16029] pbx.c: [Aug 25 15:29:56] -- Executing [s@vm-xxxxx:5] Playback("SIP/provider-xxxxxxx", "xxxxxxxxxx") in new stack [Aug 25 15:29:56] VERBOSE[16029] file.c: [Aug 25 15:29:56] -- <SIP/provider-xxxxxxx> Playing 'xxxxxxxxxx.ulaw' (language 'fr') [Aug 25 15:30:02] VERBOSE[16029] pbx.c: [Aug 25 15:30:02] -- Executing [s@vm-xxxxx:6] Playback("SIP/provider-xxxxxxx", "xxxxxxxxxx") in new stack [Aug 25 15:30:02] VERBOSE[16029] file.c: [Aug 25 15:30:02] -- <SIP/provider-xxxxxxx> Playing 'xxxxxxxxxx.ulaw' (language 'fr') [Aug 25 15:30:08] VERBOSE[16029] pbx.c: [Aug 25 15:30:08] -- Executing [s@vm-xxxxx:7] Set("SIP/provider-xxxxxxx", "MAX=0") in new stack [Aug 25 15:30:08] VERBOSE[16029] pbx.c: [Aug 25 15:30:08] -- Executing [s@vm-xxxxx:8] BackGround("SIP/provider-xxxxxxx", "xxxxxxxxxx") in new stack [Aug 25 15:30:08] VERBOSE[16029] file.c: [Aug 25 15:30:08] -- <SIP/provider-xxxxxxx> Playing 'xxxxxxxxxx.ulaw' (language 'fr') [Aug 25 15:30:14] DTMF[16029] channel.c: DTMF end '7' received on SIP/provider-xxxxxxx, duration 0 ms [Aug 25 15:30:14] DTMF[16029] channel.c: DTMF end accepted without begin '7' on SIP/provider-xxxxxxx [Aug 25 15:30:14] DTMF[16029] channel.c: DTMF end passthrough '7' on SIP/provider-xxxxxxx [Aug 25 15:30:14] DTMF[16029] channel.c: DTMF end '7' received on SIP/provider-xxxxxxx, duration 100 ms [Aug 25 15:30:14] DTMF[16029] channel.c: DTMF end passthrough '7' on SIP/provider-xxxxxxx [Aug 25 15:30:14] DTMF[16029] channel.c: DTMF end '6' received on SIP/provider-xxxxxxx, duration 0 ms [Aug 25 15:30:14] DTMF[16029] channel.c: DTMF end accepted without begin '6' on SIP/provider-xxxxxxx [Aug 25 15:30:14] DTMF[16029] channel.c: DTMF end passthrough '6' on SIP/provider-xxxxxxx [Aug 25 15:30:14] DTMF[16029] channel.c: DTMF end '6' received on SIP/provider-xxxxxxx, duration 100 ms [Aug 25 15:30:14] DTMF[16029] channel.c: DTMF end passthrough '6' on SIP/provider-xxxxxxx [Aug 25 15:30:14] DTMF[16029] channel.c: DTMF end '6' received on SIP/provider-xxxxxxx, duration 0 ms [Aug 25 15:30:14] DTMF[16029] channel.c: DTMF end accepted without begin '6' on SIP/provider-xxxxxxx [Aug 25 15:30:14] DTMF[16029] channel.c: DTMF end passthrough '6' on SIP/provider-xxxxxxx [Aug 25 15:30:14] DTMF[16029] channel.c: DTMF end '6' received on SIP/provider-xxxxxxx, duration 100 ms [Aug 25 15:30:14] DTMF[16029] channel.c: DTMF end passthrough '6' on SIP/provider-xxxxxxx [Aug 25 15:30:15] DTMF[16029] channel.c: DTMF end '8' received on SIP/provider-xxxxxxx, duration 0 ms [Aug 25 15:30:15] DTMF[16029] channel.c: DTMF end accepted without begin '8' on SIP/provider-xxxxxxx [Aug 25 15:30:15] DTMF[16029] channel.c: DTMF end passthrough '8' on SIP/provider-xxxxxxx [Aug 25 15:30:15] DTMF[16029] channel.c: DTMF end '8' received on SIP/provider-xxxxxxx, duration 100 ms [Aug 25 15:30:15] DTMF[16029] channel.c: DTMF end passthrough '8' on SIP/provider-xxxxxxx [Aug 25 15:30:15] DTMF[16029] channel.c: DTMF end '9' received on SIP/provider-xxxxxxx, duration 0 ms [Aug 25 15:30:15] DTMF[16029] channel.c: DTMF end accepted without begin '9' on SIP/provider-xxxxxxx [Aug 25 15:30:15] DTMF[16029] channel.c: DTMF end passthrough '9' on SIP/provider-xxxxxxx [Aug 25 15:30:15] DTMF[16029] channel.c: DTMF end '9' received on SIP/provider-xxxxxxx, duration 100 ms [Aug 25 15:30:15] DTMF[16029] channel.c: DTMF end passthrough '9' on SIP/provider-xxxxxxx [Aug 25 15:30:15] VERBOSE[16029] pbx.c: [Aug 25 15:30:15] -- Invalid extension '7766668899' in context 'vm-xxxxx' on SIP/provider-xxxxxxx

As you can see the DTMF come twice, the first with duration of 0ms et the
second with duration of 100ms.
I tried to set relaxdtmf=yes or rfc2833compensate=yes but I still have the
same problem…

Anybody know how I can solve this problem of DTMF duplication ?

Thank you in advance.

Loïc

2

What version of asterisk are you running? That appears to be a problem with your upstream provider. It looks to me like whoever you are interfacing with has some RFC2833 compliance issues. Just based on a wild ass guess, I would say they are probably resetting an RFC2833 timestamp somewhere they shouldn’t be.

If you are running a recent 1.6.1, I would look deeper into a potential bug. I just helped someone with this issue yesterday… but the symptom was a little different. They were getting 500ms duration packets and asterisk was cutting them into 2 and duplicating that way.

3

I am running the latest version of 1.6.1 branch : Asterisk 1.6.1.4

4

yeah, he was running the exact same version. He ended up going to 1.4.26.1 to correct the issue.

5

Ok, thanks for your feedback :wink:

But me, I can’t downgrade to 1.4 branch because I use new feature of 1.6.1 branch. And I had quite mishap with the SIP of 1.4 branch.

May be I try to downgrade to another version of 1.6 branch.

Anyone have another solution for this problem ?