Incoming Call Issues

So I have this weird issue. Incoming and outgoing calls work fine, except if the incoming call is private, then it goes straight to voicemail. Can not figure out why this is doing this or any setting that would cause this. I am on the latest FreePBX Distro with all updates using a SIP trunk with GrandStream phones.

Bump. Anybody have any ideas?
I ran the call log and can see that it tries but none of the phones ring. It goes straight to voicemail.

Hi,

Try to check asterisk logs when receiving a private call

BR
Shokuie

Here is a snippit of when I call *675555555.

VERBOSE[33981][C-000007ea] pbx.c: Executing [5555555555@from-trunk:1] Set(“SIP/BroadVoice-Primary-00002f64”, “__DIRECTION=”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [5555555555@from-trunk:2] Gosub(“SIP/BroadVoice-Primary-00002f64”, “sub-record-check,s,1(in,5555555555,dontcare)”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:1] GotoIf(“SIP/BroadVoice-Primary-00002f64”, “0?initialized”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:2] Set(“SIP/BroadVoice-Primary-00002f64”, “__REC_STATUS=INITIALIZED”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:3] Set(“SIP/BroadVoice-Primary-00002f64”, “NOW=1486078002”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:4] Set(“SIP/BroadVoice-Primary-00002f64”, “__DAY=02”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:5] Set(“SIP/BroadVoice-Primary-00002f64”, “__MONTH=02”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:6] Set(“SIP/BroadVoice-Primary-00002f64”, “__YEAR=2017”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:7] Set(“SIP/BroadVoice-Primary-00002f64”, “__TIMESTR=20170202-152642”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:8] Set(“SIP/BroadVoice-Primary-00002f64”, “__FROMEXTEN=unknown”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:9] Set(“SIP/BroadVoice-Primary-00002f64”, “__MON_FMT=wav”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:10] NoOp(“SIP/BroadVoice-Primary-00002f64”, “Recordings initialized”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:11] ExecIf(“SIP/BroadVoice-Primary-00002f64”, “0?Set(ARG3=dontcare)”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:12] Set(“SIP/BroadVoice-Primary-00002f64”, “REC_POLICY_MODE_SAVE=”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:13] ExecIf(“SIP/BroadVoice-Primary-00002f64”, “0?Set(REC_STATUS=NO)”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:14] GotoIf(“SIP/BroadVoice-Primary-00002f64”, “2?checkaction”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx_builtins.c: Goto (sub-record-check,s,17)
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:17] GotoIf(“SIP/BroadVoice-Primary-00002f64”, “1?sub-record-check,in,1”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx_builtins.c: Goto (sub-record-check,in,1)
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [in@sub-record-check:1] NoOp(“SIP/BroadVoice-Primary-00002f64”, “Inbound Recording Check to 5555555555”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [in@sub-record-check:2] Set(“SIP/BroadVoice-Primary-00002f64”, “FROMEXTEN=unknown”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [in@sub-record-check:3] ExecIf(“SIP/BroadVoice-Primary-00002f64”, “9?Set(FROMEXTEN=anonymous)”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [in@sub-record-check:4] Gosub(“SIP/BroadVoice-Primary-00002f64”, “recordcheck,1(dontcare,in,5555555555)”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp(“SIP/BroadVoice-Primary-00002f64”, “Starting recording check against dontcare”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [recordcheck@sub-record-check:2] Goto(“SIP/BroadVoice-Primary-00002f64”, “dontcare”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [recordcheck@sub-record-check:3] Return(“SIP/BroadVoice-Primary-00002f64”, “”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [in@sub-record-check:5] Return(“SIP/BroadVoice-Primary-00002f64”, “”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [5555555555@from-trunk:3] Gosub(“SIP/BroadVoice-Primary-00002f64”, “app-blacklist-check,s,1()”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@app-blacklist-check:1] GotoIf(“SIP/BroadVoice-Primary-00002f64”, “0?blacklisted”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@app-blacklist-check:2] Set(“SIP/BroadVoice-Primary-00002f64”, “CALLED_BLACKLIST=1”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@app-blacklist-check:3] Return(“SIP/BroadVoice-Primary-00002f64”, “”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [5555555555@from-trunk:4] Set(“SIP/BroadVoice-Primary-00002f64”, “__FROM_DID=5555555555”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [5555555555@from-trunk:5] Set(“SIP/BroadVoice-Primary-00002f64”, “CDR(did)=5555555555”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [5555555555@from-trunk:6] ExecIf(“SIP/BroadVoice-Primary-00002f64”, “0 ?Set(CALLERID(name)=anonymous)”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [5555555555@from-trunk:7] Set(“SIP/BroadVoice-Primary-00002f64”, “__MOHCLASS=”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [5555555555@from-trunk:8] Set(“SIP/BroadVoice-Primary-00002f64”, “__REVERSAL_REJECT=FALSE”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [5555555555@from-trunk:9] GotoIf(“SIP/BroadVoice-Primary-00002f64”, “1?post-reverse-charge”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx_builtins.c: Goto (from-trunk,5555555555,11)
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [5555555555@from-trunk:11] NoOp(“SIP/BroadVoice-Primary-00002f64”, “”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [5555555555@from-trunk:12] Set(“SIP/BroadVoice-Primary-00002f64”, “__CALLINGNAMEPRES_SV=allowed_not_screened”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [5555555555@from-trunk:13] Set(“SIP/BroadVoice-Primary-00002f64”, “__CALLINGNUMPRES_SV=allowed_not_screened”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [5555555555@from-trunk:14] Set(“SIP/BroadVoice-Primary-00002f64”, “CALLERID(name-pres)=allowed_not_screened”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [5555555555@from-trunk:15] Set(“SIP/BroadVoice-Primary-00002f64”, “CALLERID(num-pres)=allowed_not_screened”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [5555555555@from-trunk:16] NoOp(“SIP/BroadVoice-Primary-00002f64”, “CallerID Entry Point”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [5555555555@from-trunk:17] Goto(“SIP/BroadVoice-Primary-00002f64”, “ext-group,100,1”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx_builtins.c: Goto (ext-group,100,1)
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [100@ext-group:1] GotoIf(“SIP/BroadVoice-Primary-00002f64”, “0?cid”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [100@ext-group:2] PlayTones(“SIP/BroadVoice-Primary-00002f64”, “ring”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [100@ext-group:3] Progress(“SIP/BroadVoice-Primary-00002f64”, “”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [100@ext-group:4] Macro(“SIP/BroadVoice-Primary-00002f64”, “user-callerid,”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-user-callerid:1] Set(“SIP/BroadVoice-Primary-00002f64”, “TOUCH_MONITOR=1486078002.12531”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-user-callerid:2] Set(“SIP/BroadVoice-Primary-00002f64”, “AMPUSER=anonymous”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-user-callerid:3] GotoIf(“SIP/BroadVoice-Primary-00002f64”, “0?report”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-user-callerid:4] ExecIf(“SIP/BroadVoice-Primary-00002f64”, “1?Set(REALCALLERIDNUM=anonymous)”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-user-callerid:5] Set(“SIP/BroadVoice-Primary-00002f64”, “AMPUSER=”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-user-callerid:6] GotoIf(“SIP/BroadVoice-Primary-00002f64”, “0?limit”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-user-callerid:7] Set(“SIP/BroadVoice-Primary-00002f64”, “AMPUSERCIDNAME=”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-user-callerid:8] GotoIf(“SIP/BroadVoice-Primary-00002f64”, “1?report”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx_builtins.c: Goto (macro-user-callerid,s,15)
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-user-callerid:15] GotoIf(“SIP/BroadVoice-Primary-00002f64”, “0?continue”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-user-callerid:16] ExecIf(“SIP/BroadVoice-Primary-00002f64”, “1?Set(__CALLEE_ACCOUNCODE=)”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-user-callerid:17] Set(“SIP/BroadVoice-Primary-00002f64”, “__TTL=64”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-user-callerid:18] GotoIf(“SIP/BroadVoice-Primary-00002f64”, “1?continue”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx_builtins.c: Goto (macro-user-callerid,s,29)
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-user-callerid:29] Set(“SIP/BroadVoice-Primary-00002f64”, “CALLERID(number)=anonymous”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-user-callerid:30] Set(“SIP/BroadVoice-Primary-00002f64”, “CALLERID(name)=Anonymous”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-user-callerid:31] GotoIf(“SIP/BroadVoice-Primary-00002f64”, “0?cnum”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-user-callerid:32] Set(“SIP/BroadVoice-Primary-00002f64”, “CDR(cnam)=Anonymous”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-user-callerid:33] Set(“SIP/BroadVoice-Primary-00002f64”, “CDR(cnum)=anonymous”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-user-callerid:34] Set(“SIP/BroadVoice-Primary-00002f64”, “CHANNEL(language)=en”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [100@ext-group:5] Macro(“SIP/BroadVoice-Primary-00002f64”, “blkvm-setifempty,”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-blkvm-setifempty:1] GotoIf(“SIP/BroadVoice-Primary-00002f64”, “1?init”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx_builtins.c: Goto (macro-blkvm-setifempty,s,4)
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-blkvm-setifempty:4] Set(“SIP/BroadVoice-Primary-00002f64”, “__BLKVM_CHANNEL=SIP/BroadVoice-Primary-00002f64”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-blkvm-setifempty:5] Set(“SIP/BroadVoice-Primary-00002f64”, “SHARED(BLKVM,SIP/BroadVoice-Primary-00002f64)=TRUE”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-blkvm-setifempty:6] Set(“SIP/BroadVoice-Primary-00002f64”, “GOSUB_RETVAL=TRUE”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-blkvm-setifempty:7] MacroExit(“SIP/BroadVoice-Primary-00002f64”, “”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [100@ext-group:6] GotoIf(“SIP/BroadVoice-Primary-00002f64”, “1?skipov”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx_builtins.c: Goto (ext-group,100,9)
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [100@ext-group:9] Set(“SIP/BroadVoice-Primary-00002f64”, “RRNODEST=”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [100@ext-group:10] Set(“SIP/BroadVoice-Primary-00002f64”, “__NODEST=100”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [100@ext-group:11] GosubIf(“SIP/BroadVoice-Primary-00002f64”, “0?sub-rgsetcid,s,1()”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [100@ext-group:12] Set(“SIP/BroadVoice-Primary-00002f64”, “__CWIGNORE=TRUE”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [100@ext-group:13] Gosub(“SIP/BroadVoice-Primary-00002f64”, “sub-record-check,s,1(rg,100,never)”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:1] GotoIf(“SIP/BroadVoice-Primary-00002f64”, “9?initialized”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx_builtins.c: Goto (sub-record-check,s,10)
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:10] NoOp(“SIP/BroadVoice-Primary-00002f64”, “Recordings initialized”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:11] ExecIf(“SIP/BroadVoice-Primary-00002f64”, “0?Set(ARG3=dontcare)”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:12] Set(“SIP/BroadVoice-Primary-00002f64”, “REC_POLICY_MODE_SAVE=”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:13] ExecIf(“SIP/BroadVoice-Primary-00002f64”, “0?Set(REC_STATUS=NO)”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:14] GotoIf(“SIP/BroadVoice-Primary-00002f64”, “2?checkaction”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx_builtins.c: Goto (sub-record-check,s,17)
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:17] GotoIf(“SIP/BroadVoice-Primary-00002f64”, “0?sub-record-check,rg,1”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:18] NoOp(“SIP/BroadVoice-Primary-00002f64”, “Generic rg Recording Check - anonymous 100”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:19] Gosub(“SIP/BroadVoice-Primary-00002f64”, “recordcheck,1(never,rg,100)”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp(“SIP/BroadVoice-Primary-00002f64”, “Starting recording check against never”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [recordcheck@sub-record-check:2] Goto(“SIP/BroadVoice-Primary-00002f64”, “never”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx_builtins.c: Goto (sub-record-check,recordcheck,14)
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [recordcheck@sub-record-check:14] Set(“SIP/BroadVoice-Primary-00002f64”, “__REC_POLICY_MODE=NEVER”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [recordcheck@sub-record-check:15] Goto(“SIP/BroadVoice-Primary-00002f64”, “stoprec”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx_builtins.c: Goto (sub-record-check,recordcheck,25)
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [recordcheck@sub-record-check:25] NoOp(“SIP/BroadVoice-Primary-00002f64”, “Stopping recording: rg, 100”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [recordcheck@sub-record-check:26] Set(“SIP/BroadVoice-Primary-00002f64”, “__REC_STATUS=STOPPED”) in new stack
[2017-02-02 15:26:42] VERBOSE[33981][C-000007ea] pbx.c: Executing [recordcheck@sub-record-check:27] System(“SIP/BroadVoice-Primary-00002f64”, "/var/lib/asterisk/bin/stoprecording.php “SIP/BroadVoice-Primary-00002f64"”) in new stack
[2017-02-02 15:26:43] NOTICE[2485] chan_sip.c: Received SIP subscribe for peer without mailbox: 206
[2017-02-02 15:26:43] NOTICE[2485] chan_sip.c: Received SIP subscribe for peer without mailbox: 203
[2017-02-02 15:26:43] NOTICE[2485] chan_sip.c: Received SIP subscribe for peer without mailbox: 208
[2017-02-02 15:26:43] NOTICE[2485] chan_sip.c: Received SIP subscribe for peer without mailbox: 212
[2017-02-02 15:26:43] VERBOSE[33981][C-000007ea] pbx.c: Executing [recordcheck@sub-record-check:28] Return(“SIP/BroadVoice-Primary-00002f64”, “”) in new stack
[2017-02-02 15:26:43] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@sub-record-check:20] Return(“SIP/BroadVoice-Primary-00002f64”, “”) in new stack
[2017-02-02 15:26:43] VERBOSE[33981][C-000007ea] pbx.c: Executing [100@ext-group:14] Set(“SIP/BroadVoice-Primary-00002f64”, “RingGroupMethod=ringall”) in new stack
[2017-02-02 15:26:43] VERBOSE[33981][C-000007ea] pbx.c: Executing [100@ext-group:15] Macro(“SIP/BroadVoice-Primary-00002f64”, “dial,20,Ttr,202-203-209-210-211-212-214-216-218”) in new stack
[2017-02-02 15:26:43] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-dial:1] NoOp(“SIP/BroadVoice-Primary-00002f64”, "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
[2017-02-02 15:26:43] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-dial:2] ExecIf(“SIP/BroadVoice-Primary-00002f64”, “0?Set(ALERT_INFO=)”) in new stack
[2017-02-02 15:26:43] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-dial:3] ExecIf(“SIP/BroadVoice-Primary-00002f64”, “0?Set(ALERT_INFO=)”) in new stack
[2017-02-02 15:26:43] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-dial:4] ExecIf(“SIP/BroadVoice-Primary-00002f64”, “0?Set(ALERT_INFO=)”) in new stack
[2017-02-02 15:26:43] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-dial:5] ExecIf(“SIP/BroadVoice-Primary-00002f64”, “0?Set(CHANNEL(musicclass)=)”) in new stack
[2017-02-02 15:26:43] VERBOSE[33981][C-000007ea] pbx.c: Executing [s@macro-dial:6] AGI(“SIP/BroadVoice-Primary-00002f64”, “dialparties.agi”) in new stack
[2017-02-02 15:26:43] VERBOSE[33981][C-000007ea] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2017-02-02 15:26:43] VERBOSE[33981][C-000007ea] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2017-02-02 15:26:43] VERBOSE[33981][C-000007ea] res_agi.c: dialparties.agi: Caller ID name is ‘Anonymous’ number is ‘anonymous’

Is that where the log stopped? It was just getting to the good part! :slight_smile:

Here is the rest of the log.

[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Caller ID name is 'Anonymous' number is 'anonymous'
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: CW Ignore is: TRUE
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: CF Ignore is:
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: CW IN_USE/BUSY is: 1
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Methodology of ring is 'ringall'
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Added extension 202 to extension map
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Added extension 203 to extension map
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Added extension 209 to extension map
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Added extension 210 to extension map
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Added extension 211 to extension map
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Added extension 212 to extension map
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Added extension 214 to extension map
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Added extension 216 to extension map
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Added extension 218 to extension map
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 202 cf is disabled
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 203 cf is disabled
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 209 cf is disabled
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 210 cf is disabled
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 211 cf is disabled
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 212 cf is disabled
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 214 cf is disabled
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 216 cf is disabled
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 218 cf is disabled
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 202 do not disturb is disabled
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 203 do not disturb is disabled
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 209 do not disturb is disabled
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 210 do not disturb is disabled
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 211 do not disturb is disabled
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 212 do not disturb is disabled
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 214 do not disturb is disabled
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 216 do not disturb is disabled
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 218 do not disturb is disabled
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: EXTENSION_STATE: 1 (INUSE)
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 202 has ExtensionState: 1
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Checking CW and CFB status for extension 202
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 202 is not available to be called
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 202 has call waiting disabled
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 203 has ExtensionState: 0
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Checking CW and CFB status for extension 203
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: DbDel CALLTRACE/203 - Caller ID is not defined
[2017-02-02 16:11:59] NOTICE[2485] chan_sip.c: Received SIP subscribe for peer without mailbox: 215
[2017-02-02 16:11:59] NOTICE[2485] chan_sip.c: Received SIP subscribe for peer without mailbox: 216
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 209 has ExtensionState: 0
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Checking CW and CFB status for extension 209
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: DbDel CALLTRACE/209 - Caller ID is not defined
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 210 has ExtensionState: 0
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Checking CW and CFB status for extension 210
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: DbDel CALLTRACE/210 - Caller ID is not defined
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 211 has ExtensionState: 0
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Checking CW and CFB status for extension 211
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: DbDel CALLTRACE/211 - Caller ID is not defined
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 212 has ExtensionState: 0
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Checking CW and CFB status for extension 212
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: DbDel CALLTRACE/212 - Caller ID is not defined
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 214 has ExtensionState: 0
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Checking CW and CFB status for extension 214
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: DbDel CALLTRACE/214 - Caller ID is not defined
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: EXTENSION_STATE: 1 (INUSE)
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 216 has ExtensionState: 1
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Checking CW and CFB status for extension 216
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 216 is not available to be called
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 216 has call waiting disabled
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Extension 218 has ExtensionState: 0
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Checking CW and CFB status for extension 218
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: DbDel CALLTRACE/218 - Caller ID is not defined
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: dialparties.agi: Filtered ARG3: 203-209-210-211-212-214-218
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] res_agi.c: <SIP/BroadVoice-Primary-0000300c>AGI Script dialparties.agi completed, returning 0
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:9] NoOp("SIP/BroadVoice-Primary-0000300c", "Returned from dialparties with groups to dial") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:10] Set("SIP/BroadVoice-Primary-0000300c", "LOOPCNT=7") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:11] Set("SIP/BroadVoice-Primary-0000300c", "ITER=1") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:12] Set("SIP/BroadVoice-Primary-0000300c", "EXTTOCALL=203") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:13] NoOp("SIP/BroadVoice-Primary-0000300c", "Working with 203") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:14] ExecIf("SIP/BroadVoice-Primary-0000300c", "0?Set(HASH(__SIPHEADERS,Alert-Info)=;volume=)") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:15] ExecIf("SIP/BroadVoice-Primary-0000300c", "0?Set(HASH(__SIPHEADERS,Alert-Info)=;volume=)") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:16] Set("SIP/BroadVoice-Primary-0000300c", "ITER=2") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:17] GotoIf("SIP/BroadVoice-Primary-0000300c", "1?ndloopbegin") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx_builtins.c: Goto (macro-dial,s,12)
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:12] Set("SIP/BroadVoice-Primary-0000300c", "EXTTOCALL=209") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:13] NoOp("SIP/BroadVoice-Primary-0000300c", "Working with 209") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:14] ExecIf("SIP/BroadVoice-Primary-0000300c", "0?Set(HASH(__SIPHEADERS,Alert-Info)=;volume=)") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:15] ExecIf("SIP/BroadVoice-Primary-0000300c", "0?Set(HASH(__SIPHEADERS,Alert-Info)=;volume=)") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:16] Set("SIP/BroadVoice-Primary-0000300c", "ITER=3") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:17] GotoIf("SIP/BroadVoice-Primary-0000300c", "1?ndloopbegin") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx_builtins.c: Goto (macro-dial,s,12)
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:12] Set("SIP/BroadVoice-Primary-0000300c", "EXTTOCALL=210") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:13] NoOp("SIP/BroadVoice-Primary-0000300c", "Working with 210") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:14] ExecIf("SIP/BroadVoice-Primary-0000300c", "0?Set(HASH(__SIPHEADERS,Alert-Info)=;volume=)") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:15] ExecIf("SIP/BroadVoice-Primary-0000300c", "0?Set(HASH(__SIPHEADERS,Alert-Info)=;volume=)") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:16] Set("SIP/BroadVoice-Primary-0000300c", "ITER=4") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:17] GotoIf("SIP/BroadVoice-Primary-0000300c", "1?ndloopbegin") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx_builtins.c: Goto (macro-dial,s,12)
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:12] Set("SIP/BroadVoice-Primary-0000300c", "EXTTOCALL=211") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:13] NoOp("SIP/BroadVoice-Primary-0000300c", "Working with 211") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:14] ExecIf("SIP/BroadVoice-Primary-0000300c", "0?Set(HASH(__SIPHEADERS,Alert-Info)=;volume=)") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:15] ExecIf("SIP/BroadVoice-Primary-0000300c", "0?Set(HASH(__SIPHEADERS,Alert-Info)=;volume=)") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:16] Set("SIP/BroadVoice-Primary-0000300c", "ITER=5") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:17] GotoIf("SIP/BroadVoice-Primary-0000300c", "1?ndloopbegin") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx_builtins.c: Goto (macro-dial,s,12)
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:12] Set("SIP/BroadVoice-Primary-0000300c", "EXTTOCALL=212") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:13] NoOp("SIP/BroadVoice-Primary-0000300c", "Working with 212") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:14] ExecIf("SIP/BroadVoice-Primary-0000300c", "0?Set(HASH(__SIPHEADERS,Alert-Info)=;volume=)") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:15] ExecIf("SIP/BroadVoice-Primary-0000300c", "0?Set(HASH(__SIPHEADERS,Alert-Info)=;volume=)") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:16] Set("SIP/BroadVoice-Primary-0000300c", "ITER=6") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:17] GotoIf("SIP/BroadVoice-Primary-0000300c", "1?ndloopbegin") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx_builtins.c: Goto (macro-dial,s,12)
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:12] Set("SIP/BroadVoice-Primary-0000300c", "EXTTOCALL=214") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:13] NoOp("SIP/BroadVoice-Primary-0000300c", "Working with 214") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:14] ExecIf("SIP/BroadVoice-Primary-0000300c", "0?Set(HASH(__SIPHEADERS,Alert-Info)=;volume=)") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:15] ExecIf("SIP/BroadVoice-Primary-0000300c", "0?Set(HASH(__SIPHEADERS,Alert-Info)=;volume=)") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:16] Set("SIP/BroadVoice-Primary-0000300c", "ITER=7") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:17] GotoIf("SIP/BroadVoice-Primary-0000300c", "1?ndloopbegin") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx_builtins.c: Goto (macro-dial,s,12)
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:12] Set("SIP/BroadVoice-Primary-0000300c", "EXTTOCALL=218") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:13] NoOp("SIP/BroadVoice-Primary-0000300c", "Working with 218") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:14] ExecIf("SIP/BroadVoice-Primary-0000300c", "0?Set(HASH(__SIPHEADERS,Alert-Info)=;volume=)") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:15] ExecIf("SIP/BroadVoice-Primary-0000300c", "0?Set(HASH(__SIPHEADERS,Alert-Info)=;volume=)") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:16] Set("SIP/BroadVoice-Primary-0000300c", "ITER=8") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:17] GotoIf("SIP/BroadVoice-Primary-0000300c", "0?ndloopbegin") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:18] Macro("SIP/BroadVoice-Primary-0000300c", "dial-ringall-predial-hook,") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial-ringall-predial-hook:1] MacroExit("SIP/BroadVoice-Primary-0000300c", "") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:19] Dial("SIP/BroadVoice-Primary-0000300c", "SIP/203&SIP/209&SIP/210&SIP/211&SIP/212&SIP/214&SIP/218,20,TtrM(auto-blkvm)b(func-apply-sipheaders^s^1),") in new stack
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] netsock2.c: Using SIP RTP TOS bits 184
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] netsock2.c: Using SIP RTP CoS mark 5
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] netsock2.c: Using SIP RTP TOS bits 184
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] netsock2.c: Using SIP RTP CoS mark 5
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] netsock2.c: Using SIP RTP TOS bits 184
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] netsock2.c: Using SIP RTP CoS mark 5
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] netsock2.c: Using SIP RTP TOS bits 184
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] netsock2.c: Using SIP RTP CoS mark 5
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] netsock2.c: Using SIP RTP TOS bits 184
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] netsock2.c: Using SIP RTP CoS mark 5
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] netsock2.c: Using SIP RTP TOS bits 184
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] netsock2.c: Using SIP RTP CoS mark 5
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] netsock2.c: Using SIP RTP TOS bits 184
[2017-02-02 16:11:59] VERBOSE[38569][C-00000801] netsock2.c: Using SIP RTP CoS mark 5
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_stack.c: SIP/203-0000300d Internal Gosub(func-apply-sipheaders,s,1) start
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:1] NoOp("SIP/203-0000300d", "Applying SIP Headers to channel") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:2] Set("SIP/203-0000300d", "SIPHEADERKEYS=") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:3] While("SIP/203-0000300d", "0") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_while.c: Jumping to priority 6
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:7] Return("SIP/203-0000300d", "") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_stack.c: Spawn extension (from-internal, 100, 1) exited non-zero on 'SIP/203-0000300d'
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_stack.c: SIP/203-0000300d Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=

