External forwarding problem with RCF numbers

While awaiting a number port, we have some numbers RCF’d to native TNs. I have a native with an inbound route to a custom extension that calls an external number.

When we call the native it goes through to the external cell as expected. When we call the number that is RCF’d to the native the calls comes in but is then dropped.

The same thing happens if the RCF’d number rings to an on-prem handset that is forwarded to an external number.

Would be great if we can find a fix for this. There is only one trunk and it’s a Comcast PRI running through a Digium G100.

Appreciate any insight/help.

Not without the information from /var/log/asterisk/full. That will elucidate precisely what is happening on the drop.

Thank you. I apologize for not knowing exactly what to look for in here; trying to learn. All of these have the same timestamp, and I think there is a failed forward in there. First portion (32000 character limit in posts):

[2018-01-29 21:25:30] VERBOSE[11000][C-00000034] netsock2.c: Using SIP RTP TOS bits 184
[2018-01-29 21:25:30] VERBOSE[11000][C-00000034] netsock2.c: Using SIP RTP CoS mark 5
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:1] Set(“SIP/DigiumG100-00000088”, “__DIRECTION=INBOUND”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:2] Gosub(“SIP/DigiumG100-00000088”, “sub-record-check,s,1(in,2067172710,never)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:1] GotoIf(“SIP/DigiumG100-00000088”, “0?initialized”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:2] Set(“SIP/DigiumG100-00000088”, “__REC_STATUS=INITIALIZED”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:3] Set(“SIP/DigiumG100-00000088”, “NOW=1517261130”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:4] Set(“SIP/DigiumG100-00000088”, “__DAY=29”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:5] Set(“SIP/DigiumG100-00000088”, “__MONTH=01”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:6] Set(“SIP/DigiumG100-00000088”, “__YEAR=2018”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:7] Set(“SIP/DigiumG100-00000088”, “__TIMESTR=20180129-212530”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:8] Set(“SIP/DigiumG100-00000088”, “__FROMEXTEN=unknown”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:9] Set(“SIP/DigiumG100-00000088”, “__MON_FMT=wav”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:10] NoOp(“SIP/DigiumG100-00000088”, “Recordings initialized”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:11] ExecIf(“SIP/DigiumG100-00000088”, “0?Set(ARG3=dontcare)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:12] Set(“SIP/DigiumG100-00000088”, “REC_POLICY_MODE_SAVE=”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:13] ExecIf(“SIP/DigiumG100-00000088”, “0?Set(REC_STATUS=NO)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:14] GotoIf(“SIP/DigiumG100-00000088”, “2?checkaction”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (sub-record-check,s,17)
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:17] GotoIf(“SIP/DigiumG100-00000088”, “1?sub-record-check,in,1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (sub-record-check,in,1)
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:1] NoOp(“SIP/DigiumG100-00000088”, “Inbound Recording Check to 2067172710”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:2] Set(“SIP/DigiumG100-00000088”, “FROMEXTEN=unknown”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:3] ExecIf(“SIP/DigiumG100-00000088”, “10?Set(FROMEXTEN=4257659999)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:4] Gosub(“SIP/DigiumG100-00000088”, “recordcheck,1(never,in,2067172710)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:1] NoOp(“SIP/DigiumG100-00000088”, “Starting recording check against never”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:2] Goto(“SIP/DigiumG100-00000088”, “never”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (sub-record-check,recordcheck,14)
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:14] Set(“SIP/DigiumG100-00000088”, “__REC_POLICY_MODE=NEVER”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:15] Goto(“SIP/DigiumG100-00000088”, “stoprec”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (sub-record-check,recordcheck,25)
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:25] NoOp(“SIP/DigiumG100-00000088”, “Stopping recording: in, 2067172710”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:26] Set(“SIP/DigiumG100-00000088”, “__REC_STATUS=STOPPED”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:27] System(“SIP/DigiumG100-00000088”, "/var/lib/asterisk/bin/stoprecording.php “SIP/DigiumG100-00000088"”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:28] Return(“SIP/DigiumG100-00000088”, “”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:5] Return(“SIP/DigiumG100-00000088”, “”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:3] Gosub(“SIP/DigiumG100-00000088”, “app-blacklist-check,s,1()”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:1] GotoIf(“SIP/DigiumG100-00000088”, “0?blacklisted”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:2] Set(“SIP/DigiumG100-00000088”, “CALLED_BLACKLIST=1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:3] Return(“SIP/DigiumG100-00000088”, “”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:4] Set(“SIP/DigiumG100-00000088”, “__FROM_DID=2067172710”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:5] Set(“SIP/DigiumG100-00000088”, “CDR(did)=2067172710”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:6] ExecIf(“SIP/DigiumG100-00000088”, “0 ?Set(CALLERID(name)=4257659999)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:7] Set(“SIP/DigiumG100-00000088”, “__MOHCLASS=”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:8] Set(“SIP/DigiumG100-00000088”, “__REVERSAL_REJECT=FALSE”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:9] GotoIf(“SIP/DigiumG100-00000088”, “1?post-reverse-charge”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (from-trunk,2067172710,11)
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:11] NoOp(“SIP/DigiumG100-00000088”, “”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:12] Set(“SIP/DigiumG100-00000088”, “__CALLINGNAMEPRES_SV=allowed_not_screened”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:13] Set(“SIP/DigiumG100-00000088”, “__CALLINGNUMPRES_SV=allowed_not_screened”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:14] Set(“SIP/DigiumG100-00000088”, “CALLERID(name-pres)=allowed_not_screened”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:15] Set(“SIP/DigiumG100-00000088”, “CALLERID(num-pres)=allowed_not_screened”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:16] NoOp(“SIP/DigiumG100-00000088”, “CallerID Entry Point”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:17] Set(“SIP/DigiumG100-00000088”, “__CRM_DIRECTION=INBOUND”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:18] Set(“SIP/DigiumG100-00000088”, “__CRM_SOURCE=4257659999”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:19] Set(“SIP/DigiumG100-00000088”, “__CRM_LINKEDID=1517261130.1043”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:20] ExecIf(“SIP/DigiumG100-00000088”, “1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:21] Goto(“SIP/DigiumG100-00000088”, “from-did-direct,6040,1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (from-did-direct,6040,1)
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:1] GotoIf(“SIP/DigiumG100-00000088”, “1?ext-local,6040,1:followme-check,6040,1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (ext-local,6040,1)
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:1] Set(“SIP/DigiumG100-00000088”, “__RINGTIMER=15”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:2] Macro(“SIP/DigiumG100-00000088”, “exten-vm,novm,6040,0,0,0”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:1] Macro(“SIP/DigiumG100-00000088”, “user-callerid,”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:1] Set(“SIP/DigiumG100-00000088”, “TOUCH_MONITOR=1517261130.1043”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:2] Set(“SIP/DigiumG100-00000088”, “AMPUSER=4257659999”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:3] GotoIf(“SIP/DigiumG100-00000088”, “0?report”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:4] ExecIf(“SIP/DigiumG100-00000088”, “1?Set(REALCALLERIDNUM=4257659999)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:5] Set(“SIP/DigiumG100-00000088”, “AMPUSER=”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:6] GotoIf(“SIP/DigiumG100-00000088”, “0?limit”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:7] Set(“SIP/DigiumG100-00000088”, “AMPUSERCIDNAME=”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:8] ExecIf(“SIP/DigiumG100-00000088”, “0?Set(__CIDMASQUERADING=TRUE)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:9] GotoIf(“SIP/DigiumG100-00000088”, “1?report”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (macro-user-callerid,s,16)
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:16] NoOp(“SIP/DigiumG100-00000088”, “Macro Depth is 2”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:17] GotoIf(“SIP/DigiumG100-00000088”, “1?report2:macroerror”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (macro-user-callerid,s,19)
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:19] GotoIf(“SIP/DigiumG100-00000088”, “0?continue”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:20] Set(“SIP/DigiumG100-00000088”, “__TTL=64”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:21] GotoIf(“SIP/DigiumG100-00000088”, “1?continue”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (macro-user-callerid,s,37)
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:37] Set(“SIP/DigiumG100-00000088”, “CALLERID(number)=4257659999”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:38] Set(“SIP/DigiumG100-00000088”, “CALLERID(name)=CAMPBELL,LOREN”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:39] GotoIf(“SIP/DigiumG100-00000088”, “0?cnum”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:40] Set(“SIP/DigiumG100-00000088”, “CDR(cnam)=CAMPBELL,LOREN”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:41] Set(“SIP/DigiumG100-00000088”, “CDR(cnum)=4257659999”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:42] Set(“SIP/DigiumG100-00000088”, “CHANNEL(language)=en”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:2] Set(“SIP/DigiumG100-00000088”, “RingGroupMethod=none”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:3] Set(“SIP/DigiumG100-00000088”, “__EXTTOCALL=6040”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:4] Set(“SIP/DigiumG100-00000088”, “__PICKUPMARK=6040”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:5] Set(“SIP/DigiumG100-00000088”, “RT=”) in new stack
[2018-01-29 21:25:30] ERROR[27618][C-00000034] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:6] ExecIf(“SIP/DigiumG100-00000088”, “0?Macro(vm,novm,DIRECTDIAL,)”) in new stack
[2018-01-29 21:25:30] ERROR[27618][C-00000034] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2018-01-29 21:25:30] ERROR[27618][C-00000034] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:7] ExecIf(“SIP/DigiumG100-00000088”, “0?MacroExit()”) in new stack
[2018-01-29 21:25:30] ERROR[27618][C-00000034] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2018-01-29 21:25:30] ERROR[27618][C-00000034] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:8] ExecIf(“SIP/DigiumG100-00000088”, “0?Gosub(ext-intercom,*806040,1())”) in new stack
[2018-01-29 21:25:30] ERROR[27618][C-00000034] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2018-01-29 21:25:30] ERROR[27618][C-00000034] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:9] ExecIf(“SIP/DigiumG100-00000088”, “0?MacroExit()”) in new stack
[2018-01-29 21:25:30] ERROR[27618][C-00000034] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2018-01-29 21:25:30] ERROR[27618][C-00000034] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:10] ExecIf(“SIP/DigiumG100-00000088”, “0?ChanSpy(LOCAL/[email protected],q)”) in new stack
[2018-01-29 21:25:30] ERROR[27618][C-00000034] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2018-01-29 21:25:30] ERROR[27618][C-00000034] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:11] ExecIf(“SIP/DigiumG100-00000088”, “0?MacroExit()”) in new stack
[2018-01-29 21:25:30] ERROR[27618][C-00000034] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:12] Gosub(“SIP/DigiumG100-00000088”, “sub-record-check,s,1(exten,6040,dontcare)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:1] GotoIf(“SIP/DigiumG100-00000088”, “10?initialized”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (sub-record-check,s,10)
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:10] NoOp(“SIP/DigiumG100-00000088”, “Recordings initialized”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:11] ExecIf(“SIP/DigiumG100-00000088”, “0?Set(ARG3=dontcare)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:12] Set(“SIP/DigiumG100-00000088”, “REC_POLICY_MODE_SAVE=NEVER”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:13] ExecIf(“SIP/DigiumG100-00000088”, “0?Set(REC_STATUS=NO)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:14] GotoIf(“SIP/DigiumG100-00000088”, “5?checkaction”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (sub-record-check,s,17)
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:17] GotoIf(“SIP/DigiumG100-00000088”, “1?sub-record-check,exten,1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (sub-record-check,exten,1)
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:1] NoOp(“SIP/DigiumG100-00000088”, “Exten Recording Check between 4257659999 and 6040”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:2] Set(“SIP/DigiumG100-00000088”, “CALLTYPE=external”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:3] ExecIf(“SIP/DigiumG100-00000088”, “0?Set(CALLTYPE=)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:4] Set(“SIP/DigiumG100-00000088”, “CALLEE=force”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:5] ExecIf(“SIP/DigiumG100-00000088”, “0?Set(CALLEE=dontcare)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:6] GotoIf(“SIP/DigiumG100-00000088”, “1?callee”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (sub-record-check,exten,11)
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:11] Gosub(“SIP/DigiumG100-00000088”, “recordcheck,1(force,external,6040)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:1] NoOp(“SIP/DigiumG100-00000088”, “Starting recording check against force”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:2] Goto(“SIP/DigiumG100-00000088”, “force”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (sub-record-check,recordcheck,5)
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:5] Set(“SIP/DigiumG100-00000088”, “__REC_POLICY_MODE=FORCE”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:6] GotoIf(“SIP/DigiumG100-00000088”, “1?startrec”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (sub-record-check,recordcheck,16)
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:16] NoOp(“SIP/DigiumG100-00000088”, “Starting recording: external, 6040”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:17] Set(“SIP/DigiumG100-00000088”, “AUDIOHOOK_INHERIT(MixMonitor)=yes”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:18] Set(“SIP/DigiumG100-00000088”, “__CALLFILENAME=external-6040-4257659999-20180129-212530-1517261130.1043”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:19] MixMonitor(“SIP/DigiumG100-00000088”, “2018/01/29/external-6040-4257659999-20180129-212530-1517261130.1043.wav,abi(LOCAL_MIXMON_ID),”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:20] Set(“SIP/DigiumG100-00000088”, “__MIXMON_ID=0x7febf88a6670”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:21] Set(“SIP/DigiumG100-00000088”, “__RECORD_ID=SIP/DigiumG100-00000088”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:22] Set(“SIP/DigiumG100-00000088”, “__REC_STATUS=RECORDING”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:23] Set(“SIP/DigiumG100-00000088”, “CDR(recordingfile)=external-6040-4257659999-20180129-212530-1517261130.1043.wav”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:24] Return(“SIP/DigiumG100-00000088”, “”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:12] Return(“SIP/DigiumG100-00000088”, “”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:13] GotoIf(“SIP/DigiumG100-00000088”, “1?macrodial”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (macro-exten-vm,s,19)
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:19] GosubIf(“SIP/DigiumG100-00000088”, “0?clrheader,1()”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:20] Macro(“SIP/DigiumG100-00000088”, “dial-one,HhTtr,6040”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:1] Set(“SIP/DigiumG100-00000088”, “DEXTEN=6040”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:2] Set(“SIP/DigiumG100-00000088”, “__CRM_SOURCE=4257659999”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:3] ExecIf(“SIP/DigiumG100-00000088”, “0?Set(EXTTOCALL=6040)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:4] Set(“SIP/DigiumG100-00000088”, “DIALSTATUS_CW=”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:5] GosubIf(“SIP/DigiumG100-00000088”, “0?screen,1()”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:6] GosubIf(“SIP/DigiumG100-00000088”, “0?cf,1()”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:7] GotoIf(“SIP/DigiumG100-00000088”, “1?skip1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (macro-dial-one,s,10)
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:10] GotoIf(“SIP/DigiumG100-00000088”, “0?nodial”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:11] GotoIf(“SIP/DigiumG100-00000088”, “0?continue”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:12] Set(“SIP/DigiumG100-00000088”, “EXTHASCW=ENABLED”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:13] GotoIf(“SIP/DigiumG100-00000088”, “0?next1:cwinusebusy”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (macro-dial-one,s,25)
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:25] GotoIf(“SIP/DigiumG100-00000088”, “0?next3:continue”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (macro-dial-one,s,27)
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:27] GotoIf(“SIP/DigiumG100-00000088”, “0?nodial”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:28] GosubIf(“SIP/DigiumG100-00000088”, “1?dstring,1():dlocal,1()”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:1] Set(“SIP/DigiumG100-00000088”, “DSTRING=”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:2] Set(“SIP/DigiumG100-00000088”, “DEVICES=6040”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:3] ExecIf(“SIP/DigiumG100-00000088”, “0?Return()”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:4] ExecIf(“SIP/DigiumG100-00000088”, “0?Set(DEVICES=040)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:5] Set(“SIP/DigiumG100-00000088”, “LOOPCNT=1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:6] Set(“SIP/DigiumG100-00000088”, “ITER=1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:7] Set(“SIP/DigiumG100-00000088”, “THISDIAL=LOCAL/[email protected]”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:8] GosubIf(“SIP/DigiumG100-00000088”, “1?zap2dahdi,1()”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:1] ExecIf(“SIP/DigiumG100-00000088”, “0?Return()”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:2] Set(“SIP/DigiumG100-00000088”, “NEWDIAL=”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:3] Set(“SIP/DigiumG100-00000088”, “LOOPCNT2=1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:4] Set(“SIP/DigiumG100-00000088”, “ITER2=1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:5] Set(“SIP/DigiumG100-00000088”, “THISPART2=LOCAL/[email protected]”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:6] ExecIf(“SIP/DigiumG100-00000088”, “0?Set(THISPART2=DAHDIAL/[email protected])”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:7] Set(“SIP/DigiumG100-00000088”, “NEWDIAL=LOCAL/[email protected]&”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:8] Set(“SIP/DigiumG100-00000088”, “ITER2=2”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:9] GotoIf(“SIP/DigiumG100-00000088”, “0?begin2”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [z[email protected]:10] Set(“SIP/DigiumG100-00000088”, “THISDIAL=LOCAL/[email protected]”) in new stack

Second portion:

[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:11] Return(“SIP/DigiumG100-00000088”, “”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:9] GotoIf(“SIP/DigiumG100-00000088”, “1?docheck”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (macro-dial-one,dstring,14)
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:14] GotoIf(“SIP/DigiumG100-00000088”, “0?skipset”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:15] Set(“SIP/DigiumG100-00000088”, “DSTRING=LOCAL/[email protected]&”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:16] Set(“SIP/DigiumG100-00000088”, “ITER=2”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:17] GotoIf(“SIP/DigiumG100-00000088”, “0?begin”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:18] ExecIf(“SIP/DigiumG100-00000088”, “0?Return()”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:19] Set(“SIP/DigiumG100-00000088”, “DSTRING=LOCAL/[email protected]”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:20] Return(“SIP/DigiumG100-00000088”, “”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:29] GotoIf(“SIP/DigiumG100-00000088”, “0?nodial”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:30] GotoIf(“SIP/DigiumG100-00000088”, “0?skiptrace”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:31] GosubIf(“SIP/DigiumG100-00000088”, “1?ctset,1():ctclear,1()”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:1] Set(“SIP/DigiumG100-00000088”, “DB(CALLTRACE/6040)=4257659999”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:2] Return(“SIP/DigiumG100-00000088”, “”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:32] Set(“SIP/DigiumG100-00000088”, “D_OPTIONS=HhTtr”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:33] NoOp(“SIP/DigiumG100-00000088”, "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:34] ExecIf(“SIP/DigiumG100-00000088”, “0?Set(ALERT_INFO=)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:35] ExecIf(“SIP/DigiumG100-00000088”, “0?Set(ALERT_INFO=)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:36] ExecIf(“SIP/DigiumG100-00000088”, “0?Set(ALERT_INFO=)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:37] ExecIf(“SIP/DigiumG100-00000088”, “0?Set(ALERT_INFO=Normal;volume=)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:38] ExecIf(“SIP/DigiumG100-00000088”, “0?Set(ALERT_INFO=Normal;volume=)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:39] GosubIf(“SIP/DigiumG100-00000088”, “0?func-set-sipheader,s,1(Alert-Info,)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:40] ExecIf(“SIP/DigiumG100-00000088”, “0?Set(CHANNEL(musicclass)=)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:41] GosubIf(“SIP/DigiumG100-00000088”, “0?qwait,1()”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:42] Set(“SIP/DigiumG100-00000088”, “__CWIGNORE=”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:43] Set(“SIP/DigiumG100-00000088”, “__KEEPCID=TRUE”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:44] GotoIf(“SIP/DigiumG100-00000088”, “0?usegoto,1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:45] GotoIf(“SIP/DigiumG100-00000088”, “1?godial”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (macro-dial-one,s,50)
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:50] Macro(“SIP/DigiumG100-00000088”, “dialout-one-predial-hook,”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:1] MacroExit(“SIP/DigiumG100-00000088”, “”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:51] ExecIf(“SIP/DigiumG100-00000088”, “1?Set(D_OPTIONS=HhtrI)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:52] NoOp(“SIP/DigiumG100-00000088”, “”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:53] Dial(“SIP/DigiumG100-00000088”, “LOCAL/[email protected],HhtrIb(func-apply-sipheaders^s^1)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27628][C-00000034] app_mixmonitor.c: Begin MixMonitor Recording SIP/DigiumG100-00000088
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] app_stack.c: Local/[email protected];1 Internal Gosub(func-apply-sipheaders,s,1) start
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:1] ExecIf(“Local/[email protected];1”, “1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:2] NoOp(“Local/[email protected];1”, “Applying SIP Headers to channel”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:3] Set(“Local/[email protected];1”, “SIPHEADERKEYS=”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:4] While(“Local/[email protected];1”, “0”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] app_while.c: Jumping to priority 8
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:9] Return(“Local/[email protected];1”, “”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] app_stack.c: Spawn extension (outbound-allroutes, 6040, 1) exited non-zero on ‘Local/[email protected];1’
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] app_stack.c: Local/[email protected];1 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] app_dial.c: Called LOCAL/[email protected]
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:1] Macro(“Local/[email protected];2”, “user-callerid,LIMIT,EXTERNAL,”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:1] Set(“Local/[email protected];2”, “TOUCH_MONITOR=1517261130.1045”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:2] Set(“Local/[email protected];2”, “AMPUSER=4257659999”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:3] GotoIf(“Local/[email protected];2”, “0?report”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:4] ExecIf(“Local/[email protected];2”, “1?Set(REALCALLERIDNUM=4257659999)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:5] Set(“Local/[email protected];2”, “AMPUSER=”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:6] GotoIf(“Local/[email protected];2”, “0?limit”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:7] Set(“Local/[email protected];2”, “AMPUSERCIDNAME=”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:8] ExecIf(“Local/[email protected];2”, “0?Set(__CIDMASQUERADING=TRUE)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:9] GotoIf(“Local/[email protected];2”, “1?report”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx_builtins.c: Goto (macro-user-callerid,s,16)
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:16] NoOp(“Local/[email protected];2”, “Macro Depth is 1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:17] GotoIf(“Local/[email protected];2”, “1?report2:macroerror”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx_builtins.c: Goto (macro-user-callerid,s,19)
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:19] GotoIf(“Local/[email protected];2”, “1?continue”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx_builtins.c: Goto (macro-user-callerid,s,37)
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:37] Set(“Local/[email protected];2”, “CALLERID(number)=4257659999”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:38] Set(“Local/[email protected];2”, “CALLERID(name)=CAMPBELL,LOREN”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:39] GotoIf(“Local/[email protected];2”, “0?cnum”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:40] Set(“Local/[email protected];2”, “CDR(cnam)=CAMPBELL,LOREN”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:41] Set(“Local/[email protected];2”, “CDR(cnum)=4257659999”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:42] Set(“Local/[email protected];2”, “CHANNEL(language)=en”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:2] Gosub(“Local/[email protected];2”, “sub-record-check,s,1(out,14257368888,dontcare)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:1] GotoIf(“Local/[email protected];2”, “0?initialized”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:2] Set(“Local/[email protected];2”, “__REC_STATUS=INITIALIZED”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:3] Set(“Local/[email protected];2”, “NOW=1517261130”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:4] Set(“Local/[email protected];2”, “__DAY=29”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:5] Set(“Local/[email protected];2”, “__MONTH=01”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:6] Set(“Local/[email protected];2”, “__YEAR=2018”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:7] Set(“Local/[email protected];2”, “__TIMESTR=20180129-212530”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:8] Set(“Local/[email protected];2”, “__FROMEXTEN=4257659999”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:9] Set(“Local/[email protected];2”, “__MON_FMT=wav”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:10] NoOp(“Local/[email protected];2”, “Recordings initialized”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:11] ExecIf(“Local/[email protected];2”, “0?Set(ARG3=dontcare)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:12] Set(“Local/[email protected];2”, “REC_POLICY_MODE_SAVE=FORCE”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:13] ExecIf(“Local/[email protected];2”, “0?Set(REC_STATUS=NO)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:14] GotoIf(“Local/[email protected];2”, “3?checkaction”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx_builtins.c: Goto (sub-record-check,s,17)
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:17] GotoIf(“Local/[email protected];2”, “1?sub-record-check,out,1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx_builtins.c: Goto (sub-record-check,out,1)
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:1] NoOp(“Local/[email protected];2”, “Outbound Recording Check from 4257659999 to 14257368888”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:2] Set(“Local/[email protected];2”, “RECMODE=”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:3] ExecIf(“Local/[email protected];2”, “1?Goto(routewins)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx_builtins.c: Goto (sub-record-check,out,7)
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:7] Gosub(“Local/[email protected];2”, “recordcheck,1(dontcare,out,14257368888)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:1] NoOp(“Local/[email protected];2”, “Starting recording check against dontcare”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:2] Goto(“Local/[email protected];2”, “dontcare”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:3] Return(“Local/[email protected];2”, “”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:8] Return(“Local/[email protected];2”, “”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:3] ExecIf(“Local/[email protected];2”, “0 ?Set(CDR(accountcode)=)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:4] Set(“Local/[email protected];2”, “MOHCLASS=default”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:5] Set(“Local/[email protected];2”, “_NODEST=”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:6] Macro(“Local/[email protected];2”, “dialout-trunk,1,14257368888,off”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:1] Set(“Local/[email protected];2”, “DIAL_TRUNK=1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:2] GosubIf(“Local/[email protected];2”, “0?sub-pincheck,s,1()”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:3] ExecIf(“Local/[email protected];2”, “0?Set(CALLERID(num)=)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:4] GotoIf(“Local/[email protected];2”, “0?disabletrunk,1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:5] Set(“Local/[email protected];2”, “DIAL_NUMBER=14257368888”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:6] Set(“Local/[email protected];2”, “DIAL_TRUNK_OPTIONS=HhTtr”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:7] Set(“Local/[email protected];2”, “OUTBOUND_GROUP=OUT_1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:8] Set(“Local/[email protected];2”, “DIAL_TRUNK_OPTIONS=T”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:9] GotoIf(“Local/[email protected];2”, “0?nomax”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:10] GotoIf(“Local/[email protected];2”, “0?chanfull”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:11] GotoIf(“Local/[email protected];2”, “0?skipoutcid”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:12] Macro(“Local/[email protected];2”, “outbound-callerid,1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:1] NoOp(“Local/[email protected];2”, “4257659999”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:2] NoOp(“Local/[email protected];2”, “TRUE”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:3] NoOp(“Local/[email protected];2”, “off”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:4] ExecIf(“Local/[email protected];2”, “1?Set(CALLERPRES(name-pres)=allowed_not_screened)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:5] ExecIf(“Local/[email protected];2”, “1?Set(CALLERPRES(num-pres)=allowed_not_screened)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:6] ExecIf(“Local/[email protected];2”, “0?Set(REALCALLERIDNUM=4257659999)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:7] GotoIf(“Local/[email protected];2”, “0?normcid”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:8] Set(“Local/[email protected]outbound-allroutes-00000017;2”, “USEROUTCID=4257659999”) in new stack

