Can't send external call to external number (via custom extension)

Hi all!

I have a ustom extension with this dial command, that works when the extension is called from any extension:

Local/XXXXXXXX@outbound-allroutes

But, if I send a call directly to this extension, the call finishes. I get a chunnanavailable error.

Also, when a I try to do a blind transfer it doesn’t work, but on attended transfers it works ok.

Followme doesn’t work neither, when I use an external number with a pound (#)

Any help please?

Thanks!

Call trace would help:
https://wiki.freepbx.org/display/SUP/Providing+Great+Debug#ProvidingGreatDebug-AsteriskLogs

My guess is your provider is blocking outbound calls with foreign CallerID.

This is what I get:

999999999 —> DID
666666666 —> Origin
655555555 —>Destination on transfer

Code in two parts…

[2018-05-18 16:07:22] VERBOSE[2794][C-00003d5a] netsock2.c:   == Using SIP RTP TOS bits 184
[2018-05-18 16:07:22] VERBOSE[2794][C-00003d5a] netsock2.c:   == Using SIP RTP CoS mark 5
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [999999999@from-trunk-sip-MY_PROVIDER:1] Set("SIP/MY_PROVIDER-00008bb0", "GROUP()=OUT_6") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [999999999@from-trunk-sip-MY_PROVIDER:2] Goto("SIP/MY_PROVIDER-00008bb0", "from-trunk,999999999,1") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (from-trunk,999999999,1)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [999999999@from-trunk:1] Set("SIP/MY_PROVIDER-00008bb0", "__DIRECTION=INBOUND") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [999999999@from-trunk:2] Gosub("SIP/MY_PROVIDER-00008bb0", "sub-record-check,s,1(in,999999999,dontcare)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@sub-record-check:1] GotoIf("SIP/MY_PROVIDER-00008bb0", "0?initialized") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@sub-record-check:2] Set("SIP/MY_PROVIDER-00008bb0", "__REC_STATUS=INITIALIZED") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@sub-record-check:3] Set("SIP/MY_PROVIDER-00008bb0", "NOW=1526652442") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@sub-record-check:4] Set("SIP/MY_PROVIDER-00008bb0", "__DAY=18") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@sub-record-check:5] Set("SIP/MY_PROVIDER-00008bb0", "__MONTH=05") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@sub-record-check:6] Set("SIP/MY_PROVIDER-00008bb0", "__YEAR=2018") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@sub-record-check:7] Set("SIP/MY_PROVIDER-00008bb0", "__TIMESTR=20180518-160722") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@sub-record-check:8] Set("SIP/MY_PROVIDER-00008bb0", "__FROMEXTEN=unknown") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@sub-record-check:9] Set("SIP/MY_PROVIDER-00008bb0", "__MON_FMT=wav") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@sub-record-check:10] NoOp("SIP/MY_PROVIDER-00008bb0", "Recordings initialized") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@sub-record-check:11] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Set(ARG3=dontcare)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@sub-record-check:12] Set("SIP/MY_PROVIDER-00008bb0", "REC_POLICY_MODE_SAVE=") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@sub-record-check:13] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Set(REC_STATUS=NO)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@sub-record-check:14] GotoIf("SIP/MY_PROVIDER-00008bb0", "2?checkaction") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (sub-record-check,s,17)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@sub-record-check:17] GotoIf("SIP/MY_PROVIDER-00008bb0", "1?sub-record-check,in,1") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (sub-record-check,in,1)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [in@sub-record-check:1] NoOp("SIP/MY_PROVIDER-00008bb0", "Inbound Recording Check to 999999999") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [in@sub-record-check:2] Set("SIP/MY_PROVIDER-00008bb0", "FROMEXTEN=unknown") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [in@sub-record-check:3] ExecIf("SIP/MY_PROVIDER-00008bb0", "9?Set(FROMEXTEN=666666666)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [in@sub-record-check:4] Gosub("SIP/MY_PROVIDER-00008bb0", "recordcheck,1(dontcare,in,999999999)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [recordcheck@sub-record-check:1] NoOp("SIP/MY_PROVIDER-00008bb0", "Starting recording check against dontcare") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [recordcheck@sub-record-check:2] Goto("SIP/MY_PROVIDER-00008bb0", "dontcare") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (sub-record-check,recordcheck,3)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [recordcheck@sub-record-check:3] Return("SIP/MY_PROVIDER-00008bb0", "") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [in@sub-record-check:5] Return("SIP/MY_PROVIDER-00008bb0", "") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [999999999@from-trunk:3] Gosub("SIP/MY_PROVIDER-00008bb0", "app-blacklist-check,s,1()") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@app-blacklist-check:1] GotoIf("SIP/MY_PROVIDER-00008bb0", "0?blacklisted") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@app-blacklist-check:2] Set("SIP/MY_PROVIDER-00008bb0", "CALLED_BLACKLIST=1") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@app-blacklist-check:3] Return("SIP/MY_PROVIDER-00008bb0", "") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [999999999@from-trunk:4] Set("SIP/MY_PROVIDER-00008bb0", "__FROM_DID=999999999") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [999999999@from-trunk:5] Set("SIP/MY_PROVIDER-00008bb0", "CDR(did)=999999999") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [999999999@from-trunk:6] ExecIf("SIP/MY_PROVIDER-00008bb0", "1 ?Set(CALLERID(name)=666666666)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [999999999@from-trunk:7] Set("SIP/MY_PROVIDER-00008bb0", "__MOHCLASS=") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [999999999@from-trunk:8] Set("SIP/MY_PROVIDER-00008bb0", "__REVERSAL_REJECT=FALSE") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [999999999@from-trunk:9] GotoIf("SIP/MY_PROVIDER-00008bb0", "1?post-reverse-charge") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (from-trunk,999999999,11)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [999999999@from-trunk:11] NoOp("SIP/MY_PROVIDER-00008bb0", "") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [999999999@from-trunk:12] Set("SIP/MY_PROVIDER-00008bb0", "__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [999999999@from-trunk:13] Set("SIP/MY_PROVIDER-00008bb0", "__CALLINGNUMPRES_SV=allowed_not_screened") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [999999999@from-trunk:14] Set("SIP/MY_PROVIDER-00008bb0", "CALLERID(name-pres)=allowed_not_screened") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [999999999@from-trunk:15] Set("SIP/MY_PROVIDER-00008bb0", "CALLERID(num-pres)=allowed_not_screened") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [999999999@from-trunk:16] NoOp("SIP/MY_PROVIDER-00008bb0", "CallerID Entry Point") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [999999999@from-trunk:17] Macro("SIP/MY_PROVIDER-00008bb0", "prepend-cid,OFFICE1") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-prepend-cid:1] GotoIf("SIP/MY_PROVIDER-00008bb0", "1?REPCID") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (macro-prepend-cid,s,5)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-prepend-cid:5] Set("SIP/MY_PROVIDER-00008bb0", "_RGPREFIX=OFFICE1") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-prepend-cid:6] Set("SIP/MY_PROVIDER-00008bb0", "CALLERID(name)=OFFICE1666666666") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [999999999@from-trunk:18] Set("SIP/MY_PROVIDER-00008bb0", "__CRM_DIRECTION=INBOUND") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [999999999@from-trunk:19] Set("SIP/MY_PROVIDER-00008bb0", "__CRM_SOURCE=666666666") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [999999999@from-trunk:20] Set("SIP/MY_PROVIDER-00008bb0", "__CRM_LINKEDID=1526652442.37803") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [999999999@from-trunk:21] ExecIf("SIP/MY_PROVIDER-00008bb0", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [999999999@from-trunk:22] Goto("SIP/MY_PROVIDER-00008bb0", "from-did-direct,405,1") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (from-did-direct,405,1)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [405@from-did-direct:1] GotoIf("SIP/MY_PROVIDER-00008bb0", "1?ext-local,405,1:followme-check,405,1") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (ext-local,405,1)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [405@ext-local:1] Set("SIP/MY_PROVIDER-00008bb0", "__RINGTIMER=15") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [405@ext-local:2] Macro("SIP/MY_PROVIDER-00008bb0", "exten-vm,novm,405,0,0,0") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-exten-vm:1] Macro("SIP/MY_PROVIDER-00008bb0", "user-callerid,") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-user-callerid:1] Set("SIP/MY_PROVIDER-00008bb0", "TOUCH_MONITOR=1526652442.37803") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-user-callerid:2] Set("SIP/MY_PROVIDER-00008bb0", "AMPUSER=666666666") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-user-callerid:3] GotoIf("SIP/MY_PROVIDER-00008bb0", "0?report") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-user-callerid:4] ExecIf("SIP/MY_PROVIDER-00008bb0", "1?Set(REALCALLERIDNUM=666666666)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-user-callerid:5] Set("SIP/MY_PROVIDER-00008bb0", "AMPUSER=") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-user-callerid:6] GotoIf("SIP/MY_PROVIDER-00008bb0", "0?limit") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-user-callerid:7] Set("SIP/MY_PROVIDER-00008bb0", "AMPUSERCIDNAME=") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-user-callerid:8] GotoIf("SIP/MY_PROVIDER-00008bb0", "1?report") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (macro-user-callerid,s,15)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-user-callerid:15] NoOp("SIP/MY_PROVIDER-00008bb0", "Macro Depth is 2") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-user-callerid:16] GotoIf("SIP/MY_PROVIDER-00008bb0", "1?report2:macroerror") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (macro-user-callerid,s,18)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-user-callerid:18] GotoIf("SIP/MY_PROVIDER-00008bb0", "0?continue") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-user-callerid:19] Set("SIP/MY_PROVIDER-00008bb0", "__TTL=64") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-user-callerid:20] GotoIf("SIP/MY_PROVIDER-00008bb0", "1?continue") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (macro-user-callerid,s,36)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-user-callerid:36] Set("SIP/MY_PROVIDER-00008bb0", "CALLERID(number)=666666666") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-user-callerid:37] Set("SIP/MY_PROVIDER-00008bb0", "CALLERID(name)=OFFICE1666666666") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-user-callerid:38] GotoIf("SIP/MY_PROVIDER-00008bb0", "0?cnum") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-user-callerid:39] Set("SIP/MY_PROVIDER-00008bb0", "CDR(cnam)=OFFICE1666666666") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-user-callerid:40] Set("SIP/MY_PROVIDER-00008bb0", "CDR(cnum)=666666666") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-user-callerid:41] Set("SIP/MY_PROVIDER-00008bb0", "CHANNEL(language)=es_ES") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-exten-vm:2] Set("SIP/MY_PROVIDER-00008bb0", "RingGroupMethod=none") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-exten-vm:3] Set("SIP/MY_PROVIDER-00008bb0", "__EXTTOCALL=405") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-exten-vm:4] Set("SIP/MY_PROVIDER-00008bb0", "__PICKUPMARK=405") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-exten-vm:5] Set("SIP/MY_PROVIDER-00008bb0", "RT=") in new stack
[2018-05-18 16:07:22] ERROR[31903][C-00003d5a] pbx.c: Function PJSIP_HEADER not registered
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-exten-vm:6] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Macro(vm,novm,DIRECTDIAL,)") in new stack
[2018-05-18 16:07:22] ERROR[31903][C-00003d5a] pbx.c: Function PJSIP_HEADER not registered
[2018-05-18 16:07:22] ERROR[31903][C-00003d5a] pbx.c: Function PJSIP_HEADER not registered
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-exten-vm:7] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?MacroExit()") in new stack
[2018-05-18 16:07:22] ERROR[31903][C-00003d5a] pbx.c: Function PJSIP_HEADER not registered
[2018-05-18 16:07:22] ERROR[31903][C-00003d5a] pbx.c: Function PJSIP_HEADER not registered
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-exten-vm:8] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Gosub(ext-intercom,*80405,1())") in new stack
[2018-05-18 16:07:22] ERROR[31903][C-00003d5a] pbx.c: Function PJSIP_HEADER not registered
[2018-05-18 16:07:22] ERROR[31903][C-00003d5a] pbx.c: Function PJSIP_HEADER not registered
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-exten-vm:9] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?MacroExit()") in new stack
[2018-05-18 16:07:22] ERROR[31903][C-00003d5a] pbx.c: Function PJSIP_HEADER not registered
[2018-05-18 16:07:22] ERROR[31903][C-00003d5a] pbx.c: Function PJSIP_HEADER not registered
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-exten-vm:10] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?ChanSpy(SIP/405,q)") in new stack
[2018-05-18 16:07:22] ERROR[31903][C-00003d5a] pbx.c: Function PJSIP_HEADER not registered
[2018-05-18 16:07:22] ERROR[31903][C-00003d5a] pbx.c: Function PJSIP_HEADER not registered
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-exten-vm:11] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?MacroExit()") in new stack
[2018-05-18 16:07:22] ERROR[31903][C-00003d5a] pbx.c: Function PJSIP_HEADER not registered
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-exten-vm:12] Gosub("SIP/MY_PROVIDER-00008bb0", "sub-record-check,s,1(exten,405,dontcare)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@sub-record-check:1] GotoIf("SIP/MY_PROVIDER-00008bb0", "9?initialized") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (sub-record-check,s,10)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@sub-record-check:10] NoOp("SIP/MY_PROVIDER-00008bb0", "Recordings initialized") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@sub-record-check:11] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Set(ARG3=dontcare)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@sub-record-check:12] Set("SIP/MY_PROVIDER-00008bb0", "REC_POLICY_MODE_SAVE=") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@sub-record-check:13] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Set(REC_STATUS=NO)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@sub-record-check:14] GotoIf("SIP/MY_PROVIDER-00008bb0", "5?checkaction") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (sub-record-check,s,17)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@sub-record-check:17] GotoIf("SIP/MY_PROVIDER-00008bb0", "1?sub-record-check,exten,1") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (sub-record-check,exten,1)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [exten@sub-record-check:1] NoOp("SIP/MY_PROVIDER-00008bb0", "Exten Recording Check between 666666666 and 405") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [exten@sub-record-check:2] Set("SIP/MY_PROVIDER-00008bb0", "CALLTYPE=external") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [exten@sub-record-check:3] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Set(CALLTYPE=)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [exten@sub-record-check:4] Set("SIP/MY_PROVIDER-00008bb0", "CALLEE=dontcare") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [exten@sub-record-check:5] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Set(CALLEE=dontcare)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [exten@sub-record-check:6] GotoIf("SIP/MY_PROVIDER-00008bb0", "1?callee") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (sub-record-check,exten,11)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [exten@sub-record-check:11] Gosub("SIP/MY_PROVIDER-00008bb0", "recordcheck,1(dontcare,external,405)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [recordcheck@sub-record-check:1] NoOp("SIP/MY_PROVIDER-00008bb0", "Starting recording check against dontcare") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [recordcheck@sub-record-check:2] Goto("SIP/MY_PROVIDER-00008bb0", "dontcare") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (sub-record-check,recordcheck,3)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [recordcheck@sub-record-check:3] Return("SIP/MY_PROVIDER-00008bb0", "") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [exten@sub-record-check:12] Return("SIP/MY_PROVIDER-00008bb0", "") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-exten-vm:13] GotoIf("SIP/MY_PROVIDER-00008bb0", "1?macrodial") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (macro-exten-vm,s,19)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-exten-vm:19] GosubIf("SIP/MY_PROVIDER-00008bb0", "0?clrheader,1()") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-exten-vm:20] Macro("SIP/MY_PROVIDER-00008bb0", "dial-one,,Ttr,405") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:1] Set("SIP/MY_PROVIDER-00008bb0", "DEXTEN=405") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:2] Set("SIP/MY_PROVIDER-00008bb0", "__CRM_SOURCE=666666666") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:3] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Set(__EXTTOCALL=405)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:4] Set("SIP/MY_PROVIDER-00008bb0", "DIALSTATUS_CW=") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:5] GosubIf("SIP/MY_PROVIDER-00008bb0", "0?screen,1()") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:6] GosubIf("SIP/MY_PROVIDER-00008bb0", "0?cf,1()") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:7] GotoIf("SIP/MY_PROVIDER-00008bb0", "1?skip1") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (macro-dial-one,s,10)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:10] GotoIf("SIP/MY_PROVIDER-00008bb0", "0?nodial") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:11] GotoIf("SIP/MY_PROVIDER-00008bb0", "0?continue") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:12] Set("SIP/MY_PROVIDER-00008bb0", "EXTHASCW=ENABLED") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:13] GotoIf("SIP/MY_PROVIDER-00008bb0", "0?next1:cwinusebusy") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (macro-dial-one,s,25)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:25] GotoIf("SIP/MY_PROVIDER-00008bb0", "0?next3:continue") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (macro-dial-one,s,27)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:27] GotoIf("SIP/MY_PROVIDER-00008bb0", "0?nodial") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:28] GosubIf("SIP/MY_PROVIDER-00008bb0", "1?dstring,1():dlocal,1()") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [dstring@macro-dial-one:1] Set("SIP/MY_PROVIDER-00008bb0", "DSTRING=") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [dstring@macro-dial-one:2] Set("SIP/MY_PROVIDER-00008bb0", "DEVICES=99405&405") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [dstring@macro-dial-one:3] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Return()") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [dstring@macro-dial-one:4] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Set(DEVICES=9405&405)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [dstring@macro-dial-one:5] Set("SIP/MY_PROVIDER-00008bb0", "LOOPCNT=2") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [dstring@macro-dial-one:6] Set("SIP/MY_PROVIDER-00008bb0", "ITER=1") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [dstring@macro-dial-one:7] Set("SIP/MY_PROVIDER-00008bb0", "THISDIAL=SIP/99405") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [dstring@macro-dial-one:8] GosubIf("SIP/MY_PROVIDER-00008bb0", "1?zap2dahdi,1()") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:1] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Return()") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:2] Set("SIP/MY_PROVIDER-00008bb0", "NEWDIAL=") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:3] Set("SIP/MY_PROVIDER-00008bb0", "LOOPCNT2=1") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:4] Set("SIP/MY_PROVIDER-00008bb0", "ITER2=1") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:5] Set("SIP/MY_PROVIDER-00008bb0", "THISPART2=SIP/99405") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:6] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Set(THISPART2=DAHDI/99405)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:7] Set("SIP/MY_PROVIDER-00008bb0", "NEWDIAL=SIP/99405&") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:8] Set("SIP/MY_PROVIDER-00008bb0", "ITER2=2") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:9] GotoIf("SIP/MY_PROVIDER-00008bb0", "0?begin2") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:10] Set("SIP/MY_PROVIDER-00008bb0", "THISDIAL=SIP/99405") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:11] Return("SIP/MY_PROVIDER-00008bb0", "") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [dstring@macro-dial-one:9] GotoIf("SIP/MY_PROVIDER-00008bb0", "1?docheck") in new stack

