Question about DAHDi / Analog context

Hi,

I get the following Asterisk Warning when I receive a call from a PSTN line:

[2017-10-08 17:57:10] WARNING[3212][C-00000003]: app_macro.c:310 _macro_exec: No such context 'macro-from-dahdi-1' for macro 'from-dahdi-1'. Was called by s@from-analog
[2017-10-08 17:57:10] WARNING[3212][C-00000003]: app_macro.c:310 _macro_exec: No such context 'macro-from-dahdi-1' for macro 'from-dahdi-1'. Was called by s@from-analog

Any thoughts on what could be causing this?

Show the whole call from the log.

Hopefully I’ve removed any personal info. I tried to post the entire log for the call, but it was too big!:

[2017-10-08 18:55:07] VERBOSE[9554][C-00000000] sig_analog.c: Starting post polarity CID detection on channel 1
[2017-10-08 18:55:07] VERBOSE[9922][C-00000000] sig_analog.c: Starting simple switch on 'DAHDI/1-1'
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-analog:1] NoOp("DAHDI/1-1", "Entering from-dahdi with DID == ") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-analog:2] Ringing("DAHDI/1-1", "") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-analog:3] Set("DAHDI/1-1", "DID=s") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-analog:4] NoOp("DAHDI/1-1", "DID is now s") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-analog:5] GotoIf("DAHDI/1-1", "1?dahdiok:checkzap") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx_builtins.c: Goto (from-analog,s,9)
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-analog:9] NoOp("DAHDI/1-1", "Is a DAHDi Channel") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-analog:10] Set("DAHDI/1-1", "CHAN=1-1") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-analog:11] Set("DAHDI/1-1", "CHAN=1") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-analog:12] Macro("DAHDI/1-1", "from-dahdi-1,s,1") in new stack
[2017-10-08 18:55:10] WARNING[9922][C-00000000] app_macro.c: No such context 'macro-from-dahdi-1' for macro 'from-dahdi-1'. Was called by s@from-analog
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-analog:13] NoOp("DAHDI/1-1", "Returned from Macro from-dahdi-1") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-analog:14] Goto("DAHDI/1-1", "from-pstn,s,1") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx_builtins.c: Goto (from-pstn,s,1)
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-pstn:1] Set("DAHDI/1-1", "__DIRECTION=INBOUND") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-pstn:2] Gosub("DAHDI/1-1", "sub-record-check,s,1(in,s,dontcare)") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@sub-record-check:1] GotoIf("DAHDI/1-1", "0?initialized") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@sub-record-check:2] Set("DAHDI/1-1", "__REC_STATUS=INITIALIZED") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@sub-record-check:3] Set("DAHDI/1-1", "NOW=1507485310") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@sub-record-check:4] Set("DAHDI/1-1", "__DAY=08") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@sub-record-check:5] Set("DAHDI/1-1", "__MONTH=10") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@sub-record-check:6] Set("DAHDI/1-1", "__YEAR=2017") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@sub-record-check:7] Set("DAHDI/1-1", "__TIMESTR=20171008-185510") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@sub-record-check:8] Set("DAHDI/1-1", "__FROMEXTEN=unknown") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@sub-record-check:9] Set("DAHDI/1-1", "__MON_FMT=wav") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@sub-record-check:10] NoOp("DAHDI/1-1", "Recordings initialized") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@sub-record-check:11] ExecIf("DAHDI/1-1", "0?Set(ARG3=dontcare)") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@sub-record-check:12] Set("DAHDI/1-1", "REC_POLICY_MODE_SAVE=") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@sub-record-check:13] ExecIf("DAHDI/1-1", "0?Set(REC_STATUS=NO)") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@sub-record-check:14] GotoIf("DAHDI/1-1", "2?checkaction") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx_builtins.c: Goto (sub-record-check,s,17)
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@sub-record-check:17] GotoIf("DAHDI/1-1", "1?sub-record-check,in,1") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx_builtins.c: Goto (sub-record-check,in,1)
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [in@sub-record-check:1] NoOp("DAHDI/1-1", "Inbound Recording Check to s") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [in@sub-record-check:2] Set("DAHDI/1-1", "FROMEXTEN=unknown") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [in@sub-record-check:3] ExecIf("DAHDI/1-1", "11?Set(FROMEXTEN=0123456789)") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [in@sub-record-check:4] Gosub("DAHDI/1-1", "recordcheck,1(dontcare,in,s)") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("DAHDI/1-1", "Starting recording check against dontcare") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("DAHDI/1-1", "dontcare") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [recordcheck@sub-record-check:3] Return("DAHDI/1-1", "") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [in@sub-record-check:5] Return("DAHDI/1-1", "") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-pstn:3] Gosub("DAHDI/1-1", "app-blacklist-check,s,1()") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@app-blacklist-check:1] GotoIf("DAHDI/1-1", "0?blacklisted") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@app-blacklist-check:2] Set("DAHDI/1-1", "CALLED_BLACKLIST=1") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@app-blacklist-check:3] Return("DAHDI/1-1", "") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-pstn:4] ExecIf("DAHDI/1-1", "1?Set(__FROM_DID=s)") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-pstn:5] Set("DAHDI/1-1", "CDR(did)=s") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-pstn:6] ExecIf("DAHDI/1-1", "1 ?Set(CALLERID(name)=0123456789)") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-pstn:7] Set("DAHDI/1-1", "__MOHCLASS=") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-pstn:8] Set("DAHDI/1-1", "__REVERSAL_REJECT=FALSE") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-pstn:9] GotoIf("DAHDI/1-1", "1?post-reverse-charge") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx_builtins.c: Goto (from-pstn,s,11)
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-pstn:11] NoOp("DAHDI/1-1", "") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-pstn:12] Set("DAHDI/1-1", "__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-pstn:13] Set("DAHDI/1-1", "__CALLINGNUMPRES_SV=allowed_not_screened") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-pstn:14] Set("DAHDI/1-1", "CALLERID(name-pres)=allowed_not_screened") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-pstn:15] Set("DAHDI/1-1", "CALLERID(num-pres)=allowed_not_screened") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-pstn:16] Gosub("DAHDI/1-1", "cidlookup,cidlookup_12,1()") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [cidlookup_12@cidlookup:1] ExecIf("DAHDI/1-1", "1?Set(CALLERID(name)=Chaser)") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [cidlookup_12@cidlookup:2] Return("DAHDI/1-1", "") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-pstn:17] NoOp("DAHDI/1-1", "CallerID Entry Point") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-pstn:18] Set("DAHDI/1-1", "__CRM_DIRECTION=INBOUND") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-pstn:19] Set("DAHDI/1-1", "__CRM_SOURCE=0123456789") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-pstn:20] Set("DAHDI/1-1", "__CRM_LINKEDID=1507485307.0") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-pstn:21] ExecIf("DAHDI/1-1", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@from-pstn:22] Goto("DAHDI/1-1", "ext-group,600,1") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx_builtins.c: Goto (ext-group,600,1)
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [600@ext-group:1] GotoIf("DAHDI/1-1", "0?cid") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [600@ext-group:2] PlayTones("DAHDI/1-1", "ring") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [600@ext-group:3] Progress("DAHDI/1-1", "") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [600@ext-group:4] Macro("DAHDI/1-1", "user-callerid,") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@macro-user-callerid:1] Set("DAHDI/1-1", "TOUCH_MONITOR=1507485307.0") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@macro-user-callerid:2] Set("DAHDI/1-1", "AMPUSER=0123456789") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("DAHDI/1-1", "0?report") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@macro-user-callerid:4] ExecIf("DAHDI/1-1", "1?Set(__REALCALLERIDNUM=0123456789)") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@macro-user-callerid:5] Set("DAHDI/1-1", "AMPUSER=") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@macro-user-callerid:6] GotoIf("DAHDI/1-1", "0?limit") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@macro-user-callerid:7] Set("DAHDI/1-1", "AMPUSERCIDNAME=") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@macro-user-callerid:8] GotoIf("DAHDI/1-1", "1?report") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx_builtins.c: Goto (macro-user-callerid,s,15)
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@macro-user-callerid:15] GotoIf("DAHDI/1-1", "0?continue") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@macro-user-callerid:16] ExecIf("DAHDI/1-1", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@macro-user-callerid:17] Set("DAHDI/1-1", "__TTL=6") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@macro-user-callerid:18] GotoIf("DAHDI/1-1", "1?continue") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx_builtins.c: Goto (macro-user-callerid,s,29)
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@macro-user-callerid:29] Set("DAHDI/1-1", "CALLERID(number)=0123456789") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@macro-user-callerid:30] Set("DAHDI/1-1", "CALLERID(name)=Chaser") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@macro-user-callerid:31] GotoIf("DAHDI/1-1", "0?cnum") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@macro-user-callerid:32] Set("DAHDI/1-1", "CDR(cnam)=Chaser") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@macro-user-callerid:33] Set("DAHDI/1-1", "CDR(cnum)=0123456789") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@macro-user-callerid:34] Set("DAHDI/1-1", "CHANNEL(language)=en") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [600@ext-group:5] Macro("DAHDI/1-1", "blkvm-setifempty,") in new stack
[2017-10-08 18:55:10] VERBOSE[9922][C-00000000] pbx.c: Executing [s@macro-blkvm-setifempty:1] GotoIf("DAHDI/1-1", "1?init") in new stack

…and another question. Why is everything getting reported twice???

Edit. Solved the duplicate log entries with this:

I’ve updated the log above with a new one that has single entries

The logging doubles is a logging mis-config, possibly some unnecessary additions to logger_logfiles_custom.conf

The macro is used so you can manually set channel DIDs under Connectivity, DAHDI Channel
DIDs.

Thanks for the feedback.

Yes, I found duplicate entries in logger_logfiles_custom.conf. I commented them out, and I’m now getting single entries.

So, is it normal to get the macro warning if I don’t have any manually set channel DIDs?