[asterisk-users] Delay between DTMF Down & Detected Digit

[Jonathan Campbell]

Good Morning,

I've recently gotten Asterisk installed and configured our IVR using
FreePBX. Things seem to be going well except a few of our inbound
callers are ending up in the wrong place when trying to connect to a
specific extension. The example I had this morning was someone trying to
call extension 212 and getting connected to the Sales queue which is
option 2 on the IVR. I looked in our log and it seems like there was a
seventeen second delay between the caller pressing the last 2 and when
Asterisk acknowledged it. By that time, Asterisk had decided that "21"
wasn't a valid extension and the subsequent "2" dropped the caller into
the Sales queue.

I did my best to search for this issue in the archives and I found one
reference to relaxdtmf, but I wasn't sure if that would address the
issue and I wouldn't want it to cause talkoff.

For reference, we're using a Wildcard TE410P for these incoming calls.
I've included the configuration for the ivr and a scrubbed segment from
the log. If any additional information is needed, please let me know.

Any help is appreciated in advance!

Jon


[ivr-3]
include => ivr-3-custom
include => ext-findmefollow
include => ext-local
include => app-directory
exten => h,1,Hangup
exten => s,1,Set(LOOPCOUNT=0)
exten => s,n,Set(__DIR-CONTEXT=default)
exten => s,n,Answer
exten => s,n,Wait(1)
exten => s,n(begin),Set(TIMEOUT(digit)=3)
exten => s,n,Set(TIMEOUT(response)=10)
exten => s,n,Background(custom/RM_Daytime)
exten => hang,1,Playback(vm-goodbye)
exten => hang,n,Hangup
exten => 0,1,Goto(ext-queues,300,1)
exten => 1,1,Goto(ext-queues,300,1)
exten => 2,1,Goto(ext-queues,400,1)
exten => 7,1,Goto(ext-queues,700,1)
exten => t,1,Goto(ext-queues,300,1)
exten => i,1,Playback(invalid)
exten => i,n,Goto(loop,1)
exten => loop,1,Set(LOOPCOUNT=$[${LOOPCOUNT} + 1])
exten => loop,n,GotoIf($[${LOOPCOUNT} > 2]?hang,1)
exten => loop,n,Goto(ivr-3,s,begin)
exten => fax,1,Goto(ext-fax,in_fax,1)

; end of [ivr-3]

Nov  8 11:13:53 VERBOSE[24018] logger.c:     -- Accepting call from
'XXXXXXXXXX' to 's' on channel 0/7, span 1
Nov  8 11:13:53 DEBUG[24018] chan_zap.c: Enabled echo cancellation on
channel 7
...
Nov  8 11:13:58 DEBUG[3561] chan_zap.c: Exception on 23, channel 7
Nov  8 11:13:58 DEBUG[3561] chan_zap.c: Got event Event 131122(131122)
on channel 7 (index 0)
Nov  8 11:13:58 DEBUG[3561] chan_zap.c: DTMF Down '2'
Nov  8 11:13:58 DEBUG[3561] chan_zap.c: Exception on 23, channel 7
Nov  8 11:13:58 DEBUG[3561] chan_zap.c: Got event Event 262194(262194)
on channel 7 (index 0)
Nov  8 11:13:58 DEBUG[3561] chan_zap.c: Detected digit '2'
Nov  8 11:13:58 DEBUG[3561] pbx.c: Oooh, got something to jump out with
('2')!
Nov  8 11:13:58 DEBUG[3561] chan_zap.c: Exception on 23, channel 7
Nov  8 11:13:58 DEBUG[3561] chan_zap.c: Got event Event 131121(131121)
on channel 7 (index 0)
Nov  8 11:13:58 DEBUG[3561] chan_zap.c: DTMF Down '1'
Nov  8 11:13:58 DEBUG[3561] chan_zap.c: Exception on 23, channel 7
Nov  8 11:13:58 DEBUG[3561] chan_zap.c: Got event Event 262193(262193)
on channel 7 (index 0)
Nov  8 11:13:58 DEBUG[3561] chan_zap.c: Detected digit '1'
Nov  8 11:13:58 DEBUG[3561] chan_zap.c: Exception on 23, channel 7
Nov  8 11:13:58 DEBUG[3561] chan_zap.c: Got event Event 131122(131122)
on channel 7 (index 0)
Nov  8 11:13:58 DEBUG[3561] chan_zap.c: DTMF Down '2'
Nov  8 11:14:01 VERBOSE[3561] logger.c:     -- Invalid extension '21' in
context 'ivr-3' on Zap/7-1
Nov  8 11:14:01 VERBOSE[3561] logger.c:   == CDR updated on Zap/7-1
Nov  8 11:14:01 VERBOSE[3561] logger.c:     -- Executing
Playback("Zap/7-1", "invalid") in new stack
Nov  8 11:14:01 DEBUG[3561] channel.c: Scheduling timer at 160 sample
intervals
Nov  8 11:14:01 DEBUG[24018] chan_zap.c: Echo cancellation already on
...
Nov  8 11:14:15 DEBUG[3561] chan_zap.c: Exception on 23, channel 7
Nov  8 11:14:15 DEBUG[3561] chan_zap.c: Got event Event 262194(262194)
on channel 7 (index 0)
Nov  8 11:14:15 DEBUG[3561] chan_zap.c: Detected digit '2'