IVR application gets user input OK but ignores it and times out

I’m new to this forum, so apologies if I’m posting this in the wrong place.
I have an up to date (version 14.0.5.) FreePBX installation running in a QEMU virtual machine with plenty of RAM and disk space.

I created an IVR with options 1 and 2 to go to different, existing, destinations.
I then make the IVR the target of an inbound route. On ringing in to this route, the caller hears the announcement ok, but anything they press is ignored. I did play with all three valid values of dtmfmode in the trunk SIP settings, with no difference. However, I think the entered number is received OK, because it appears in the asterisk logfile (“app_read.c: User entered ‘1’”), which is included below. Curiously the “user entered” appears after the 10s timeout. It’s as if there’s an inter-digit timeout that’s longer than the number entry timeout - however the logfile below suggests that the inter-digit timeout is 3s.

Can anybody suggest what I’m doing wrong?

[2019-04-02 10:57:11] VERBOSE[14865][C-00000050] file.c: <SIP/spa3000-line-000001ad> Playing 'custom/please_press_a_1.slin' (language 'en_GB')
[2019-04-02 10:57:15] VERBOSE[14865][C-00000050] pbx.c: Executing [[email protected]:12] Read("SIP/spa3000-line-000001ad", "IVREXT,,,,0,10") in new stack
[2019-04-02 10:57:26] VERBOSE[14865][C-00000050] app_read.c: User entered '1'
[2019-04-02 10:57:26] VERBOSE[14865][C-00000050] pbx.c: Executing [[email protected]:13] GotoIf("SIP/spa3000-line-000001ad", "0?t,1") in new stack
[2019-04-02 10:57:26] VERBOSE[14865][C-00000050] pbx.c: Executing [[email protected]:14] GotoIf("SIP/spa3000-line-000001ad", "1?i,1") in new stack
[2019-04-02 10:57:26] VERBOSE[14865][C-00000050] pbx_builtins.c: Goto (ivr-1,i,1)
[2019-04-02 10:57:26] VERBOSE[14865][C-00000050] pbx.c: Executing [[email protected]:1] Set("SIP/spa3000-line-000001ad", "INVALID_LOOPCOUNT=1") in new stack
[2019-04-02 10:57:26] VERBOSE[14865][C-00000050] pbx.c: Executing [[email protected]:2] GotoIf("SIP/spa3000-line-000001ad", "0?final") in new stack
[2019-04-02 10:57:26] VERBOSE[14865][C-00000050] pbx.c: Executing [[email protected]:3] Set("SIP/spa3000-line-000001ad", "IVR_MSG=no-valid-responce-pls-try-again") in new stack
[2019-04-02 10:57:26] VERBOSE[14865][C-00000050] pbx.c: Executing [[email protected]:4] Goto("SIP/spa3000-line-000001ad", "s,start") in new stack
[2019-04-02 10:57:26] VERBOSE[14865][C-00000050] pbx_builtins.c: Goto (ivr-1,s,10)
[2019-04-02 10:57:26] VERBOSE[14865][C-00000050] pbx.c: Executing [[email protected]:10] Set("SIP/spa3000-line-000001ad", "TIMEOUT(digit)=3") in new stack
[2019-04-02 10:57:26] VERBOSE[14865][C-00000050] func_timeout.c: Digit timeout set to 3.000
[2019-04-02 10:57:26] VERBOSE[14865][C-00000050] pbx.c: Executing [[email protected]:11] ExecIf("SIP/spa3000-line-000001ad", "1?Background(no-valid-responce-pls-try-again)") in new stack
[2019-04-02 10:57:26] VERBOSE[14865][C-00000050] file.c: <SIP/spa3000-line-000001ad> Playing 'no-valid-responce-pls-try-again.ulaw' (language 'en_GB')
[2019-04-02 10:57:30] VERBOSE[14865][C-00000050] pbx.c: Executing [[email protected]:12] Read("SIP/spa3000-line-000001ad", "IVREXT,,,,0,10") in new stack
[2019-04-02 10:57:42] VERBOSE[14865][C-00000050] app_read.c: User entered '2'
[2019-04-02 10:57:42] VERBOSE[14865][C-00000050] pbx.c: Executing [[email protected]:13] GotoIf("SIP/spa3000-line-000001ad", "0?t,1") in new stack
[2019-04-02 10:57:42] VERBOSE[14865][C-00000050] pbx.c: Executing [[email protected]:14] GotoIf("SIP/spa3000-line-000001ad", "1?i,1") in new stack
[2019-04-02 10:57:42] VERBOSE[14865][C-00000050] pbx_builtins.c: Goto (ivr-1,i,1)
[2019-04-02 10:57:42] VERBOSE[14865][C-00000050] pbx.c: Executing [[email protected]:1] Set("SIP/spa3000-line-000001ad", "INVALID_LOOPCOUNT=2") in new stack
[2019-04-02 10:57:42] VERBOSE[14865][C-00000050] pbx.c: Executing [[email protected]:2] GotoIf("SIP/spa3000-line-000001ad", "0?final") in new stack
[2019-04-02 10:57:42] VERBOSE[14865][C-00000050] pbx.c: Executing [[email protected]:3] Set("SIP/spa3000-line-000001ad", "IVR_MSG=no-valid-responce-pls-try-again") in new stack
[2019-04-02 10:57:42] VERBOSE[14865][C-00000050] pbx.c: Executing [[email protected]:4] Goto("SIP/spa3000-line-000001ad", "s,start") in new stack
[2019-04-02 10:57:42] VERBOSE[14865][C-00000050] pbx_builtins.c: Goto (ivr-1,s,10)
[2019-04-02 10:57:42] VERBOSE[14865][C-00000050] pbx.c: Executing [[email protected]:10] Set("SIP/spa3000-line-000001ad", "TIMEOUT(digit)=3") in new stack
[2019-04-02 10:57:42] VERBOSE[14865][C-00000050] func_timeout.c: Digit timeout set to 3.000
[2019-04-02 10:57:42] VERBOSE[14865][C-00000050] pbx.c: Executing [[email protected]:11] ExecIf("SIP/spa3000-line-000001ad", "1?Background(no-valid-responce-pls-try-again)") in new stack
[2019-04-02 10:57:42] VERBOSE[14865][C-00000050] file.c: <SIP/spa3000-line-000001ad> Playing 'no-valid-responce-pls-try-again.ulaw' (language 'en_GB')
[2019-04-02 10:57:46] VERBOSE[14865][C-00000050] pbx.c: Executing [[email protected]:12] Read("SIP/spa3000-line-000001ad", "IVREXT,,,,0,10") in new stack
[2019-04-02 10:57:55] VERBOSE[14865][C-00000050] app_read.c: User disconnected
[2019-04-02 10:57:55] VERBOSE[14865][C-00000050] pbx.c: Executing [[email protected]:1] Hangup("SIP/spa3000-line-000001ad", "") in new stack
[2019-04-02 10:57:55] VERBOSE[14865][C-00000050] pbx.c: Spawn extension (ivr-1, h, 1) exited non-zero on 'SIP/spa3000-line-000001ad'
[2019-04-02 10:57:55] VERBOSE[14865][C-00000050] app_stack.c: SIP/spa3000-line-000001ad Internal Gosub(crm-hangup,s,1) start

Please Upgrade IVR module version to the latest which is available (14.0.9) on EDGE track

1 Like

This topic was automatically closed 7 days after the last reply. New replies are no longer allowed.