Second part…

[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (macro-dial-one,dstring,14)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [dstring@macro-dial-one:14] GotoIf("SIP/MY_PROVIDER-00008bb0", "0?skipset") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [dstring@macro-dial-one:15] Set("SIP/MY_PROVIDER-00008bb0", "DSTRING=SIP/99405&") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [dstring@macro-dial-one:16] Set("SIP/MY_PROVIDER-00008bb0", "ITER=2") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [dstring@macro-dial-one:17] GotoIf("SIP/MY_PROVIDER-00008bb0", "1?begin") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (macro-dial-one,dstring,7)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [dstring@macro-dial-one:7] Set("SIP/MY_PROVIDER-00008bb0", "THISDIAL=SIP/405") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [dstring@macro-dial-one:8] GosubIf("SIP/MY_PROVIDER-00008bb0", "1?zap2dahdi,1()") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:1] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Return()") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:2] Set("SIP/MY_PROVIDER-00008bb0", "NEWDIAL=") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:3] Set("SIP/MY_PROVIDER-00008bb0", "LOOPCNT2=1") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:4] Set("SIP/MY_PROVIDER-00008bb0", "ITER2=1") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:5] Set("SIP/MY_PROVIDER-00008bb0", "THISPART2=SIP/405") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:6] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Set(THISPART2=DAHDI/405)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:7] Set("SIP/MY_PROVIDER-00008bb0", "NEWDIAL=SIP/405&") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:8] Set("SIP/MY_PROVIDER-00008bb0", "ITER2=2") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:9] GotoIf("SIP/MY_PROVIDER-00008bb0", "0?begin2") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:10] Set("SIP/MY_PROVIDER-00008bb0", "THISDIAL=SIP/405") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:11] Return("SIP/MY_PROVIDER-00008bb0", "") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [dstring@macro-dial-one:9] GotoIf("SIP/MY_PROVIDER-00008bb0", "1?docheck") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (macro-dial-one,dstring,14)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [dstring@macro-dial-one:14] GotoIf("SIP/MY_PROVIDER-00008bb0", "0?skipset") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [dstring@macro-dial-one:15] Set("SIP/MY_PROVIDER-00008bb0", "DSTRING=SIP/99405&SIP/405&") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [dstring@macro-dial-one:16] Set("SIP/MY_PROVIDER-00008bb0", "ITER=3") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [dstring@macro-dial-one:17] GotoIf("SIP/MY_PROVIDER-00008bb0", "0?begin") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [dstring@macro-dial-one:18] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Return()") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [dstring@macro-dial-one:19] Set("SIP/MY_PROVIDER-00008bb0", "DSTRING=SIP/99405&SIP/405") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [dstring@macro-dial-one:20] Return("SIP/MY_PROVIDER-00008bb0", "") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:29] GotoIf("SIP/MY_PROVIDER-00008bb0", "0?nodial") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:30] GotoIf("SIP/MY_PROVIDER-00008bb0", "0?skiptrace") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:31] GosubIf("SIP/MY_PROVIDER-00008bb0", "1?ctset,1():ctclear,1()") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [ctset@macro-dial-one:1] Set("SIP/MY_PROVIDER-00008bb0", "DB(CALLTRACE/405)=666666666") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [ctset@macro-dial-one:2] Return("SIP/MY_PROVIDER-00008bb0", "") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:32] Set("SIP/MY_PROVIDER-00008bb0", "D_OPTIONS=Ttr") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:33] NoOp("SIP/MY_PROVIDER-00008bb0", "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:34] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Set(ALERT_INFO=)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:35] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Set(ALERT_INFO=)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:36] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Set(ALERT_INFO=)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:37] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Set(ALERT_INFO=Normal;volume=)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:38] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Set(ALERT_INFO=Normal;volume=)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:39] GosubIf("SIP/MY_PROVIDER-00008bb0", "0?func-set-sipheader,s,1(Alert-Info,)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:40] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Set(CHANNEL(musicclass)=)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:41] GosubIf("SIP/MY_PROVIDER-00008bb0", "0?qwait,1()") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:42] Set("SIP/MY_PROVIDER-00008bb0", "__CWIGNORE=") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:43] Set("SIP/MY_PROVIDER-00008bb0", "__KEEPCID=TRUE") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:44] GotoIf("SIP/MY_PROVIDER-00008bb0", "0?usegoto,1") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:45] GotoIf("SIP/MY_PROVIDER-00008bb0", "1?godial") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (macro-dial-one,s,50)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:50] Macro("SIP/MY_PROVIDER-00008bb0", "dialout-one-predial-hook,") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dialout-one-predial-hook:1] MacroExit("SIP/MY_PROVIDER-00008bb0", "") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:51] ExecIf("SIP/MY_PROVIDER-00008bb0", "1?Set(D_OPTIONS=trI)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:52] GotoIf("SIP/MY_PROVIDER-00008bb0", "1?zulunourl") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (macro-dial-one,s,54)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:54] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Set(ZULU_TYPE=)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:55] GotoIf("SIP/MY_PROVIDER-00008bb0", "1?skippopup") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (macro-dial-one,s,62)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:62] UserEvent("SIP/MY_PROVIDER-00008bb0", "zulu-call,eventtype:calling,extension:405,type:,url:,cnam:OFFICE1666666666,cnum:666666666,lid:1526652442.37803") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:63] NoOp("SIP/MY_PROVIDER-00008bb0", "Zulu Finished") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:64] NoOp("SIP/MY_PROVIDER-00008bb0", "") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-dial-one:65] Dial("SIP/MY_PROVIDER-00008bb0", "SIP/99405&SIP/405,,trIb(func-apply-sipheaders^s^1)") in new stack
[2018-05-18 16:07:22] WARNING[31903][C-00003d5a] app_dial.c: Unable to create channel of type 'SIP' (cause 20 - Subscriber absent)
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] netsock2.c:   == Using SIP RTP TOS bits 184
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] netsock2.c:   == Using SIP RTP CoS mark 5
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] app_stack.c:     -- SIP/405-00008bb1 Internal Gosub(func-apply-sipheaders,s,1) start
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@func-apply-sipheaders:1] ExecIf("SIP/405-00008bb1", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@func-apply-sipheaders:2] NoOp("SIP/405-00008bb1", "Applying SIP Headers to channel") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@func-apply-sipheaders:3] Set("SIP/405-00008bb1", "SIPHEADERKEYS=") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@func-apply-sipheaders:4] While("SIP/405-00008bb1", "0") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] app_while.c:     -- Jumping to priority 7
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@func-apply-sipheaders:8] Return("SIP/405-00008bb1", "") in new stack
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] app_stack.c:   == Spawn extension (from-internal, 405, 1) exited non-zero on 'SIP/405-00008bb1'
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] app_stack.c:     -- SIP/405-00008bb1 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] app_dial.c:     -- Called SIP/405
[2018-05-18 16:07:22] VERBOSE[31903][C-00003d5a] app_dial.c:     -- Connected line update to SIP/MY_PROVIDER-00008bb0 prevented.
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] app_dial.c:     -- SIP/405-00008bb1 is ringing
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] app_stack.c:     -- SIP/405-00008bb1 Internal Gosub(crm-hangup,s,1) start
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@crm-hangup:1] NoOp("SIP/405-00008bb1", "Sending Hangup to CRM") in new stack
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@crm-hangup:2] NoOp("SIP/405-00008bb1", "HANGUP CAUSE: 16") in new stack
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@crm-hangup:3] ExecIf("SIP/405-00008bb1", "0?Set(__CRM_VOICEMAIL=)") in new stack
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@crm-hangup:4] NoOp("SIP/405-00008bb1", "MASTER CHANNEL: 1526652442.37804 = 1526652442.37803") in new stack
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@crm-hangup:5] GotoIf("SIP/405-00008bb1", "1?return") in new stack
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (crm-hangup,s,8)
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@crm-hangup:8] Return("SIP/405-00008bb1", "") in new stack
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] app_stack.c:   == Spawn extension (from-internal, 405, 1) exited non-zero on 'SIP/405-00008bb1'
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] app_stack.c:     -- SIP/405-00008bb1 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] app_macro.c:   == Spawn extension (macro-dial-one, s, 65) exited non-zero on 'SIP/MY_PROVIDER-00008bb0' in macro 'dial-one'
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] app_macro.c:   == Spawn extension (macro-exten-vm, s, 20) exited non-zero on 'SIP/MY_PROVIDER-00008bb0' in macro 'exten-vm'
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] pbx.c:   == Spawn extension (ext-local, 405, 2) exited non-zero on 'SIP/MY_PROVIDER-00008bb0'
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [h@ext-local:1] Macro("SIP/MY_PROVIDER-00008bb0", "hangupcall,") in new stack
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-hangupcall:1] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Set(CDR(recordingfile)=.wav)") in new stack
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-hangupcall:2] GotoIf("SIP/MY_PROVIDER-00008bb0", "1?theend") in new stack
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] pbx.c:     -- Goto (macro-hangupcall,s,4)
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-hangupcall:4] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Set(CDR(recordingfile)=)") in new stack
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@macro-hangupcall:5] Hangup("SIP/MY_PROVIDER-00008bb0", "") in new stack
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] app_macro.c:   == Spawn extension (macro-hangupcall, s, 5) exited non-zero on 'SIP/MY_PROVIDER-00008bb0' in macro 'hangupcall'
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] pbx.c:   == Spawn extension (ext-local, h, 1) exited non-zero on 'SIP/MY_PROVIDER-00008bb0'
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] app_stack.c:     -- SIP/MY_PROVIDER-00008bb0 Internal Gosub(crm-hangup,s,1) start
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@crm-hangup:1] NoOp("SIP/MY_PROVIDER-00008bb0", "Sending Hangup to CRM") in new stack
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@crm-hangup:2] NoOp("SIP/MY_PROVIDER-00008bb0", "HANGUP CAUSE: 16") in new stack
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@crm-hangup:3] ExecIf("SIP/MY_PROVIDER-00008bb0", "0?Set(__CRM_VOICEMAIL=)") in new stack
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@crm-hangup:4] NoOp("SIP/MY_PROVIDER-00008bb0", "MASTER CHANNEL: 1526652442.37803 = 1526652442.37803") in new stack
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@crm-hangup:5] GotoIf("SIP/MY_PROVIDER-00008bb0", "0?return") in new stack
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@crm-hangup:6] Set("SIP/MY_PROVIDER-00008bb0", "__CRM_HANGUP=1") in new stack
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@crm-hangup:7] AGI("SIP/MY_PROVIDER-00008bb0", "sangomacrm.agi") in new stack
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] res_agi.c:     -- Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] res_agi.c:     -- <SIP/MY_PROVIDER-00008bb0>AGI Script sangomacrm.agi completed, returning 0
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] pbx.c:     -- Executing [s@crm-hangup:8] Return("SIP/MY_PROVIDER-00008bb0", "") in new stack
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] app_stack.c:   == Spawn extension (ext-local, h, 1) exited non-zero on 'SIP/MY_PROVIDER-00008bb0'
[2018-05-18 16:07:23] VERBOSE[31903][C-00003d5a] app_stack.c:     -- SIP/MY_PROVIDER-00008bb0 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=

Well, I have detected the same error on a few FreePBX I have on production. I made a tcpdump to see if the call is being executed, but no outbound call is executing to my provider, so FreePBX doesn’t simply make the call.

This happens to me even if I use and external phone number with “#” on ring groups.

But it does work on aother PBX. Any idea?? How can I get the reason of the error?

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