Last portion. External TNs have been changed for privacy.

[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:9] GotoIf(“Local/[email protected];2”, “0?normcid”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:10] GotoIf(“Local/[email protected];2”, “1?bypass”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx_builtins.c: Goto (macro-outbound-callerid,s,12)
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:12] Set(“Local/[email protected];2”, “EMERGENCYCID=”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:13] Set(“Local/[email protected];2”, “TRUNKOUTCID=4257326000”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:14] GotoIf(“Local/[email protected];2”, “1?trunkcid”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx_builtins.c: Goto (macro-outbound-callerid,s,19)
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:19] ExecIf(“Local/[email protected];2”, “1?Set(CALLERID(all)=4257326000)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:20] ExecIf(“Local/[email protected];2”, “1?Set(CALLERID(all)=4257659999)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:21] ExecIf(“Local/[email protected];2”, “0?Set(CALLERID(all)=)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:22] ExecIf(“Local/[email protected];2”, “0?Set(CALLERPRES(name-pres)=prohib_passed_screen)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:23] ExecIf(“Local/[email protected];2”, “0?Set(CALLERPRES(num-pres)=prohib_passed_screen)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:24] Set(“Local/[email protected];2”, “CDR(outbound_cnum)=4257659999”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:25] Set(“Local/[email protected];2”, “CDR(outbound_cnam)=”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:13] GosubIf(“Local/[email protected];2”, “0?sub-flp-1,s,1()”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:14] Set(“Local/[email protected];2”, “OUTNUM=14257368888”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:15] Set(“Local/[email protected];2”, “custom=SIP/DigiumG100”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:16] ExecIf(“Local/[email protected];2”, “0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)T)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:17] ExecIf(“Local/[email protected];2”, “0?Set(DIAL_TRUNK_OPTIONS=TM(confirm))”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:18] Macro(“Local/[email protected];2”, “dialout-trunk-predial-hook,”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:1] MacroExit(“Local/[email protected];2”, “”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:19] GotoIf(“Local/[email protected];2”, “1?skipcrm”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx_builtins.c: Goto (macro-dialout-trunk,s,25)
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:25] NoOp(“Local/[email protected];2”, “CRM Finished”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:26] GotoIf(“Local/[email protected];2”, “0?bypass,1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:27] ExecIf(“Local/[email protected];2”, “0?Set(CONNECTEDLINE(num,i)=14257368888)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:28] ExecIf(“Local/[email protected];2”, “0?Set(CONNECTEDLINE(name,i)=CID:4257659999)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:29] ExecIf(“Local/[email protected];2”, “0?Set(CONNECTEDLINE(name,i)=CID:(Hidden)4257659999)”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:30] GotoIf(“Local/[email protected];2”, “0?customtrunk”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:31] Dial(“Local/[email protected];2”, “SIP/DigiumG100/14257368888,300,T”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] netsock2.c: Using SIP RTP TOS bits 184
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] netsock2.c: Using SIP RTP CoS mark 5
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] app_dial.c: Called SIP/DigiumG100/14257368888
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] app_dial.c: Everyone is busy/congested at this time (1:0/0/1)
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:32] NoOp(“Local/[email protected];2”, “Dial failed for some reason with DIALSTATUS = CHANUNAVAIL and HANGUPCAUSE = 1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:33] GotoIf(“Local/[email protected];2”, “0?continue,1:s-CHANUNAVAIL,1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx_builtins.c: Goto (macro-dialout-trunk,s-CHANUNAVAIL,1)
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:1] Set(“Local/[email protected];2”, “RC=1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:2] Goto(“Local/[email protected];2”, “1,1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx_builtins.c: Goto (macro-dialout-trunk,1,1)
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:1] Goto(“Local/[email protected];2”, “s-INVALIDNMBR,1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx_builtins.c: Goto (macro-dialout-trunk,s-INVALIDNMBR,1)
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:1] NoOp(“Local/[email protected];2”, “Dial failed due to trunk reporting Address Incomplete - giving up”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:2] Progress(“Local/[email protected];2”, “”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:3] Playback(“Local/[email protected];2”, “ss-noservice,noanswer”) in new stack
[2018-01-29 21:25:30] VERBOSE[27618][C-00000034] app_dial.c: Local/[email protected];1 is making progress passing it to SIP/DigiumG100-00000088
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] file.c: <Local/[email protected];2> Playing ‘ss-noservice.ulaw’ (language ‘en’)
[2018-01-29 21:25:35] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:4] Busy(“Local/[email protected];2”, “20”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] app_dial.c: Local/[email protected];1 is busy
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] app_stack.c: Local/[email protected];1 Internal Gosub(crm-hangup,s,1) start
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:1] NoOp(“Local/[email protected];1”, “Sending Hangup to CRM”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:2] NoOp(“Local/[email protected];1”, “HANGUP CAUSE: 0”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:3] ExecIf(“Local/[email protected];1”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:4] NoOp(“Local/[email protected];1”, “MASTER CHANNEL: 1517261130.1044 = 1517261130.1043”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:5] GotoIf(“Local/[email protected]0017;1”, “1?return”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (crm-hangup,s,8)
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:8] Return(“Local/[email protected];1”, “”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] app_stack.c: Spawn extension (outbound-allroutes, 6040, 1) exited non-zero on ‘Local/[email protected];1’
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] app_stack.c: Local/[email protected];1 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] app_dial.c: Everyone is busy/congested at this time (1:1/0/0)
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:54] ExecIf(“SIP/DigiumG100-00000088”, “0?MacroExit()”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:55] ExecIf(“SIP/DigiumG100-00000088”, “0?Set(DIALSTATUS=)”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:56] GosubIf(“SIP/DigiumG100-00000088”, “0?s-BUSY,1()”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:57] MacroExit(“SIP/DigiumG100-00000088”, “”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:21] Set(“SIP/DigiumG100-00000088”, “SV_DIALSTATUS=BUSY”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:22] GosubIf(“SIP/DigiumG100-00000088”, “0?docfu,1()”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:23] GosubIf(“SIP/DigiumG100-00000088”, “0?docfb,1()”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:24] Set(“SIP/DigiumG100-00000088”, “DIALSTATUS=BUSY”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:25] ExecIf(“SIP/DigiumG100-00000088”, “0?MacroExit()”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:26] GotoIf(“SIP/DigiumG100-00000088”, “1?s-BUSY,1”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (macro-exten-vm,s-BUSY,1)
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:1] GotoIf(“SIP/DigiumG100-00000088”, “0?exit,1”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:2] PlayTones(“SIP/DigiumG100-00000088”, “busy”) in new stack
[2018-01-29 21:25:35] VERBOSE[27629][C-00000034] app_macro.c: Spawn extension (macro-dialout-trunk, s-INVALIDNMBR, 4) exited non-zero on ‘Local/[email protected];2’ in macro ‘dialout-trunk’
[2018-01-29 21:25:35] VERBOSE[27629][C-00000034] pbx.c: Spawn extension (outbound-allroutes, 14257368888, 6) exited non-zero on ‘Local/[email protected];2’
[2018-01-29 21:25:35] WARNING[27618][C-00000034] translate.c: no samples for ulawtolin
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:3] Busy(“SIP/DigiumG100-00000088”, “20”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] app_macro.c: Spawn extension (macro-exten-vm, s-BUSY, 3) exited non-zero on ‘SIP/DigiumG100-00000088’ in macro ‘exten-vm’
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Spawn extension (ext-local, 6040, 2) exited non-zero on ‘SIP/DigiumG100-00000088’
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:1] Macro(“SIP/DigiumG100-00000088”, “hangupcall,”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:1] GotoIf(“SIP/DigiumG100-00000088”, “1?theend”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:3] ExecIf(“SIP/DigiumG100-00000088”, “0?Set(CDR(recordingfile)=)”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:4] NoOp(“SIP/DigiumG100-00000088”, " monior file= /var/spool/asterisk/monitor/2018/01/29/external-6040-4257659999-20180129-212530-1517261130.1043.wav") in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:5] AGI(“SIP/DigiumG100-00000088”, “attendedtransfer-rec-restart.php,/var/spool/asterisk/monitor/2018/01/29/external-6040-4257659999-20180129-212530-1517261130.1043.wav”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/attendedtransfer-rec-restart.php
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] res_agi.c: <SIP/DigiumG100-00000088>AGI Script attendedtransfer-rec-restart.php completed, returning 0
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:6] Hangup(“SIP/DigiumG100-00000088”, “”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] app_macro.c: Spawn extension (macro-hangupcall, s, 6) exited non-zero on ‘SIP/DigiumG100-00000088’ in macro ‘hangupcall’
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Spawn extension (ext-local, h, 1) exited non-zero on ‘SIP/DigiumG100-00000088’
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] app_stack.c: SIP/DigiumG100-00000088 Internal Gosub(crm-hangup,s,1) start
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:1] NoOp(“SIP/DigiumG100-00000088”, “Sending Hangup to CRM”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:2] NoOp(“SIP/DigiumG100-00000088”, “HANGUP CAUSE: 17”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:3] ExecIf(“SIP/DigiumG100-00000088”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:4] NoOp(“SIP/DigiumG100-00000088”, “MASTER CHANNEL: 1517261130.1043 = 1517261130.1043”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:5] GotoIf(“SIP/DigiumG100-00000088”, “0?return”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:6] Set(“SIP/DigiumG100-00000088”, “__CRM_HANGUP=1”) in new stack
[2018-01-29 21:25:35] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:7] AGI(“SIP/DigiumG100-00000088”, “sangomacrm.agi”) in new stack
[2018-01-29 21:25:36] VERBOSE[27618][C-00000034] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2018-01-29 21:25:36] VERBOSE[27618][C-00000034] res_agi.c: <SIP/DigiumG100-00000088>AGI Script sangomacrm.agi completed, returning 0
[2018-01-29 21:25:36] VERBOSE[27618][C-00000034] pbx.c: Executing [[email protected]:8] Return(“SIP/DigiumG100-00000088”, “”) in new stack
[2018-01-29 21:25:36] VERBOSE[27618][C-00000034] app_stack.c: Spawn extension (ext-local, h, 1) exited non-zero on ‘SIP/DigiumG100-00000088’
[2018-01-29 21:25:36] VERBOSE[27618][C-00000034] app_stack.c: SIP/DigiumG100-00000088 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2018-01-29 21:25:36] VERBOSE[27628][C-00000034] app_mixmonitor.c: MixMonitor close filestream (mixed)
[2018-01-29 21:25:36] VERBOSE[27628][C-00000034] app_mixmonitor.c: End MixMonitor Recording SIP/DigiumG100-00000088