And the remaining of the log where it eventually ends up in voicemail.

[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_stack.c: SIP/209-0000300e Internal Gosub(func-apply-sipheaders,s,1) start
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:1] NoOp("SIP/209-0000300e", "Applying SIP Headers to channel") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:2] Set("SIP/209-0000300e", "SIPHEADERKEYS=") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:3] While("SIP/209-0000300e", "0") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_while.c: Jumping to priority 6
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:7] Return("SIP/209-0000300e", "") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_stack.c: Spawn extension (from-internal, 100, 1) exited non-zero on 'SIP/209-0000300e'
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_stack.c: SIP/209-0000300e Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_stack.c: SIP/210-0000300f Internal Gosub(func-apply-sipheaders,s,1) start
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:1] NoOp("SIP/210-0000300f", "Applying SIP Headers to channel") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:2] Set("SIP/210-0000300f", "SIPHEADERKEYS=") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:3] While("SIP/210-0000300f", "0") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_while.c: Jumping to priority 6
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:7] Return("SIP/210-0000300f", "") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_stack.c: Spawn extension (from-internal, 100, 1) exited non-zero on 'SIP/210-0000300f'
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_stack.c: SIP/210-0000300f Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_stack.c: SIP/211-00003010 Internal Gosub(func-apply-sipheaders,s,1) start
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:1] NoOp("SIP/211-00003010", "Applying SIP Headers to channel") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:2] Set("SIP/211-00003010", "SIPHEADERKEYS=") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:3] While("SIP/211-00003010", "0") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_while.c: Jumping to priority 6
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:7] Return("SIP/211-00003010", "") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_stack.c: Spawn extension (from-internal, 100, 1) exited non-zero on 'SIP/211-00003010'
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_stack.c: SIP/211-00003010 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_stack.c: SIP/212-00003011 Internal Gosub(func-apply-sipheaders,s,1) start
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:1] NoOp("SIP/212-00003011", "Applying SIP Headers to channel") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:2] Set("SIP/212-00003011", "SIPHEADERKEYS=") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:3] While("SIP/212-00003011", "0") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_while.c: Jumping to priority 6
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:7] Return("SIP/212-00003011", "") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_stack.c: Spawn extension (from-internal, 100, 1) exited non-zero on 'SIP/212-00003011'
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_stack.c: SIP/212-00003011 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_stack.c: SIP/214-00003012 Internal Gosub(func-apply-sipheaders,s,1) start
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:1] NoOp("SIP/214-00003012", "Applying SIP Headers to channel") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:2] Set("SIP/214-00003012", "SIPHEADERKEYS=") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:3] While("SIP/214-00003012", "0") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_while.c: Jumping to priority 6
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:7] Return("SIP/214-00003012", "") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_stack.c: Spawn extension (from-internal, 100, 1) exited non-zero on 'SIP/214-00003012'
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_stack.c: SIP/214-00003012 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_stack.c: SIP/218-00003013 Internal Gosub(func-apply-sipheaders,s,1) start
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:1] NoOp("SIP/218-00003013", "Applying SIP Headers to channel") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:2] Set("SIP/218-00003013", "SIPHEADERKEYS=") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:3] While("SIP/218-00003013", "0") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_while.c: Jumping to priority 6
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@func-apply-sipheaders:7] Return("SIP/218-00003013", "") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_stack.c: Spawn extension (from-internal, 100, 1) exited non-zero on 'SIP/218-00003013'
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_stack.c: SIP/218-00003013 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_dial.c: Called SIP/203
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_dial.c: Called SIP/209
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_dial.c: Called SIP/210
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_dial.c: Called SIP/211
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_dial.c: Called SIP/212
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_dial.c: Called SIP/214
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_dial.c: Called SIP/218
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_dial.c: SIP/218-00003013 connected line has changed. Saving it until answer for SIP/BroadVoice-Primary-0000300c
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_dial.c: SIP/214-00003012 connected line has changed. Saving it until answer for SIP/BroadVoice-Primary-0000300c
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_dial.c: SIP/212-00003011 connected line has changed. Saving it until answer for SIP/BroadVoice-Primary-0000300c
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_dial.c: SIP/211-00003010 connected line has changed. Saving it until answer for SIP/BroadVoice-Primary-0000300c
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_dial.c: SIP/210-0000300f connected line has changed. Saving it until answer for SIP/BroadVoice-Primary-0000300c
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_dial.c: SIP/209-0000300e connected line has changed. Saving it until answer for SIP/BroadVoice-Primary-0000300c
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_dial.c: SIP/203-0000300d connected line has changed. Saving it until answer for SIP/BroadVoice-Primary-0000300c
[2017-02-02 16:12:00] VERBOSE[2485][C-00000801] chan_sip.c: Got SIP response 433 "Anonymity Disallowed" back from 10.1.10.96:41430
[2017-02-02 16:12:00] VERBOSE[2485][C-00000801] chan_sip.c: Got SIP response 433 "Anonymity Disallowed" back from 10.1.10.101:11510
[2017-02-02 16:12:00] VERBOSE[2485][C-00000801] chan_sip.c: Got SIP response 433 "Anonymity Disallowed" back from 10.1.10.134:57631
[2017-02-02 16:12:00] VERBOSE[2485][C-00000801] chan_sip.c: Got SIP response 433 "Anonymity Disallowed" back from 10.1.10.103:49484
[2017-02-02 16:12:00] VERBOSE[2485][C-00000801] chan_sip.c: Got SIP response 433 "Anonymity Disallowed" back from 10.1.10.23:19489
[2017-02-02 16:12:00] VERBOSE[2485][C-00000801] chan_sip.c: Got SIP response 433 "Anonymity Disallowed" back from 10.1.10.99:22805
[2017-02-02 16:12:00] VERBOSE[2485][C-00000801] chan_sip.c: Got SIP response 433 "Anonymity Disallowed" back from 10.1.10.88:30219
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] app_dial.c: Everyone is busy/congested at this time (7:0/0/7)
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:20] Set("SIP/BroadVoice-Primary-0000300c", "DIALSTATUS=CHANUNAVAIL") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:21] GosubIf("SIP/BroadVoice-Primary-0000300c", "0?CHANUNAVAIL,1()") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:22] NoOp("SIP/BroadVoice-Primary-0000300c", "Returning since nobody answered") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-dial:23] MacroExit("SIP/BroadVoice-Primary-0000300c", "") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [100@ext-group:16] Gosub("SIP/BroadVoice-Primary-0000300c", "sub-record-cancel,s,1()") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@sub-record-cancel:1] Return("SIP/BroadVoice-Primary-0000300c", "") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [100@ext-group:17] Set("SIP/BroadVoice-Primary-0000300c", "RingGroupMethod=") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [100@ext-group:18] GotoIf("SIP/BroadVoice-Primary-0000300c", "0?nodest") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [100@ext-group:19] Set("SIP/BroadVoice-Primary-0000300c", "__CWIGNORE=") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [100@ext-group:20] Set("SIP/BroadVoice-Primary-0000300c", "__NODEST=") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [100@ext-group:21] Macro("SIP/BroadVoice-Primary-0000300c", "blkvm-clr,") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-blkvm-clr:1] Set("SIP/BroadVoice-Primary-0000300c", "SHARED(BLKVM,SIP/BroadVoice-Primary-0000300c)=") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-blkvm-clr:2] Set("SIP/BroadVoice-Primary-0000300c", "GOSUB_RETVAL=") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-blkvm-clr:3] MacroExit("SIP/BroadVoice-Primary-0000300c", "") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [100@ext-group:22] Goto("SIP/BroadVoice-Primary-0000300c", "ext-local,vmu200,1") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx_builtins.c: Goto (ext-local,vmu200,1)
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [vmu200@ext-local:1] Macro("SIP/BroadVoice-Primary-0000300c", "vm,200,NOANSWER,") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-vm:1] Macro("SIP/BroadVoice-Primary-0000300c", "user-callerid,SKIPTTL") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-user-callerid:1] Set("SIP/BroadVoice-Primary-0000300c", "TOUCH_MONITOR=1486080717.12699") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-user-callerid:2] Set("SIP/BroadVoice-Primary-0000300c", "AMPUSER=anonymous") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("SIP/BroadVoice-Primary-0000300c", "0?report") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-user-callerid:4] ExecIf("SIP/BroadVoice-Primary-0000300c", "0?Set(REALCALLERIDNUM=anonymous)") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-user-callerid:5] Set("SIP/BroadVoice-Primary-0000300c", "AMPUSER=") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-user-callerid:6] GotoIf("SIP/BroadVoice-Primary-0000300c", "0?limit") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-user-callerid:7] Set("SIP/BroadVoice-Primary-0000300c", "AMPUSERCIDNAME=") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-user-callerid:8] GotoIf("SIP/BroadVoice-Primary-0000300c", "1?report") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx_builtins.c: Goto (macro-user-callerid,s,15)
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-user-callerid:15] GotoIf("SIP/BroadVoice-Primary-0000300c", "1?continue") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx_builtins.c: Goto (macro-user-callerid,s,29)
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-user-callerid:29] Set("SIP/BroadVoice-Primary-0000300c", "CALLERID(number)=anonymous") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-user-callerid:30] Set("SIP/BroadVoice-Primary-0000300c", "CALLERID(name)=Anonymous") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-user-callerid:31] GotoIf("SIP/BroadVoice-Primary-0000300c", "0?cnum") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-user-callerid:32] Set("SIP/BroadVoice-Primary-0000300c", "CDR(cnam)=Anonymous") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-user-callerid:33] Set("SIP/BroadVoice-Primary-0000300c", "CDR(cnum)=anonymous") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-user-callerid:34] Set("SIP/BroadVoice-Primary-0000300c", "CHANNEL(language)=en") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-vm:2] Set("SIP/BroadVoice-Primary-0000300c", "VMGAIN=") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-vm:3] Macro("SIP/BroadVoice-Primary-0000300c", "blkvm-check,") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-blkvm-check:1] Set("SIP/BroadVoice-Primary-0000300c", "GOSUB_RETVAL=") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-blkvm-check:2] ExecIf("SIP/BroadVoice-Primary-0000300c", "0?Set(GOSUB_RETVAL=TRUE)") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-blkvm-check:3] MacroExit("SIP/BroadVoice-Primary-0000300c", "") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-vm:4] GotoIf("SIP/BroadVoice-Primary-0000300c", "1?vmx,1") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx_builtins.c: Goto (macro-vm,vmx,1)
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [vmx@macro-vm:1] Set("SIP/BroadVoice-Primary-0000300c", "MEXTEN=200") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [vmx@macro-vm:2] Set("SIP/BroadVoice-Primary-0000300c", "MMODE=NOANSWER") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [vmx@macro-vm:3] Set("SIP/BroadVoice-Primary-0000300c", "RETVM=") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [vmx@macro-vm:4] Set("SIP/BroadVoice-Primary-0000300c", "MODE=unavail") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [vmx@macro-vm:5] Macro("SIP/BroadVoice-Primary-0000300c", "get-vmcontext,200") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-get-vmcontext:1] Set("SIP/BroadVoice-Primary-0000300c", "VMCONTEXT=default") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-get-vmcontext:2] GotoIf("SIP/BroadVoice-Primary-0000300c", "0?200:300") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx_builtins.c: Goto (macro-get-vmcontext,s,300)
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-get-vmcontext:300] NoOp("SIP/BroadVoice-Primary-0000300c", "") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [vmx@macro-vm:6] Set("SIP/BroadVoice-Primary-0000300c", "MODE=unavail") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [vmx@macro-vm:7] NoOp("SIP/BroadVoice-Primary-0000300c", "MODE IS: unavail") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [vmx@macro-vm:8] GotoIf("SIP/BroadVoice-Primary-0000300c", "1?chknomsg") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx_builtins.c: Goto (macro-vm,vmx,10)
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [vmx@macro-vm:10] GotoIf("SIP/BroadVoice-Primary-0000300c", "0?s-NOANSWER,1") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [vmx@macro-vm:11] GotoIf("SIP/BroadVoice-Primary-0000300c", "1?notdirect") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx_builtins.c: Goto (macro-vm,vmx,13)
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [vmx@macro-vm:13] NoOp("SIP/BroadVoice-Primary-0000300c", "Checking if ext 200 is enabled: ") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [vmx@macro-vm:14] GotoIf("SIP/BroadVoice-Primary-0000300c", "1?s-NOANSWER,1") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx_builtins.c: Goto (macro-vm,s-NOANSWER,1)
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s-NOANSWER@macro-vm:1] Macro("SIP/BroadVoice-Primary-0000300c", "get-vmcontext,200") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-get-vmcontext:1] Set("SIP/BroadVoice-Primary-0000300c", "VMCONTEXT=default") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-get-vmcontext:2] GotoIf("SIP/BroadVoice-Primary-0000300c", "0?200:300") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx_builtins.c: Goto (macro-get-vmcontext,s,300)
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-get-vmcontext:300] NoOp("SIP/BroadVoice-Primary-0000300c", "") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] pbx.c: Executing [s-NOANSWER@macro-vm:2] VoiceMail("SIP/BroadVoice-Primary-0000300c", "200@default,u") in new stack
[2017-02-02 16:12:00] VERBOSE[38569][C-00000801] file.c: <SIP/BroadVoice-Primary-0000300c> Playing '/var/spool/asterisk/voicemail/default/200/unavail.slin' (language 'en')
[2017-02-02 16:12:00] NOTICE[2485] chan_sip.c: Received SIP subscribe for peer without mailbox: 201
[2017-02-02 16:12:01] NOTICE[2485] chan_sip.c: Received SIP subscribe for peer without mailbox: 201
[2017-02-02 16:12:01] NOTICE[2485] chan_sip.c: Received SIP subscribe for peer without mailbox: 202
[2017-02-02 16:12:02] NOTICE[2485] chan_sip.c: Received SIP subscribe for peer without mailbox: 213
[2017-02-02 16:12:02] NOTICE[2485] chan_sip.c: Received SIP subscribe for peer without mailbox: 214
[2017-02-02 16:12:02] NOTICE[2485] chan_sip.c: Received SIP subscribe for peer without mailbox: 202
[2017-02-02 16:12:03] VERBOSE[38569][C-00000801] app_macro.c: Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on 'SIP/BroadVoice-Primary-0000300c' in macro 'vm'
[2017-02-02 16:12:03] VERBOSE[38569][C-00000801] pbx.c: Spawn extension (ext-local, vmu200, 1) exited non-zero on 'SIP/BroadVoice-Primary-0000300c'
[2017-02-02 16:12:03] VERBOSE[38569][C-00000801] pbx.c: Executing [h@ext-local:1] Macro("SIP/BroadVoice-Primary-0000300c", "hangupcall,") in new stack
[2017-02-02 16:12:03] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("SIP/BroadVoice-Primary-0000300c", "1?theend") in new stack
[2017-02-02 16:12:03] VERBOSE[38569][C-00000801] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2017-02-02 16:12:03] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("SIP/BroadVoice-Primary-0000300c", "0?Set(CDR(recordingfile)=)") in new stack
[2017-02-02 16:12:03] VERBOSE[38569][C-00000801] pbx.c: Executing [s@macro-hangupcall:4] Hangup("SIP/BroadVoice-Primary-0000300c", "") in new stack
[2017-02-02 16:12:03] VERBOSE[38569][C-00000801] app_macro.c: Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/BroadVoice-Primary-0000300c' in macro 'hangupcall'

