Hello all, we’re a relatively new office using FreePBX. We’re using the AsteriskNOW distro with FreePBX 6.12.65-32, Asterisk 12.0.2
The issue we’re seeing is when we are connected to an external caller, the external caller can press ## to initiate a transfer, and our FreePBX is interpreting it as an internal transfer and prompts our internal caller for an extension to transfer to.
I replicate this by calling in from my cell to my Polycom VVX 310 on my desk, then pressing ## on my cell. My desk phone gets our music-on-hold, and the cell hears “Transfer” spoken by FreePBX and then a dial tone. I then hang up on my cell.
This problem has prevented us from navigating certain phone trees. Some phone trees will send tones when navigating, and in particular one frequently called phone tree uses ## to connect you to an agent.
My research on this has suggested the Dial Plan options of “Tt” are what enable caller and callee to use ## to initiate transfers. I have found three locations in FreePBX where these options can be set: Two in Advanced Settings, and one in the trunk’s settings. I have removed Tt from the trunk’s dial options and in Advanced Settings’s “Asterisk Outbound Trunk Dial Options.” I have NOT yet removed it from “Asterisk Dial Options” since I fear it will disable transferring internally as well. I am setting up a test PBX in order to experiment with this.
I am not sure what configuration files are useful to post.
I appreciate any assistance on this issue. Thank you.
Here is the log of the test call:
[2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [REDACTED@from-trunk:1] Set("SIP/charter-000054fd", "__FROM_DID=REDACTED") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [REDACTED@from-trunk:2] Gosub("SIP/charter-000054fd", "sub-record-check,s,1(in,REDACTED,dontcare)") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@sub-record-check:1] GotoIf("SIP/charter-000054fd", "0?initialized") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@sub-record-check:2] Set("SIP/charter-000054fd", "__REC_STATUS=INITIALIZED") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@sub-record-check:3] Set("SIP/charter-000054fd", "NOW=1456755389") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@sub-record-check:4] Set("SIP/charter-000054fd", "__DAY=29") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@sub-record-check:5] Set("SIP/charter-000054fd", "__MONTH=02") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@sub-record-check:6] Set("SIP/charter-000054fd", "__YEAR=2016") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@sub-record-check:7] Set("SIP/charter-000054fd", "__TIMESTR=20160229-091629") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@sub-record-check:8] Set("SIP/charter-000054fd", "__FROMEXTEN=unknown") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@sub-record-check:9] Set("SIP/charter-000054fd", "__MON_FMT=wav") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@sub-record-check:10] NoOp("SIP/charter-000054fd", "Recordings initialized") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@sub-record-check:11] ExecIf("SIP/charter-000054fd", "0?Set(ARG3=dontcare)") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@sub-record-check:12] Set("SIP/charter-000054fd", "REC_POLICY_MODE_SAVE=") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@sub-record-check:13] ExecIf("SIP/charter-000054fd", "0?Set(REC_STATUS=NO)") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@sub-record-check:14] GotoIf("SIP/charter-000054fd", "2?checkaction") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@sub-record-check:17] GotoIf("SIP/charter-000054fd", "1?sub-record-check,in,1") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [in@sub-record-check:1] NoOp("SIP/charter-000054fd", "Inbound Recording Check to REDACTED") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [in@sub-record-check:2] Set("SIP/charter-000054fd", "FROMEXTEN=unknown") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [in@sub-record-check:3] ExecIf("SIP/charter-000054fd", "10?Set(FROMEXTEN=REDACTED)") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [in@sub-record-check:4] Gosub("SIP/charter-000054fd", "recordcheck,1(dontcare,in,REDACTED)") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [recordcheck@sub-record-check:1] NoOp("SIP/charter-000054fd", "Starting recording check against dontcare") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [recordcheck@sub-record-check:2] Goto("SIP/charter-000054fd", "dontcare") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [recordcheck@sub-record-check:3] Return("SIP/charter-000054fd", "") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [in@sub-record-check:5] Return("SIP/charter-000054fd", "") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [REDACTED@from-trunk:3] Gosub("SIP/charter-000054fd", "app-blacklist-check,s,1()") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@app-blacklist-check:1] GotoIf("SIP/charter-000054fd", "0?blacklisted") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@app-blacklist-check:2] Set("SIP/charter-000054fd", "CALLED_BLACKLIST=1") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@app-blacklist-check:3] Return("SIP/charter-000054fd", "") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [REDACTED@from-trunk:4] Set("SIP/charter-000054fd", "CDR(did)=REDACTED") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [REDACTED@from-trunk:5] ExecIf("SIP/charter-000054fd", "0 ?Set(CALLERID(name)=REDACTED)") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [REDACTED@from-trunk:6] Set("SIP/charter-000054fd", "CHANNEL(musicclass)=default") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [REDACTED@from-trunk:7] Set("SIP/charter-000054fd", "__MOHCLASS=default") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [REDACTED@from-trunk:8] GotoIf("SIP/charter-000054fd", "0?macro-hangupcall") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [REDACTED@from-trunk:9] Set("SIP/charter-000054fd", "__CALLINGPRES_SV=allowed_not_screened") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [REDACTED@from-trunk:10] Set("SIP/charter-000054fd", "CALLERPRES()=allowed_not_screened") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [REDACTED@from-trunk:11] Goto("SIP/charter-000054fd", "timeconditions,1,1") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [1@timeconditions:1] Set("SIP/charter-000054fd", "DB(TC/1/INUSESTATE)=INUSE") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [1@timeconditions:2] Set("SIP/charter-000054fd", "DB(TC/1/NOT_INUSESTATE)=NOT_INUSE") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [1@timeconditions:3] GotoIfTime("SIP/charter-000054fd", "09:00-16:55,mon-fri,1-31,jan-dec?truestate") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [1@timeconditions:12] GotoIf("SIP/charter-000054fd", "0?falsegoto") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [1@timeconditions:13] ExecIf("SIP/charter-000054fd", "0?Set(DB(TC/1)=)") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [1@timeconditions:14] Set("SIP/charter-000054fd", "DEVICE_STATE(Custom:TC1)=NOT_INUSE") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [1@timeconditions:15] ExecIf("SIP/charter-000054fd", "0?Set(NOT_INUSE)") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [1@timeconditions:16] GotoIf("SIP/charter-000054fd", "1?ivr-1,s,1") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@ivr-1:1] Set("SIP/charter-000054fd", "TIMEOUT_LOOPCOUNT=0") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@ivr-1:2] Set("SIP/charter-000054fd", "INVALID_LOOPCOUNT=0") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@ivr-1:3] Set("SIP/charter-000054fd", "_IVR_CONTEXT_ivr-1=") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@ivr-1:4] Set("SIP/charter-000054fd", "_IVR_CONTEXT=ivr-1") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@ivr-1:5] Set("SIP/charter-000054fd", "__IVR_RETVM=") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@ivr-1:6] GotoIf("SIP/charter-000054fd", "0?skip") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@ivr-1:7] Answer("SIP/charter-000054fd", "") in new stack [2016-02-29 09:16:29] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@ivr-1:8] Wait("SIP/charter-000054fd", "1") in new stack [2016-02-29 09:16:30] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@ivr-1:9] Set("SIP/charter-000054fd", "IVR_MSG=custom/hm_main_greeting_amp") in new stack [2016-02-29 09:16:30] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@ivr-1:10] Set("SIP/charter-000054fd", "TIMEOUT(digit)=3") in new stack [2016-02-29 09:16:30] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@ivr-1:11] ExecIf("SIP/charter-000054fd", "1?Background(custom/hm_main_greeting_amp)") in new stack [2016-02-29 09:16:30] VERBOSE[15378][C-00006fcf] file.c: -- <SIP/charter-000054fd> Playing 'custom/hm_main_greeting_amp.slin' (language 'en') [2016-02-29 09:16:34] DTMF[15378][C-00006fcf] channel.c: DTMF begin '9' received on SIP/charter-000054fd [2016-02-29 09:16:34] DTMF[15378][C-00006fcf] channel.c: DTMF begin ignored '9' on SIP/charter-000054fd [2016-02-29 09:16:35] DTMF[15378][C-00006fcf] channel.c: DTMF end '9' received on SIP/charter-000054fd, duration 85 ms [2016-02-29 09:16:35] DTMF[15378][C-00006fcf] channel.c: DTMF end passthrough '9' on SIP/charter-000054fd [2016-02-29 09:16:35] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [9@ivr-1:1] Goto("SIP/charter-000054fd", "ivr-3,s,1") in new stack [2016-02-29 09:16:35] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@ivr-3:1] Set("SIP/charter-000054fd", "TIMEOUT_LOOPCOUNT=0") in new stack [2016-02-29 09:16:35] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@ivr-3:2] Set("SIP/charter-000054fd", "INVALID_LOOPCOUNT=0") in new stack [2016-02-29 09:16:35] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@ivr-3:3] Set("SIP/charter-000054fd", "_IVR_CONTEXT_ivr-3=ivr-1") in new stack [2016-02-29 09:16:35] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@ivr-3:4] Set("SIP/charter-000054fd", "_IVR_CONTEXT=ivr-3") in new stack [2016-02-29 09:16:35] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@ivr-3:5] Set("SIP/charter-000054fd", "__IVR_RETVM=") in new stack [2016-02-29 09:16:35] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@ivr-3:6] GotoIf("SIP/charter-000054fd", "1?skip") in new stack [2016-02-29 09:16:35] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@ivr-3:9] Set("SIP/charter-000054fd", "IVR_MSG=custom/hm_dialextnow_amp") in new stack [2016-02-29 09:16:35] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@ivr-3:10] Set("SIP/charter-000054fd", "TIMEOUT(digit)=3") in new stack [2016-02-29 09:16:35] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@ivr-3:11] ExecIf("SIP/charter-000054fd", "1?Background(custom/hm_dialextnow_amp)") in new stack [2016-02-29 09:16:35] VERBOSE[15378][C-00006fcf] file.c: -- <SIP/charter-000054fd> Playing 'custom/hm_dialextnow_amp.slin' (language 'en') [2016-02-29 09:16:36] DTMF[15378][C-00006fcf] channel.c: DTMF begin '1' received on SIP/charter-000054fd [2016-02-29 09:16:36] DTMF[15378][C-00006fcf] channel.c: DTMF begin ignored '1' on SIP/charter-000054fd [2016-02-29 09:16:36] DTMF[15378][C-00006fcf] channel.c: DTMF end '1' received on SIP/charter-000054fd, duration 85 ms [2016-02-29 09:16:36] DTMF[15378][C-00006fcf] channel.c: DTMF end passthrough '1' on SIP/charter-000054fd [2016-02-29 09:16:36] DTMF[15378][C-00006fcf] channel.c: DTMF begin '5' received on SIP/charter-000054fd [2016-02-29 09:16:36] DTMF[15378][C-00006fcf] channel.c: DTMF begin ignored '5' on SIP/charter-000054fd [2016-02-29 09:16:36] DTMF[15378][C-00006fcf] channel.c: DTMF end '5' received on SIP/charter-000054fd, duration 80 ms [2016-02-29 09:16:36] DTMF[15378][C-00006fcf] channel.c: DTMF end passthrough '5' on SIP/charter-000054fd [2016-02-29 09:16:36] DTMF[15378][C-00006fcf] channel.c: DTMF begin '2' received on SIP/charter-000054fd [2016-02-29 09:16:36] DTMF[15378][C-00006fcf] channel.c: DTMF begin ignored '2' on SIP/charter-000054fd [2016-02-29 09:16:36] DTMF[15378][C-00006fcf] channel.c: DTMF end '2' received on SIP/charter-000054fd, duration 80 ms [2016-02-29 09:16:36] DTMF[15378][C-00006fcf] channel.c: DTMF end passthrough '2' on SIP/charter-000054fd [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: == CDR updated on SIP/charter-000054fd [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [152@ivr-3:1] Macro("SIP/charter-000054fd", "blkvm-clr,") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-blkvm-clr:1] Set("SIP/charter-000054fd", "SHARED(BLKVM,)=") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-blkvm-clr:2] Set("SIP/charter-000054fd", "GOSUB_RETVAL=") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-blkvm-clr:3] MacroExit("SIP/charter-000054fd", "") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [152@ivr-3:2] Set("SIP/charter-000054fd", "__NODEST=") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [152@ivr-3:3] Goto("SIP/charter-000054fd", "from-did-direct,152,1") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [152@from-did-direct:1] GotoIf("SIP/charter-000054fd", "0?ext-local,152,1") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [152@from-did-direct:2] Macro("SIP/charter-000054fd", "user-callerid,") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-user-callerid:1] Set("SIP/charter-000054fd", "TOUCH_MONITOR=1456755389.91966") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-user-callerid:2] Set("SIP/charter-000054fd", "AMPUSER=REDACTED") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-user-callerid:3] GotoIf("SIP/charter-000054fd", "0?report") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-user-callerid:4] ExecIf("SIP/charter-000054fd", "1?Set(REALCALLERIDNUM=REDACTED)") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-user-callerid:5] Set("SIP/charter-000054fd", "AMPUSER=") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/charter-000054fd", "0?limit") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-user-callerid:7] Set("SIP/charter-000054fd", "AMPUSERCIDNAME=") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-user-callerid:8] GotoIf("SIP/charter-000054fd", "1?report") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-user-callerid:16] GotoIf("SIP/charter-000054fd", "0?continue") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-user-callerid:17] ExecIf("SIP/charter-000054fd", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-user-callerid:18] Set("SIP/charter-000054fd", "__TTL=64") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-user-callerid:19] GotoIf("SIP/charter-000054fd", "1?continue") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-user-callerid:30] Set("SIP/charter-000054fd", "CALLERID(number)=REDACTED") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-user-callerid:31] Set("SIP/charter-000054fd", "CALLERID(name)=REDACTED") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-user-callerid:32] Set("SIP/charter-000054fd", "CDR(cnum)=REDACTED") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-user-callerid:33] Set("SIP/charter-000054fd", "CDR(cnam)=REDACTED") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-user-callerid:34] Set("SIP/charter-000054fd", "CHANNEL(language)=en") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-user-callerid:35] GosubIf("SIP/charter-000054fd", "0?app-check-classofservce,s,1()") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [152@from-did-direct:3] Set("SIP/charter-000054fd", "DIAL_OPTIONS=TtrI") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [152@from-did-direct:4] Set("SIP/charter-000054fd", "CONNECTEDLINE(num,i)=152") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [152@from-did-direct:5] Gosub("SIP/charter-000054fd", "sub-presencestate-display,s,1(152)") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@sub-presencestate-display:1] Goto("SIP/charter-000054fd", "state-not_set,1") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [state-not_set@sub-presencestate-display:1] Set("SIP/charter-000054fd", "PRESENCESTATE_DISPLAY=") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [state-not_set@sub-presencestate-display:2] Return("SIP/charter-000054fd", "") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [152@from-did-direct:6] Set("SIP/charter-000054fd", "CONNECTEDLINE(name)=REDACTED") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [152@from-did-direct:7] Set("SIP/charter-000054fd", "FM_DIALSTATUS=NOT_INUSE") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [152@from-did-direct:8] Set("SIP/charter-000054fd", "__EXTTOCALL=152") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [152@from-did-direct:9] Set("SIP/charter-000054fd", "__PICKUPMARK=152") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [152@from-did-direct:10] Macro("SIP/charter-000054fd", "blkvm-setifempty,") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-blkvm-setifempty:1] GotoIf("SIP/charter-000054fd", "1?init") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-blkvm-setifempty:4] Set("SIP/charter-000054fd", "__BLKVM_CHANNEL=SIP/charter-000054fd") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-blkvm-setifempty:5] Set("SIP/charter-000054fd", "SHARED(BLKVM,SIP/charter-000054fd)=TRUE") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-blkvm-setifempty:6] Set("SIP/charter-000054fd", "GOSUB_RETVAL=TRUE") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-blkvm-setifempty:7] MacroExit("SIP/charter-000054fd", "") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [152@from-did-direct:11] GotoIf("SIP/charter-000054fd", "1?skipov") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [152@from-did-direct:14] Set("SIP/charter-000054fd", "RRNODEST=") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [152@from-did-direct:15] Set("SIP/charter-000054fd", "__NODEST=152") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [152@from-did-direct:16] GosubIf("SIP/charter-000054fd", "0?sub-fmsetcid,s,1()") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [152@from-did-direct:17] Set("SIP/charter-000054fd", "RecordMethod=Group") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [152@from-did-direct:18] Gosub("SIP/charter-000054fd", "sub-record-check,s,1(exten,152,)") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@sub-record-check:1] GotoIf("SIP/charter-000054fd", "10?initialized") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@sub-record-check:10] NoOp("SIP/charter-000054fd", "Recordings initialized") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@sub-record-check:11] ExecIf("SIP/charter-000054fd", "1?Set(ARG3=dontcare)") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@sub-record-check:12] Set("SIP/charter-000054fd", "REC_POLICY_MODE_SAVE=") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@sub-record-check:13] ExecIf("SIP/charter-000054fd", "0?Set(REC_STATUS=NO)") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@sub-record-check:14] GotoIf("SIP/charter-000054fd", "5?checkaction") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@sub-record-check:17] GotoIf("SIP/charter-000054fd", "1?sub-record-check,exten,1") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [exten@sub-record-check:1] NoOp("SIP/charter-000054fd", "Exten Recording Check between REDACTED and 152") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [exten@sub-record-check:2] Set("SIP/charter-000054fd", "CALLTYPE=external") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [exten@sub-record-check:3] ExecIf("SIP/charter-000054fd", "0?Set(CALLTYPE=)") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [exten@sub-record-check:4] Set("SIP/charter-000054fd", "CALLEE=dontcare") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [exten@sub-record-check:5] ExecIf("SIP/charter-000054fd", "0?Set(CALLEE=dontcare)") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [exten@sub-record-check:6] GotoIf("SIP/charter-000054fd", "1?callee") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [exten@sub-record-check:11] Gosub("SIP/charter-000054fd", "recordcheck,1(dontcare,external,152)") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [recordcheck@sub-record-check:1] NoOp("SIP/charter-000054fd", "Starting recording check against dontcare") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [recordcheck@sub-record-check:2] Goto("SIP/charter-000054fd", "dontcare") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [recordcheck@sub-record-check:3] Return("SIP/charter-000054fd", "") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [exten@sub-record-check:12] Return("SIP/charter-000054fd", "") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [152@from-did-direct:19] Set("SIP/charter-000054fd", "RingGroupMethod=ringallv2-prim") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [152@from-did-direct:20] Set("SIP/charter-000054fd", "_FMGRP=152") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [152@from-did-direct:21] GotoIf("SIP/charter-000054fd", "0?doconfirm") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [152@from-did-direct:22] Macro("SIP/charter-000054fd", "dial,28,TtrI,154-155") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-dial:1] GotoIf("SIP/charter-000054fd", "0?dial") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-dial:2] Set("SIP/charter-000054fd", "CHANNEL(musicclass)=default") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-dial:3] AGI("SIP/charter-000054fd", "dialparties.agi") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] res_agi.c: -- <SIP/charter-000054fd>AGI Script dialparties.agi completed, returning 0 [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-dial:7] Dial("SIP/charter-000054fd", "Local/FMPR-152@from-internal&Local/FMGL-154-155@from-internal,28,TtrIM(auto-blkvm)") in new stack [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] app_dial.c: -- Connected line update to SIP/charter-000054fd prevented. [2016-02-29 09:16:36] VERBOSE[15378][C-00006fcf] app_dial.c: -- Connected line update to SIP/charter-000054fd prevented. [2016-02-29 09:16:38] VERBOSE[15378][C-00006fcf] app_dial.c: -- Connected line update to SIP/charter-000054fd prevented. [2016-02-29 09:16:38] VERBOSE[15387][C-00006fcf] pbx.c: -- Executing [s@macro-blkvm-clr:1] Set("SIP/152-000054fe", "SHARED(BLKVM,SIP/charter-000054fd)=") in new stack [2016-02-29 09:16:38] VERBOSE[15378][C-00006fcf] app_dial.c: -- Local/FMPR-152@from-internal-0000880e;1 answered SIP/charter-000054fd [2016-02-29 09:16:38] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-blkvm-clr:1] Set("Local/FMPR-152@from-internal-0000880e;1", "SHARED(BLKVM,SIP/charter-000054fd)=") in new stack [2016-02-29 09:16:41] DTMF[15378][C-00006fcf] channel.c: DTMF begin '#' received on SIP/charter-000054fd [2016-02-29 09:16:41] DTMF[15378][C-00006fcf] channel.c: DTMF begin passthrough '#' on SIP/charter-000054fd [2016-02-29 09:16:41] DTMF[15378][C-00006fcf] channel.c: DTMF end '#' received on SIP/charter-000054fd, duration 80 ms [2016-02-29 09:16:41] DTMF[15378][C-00006fcf] channel.c: DTMF end accepted with begin '#' on SIP/charter-000054fd [2016-02-29 09:16:41] DTMF[15378][C-00006fcf] channel.c: DTMF end '#' detected to have actual duration 69 on the wire, emulation will be triggered on SIP/charter-000054fd [2016-02-29 09:16:41] DTMF[15378][C-00006fcf] channel.c: DTMF end '#' has duration 69 but want minimum 80, emulating on SIP/charter-000054fd [2016-02-29 09:16:42] DTMF[15378][C-00006fcf] channel.c: DTMF end emulation of '#' queued on SIP/charter-000054fd [2016-02-29 09:16:42] DTMF[15378][C-00006fcf] channel.c: DTMF begin '#' received on SIP/charter-000054fd [2016-02-29 09:16:42] DTMF[15378][C-00006fcf] channel.c: DTMF begin passthrough '#' on SIP/charter-000054fd [2016-02-29 09:16:42] DTMF[15378][C-00006fcf] channel.c: DTMF end '#' received on SIP/charter-000054fd, duration 85 ms [2016-02-29 09:16:42] DTMF[15378][C-00006fcf] channel.c: DTMF end accepted with begin '#' on SIP/charter-000054fd [2016-02-29 09:16:42] DTMF[15378][C-00006fcf] channel.c: DTMF end '#' detected to have actual duration 69 on the wire, emulation will be triggered on SIP/charter-000054fd [2016-02-29 09:16:42] DTMF[15378][C-00006fcf] channel.c: DTMF end '#' has duration 69 but want minimum 80, emulating on SIP/charter-000054fd [2016-02-29 09:16:42] DTMF[15378][C-00006fcf] channel.c: DTMF end emulation of '#' queued on SIP/charter-000054fd [2016-02-29 09:16:42] VERBOSE[15378][C-00006fcf] file.c: -- <SIP/charter-000054fd> Playing 'pbx-transfer.ulaw' (language 'en') [2016-02-29 09:16:46] VERBOSE[15378][C-00006fcf] file.c: -- <SIP/charter-000054fd> Playing 'pbx-invalid.ulaw' (language 'en') [2016-02-29 09:16:46] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [h@macro-dial:1] Macro("SIP/charter-000054fd", "hangupcall") in new stack [2016-02-29 09:16:46] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-hangupcall:1] ExecIf("SIP/charter-000054fd", "0?Set(CDR(recordingfile)=.wav)") in new stack [2016-02-29 09:16:46] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-hangupcall:2] GotoIf("SIP/charter-000054fd", "1?theend") in new stack [2016-02-29 09:16:46] VERBOSE[15378][C-00006fcf] pbx.c: -- Executing [s@macro-hangupcall:4] Hangup("SIP/charter-000054fd", "") in new stack [2016-02-29 09:16:46] VERBOSE[15378][C-00006fcf] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/charter-000054fd' in macro 'hangupcall' [2016-02-29 09:16:46] VERBOSE[15378][C-00006fcf] pbx.c: == Spawn extension (macro-dial, h, 1) exited non-zero on 'SIP/charter-000054fd' [2016-02-29 09:16:46] VERBOSE[15378][C-00006fcf] app_macro.c: == Spawn extension (macro-dial, s, 7) exited non-zero on 'SIP/charter-000054fd' in macro 'dial' [2016-02-29 09:16:46] VERBOSE[15378][C-00006fcf] pbx.c: == Spawn extension (from-did-direct, 152, 22) exited non-zero on 'SIP/charter-000054fd'