Hi. When I call in to my PIAF system using my cell phone and dial extension 14 about half the time the call goes to extension 33. I’ve looked through the logs but am not sure what I’m looking for or what would be appropriate to post here. Any help would be appreciated at helping me figure this out. Thanks.
Interesting. It my take some work to get a POTS phone connection but I’ll try that. I know that several other people have experienced the same problems. My boss with his cell phone, our web consultant (using voip of some sort), our bank.
More than likely, you’re not getting clean DTMF tones over the cellular connection in this is happening just over the cell. To test, what happens when you make the same call from a POTS connection?
Enable DTMF logging in logging_logfiles_custom.conf and see what happens. I’ve never heard of DTMF being misinterpreted (usually it just doesn’t work if there are problems.)
Sorry, I’m new at this. Can you help me get to that file. Thanks.
Edit /etc/asterisk/logging_logfiles_custom.conf. Add dtmf to one of the existing entries or create a new one. All DTMF digits will be dumped into the corresponding log file in /var/log/asterisk. Should give you an idea what digits the server is seeing.
Here are the parts of the log that are around lines that say DTMF. Can you help me understand what they mean? I hope I’ve provided the correct information. For each of the calls I dialed either 12 or 14. Most of the time it went to the correct extension, however several times it went to the wrong extension. Thanks so much for your help.
[2013-05-09 11:19:41] VERBOSE[25752] func_timeout.c: – Response timeout set to 5.000
[2013-05-09 11:19:41] VERBOSE[25752] pbx.c: – Executing [s@ivr-14:11] Set(“SIP/vitel-inbound-00002306”, “__IVR_RETVM=”) in new stack
[2013-05-09 11:19:41] VERBOSE[25752] pbx.c: – Executing [s@ivr-14:12] ExecIf(“SIP/vitel-inbound-00002306”, “1?Background(custom/complete_main_menu)”) in new stack
[2013-05-09 11:19:41] VERBOSE[25752] file.c: – <SIP/vitel-inbound-00002306> Playing ‘custom/complete_main_menu.slin’ (language ‘en’)
[2013-05-09 11:19:58] DTMF[25752] channel.c: DTMF begin ‘1’ received on SIP/vitel-inbound-00002306
[2013-05-09 11:19:58] DTMF[25752] channel.c: DTMF begin ignored ‘1’ on SIP/vitel-inbound-00002306
[2013-05-09 11:19:58] DTMF[25752] channel.c: DTMF end ‘1’ received on SIP/vitel-inbound-00002306, duration 100 ms
[2013-05-09 11:19:58] DTMF[25752] channel.c: DTMF end passthrough ‘1’ on SIP/vitel-inbound-00002306
[2013-05-09 11:20:01] VERBOSE[25752] pbx.c: == CDR updated on SIP/vitel-inbound-00002306
[2013-05-09 11:20:01] VERBOSE[25752] pbx.c: – Executing [1@ivr-14:1] Macro(“SIP/vitel-inbound-00002306”, “blkvm-clr,”) in new stack
[2013-05-09 11:20:01] VERBOSE[25752] pbx.c: – Executing [s@macro-blkvm-clr:1] Set(“SIP/vitel-inbound-00002306”, “SHARED(BLKVM,)=”) in new stack
[2013-05-09 11:20:01] VERBOSE[25752] pbx.c: – Executing [s@macro-blkvm-clr:2] Set(“SIP/vitel-inbound-00002306”, “GOSUB_RETVAL=”) in new stack
[2013-05-09 11:20:01] VERBOSE[25752] pbx.c: – Executing [s@macro-blkvm-clr:3] MacroExit(“SIP/vitel-inbound-00002306”, “”) in new stack
[2013-05-09 11:20:20] VERBOSE[25754] func_timeout.c: – Response timeout set to 5.000
[2013-05-09 11:20:20] VERBOSE[25754] pbx.c: – Executing [s@ivr-14:11] Set(“SIP/vitel-inbound-00002308”, “__IVR_RETVM=”) in new stack
[2013-05-09 11:20:20] VERBOSE[25754] pbx.c: – Executing [s@ivr-14:12] ExecIf(“SIP/vitel-inbound-00002308”, “1?Background(custom/complete_main_menu)”) in new stack
[2013-05-09 11:20:20] VERBOSE[25754] file.c: – <SIP/vitel-inbound-00002308> Playing ‘custom/complete_main_menu.slin’ (language ‘en’)
[2013-05-09 11:20:26] DTMF[25754] channel.c: DTMF begin ‘1’ received on SIP/vitel-inbound-00002308
[2013-05-09 11:20:26] DTMF[25754] channel.c: DTMF begin ignored ‘1’ on SIP/vitel-inbound-00002308
[2013-05-09 11:20:26] DTMF[25754] channel.c: DTMF end ‘1’ received on SIP/vitel-inbound-00002308, duration 100 ms
[2013-05-09 11:20:26] DTMF[25754] channel.c: DTMF end passthrough ‘1’ on SIP/vitel-inbound-00002308
[2013-05-09 11:20:27] DTMF[25754] channel.c: DTMF begin ‘4’ received on SIP/vitel-inbound-00002308
[2013-05-09 11:20:27] DTMF[25754] channel.c: DTMF begin ignored ‘4’ on SIP/vitel-inbound-00002308
[2013-05-09 11:20:27] DTMF[25754] channel.c: DTMF end ‘4’ received on SIP/vitel-inbound-00002308, duration 100 ms
[2013-05-09 11:20:27] DTMF[25754] channel.c: DTMF end passthrough ‘4’ on SIP/vitel-inbound-00002308
[2013-05-09 11:20:27] VERBOSE[25754] pbx.c: == CDR updated on SIP/vitel-inbound-00002308
[2013-05-09 11:20:27] VERBOSE[25754] pbx.c: – Executing [14@ivr-14:1] Macro(“SIP/vitel-inbound-00002308”, “blkvm-clr,”) in new stack
[2013-05-09 11:20:27] VERBOSE[25754] pbx.c: – Executing [s@macro-blkvm-clr:1] Set(“SIP/vitel-inbound-00002308”, “SHARED(BLKVM,)=”) in new stack
[2013-05-09 11:20:27] VERBOSE[25754] pbx.c: – Executing [s@macro-blkvm-clr:2] Set(“SIP/vitel-inbound-00002308”, “GOSUB_RETVAL=”) in new stack
[2013-05-09 11:20:27] VERBOSE[25754] pbx.c: – Executing [s@macro-blkvm-clr:3] MacroExit(“SIP/vitel-inbound-00002308”, “”) in new stack
[2013-05-09 11:21:01] VERBOSE[25756] func_timeout.c: – Response timeout set to 5.000
[2013-05-09 11:21:01] VERBOSE[25756] pbx.c: – Executing [s@ivr-14:11] Set(“SIP/vitel-inbound-0000230c”, “__IVR_RETVM=”) in new stack
[2013-05-09 11:21:01] VERBOSE[25756] pbx.c: – Executing [s@ivr-14:12] ExecIf(“SIP/vitel-inbound-0000230c”, “1?Background(custom/complete_main_menu)”) in new stack
[2013-05-09 11:21:01] VERBOSE[25756] file.c: – <SIP/vitel-inbound-0000230c> Playing ‘custom/complete_main_menu.slin’ (language ‘en’)
[2013-05-09 11:21:04] DTMF[25756] channel.c: DTMF begin ‘2’ received on SIP/vitel-inbound-0000230c
[2013-05-09 11:21:04] DTMF[25756] channel.c: DTMF begin ignored ‘2’ on SIP/vitel-inbound-0000230c
[2013-05-09 11:21:04] DTMF[25756] channel.c: DTMF end ‘2’ received on SIP/vitel-inbound-0000230c, duration 100 ms
[2013-05-09 11:21:04] DTMF[25756] channel.c: DTMF end passthrough ‘2’ on SIP/vitel-inbound-0000230c
[2013-05-09 11:21:07] VERBOSE[25756] pbx.c: == CDR updated on SIP/vitel-inbound-0000230c
[2013-05-09 11:21:07] VERBOSE[25756] pbx.c: – Executing [2@ivr-14:1] Macro(“SIP/vitel-inbound-0000230c”, “blkvm-clr,”) in new stack
[2013-05-09 11:21:07] VERBOSE[25756] pbx.c: – Executing [s@macro-blkvm-clr:1] Set(“SIP/vitel-inbound-0000230c”, “SHARED(BLKVM,)=”) in new stack
[2013-05-09 11:21:07] VERBOSE[25756] pbx.c: – Executing [s@macro-blkvm-clr:2] Set(“SIP/vitel-inbound-0000230c”, “GOSUB_RETVAL=”) in new stack
[2013-05-09 11:21:07] VERBOSE[25756] pbx.c: – Executing [s@macro-blkvm-clr:3] MacroExit(“SIP/vitel-inbound-0000230c”, “”) in new stack
[2013-05-09 11:21:07] VERBOSE[25756] pbx.c: – Executing [2@ivr-14:2] Set(“SIP/vitel-inbound-0000230c”, “__NODEST=”) in new stack
[2013-05-09 11:21:07] VERBOSE[25756] pbx.c: – Executing [2@ivr-14:3] Goto(“SIP/vitel-inbound-0000230c”, “from-did-direct,18,1”) in new stack
[2013-05-09 11:21:01] VERBOSE[25756] pbx.c: – Executing [s@ivr-14:11] Set(“SIP/vitel-inbound-0000230c”, “__IVR_RETVM=”) in new stack
[2013-05-09 11:21:01] VERBOSE[25756] pbx.c: – Executing [s@ivr-14:12] ExecIf(“SIP/vitel-inbound-0000230c”, “1?Background(custom/complete_main_menu)”) in new stack
[2013-05-09 11:21:01] VERBOSE[25756] file.c: – <SIP/vitel-inbound-0000230c> Playing ‘custom/complete_main_menu.slin’ (language ‘en’)
[2013-05-09 11:21:04] DTMF[25756] channel.c: DTMF begin ‘2’ received on SIP/vitel-inbound-0000230c
[2013-05-09 11:21:04] DTMF[25756] channel.c: DTMF begin ignored ‘2’ on SIP/vitel-inbound-0000230c
[2013-05-09 11:21:04] DTMF[25756] channel.c: DTMF end ‘2’ received on SIP/vitel-inbound-0000230c, duration 100 ms
[2013-05-09 11:21:04] DTMF[25756] channel.c: DTMF end passthrough ‘2’ on SIP/vitel-inbound-0000230c
[2013-05-09 11:21:07] VERBOSE[25756] pbx.c: == CDR updated on SIP/vitel-inbound-0000230c
[2013-05-09 11:21:07] VERBOSE[25756] pbx.c: – Executing [2@ivr-14:1] Macro(“SIP/vitel-inbound-0000230c”, “blkvm-clr,”) in new stack
[2013-05-09 11:21:07] VERBOSE[25756] pbx.c: – Executing [s@macro-blkvm-clr:1] Set(“SIP/vitel-inbound-0000230c”, “SHARED(BLKVM,)=”) in new stack
[2013-05-09 11:21:07] VERBOSE[25756] pbx.c: – Executing [s@macro-blkvm-clr:2] Set(“SIP/vitel-inbound-0000230c”, “GOSUB_RETVAL=”) in new stack
[2013-05-09 11:21:22] VERBOSE[25787] func_timeout.c: – Response timeout set to 5.000
[2013-05-09 11:21:22] VERBOSE[25787] pbx.c: – Executing [s@ivr-14:11] Set(“SIP/vitel-inbound-00002310”, “__IVR_RETVM=”) in new stack
[2013-05-09 11:21:22] VERBOSE[25787] pbx.c: – Executing [s@ivr-14:12] ExecIf(“SIP/vitel-inbound-00002310”, “1?Background(custom/complete_main_menu)”) in new stack
[2013-05-09 11:21:22] VERBOSE[25787] file.c: – <SIP/vitel-inbound-00002310> Playing ‘custom/complete_main_menu.slin’ (language ‘en’)
[2013-05-09 11:21:24] DTMF[25787] channel.c: DTMF begin ‘1’ received on SIP/vitel-inbound-00002310
[2013-05-09 11:21:24] DTMF[25787] channel.c: DTMF begin ignored ‘1’ on SIP/vitel-inbound-00002310
[2013-05-09 11:21:24] DTMF[25787] channel.c: DTMF end ‘1’ received on SIP/vitel-inbound-00002310, duration 100 ms
[2013-05-09 11:21:24] DTMF[25787] channel.c: DTMF end passthrough ‘1’ on SIP/vitel-inbound-00002310
[2013-05-09 11:21:25] DTMF[25787] channel.c: DTMF begin ‘2’ received on SIP/vitel-inbound-00002310
[2013-05-09 11:21:25] DTMF[25787] channel.c: DTMF begin ignored ‘2’ on SIP/vitel-inbound-00002310
[2013-05-09 11:21:25] DTMF[25787] channel.c: DTMF end ‘2’ received on SIP/vitel-inbound-00002310, duration 100 ms
[2013-05-09 11:21:25] DTMF[25787] channel.c: DTMF end passthrough ‘2’ on SIP/vitel-inbound-00002310
[2013-05-09 11:21:25] VERBOSE[25787] pbx.c: == CDR updated on SIP/vitel-inbound-00002310
[2013-05-09 11:21:25] VERBOSE[25787] pbx.c: – Executing [12@ivr-14:1] Macro(“SIP/vitel-inbound-00002310”, “blkvm-clr,”) in new stack
[2013-05-09 11:21:25] VERBOSE[25787] pbx.c: – Executing [s@macro-blkvm-clr:1] Set(“SIP/vitel-inbound-00002310”, “SHARED(BLKVM,)=”) in new stack
[2013-05-09 11:21:25] VERBOSE[25787] pbx.c: – Executing [s@macro-blkvm-clr:2] Set(“SIP/vitel-inbound-00002310”, “GOSUB_RETVAL=”) in new stack
Well it’s plain to see that each of those entries isn’t 12 or 14. Looks like 1, 14, 2, 2, 12. So your DTMF isn’t making it through somewhere. I’d start with your SIP trunk provider and see what they have to say.
Is it possible the timeout is too short? Is 33 your t destination?
I wanted to close out this thread and let everyone know this was resolved.
I had forgotten that the main office number was being hosted (is that the right term) with Comcast and forwarded to a number with Vitelity. When I remember that, I called directly to the number hosted with Vitelity and the DTMF worked fine. So the problem was between Comcast and Vitelity. I contacted both companies and techs at both places were helpful but could not fix it. I asked Vitelity if they could expedite the port, which they did and I have not had any problems since.
Hi there,
I was wondering what you mean by “expedite the port”.
We are facing a similar issue where callers from some carriers (specifically ATT and Sprint) fail to go to the correct extensions.
Thanks
Hi,
I want to implement this. Where can I find this setting to extend my timeout.
Thanks