Did you see that one?

I was still parsing through. Excuse my ignorance, but even though you’ve pointed it out, I cannot see why it’s failing; there is a valid TN in there…and if we dial the native TN that triggers this forward, it works. It’s only failing when the non-native TN RCF’d to the functioning native is called.

Also seeing this:

[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] app_dial.c: Called SIP/DigiumG100/14257368888
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] app_dial.c: Everyone is busy/congested at this time (1:0/0/1)
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:32] NoOp(“Local/[email protected];2”, “Dial failed for some reason with DIALSTATUS = CHANUNAVAIL and HANGUPCAUSE = 1”) in new stack
[2018-01-29 21:25:30] VERBOSE[27629][C-00000034] pbx.c: Executing [[email protected]:33] GotoIf(“Local/[email protected];2”, “0?continue,1:s-CHANUNAVAIL,1”) in new stack

Still doesn’t make sense to me; architecture is PRI to Digium G100 to FreePBX via SIP trunk. Sorry if I’m missing something obvious here, I just can’t get my head around why it errors only when the RCF’d number is called.

Is it possible that you only paid for one RCF path but are trying to use it twice?

Asterisk has a problem with forwarding forwarded calls - it’s hard coded in such a way to make that a problem. While this doesn’t sound like that’s the case, it’s certainly something to look at. Since your RCF is outside of Asterisk, the call forward loop detection shouldn’t be getting invoked, but you never know.