Do you have privacy activated on your extensions?

[2017-02-02 16:12:00] VERBOSE[2485][C-00000801] chan_sip.c: Got SIP response 433 “Anonymity Disallowed” back from 10.1.10.96:41430
[2017-02-02 16:12:00] VERBOSE[2485][C-00000801] chan_sip.c: Got SIP response 433 “Anonymity Disallowed” back from 10.1.10.101:11510
[2017-02-02 16:12:00] VERBOSE[2485][C-00000801] chan_sip.c: Got SIP response 433 “Anonymity Disallowed” back from 10.1.10.134:57631
[2017-02-02 16:12:00] VERBOSE[2485][C-00000801] chan_sip.c: Got SIP response 433 “Anonymity Disallowed” back from 10.1.10.103:49484
[2017-02-02 16:12:00] VERBOSE[2485][C-00000801] chan_sip.c: Got SIP response 433 “Anonymity Disallowed” back from 10.1.10.23:19489
[2017-02-02 16:12:00] VERBOSE[2485][C-00000801] chan_sip.c: Got SIP response 433 “Anonymity Disallowed” back from 10.1.10.99:22805
[2017-02-02 16:12:00] VERBOSE[2485][C-00000801] chan_sip.c: Got SIP response 433 “Anonymity Disallowed” back from 10.1.10.88:30219

1 Like

I saw that as well but privacy is not activated on the extensions. It is disabled on all extensions.

what kind of phones are they

They are Grandstream GXP2140 phones.

AH!
Grandstream have anonymous blocking features!
If you http into the gui check Account# -> Call Settings
Check for “Anonymous Call Rejection” see if its been set to “YES” (i think its normally no, but stuff happens)

WOW!!! Can’t believe I missed that. Each phone has 2 lines, and I check the first one and it had it disabled but did not think to check the 2nd one. That was it! Thank you dickson.

Glad it fixed your issue! :slight_smile: