Outbound number lands in our blacklist

We accidentally discovered something odd today. When we place an outbound phone call, but forget to dial a number, so we’re dialing 10 digits, we end up in our own Blacklist.

I’ve checked the blacklist, and the number isn’t in the list. Nothing even close to the number is in our Blacklist. The number dialed starts with 9764 if that matters.

FreePBX 14.1.11 Asterisk 13.22.0

Provide a call trace of this happening on an outbound call. https://wiki.freepbx.org/display/SUP/Providing+Great+Debug#ProvidingGreatDebug-AsteriskLogs

When I try the command string listed I get a response:

"No such command 'tail -f /var/log/asterisk/full' (type 'core show help tail -f' for other possible commands)"

If I run it from SSH I get the following. I did remove my private info.

[2019-05-08 15:42:08] VERBOSE[32126][C-00000ad0] app_stack.c: Spawn extension (followme-sub, 201, 38) exited non-zero on 'SIP/202-00001a8c'
[2019-05-08 15:42:08] VERBOSE[32126][C-00000ad0] app_stack.c: SIP/202-00001a8c Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2019-05-08 15:42:08] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state Idle for Notify User 213 
[2019-05-08 15:42:08] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state Idle for Notify User 219 
[2019-05-08 15:42:08] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state Idle for Notify User 212 
[2019-05-08 15:42:08] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state Idle for Notify User 202 
[2019-05-08 15:42:08] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state Idle for Notify User 207 
[2019-05-08 15:42:08] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state Idle for Notify User 203 
[2019-05-08 15:42:08] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state Idle for Notify User 201 
[2019-05-08 15:42:08] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state Idle for Notify User 250 
[2019-05-08 15:47:53] VERBOSE[24235][C-00000ad1] netsock2.c: Using SIP RTP TOS bits 184
[2019-05-08 15:47:53] VERBOSE[24235][C-00000ad1] netsock2.c: Using SIP RTP CoS mark 5
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [9764xxxxxx@from-internal:1] Macro("SIP/202-00001a8f", "user-callerid,LIMIT,EXTERNAL,") in new stack
[2019-05-08 15:47:53] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state InUse for Notify User 213 
[2019-05-08 15:47:53] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state InUse for Notify User 219 
[2019-05-08 15:47:53] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state InUse for Notify User 212 
[2019-05-08 15:47:53] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state InUse for Notify User 202 
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:1] Set("SIP/202-00001a8f", "TOUCH_MONITOR=1557344873.14943") in new stack
[2019-05-08 15:47:53] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state InUse for Notify User 207 
[2019-05-08 15:47:53] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state InUse for Notify User 203 
[2019-05-08 15:47:53] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state InUse for Notify User 201 
[2019-05-08 15:47:53] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state InUse for Notify User 250 
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:2] Set("SIP/202-00001a8f", "AMPUSER=202") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("SIP/202-00001a8f", "0?report") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:4] ExecIf("SIP/202-00001a8f", "1?Set(REALCALLERIDNUM=202)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:5] Set("SIP/202-00001a8f", "AMPUSER=202") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:6] GotoIf("SIP/202-00001a8f", "0?limit") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:7] Set("SIP/202-00001a8f", "AMPUSERCIDNAME=My Name") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:8] ExecIf("SIP/202-00001a8f", "0?Set(__CIDMASQUERADING=TRUE)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:9] GotoIf("SIP/202-00001a8f", "0?report") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:10] Set("SIP/202-00001a8f", "AMPUSERCID=202") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:11] Set("SIP/202-00001a8f", "__DIAL_OPTIONS=Ttr") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:12] Set("SIP/202-00001a8f", "CALLERID(all)="My Name" <202>") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:13] GotoIf("SIP/202-00001a8f", "0?limit") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:14] ExecIf("SIP/202-00001a8f", "1?Set(GROUP(concurrency_limit)=202)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:15] GosubIf("SIP/202-00001a8f", "7?sub-ccss,s,1(from-internal,9764xxxxxx)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-ccss:1] ExecIf("SIP/202-00001a8f", "0?Return()") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-ccss:2] Set("SIP/202-00001a8f", "CCSS_SETUP=TRUE") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-ccss:3] GosubIf("SIP/202-00001a8f", "0?monitor_config,1(from-internal,9764xxxxxx):monitor_default,1(from-internal,9764xxxxxx)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [monitor_default@sub-ccss:1] GotoIf("SIP/202-00001a8f", "0?is_exten") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [monitor_default@sub-ccss:2] StackPop("SIP/202-00001a8f", "") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [monitor_default@sub-ccss:3] Return("SIP/202-00001a8f", "FALSE") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:16] ExecIf("SIP/202-00001a8f", "0?Set(CHANNEL(language)=)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:17] NoOp("SIP/202-00001a8f", "Macro Depth is 1") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:18] GotoIf("SIP/202-00001a8f", "1?report2:macroerror") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx_builtins.c: Goto (macro-user-callerid,s,19)
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:19] GotoIf("SIP/202-00001a8f", "1?continue") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx_builtins.c: Goto (macro-user-callerid,s,38)
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:38] Set("SIP/202-00001a8f", "CALLERID(number)=202") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:39] Set("SIP/202-00001a8f", "CALLERID(name)=My Name") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:40] GotoIf("SIP/202-00001a8f", "0?cnum") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:41] Set("SIP/202-00001a8f", "CDR(cnam)=My Name") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:42] Set("SIP/202-00001a8f", "CDR(cnum)=202") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-user-callerid:43] Set("SIP/202-00001a8f", "CHANNEL(language)=en") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [9764xxxxxx@from-internal:2] Gosub("SIP/202-00001a8f", "sub-record-check,s,1(out,9764xxxxxx,dontcare)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-record-check:1] GotoIf("SIP/202-00001a8f", "0?initialized") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-record-check:2] Set("SIP/202-00001a8f", "__REC_STATUS=INITIALIZED") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-record-check:3] Set("SIP/202-00001a8f", "NOW=1557344873") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-record-check:4] Set("SIP/202-00001a8f", "__DAY=08") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-record-check:5] Set("SIP/202-00001a8f", "__MONTH=05") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-record-check:6] Set("SIP/202-00001a8f", "__YEAR=2019") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-record-check:7] Set("SIP/202-00001a8f", "__TIMESTR=20190508-154753") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-record-check:8] Set("SIP/202-00001a8f", "__FROMEXTEN=202") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-record-check:9] Set("SIP/202-00001a8f", "__MON_FMT=wav") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-record-check:10] NoOp("SIP/202-00001a8f", "Recordings initialized") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-record-check:11] ExecIf("SIP/202-00001a8f", "0?Set(ARG3=dontcare)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-record-check:12] Set("SIP/202-00001a8f", "REC_POLICY_MODE_SAVE=") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-record-check:13] ExecIf("SIP/202-00001a8f", "0?Set(REC_STATUS=NO)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-record-check:14] GotoIf("SIP/202-00001a8f", "3?checkaction") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx_builtins.c: Goto (sub-record-check,s,17)
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-record-check:17] GotoIf("SIP/202-00001a8f", "1?sub-record-check,out,1") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx_builtins.c: Goto (sub-record-check,out,1)
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [out@sub-record-check:1] NoOp("SIP/202-00001a8f", "Outbound Recording Check from 202 to 97642xxxxxx") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [out@sub-record-check:2] Set("SIP/202-00001a8f", "RECMODE=never") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [out@sub-record-check:3] ExecIf("SIP/202-00001a8f", "0?Goto(routewins)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [out@sub-record-check:4] ExecIf("SIP/202-00001a8f", "0?Goto(routewins)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [out@sub-record-check:5] Gosub("SIP/202-00001a8f", "recordcheck,1(never,out,9764xxxxxx)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("SIP/202-00001a8f", "Starting recording check against never") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("SIP/202-00001a8f", "never") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx_builtins.c: Goto (sub-record-check,recordcheck,14)
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [recordcheck@sub-record-check:14] Set("SIP/202-00001a8f", "__REC_POLICY_MODE=NEVER") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [recordcheck@sub-record-check:15] Goto("SIP/202-00001a8f", "stoprec") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx_builtins.c: Goto (sub-record-check,recordcheck,24)
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [recordcheck@sub-record-check:24] NoOp("SIP/202-00001a8f", "Stopping recording: out, 9764xxxxxx") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [recordcheck@sub-record-check:25] Set("SIP/202-00001a8f", "__REC_STATUS=STOPPED") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [recordcheck@sub-record-check:26] System("SIP/202-00001a8f", "/var/lib/asterisk/bin/stoprecording.php "SIP/202-00001a8f"") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [recordcheck@sub-record-check:27] Return("SIP/202-00001a8f", "") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [out@sub-record-check:6] Return("SIP/202-00001a8f", "") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [9764xxxxxx@from-internal:3] ExecIf("SIP/202-00001a8f", "0 ?Set(CDR(accountcode)=)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [9764xxxxxx@from-internal:4] Set("SIP/202-00001a8f", "ROUTE_CIDSAVE="My Name" <202>") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [9764xxxxxx@from-internal:5] Set("SIP/202-00001a8f", "MOHCLASS=none") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [9764xxxxxx@from-internal:6] ExecIf("SIP/202-00001a8f", "0?Set(TRUNKCIDOVERRIDE="CD Solutions"<937xxxxxxx>)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [976xxxxxx@from-internal:7] Set("SIP/202-00001a8f", "_NODEST=") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [9764xxxxxx@from-internal:8] Macro("SIP/202-00001a8f", "dialout-trunk,6,9764xxxxxx,,off") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:1] Set("SIP/202-00001a8f", "DIAL_TRUNK=6") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:2] ExecIf("SIP/202-00001a8f", "0?Set(DIAL_OPTIONS=tr)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:3] GosubIf("SIP/202-00001a8f", "0?sub-pincheck,s,1()") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:4] ExecIf("SIP/202-00001a8f", "0?Set(CALLERID(num)=202)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:5] GotoIf("SIP/202-00001a8f", "0?disabletrunk,1") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:6] Set("SIP/202-00001a8f", "DIAL_NUMBER=9764xxxxxx") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:7] Set("SIP/202-00001a8f", "DIAL_TRUNK_OPTIONS=Ttr") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:8] Set("SIP/202-00001a8f", "OUTBOUND_GROUP=OUT_6") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:9] Set("SIP/202-00001a8f", "DIAL_TRUNK_OPTIONS=Tt") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:10] GotoIf("SIP/202-00001a8f", "1?nomax") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx_builtins.c: Goto (macro-dialout-trunk,s,12)
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:12] GotoIf("SIP/202-00001a8f", "0?skipoutcid") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:13] Macro("SIP/202-00001a8f", "outbound-callerid,6") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-outbound-callerid:1] NoOp("SIP/202-00001a8f", "202") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-outbound-callerid:2] NoOp("SIP/202-00001a8f", "") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-outbound-callerid:3] NoOp("SIP/202-00001a8f", "off") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-outbound-callerid:4] ExecIf("SIP/202-00001a8f", "0?Set(CALLERPRES(name-pres)=)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-outbound-callerid:5] ExecIf("SIP/202-00001a8f", "0?Set(CALLERPRES(num-pres)=)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-outbound-callerid:6] ExecIf("SIP/202-00001a8f", "0?Set(REALCALLERIDNUM=202)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-outbound-callerid:7] ExecIf("SIP/202-00001a8f", "0?Set(AMPUSER=202)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-outbound-callerid:8] GotoIf("SIP/202-00001a8f", "1?normcid") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx_builtins.c: Goto (macro-outbound-callerid,s,12)
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-outbound-callerid:12] Set("SIP/202-00001a8f", "USEROUTCID="CD Solutions" <937xxxxxxx>") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-outbound-callerid:13] Set("SIP/202-00001a8f", "EMERGENCYCID=") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-outbound-callerid:14] Set("SIP/202-00001a8f", "TRUNKOUTCID="CD Solutions Inc" <937xxxxxxx>") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-outbound-callerid:15] GotoIf("SIP/202-00001a8f", "1?trunkcid") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx_builtins.c: Goto (macro-outbound-callerid,s,21)
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-outbound-callerid:21] ExecIf("SIP/202-00001a8f", "1?Set(CALLERID(all)="CD Solutions Inc" <937xxxxxxx>)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-outbound-callerid:22] ExecIf("SIP/202-00001a8f", "1?Set(CALLERID(all)="CD Solutions" <937xxxxxxx>)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-outbound-callerid:23] ExecIf("SIP/202-00001a8f", "0?Set(CALLERID(all)=)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-outbound-callerid:24] ExecIf("SIP/202-00001a8f", "0?Set(CALLERPRES(name-pres)=prohib_passed_screen)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-outbound-callerid:25] ExecIf("SIP/202-00001a8f", "0?Set(CALLERPRES(num-pres)=prohib_passed_screen)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-outbound-callerid:26] Set("SIP/202-00001a8f", "CDR(outbound_cnum)=937xxxxxxx") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-outbound-callerid:27] Set("SIP/202-00001a8f", "CDR(outbound_cnam)=CD Solutions") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:14] GosubIf("SIP/202-00001a8f", "1?sub-flp-6,s,1()") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-flp-6:1] ExecIf("SIP/202-00001a8f", "0?Set(TARGET_FLP_6=764231505)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-flp-6:2] GotoIf("SIP/202-00001a8f", "0?match") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-flp-6:3] ExecIf("SIP/202-00001a8f", "0?Set(TARGET_FLP_6=764231505)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-flp-6:4] GotoIf("SIP/202-00001a8f", "0?match") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-flp-6:5] ExecIf("SIP/202-00001a8f", "0?Set(TARGET_FLP_6=764231505)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-flp-6:6] GotoIf("SIP/202-00001a8f", "0?match") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-flp-6:7] ExecIf("SIP/202-00001a8f", "0?Set(TARGET_FLP_6=764231505)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-flp-6:8] GotoIf("SIP/202-00001a8f", "0?match") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@sub-flp-6:9] Return("SIP/202-00001a8f", "") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:15] Set("SIP/202-00001a8f", "OUTNUM=9764xxxxxx") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:16] Set("SIP/202-00001a8f", "custom=SIP/Dead_Trunk") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:17] ExecIf("SIP/202-00001a8f", "1?Set(DIAL_TRUNK_OPTIONS=M(setmusic^none)Tt)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:18] ExecIf("SIP/202-00001a8f", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^none)TtM(confirm))") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:19] Macro("SIP/202-00001a8f", "dialout-trunk-predial-hook,") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("SIP/202-00001a8f", "") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:20] GotoIf("SIP/202-00001a8f", "0?skipcrm") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:21] Set("SIP/202-00001a8f", "__CRM_DIRECTION=OUTBOUND") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:22] Set("SIP/202-00001a8f", "__CRM_DESTINATION=9764xxxxxx") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:23] Set("SIP/202-00001a8f", "__CRM_SOURCE=202") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:24] AGI("SIP/202-00001a8f", "sangomacrm.agi") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] res_agi.c: <SIP/202-00001a8f>AGI Script sangomacrm.agi completed, returning 0
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:25] Set("SIP/202-00001a8f", "CHANNEL(hangup_handler_push)=crm-hangup,s,1") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:26] NoOp("SIP/202-00001a8f", "CRM Finished") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:27] GotoIf("SIP/202-00001a8f", "0?bypass,1") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:28] ExecIf("SIP/202-00001a8f", "1?Set(CONNECTEDLINE(num,i)=9764xxxxxx)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:29] ExecIf("SIP/202-00001a8f", "1?Set(CONNECTEDLINE(name,i)=CID:937xxxxxxx)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:30] ExecIf("SIP/202-00001a8f", "0?Set(CONNECTEDLINE(name,i)=CID:(Hidden)937xxxxxxx)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:31] GotoIf("SIP/202-00001a8f", "0?customtrunk") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:32] Dial("SIP/202-00001a8f", "SIP/Dead_Trunk/9764xxxxxx,300,M(setmusic^none)Ttb(func-apply-sipheaders^s^1,(6))") in new stack
[2019-05-08 15:47:53] WARNING[883][C-00000ad1] app_dial.c: Unable to create channel of type 'SIP' (cause 20 - Subscriber absent)
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] app_dial.c: Everyone is busy/congested at this time (1:0/0/1)
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:33] NoOp("SIP/202-00001a8f", "Dial failed for some reason with DIALSTATUS = CHANUNAVAIL and HANGUPCAUSE = 20") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@macro-dialout-trunk:34] GotoIf("SIP/202-00001a8f", "0?continue,1:s-CHANUNAVAIL,1") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx_builtins.c: Goto (macro-dialout-trunk,s-CHANUNAVAIL,1)
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s-CHANUNAVAIL@macro-dialout-trunk:1] Set("SIP/202-00001a8f", "RC=20") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s-CHANUNAVAIL@macro-dialout-trunk:2] Goto("SIP/202-00001a8f", "20,1") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx_builtins.c: Goto (macro-dialout-trunk,20,1)
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [20@macro-dialout-trunk:1] Goto("SIP/202-00001a8f", "continue,1") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx_builtins.c: Goto (macro-dialout-trunk,continue,1)
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [continue@macro-dialout-trunk:1] NoOp("SIP/202-00001a8f", "TRUNK Dial failed due to CHANUNAVAIL HANGUPCAUSE: 20 - failing through to other trunks") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [continue@macro-dialout-trunk:2] ExecIf("SIP/202-00001a8f", "1?Set(CALLERID(number)=202)") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [9764xxxxxx@from-internal:9] Set("SIP/202-00001a8f", "CALLERID(all)="My Name" <202>") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [9764xxxxxx@from-internal:10] Set("SIP/202-00001a8f", "_KEEPCID=TRUE") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [9764xxxxxx@from-internal:11] Goto("SIP/202-00001a8f", "app-announcement-7,s,1") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx_builtins.c: Goto (app-announcement-7,s,1)
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@app-announcement-7:1] GotoIf("SIP/202-00001a8f", "0?begin") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@app-announcement-7:2] Answer("SIP/202-00001a8f", "") in new stack
[2019-05-08 15:47:53] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@app-announcement-7:3] Wait("SIP/202-00001a8f", "1") in new stack
[2019-05-08 15:47:54] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@app-announcement-7:4] NoOp("SIP/202-00001a8f", "Playing announcement AnnoyingCaller") in new stack
[2019-05-08 15:47:54] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@app-announcement-7:5] Playback("SIP/202-00001a8f", "custom/AnnoyingCalls,noanswer") in new stack
[2019-05-08 15:47:54] VERBOSE[883][C-00000ad1] file.c: <SIP/202-00001a8f> Playing 'custom/AnnoyingCalls.slin' (language 'en')
[2019-05-08 15:48:01] VERBOSE[883][C-00000ad1] app_stack.c: SIP/202-00001a8f Internal Gosub(crm-hangup,s,1) start
[2019-05-08 15:48:01] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@crm-hangup:1] NoOp("SIP/202-00001a8f", "Sending Hangup to CRM") in new stack
[2019-05-08 15:48:01] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@crm-hangup:2] NoOp("SIP/202-00001a8f", "HANGUP CAUSE: 20") in new stack
[2019-05-08 15:48:01] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@crm-hangup:3] ExecIf("SIP/202-00001a8f", "0?Set(__CRM_VOICEMAIL=)") in new stack
[2019-05-08 15:48:01] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@crm-hangup:4] NoOp("SIP/202-00001a8f", "MASTER CHANNEL: 1557344873.14943 = 1557344873.14943") in new stack
[2019-05-08 15:48:01] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@crm-hangup:5] GotoIf("SIP/202-00001a8f", "0?return") in new stack
[2019-05-08 15:48:01] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@crm-hangup:6] Set("SIP/202-00001a8f", "__CRM_HANGUP=1") in new stack
[2019-05-08 15:48:01] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@crm-hangup:7] AGI("SIP/202-00001a8f", "sangomacrm.agi") in new stack
[2019-05-08 15:48:01] VERBOSE[883][C-00000ad1] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2019-05-08 15:48:02] VERBOSE[883][C-00000ad1] res_agi.c: <SIP/202-00001a8f>AGI Script sangomacrm.agi completed, returning 0
[2019-05-08 15:48:02] VERBOSE[883][C-00000ad1] pbx.c: Executing [s@crm-hangup:8] Return("SIP/202-00001a8f", "") in new stack
[2019-05-08 15:48:02] VERBOSE[883][C-00000ad1] app_stack.c: Spawn extension (app-announcement-7, s, 5) exited non-zero on 'SIP/202-00001a8f'
[2019-05-08 15:48:02] VERBOSE[883][C-00000ad1] app_stack.c: SIP/202-00001a8f Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2019-05-08 15:48:02] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state Idle for Notify User 213 
[2019-05-08 15:48:02] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state Idle for Notify User 219 
[2019-05-08 15:48:02] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state Idle for Notify User 212 
[2019-05-08 15:48:02] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state Idle for Notify User 202 
[2019-05-08 15:48:02] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state Idle for Notify User 207 
[2019-05-08 15:48:02] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state Idle for Notify User 203 
[2019-05-08 15:48:02] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state Idle for Notify User 201 
[2019-05-08 15:48:02] VERBOSE[24186] chan_sip.c: Extension Changed 202[ext-local] new state Idle for Notify User 250 
^C

Blockquote

There is something weird going on with the failover trunk, but I don’t see anything in that trace that references the AstDB Blacklist.

The only trunks enabled are SIP Station trunks plus one “dead” trunk that isn’t supposed to go anywhere. If I disable the dead trunk the problem still exists. Nothing changes.

So… still no idea why it’s going there, but there it goes.

These numbers start with 976 (and optionally 4)?

Ah ha! I have an outbound route with pattern 976XXXXXXX which routes calls to the dead trunk. Basically the dead trunk is a way to block mostly international calls.

That blocked trunk is set to go to the blacklist announcement. What I need to do is route it to a different announcement. Mystery solved.

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