The error message from your provider says that the Dial failed due to trunk reporting Address Incomplete and that your provider is giving up on the call. This error can be used when people are using foreign Caller IDs. Does your provider care about your outbound caller ID settings?

I don’t think so; the outbound calls should not be on the RCF path; the losing provider is simply remote forwarding the calls to new native numbers (pending port), and the outbound/forwarded calls should just go out directly on the PRI.

At least that’s what I think. The custom dial string on the extension that should ring the external number is: LOCAL/[email protected]

Maybe it needs to be modified to use just the SIP trunk that lands on the PRI? I just don’t see how FreePBX would know to do anything else; it only has one outbound route.

“Does your provider care about your outbound caller ID settings?”

No, they do not. They accept what we send. That said, I can try setting the outbound CallerID on the custom extension to a native TN and see what happens. Can’t get my head around how that would be different than a call to the native routed to that extension/external number, which works.

Same result: Call rings once, then plays a busy signal.

From your logs

so calling 14257368888 on DigiumG100 is returning a “1” which means that number is unallocated on outbound-allroutes, so check your dialpatterns against your preferred outbound trunk routing perhaps you need to strip the initial 1 ? or you might need to add a route that can handle it after the PRI fails

Thanks. I understand what you are saying, but don’t see how it explains why the route works if the native TN that routes to the custom extension is dialed.

Works:
Native TN -> custom extension -> external number

Fails:
RCF number ->. native TN -> custom extension -> external number

Same native TN and extension. Can also pick up a handset and dial the external number as its entered in the custom extension and the call goes through.

you would have to post that call process, obviously you can’t call 14257368888 on your programmed outbound routes, perhaps your “custom extension” context can, we have no knowledge of what that is from you yet, please post it.

Note: Uploading file with a TGZ extension, as txt isn’t accepted. It’s a text file. It’s over 160,000 characters and the post limit is 32,000.
RCF Issue.tgz (164.5 KB)

Three calls in here. All from 4257659999.
First call is to the non-native RCF’d to 2067177777. Call fails, one ring then busy.
Second call is to the native TN, 2067177777 with an inbound route to the custom ext. Call goes to custom extension and then out to 2062628888, successful
Third call is to another native TN, 2067176666, with an inbound route to the custom ext. Call goes to custom extension and then out to 2062628888, successful.

More info: If I remove the leading 1 from the custom dial setting for the extension, calls to the RCF’d number go through. So there is something about the leading 1 that somehow only affects externally routed RCF’d calls.

LOCAL/[email protected]
Call to RCF number fails.
Call to native number works.

LOCAL/[email protected]
Call to RCF’d number works.
Call to native number works.

that would be a QED, no? don’t do that. . to verify, post a call that did go through.

There is an example of a successful call in the log I posted.

I’m starting to think this is an arcane bug.