Call Screening not asking for name 13.0.192.16

When I turn on Call Screening for an extension (memory or non memory) (from Inbound Route), that extension will not answer prompting the caller to state their name. However when the called extension rings and the call is answered it states a call from (no audio) then offers options which all work.

I have turned off Find Me Follow me and reproduced this on 2 different Inbound routes to 2 different extensions with the same behavior.

13.0.192.16

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

Sorry I’m not the best with Linux CLI. I was able to execute the command to log you referenced, but how do I get that output on the forum? I can’t screen print / capture from my Oracle Box VM because the output is too much for one screen. The referenced article doesn’t offer an easy way to get access to the file if it’s creating one.

I’ve added some detail to the wiki page that will help you:
https://wiki.freepbx.org/display/SUP/Providing+Great+Debug#ProvidingGreatDebug-AsteriskLogs-PartII

Oh cool. Pastebin is key. I’ll try and get this log / trace info posted to the forum this weekend. In the meantime if anyone else has any suggestions I’ll give them a try.

@lgaetz why didn’t you just suggest cutting and pasting from Reports–>Asterisk Log files?

@lgaetz thanks for your help… here is part 1 of logfile:

[2018-02-22 14:27:21] VERBOSE[1940][C-00000001] netsock2.c: == Using SIP RTP TOS bits 184
[2018-02-22 14:27:21] VERBOSE[1940][C-00000001] netsock2.c: == Using SIP RTP CoS mark 5
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [+1**********@from-trunk:1] Set("SIP/TwilioIn0-00000002", "__DIRECTION=INBOUND") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [+1**********@from-trunk:2] Gosub("SIP/TwilioIn0-00000002", "sub-record-check,s,1(in,+1**********,dontcare)") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] GotoIf("SIP/TwilioIn0-00000002", "0?initialized") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:2] Set("SIP/TwilioIn0-00000002", "__REC_STATUS=INITIALIZED") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:3] Set("SIP/TwilioIn0-00000002", "NOW=1519331241") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:4] Set("SIP/TwilioIn0-00000002", "__DAY=22") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:5] Set("SIP/TwilioIn0-00000002", "__MONTH=02") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:6] Set("SIP/TwilioIn0-00000002", "__YEAR=2018") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:7] Set("SIP/TwilioIn0-00000002", "__TIMESTR=20180222-142721") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:8] Set("SIP/TwilioIn0-00000002", "__FROMEXTEN=unknown") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:9] Set("SIP/TwilioIn0-00000002", "__MON_FMT=wav") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:10] NoOp("SIP/TwilioIn0-00000002", "Recordings initialized") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:11] ExecIf("SIP/TwilioIn0-00000002", "0?Set(ARG3=dontcare)") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:12] Set("SIP/TwilioIn0-00000002", "REC_POLICY_MODE_SAVE=") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:13] ExecIf("SIP/TwilioIn0-00000002", "0?Set(REC_STATUS=NO)") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:14] GotoIf("SIP/TwilioIn0-00000002", "2?checkaction") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Goto (sub-record-check,s,17)
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:17] GotoIf("SIP/TwilioIn0-00000002", "1?sub-record-check,in,1") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Goto (sub-record-check,in,1)
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] NoOp("SIP/TwilioIn0-00000002", "Inbound Recording Check to +1**********") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:2] Set("SIP/TwilioIn0-00000002", "FROMEXTEN=unknown") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:3] ExecIf("SIP/TwilioIn0-00000002", "12?Set(FROMEXTEN=+1615*******)") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:4] Gosub("SIP/TwilioIn0-00000002", "recordcheck,1(dontcare,in,+1**********)") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] NoOp("SIP/TwilioIn0-00000002", "Starting recording check against dontcare") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:2] Goto("SIP/TwilioIn0-00000002", "dontcare") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Goto (sub-record-check,recordcheck,3)
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:3] Return("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:5] Return("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [+1**********@from-trunk:3] Gosub("SIP/TwilioIn0-00000002", "app-blacklist-check,s,1()") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] GotoIf("SIP/TwilioIn0-00000002", "0?blacklisted") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:2] Set("SIP/TwilioIn0-00000002", "CALLED_BLACKLIST=1") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:3] Return("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [+1**********@from-trunk:4] Set("SIP/TwilioIn0-00000002", "__FROM_DID=+1**********") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [+1**********@from-trunk:5] Set("SIP/TwilioIn0-00000002", "CDR(did)=+1**********") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [+1**********@from-trunk:6] ExecIf("SIP/TwilioIn0-00000002", "1 ?Set(CALLERID(name)=+1615*******)") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [+1**********@from-trunk:7] Set("SIP/TwilioIn0-00000002", "__MOHCLASS=") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [+1**********@from-trunk:8] Set("SIP/TwilioIn0-00000002", "__REVERSAL_REJECT=FALSE") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [+1**********@from-trunk:9] GotoIf("SIP/TwilioIn0-00000002", "1?post-reverse-charge") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Goto (from-trunk,+1**********,11)
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [+1**********@from-trunk:11] NoOp("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [+1**********@from-trunk:12] Macro("SIP/TwilioIn0-00000002", "privacy-mgr,3,10") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] Set("SIP/TwilioIn0-00000002", "KEEPCID=+1615*******") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:2] Set("SIP/TwilioIn0-00000002", "TESTCID=16155795879.000000") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:3] ExecIf("SIP/TwilioIn0-00000002", "0?Set(CALLERID(num)=)") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:4] PrivacyManager("SIP/TwilioIn0-00000002", "3,10") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] app_privacy.c: -- CallerID number present: Skipping
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:5] GotoIf("SIP/TwilioIn0-00000002", "0?fail") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:6] GosubIf("SIP/TwilioIn0-00000002", "1?app-blacklist-check,s,1()") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] GotoIf("SIP/TwilioIn0-00000002", "0?blacklisted") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:2] Set("SIP/TwilioIn0-00000002", "CALLED_BLACKLIST=1") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:3] Return("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:7] Set("SIP/TwilioIn0-00000002", "CALLERID(num-pres)=allowed_passed_screen") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:8] MacroExit("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [+1**********@from-trunk:13] Gosub("SIP/TwilioIn0-00000002", "cidlookup,cidlookup_2,1()") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] Set("SIP/TwilioIn0-00000002", "CURLOPT(httptimeout)=7") in new stack
[2018-02-22 14:27:22] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:2] Set("SIP/TwilioIn0-00000002", "CALLERID(name)=john doe") in new stack
[2018-02-22 14:27:22] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:3] Return("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:22] VERBOSE[6341][C-00000001] pbx.c: -- Executing [+1**********@from-trunk:14] NoOp("SIP/TwilioIn0-00000002", "CallerID Entry Point") in new stack
[2018-02-22 14:27:22] VERBOSE[6341][C-00000001] pbx.c: -- Executing [+1**********@from-trunk:15] Set("SIP/TwilioIn0-00000002", "FAX_DEST=") in new stack
[2018-02-22 14:27:22] VERBOSE[6341][C-00000001] pbx.c: -- Executing [+1**********@from-trunk:16] Set("SIP/TwilioIn0-00000002", "FAXOPT(faxdetect)=yes") in new stack
[2018-02-22 14:27:22] VERBOSE[6341][C-00000001] pbx.c: -- Executing [+1**********@from-trunk:17] Answer("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:22] VERBOSE[6341][C-00000001] pbx.c: -- Executing [+1**********@from-trunk:18] Wait("SIP/TwilioIn0-00000002", "4") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [+1**********@from-trunk:19] Set("SIP/TwilioIn0-00000002", "__CRM_DIRECTION=INBOUND") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [+1**********@from-trunk:20] Set("SIP/TwilioIn0-00000002", "__CRM_SOURCE=+1615*******") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [+1**********@from-trunk:21] Set("SIP/TwilioIn0-00000002", "__CRM_LINKEDID=1519331241.2") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [+1**********@from-trunk:22] ExecIf("SIP/TwilioIn0-00000002", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [+1**********@from-trunk:23] Goto("SIP/TwilioIn0-00000002", "from-did-direct,501,1") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Goto (from-did-direct,501,1)
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] GotoIf("SIP/TwilioIn0-00000002", "0?ext-local,501,1:followme-check,501,1") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Goto (followme-check,501,1)
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] Gosub("SIP/TwilioIn0-00000002", "followme-sub,501,1()") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] Macro("SIP/TwilioIn0-00000002", "user-callerid,") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] Set("SIP/TwilioIn0-00000002", "TOUCH_MONITOR=1519331241.2") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:2] Set("SIP/TwilioIn0-00000002", "AMPUSER=+1615*******") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:3] GotoIf("SIP/TwilioIn0-00000002", "0?report") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:4] ExecIf("SIP/TwilioIn0-00000002", "1?Set(REALCALLERIDNUM=+1615*******)") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:5] Set("SIP/TwilioIn0-00000002", "AMPUSER=") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:6] GotoIf("SIP/TwilioIn0-00000002", "0?limit") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:7] Set("SIP/TwilioIn0-00000002", "AMPUSERCIDNAME=") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:8] GotoIf("SIP/TwilioIn0-00000002", "1?report") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Goto (macro-user-callerid,s,15)
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:15] GotoIf("SIP/TwilioIn0-00000002", "0?continue") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:16] ExecIf("SIP/TwilioIn0-00000002", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:17] Set("SIP/TwilioIn0-00000002", "__TTL=64") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:18] GotoIf("SIP/TwilioIn0-00000002", "1?continue") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Goto (macro-user-callerid,s,29)
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:29] Set("SIP/TwilioIn0-00000002", "CALLERID(number)=+1615*******") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:30] Set("SIP/TwilioIn0-00000002", "CALLERID(name)=john doe") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:31] GotoIf("SIP/TwilioIn0-00000002", "0?cnum") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:32] Set("SIP/TwilioIn0-00000002", "CDR(cnam)=john doe") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:33] Set("SIP/TwilioIn0-00000002", "CDR(cnum)=+1615*******") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:34] Set("SIP/TwilioIn0-00000002", "CHANNEL(language)=en") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:2] Set("SIP/TwilioIn0-00000002", "DIAL_OPTIONS=TtrI") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:3] Set("SIP/TwilioIn0-00000002", "CONNECTEDLINE(num,i)=501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:4] Gosub("SIP/TwilioIn0-00000002", "sub-presencestate-display,s,1(501)") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] Goto("SIP/TwilioIn0-00000002", "state-not_set,1") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Goto (sub-presencestate-display,state-not_set,1)
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] Set("SIP/TwilioIn0-00000002", "PRESENCESTATE_DISPLAY=") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:2] Return("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:5] Set("SIP/TwilioIn0-00000002", "CONNECTEDLINE(name)=john doe") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:6] Set("SIP/TwilioIn0-00000002", "FM_DIALSTATUS=NOT_INUSE") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:7] Set("SIP/TwilioIn0-00000002", "__EXTTOCALL=501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:8] Set("SIP/TwilioIn0-00000002", "__PICKUPMARK=501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:9] Macro("SIP/TwilioIn0-00000002", "blkvm-setifempty,") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] GotoIf("SIP/TwilioIn0-00000002", "1?init") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Goto (macro-blkvm-setifempty,s,4)
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:4] Set("SIP/TwilioIn0-00000002", "__BLKVM_CHANNEL=SIP/TwilioIn0-00000002") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:5] Set("SIP/TwilioIn0-00000002", "SHARED(BLKVM,SIP/TwilioIn0-00000002)=TRUE") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:6] Set("SIP/TwilioIn0-00000002", "GOSUB_RETVAL=TRUE") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:7] MacroExit("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:10] GotoIf("SIP/TwilioIn0-00000002", "1?skipov") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Goto (followme-sub,501,13)
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:13] Set("SIP/TwilioIn0-00000002", "RRNODEST=") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:14] Set("SIP/TwilioIn0-00000002", "__NODEST=501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:15] GosubIf("SIP/TwilioIn0-00000002", "0?sub-fmsetcid,s,1()") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:16] GotoIf("SIP/TwilioIn0-00000002", "1?skipprepend") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Goto (followme-sub,501,18)
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:18] Set("SIP/TwilioIn0-00000002", "RecordMethod=Group") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:19] Gosub("SIP/TwilioIn0-00000002", "sub-record-check,s,1(exten,501,)") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] GotoIf("SIP/TwilioIn0-00000002", "12?initialized") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Goto (sub-record-check,s,10)
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:10] NoOp("SIP/TwilioIn0-00000002", "Recordings initialized") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:11] ExecIf("SIP/TwilioIn0-00000002", "1?Set(ARG3=dontcare)") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:12] Set("SIP/TwilioIn0-00000002", "REC_POLICY_MODE_SAVE=") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:13] ExecIf("SIP/TwilioIn0-00000002", "0?Set(REC_STATUS=NO)") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:14] GotoIf("SIP/TwilioIn0-00000002", "5?checkaction") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Goto (sub-record-check,s,17)
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:17] GotoIf("SIP/TwilioIn0-00000002", "1?sub-record-check,exten,1") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Goto (sub-record-check,exten,1)
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] NoOp("SIP/TwilioIn0-00000002", "Exten Recording Check between +1615******* and 501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:2] Set("SIP/TwilioIn0-00000002", "CALLTYPE=external") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:3] ExecIf("SIP/TwilioIn0-00000002", "0?Set(CALLTYPE=)") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:4] Set("SIP/TwilioIn0-00000002", "CALLEE=dontcare") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:5] ExecIf("SIP/TwilioIn0-00000002", "0?Set(CALLEE=dontcare)") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:6] GotoIf("SIP/TwilioIn0-00000002", "1?callee") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Goto (sub-record-check,exten,11)
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:11] Gosub("SIP/TwilioIn0-00000002", "recordcheck,1(dontcare,external,501)") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] NoOp("SIP/TwilioIn0-00000002", "Starting recording check against dontcare") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:2] Goto("SIP/TwilioIn0-00000002", "dontcare") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Goto (sub-record-check,recordcheck,3)
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:3] Return("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:12] Return("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:20] GotoIf("SIP/TwilioIn0-00000002", "1?skipdring") in new stack

@lgaetz here is part 2:

[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Goto (followme-sub,501,23)
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:23] Set("SIP/TwilioIn0-00000002", "STRATEGY=hunt") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:24] Set("SIP/TwilioIn0-00000002", "__RVOL=") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:25] GotoIf("SIP/TwilioIn0-00000002", "0?skipsimple") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:26] GotoIf("SIP/TwilioIn0-00000002", "0 ?skipsimple") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:27] Macro("SIP/TwilioIn0-00000002", "simple-dial,501,15") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] Set("SIP/TwilioIn0-00000002", "__EXTTOCALL=501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:2] Set("SIP/TwilioIn0-00000002", "RT=15") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:3] Set("SIP/TwilioIn0-00000002", "CFUEXT=") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:4] Set("SIP/TwilioIn0-00000002", "CFBEXT=") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:5] Set("SIP/TwilioIn0-00000002", "CWI_TMP=") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:6] Macro("SIP/TwilioIn0-00000002", "dial-one,15,TtrI,501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] Set("SIP/TwilioIn0-00000002", "DEXTEN=501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:2] Set("SIP/TwilioIn0-00000002", "__CRM_SOURCE=+1615*******") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:3] ExecIf("SIP/TwilioIn0-00000002", "0?Set(EXTTOCALL=501)") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:4] Set("SIP/TwilioIn0-00000002", "DIALSTATUS_CW=") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:5] GosubIf("SIP/TwilioIn0-00000002", "1?screen,1()") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] GotoIf("SIP/TwilioIn0-00000002", "1?memory") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Goto (macro-dial-one,screen,3)
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:3] Set("SIP/TwilioIn0-00000002", "__SCREEN=memory") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:4] Set("SIP/TwilioIn0-00000002", "__SCREEN_EXTEN=501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:5] Set("SIP/TwilioIn0-00000002", "ARG2=TtrIp") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:6] Return("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:6] GosubIf("SIP/TwilioIn0-00000002", "0?cf,1()") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:7] GotoIf("SIP/TwilioIn0-00000002", "1?skip1") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Goto (macro-dial-one,s,10)
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:10] GotoIf("SIP/TwilioIn0-00000002", "0?nodial") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:11] GotoIf("SIP/TwilioIn0-00000002", "0?continue") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:12] Set("SIP/TwilioIn0-00000002", "EXTHASCW=ENABLED") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:13] GotoIf("SIP/TwilioIn0-00000002", "0?next1:cwinusebusy") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Goto (macro-dial-one,s,25)
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:25] GotoIf("SIP/TwilioIn0-00000002", "0?next3:continue") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Goto (macro-dial-one,s,27)
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:27] GotoIf("SIP/TwilioIn0-00000002", "0?nodial") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:28] GosubIf("SIP/TwilioIn0-00000002", "1?dstring,1():dlocal,1()") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] Set("SIP/TwilioIn0-00000002", "DSTRING=") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:2] Set("SIP/TwilioIn0-00000002", "DEVICES=501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:3] ExecIf("SIP/TwilioIn0-00000002", "0?Return()") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:4] ExecIf("SIP/TwilioIn0-00000002", "0?Set(DEVICES=01)") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:5] Set("SIP/TwilioIn0-00000002", "LOOPCNT=1") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:6] Set("SIP/TwilioIn0-00000002", "ITER=1") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:7] Set("SIP/TwilioIn0-00000002", "THISDIAL=SIP/501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:8] GosubIf("SIP/TwilioIn0-00000002", "1?zap2dahdi,1()") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] ExecIf("SIP/TwilioIn0-00000002", "0?Return()") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:2] Set("SIP/TwilioIn0-00000002", "NEWDIAL=") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:3] Set("SIP/TwilioIn0-00000002", "LOOPCNT2=1") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:4] Set("SIP/TwilioIn0-00000002", "ITER2=1") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:5] Set("SIP/TwilioIn0-00000002", "THISPART2=SIP/501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:6] ExecIf("SIP/TwilioIn0-00000002", "0?Set(THISPART2=DAHDI/501)") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:7] Set("SIP/TwilioIn0-00000002", "NEWDIAL=SIP/501&") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:8] Set("SIP/TwilioIn0-00000002", "ITER2=2") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:9] GotoIf("SIP/TwilioIn0-00000002", "0?begin2") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:10] Set("SIP/TwilioIn0-00000002", "THISDIAL=SIP/501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:11] Return("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:9] GotoIf("SIP/TwilioIn0-00000002", "1?docheck") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Goto (macro-dial-one,dstring,14)
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:14] GotoIf("SIP/TwilioIn0-00000002", "0?skipset") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:15] Set("SIP/TwilioIn0-00000002", "DSTRING=SIP/501&") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:16] Set("SIP/TwilioIn0-00000002", "ITER=2") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:17] GotoIf("SIP/TwilioIn0-00000002", "0?begin") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:18] ExecIf("SIP/TwilioIn0-00000002", "0?Return()") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:19] Set("SIP/TwilioIn0-00000002", "DSTRING=SIP/501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:20] Return("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:29] GotoIf("SIP/TwilioIn0-00000002", "0?nodial") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:30] GotoIf("SIP/TwilioIn0-00000002", "0?skiptrace") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:31] GosubIf("SIP/TwilioIn0-00000002", "1?ctset,1():ctclear,1()") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] Set("SIP/TwilioIn0-00000002", "DB(CALLTRACE/501)=+1615*******") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:2] Return("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:32] Set("SIP/TwilioIn0-00000002", "D_OPTIONS=TtrIpM(auto-blkvm)") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:33] NoOp("SIP/TwilioIn0-00000002", "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:34] ExecIf("SIP/TwilioIn0-00000002", "0?Set(ALERT_INFO=)") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:35] ExecIf("SIP/TwilioIn0-00000002", "0?Set(ALERT_INFO=)") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:36] ExecIf("SIP/TwilioIn0-00000002", "0?Set(ALERT_INFO=)") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:37] ExecIf("SIP/TwilioIn0-00000002", "0?Set(ALERT_INFO=Normal;volume=)") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:38] ExecIf("SIP/TwilioIn0-00000002", "0?Set(ALERT_INFO=Normal;volume=)") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:39] GosubIf("SIP/TwilioIn0-00000002", "0?func-set-sipheader,s,1(Alert-Info,)") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:40] ExecIf("SIP/TwilioIn0-00000002", "0?Set(CHANNEL(musicclass)=)") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:41] GosubIf("SIP/TwilioIn0-00000002", "0?qwait,1()") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:42] Set("SIP/TwilioIn0-00000002", "__CWIGNORE=") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:43] Set("SIP/TwilioIn0-00000002", "__KEEPCID=TRUE") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:44] GotoIf("SIP/TwilioIn0-00000002", "0?usegoto,1") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:45] GotoIf("SIP/TwilioIn0-00000002", "1?godial") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Goto (macro-dial-one,s,50)
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:50] Macro("SIP/TwilioIn0-00000002", "dialout-one-predial-hook,") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] MacroExit("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:51] ExecIf("SIP/TwilioIn0-00000002", "1?Set(D_OPTIONS=trIpM(auto-blkvm)I)") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:52] Dial("SIP/TwilioIn0-00000002", "SIP/501,15,trIpM(auto-blkvm)Ib(func-apply-sipheaders^s^1)") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] app_dial.c: -- Privacy Screening, clid is '+1615*******'
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] netsock2.c: == Using SIP RTP TOS bits 184
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] netsock2.c: == Using SIP RTP CoS mark 5
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] app_stack.c: -- SIP/501-00000003 Internal Gosub(func-apply-sipheaders,s,1) start
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] ExecIf("SIP/501-00000003", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:2] NoOp("SIP/501-00000003", "Applying SIP Headers to channel") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:3] Set("SIP/501-00000003", "SIPHEADERKEYS=") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:4] While("SIP/501-00000003", "0") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] app_while.c: -- Jumping to priority 7
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:8] Return("SIP/501-00000003", "") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] app_stack.c: == Spawn extension (from-internal, 501, 1) exited non-zero on 'SIP/501-00000003'
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] app_stack.c: -- SIP/501-00000003 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] app_dial.c: -- Called SIP/501
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] app_dial.c: -- Connected line update to SIP/TwilioIn0-00000002 prevented.
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] app_dial.c: -- SIP/501-00000003 is ringing
[2018-02-22 14:27:34] VERBOSE[6341][C-00000001] app_dial.c: -- Connected line update to SIP/TwilioIn0-00000002 prevented.
[2018-02-22 14:27:34] VERBOSE[6341][C-00000001] app_dial.c: -- SIP/501-00000003 answered SIP/TwilioIn0-00000002
[2018-02-22 14:27:34] VERBOSE[6341][C-00000001] file.c: -- <SIP/501-00000003> Playing 'priv-callpending.ulaw' (language 'en')
[2018-02-22 14:27:38] VERBOSE[6341][C-00000001] file.c: -- <SIP/501-00000003> Playing 'priv-callerintros/+1615*******.slin' (language 'en')
[2018-02-22 14:27:38] VERBOSE[6341][C-00000001] file.c: -- <SIP/501-00000003> Playing 'screen-callee-options.ulaw' (language 'en')
[2018-02-22 14:27:41] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] Set("SIP/501-00000003", "__MACRO_RESULT=") in new stack
[2018-02-22 14:27:41] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:2] Set("SIP/501-00000003", "CFIGNORE=") in new stack
[2018-02-22 14:27:41] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:3] Set("SIP/501-00000003", "MASTER_CHANNEL(CFIGNORE)=") in new stack
[2018-02-22 14:27:41] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:4] Set("SIP/501-00000003", "FORWARD_CONTEXT=from-internal") in new stack
[2018-02-22 14:27:41] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]lkvm:5] Set("SIP/501-00000003", "MASTER_CHANNEL(FORWARD_CONTEXT)=from-internal") in new stack
[2018-02-22 14:27:41] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:6] Macro("SIP/501-00000003", "blkvm-clr,") in new stack
[2018-02-22 14:27:41] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] Set("SIP/501-00000003", "SHARED(BLKVM,SIP/TwilioIn0-00000002)=") in new stack
[2018-02-22 14:27:41] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:2] Set("SIP/501-00000003", "GOSUB_RETVAL=") in new stack
[2018-02-22 14:27:41] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:3] MacroExit("SIP/501-00000003", "") in new stack
[2018-02-22 14:27:41] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:7] ExecIf("SIP/501-00000003", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(num))=501)") in new stack
[2018-02-22 14:27:41] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:8] ExecIf("SIP/501-00000003", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(name))=john doe)") in new stack
[2018-02-22 14:27:44] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] Macro("SIP/TwilioIn0-00000002", "hangupcall,") in new stack
[2018-02-22 14:27:44] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] ExecIf("SIP/TwilioIn0-00000002", "0?Set(CDR(recordingfile)=.wav)") in new stack
[2018-02-22 14:27:44] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:2] GotoIf("SIP/TwilioIn0-00000002", "1?theend") in new stack
[2018-02-22 14:27:44] VERBOSE[6341][C-00000001] pbx.c: -- Goto (macro-hangupcall,s,4)
[2018-02-22 14:27:44] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:4] ExecIf("SIP/TwilioIn0-00000002", "0?Set(CDR(recordingfile)=)") in new stack
[2018-02-22 14:27:44] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:5] Hangup("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:44] VERBOSE[6341][C-00000001] app_macro.c: == Spawn extension (macro-hangupcall, s, 5) exited non-zero on 'SIP/TwilioIn0-00000002' in macro 'hangupcall'
[2018-02-22 14:27:44] VERBOSE[6341][C-00000001] pbx.c: == Spawn extension (macro-dial-one, h, 1) exited non-zero on 'SIP/TwilioIn0-00000002'
[2018-02-22 14:27:44] VERBOSE[6341][C-00000001] app_stack.c: -- SIP/TwilioIn0-00000002 Internal Gosub(crm-hangup,s,1) start
[2018-02-22 14:27:44] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] NoOp("SIP/TwilioIn0-00000002", "Sending Hangup to CRM") in new stack
[2018-02-22 14:27:44] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:2] NoOp("SIP/TwilioIn0-00000002", "HANGUP CAUSE: 16") in new stack
[2018-02-22 14:27:44] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:3] ExecIf("SIP/TwilioIn0-00000002", "0?Set(__CRM_VOICEMAIL=)") in new stack
[2018-02-22 14:27:44] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:4] NoOp("SIP/TwilioIn0-00000002", "MASTER CHANNEL: 1519331241.2 = 1519331241.2") in new stack
[2018-02-22 14:27:44] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:5] GotoIf("SIP/TwilioIn0-00000002", "0?return") in new stack
[2018-02-22 14:27:44] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:6] Set("SIP/TwilioIn0-00000002", "__CRM_HANGUP=1") in new stack
[2018-02-22 14:27:44] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:7] AGI("SIP/TwilioIn0-00000002", "sangomacrm.agi") in new stack
[2018-02-22 14:27:44] VERBOSE[6341][C-00000001] res_agi.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2018-02-22 14:27:47] VERBOSE[6341][C-00000001] res_agi.c: -- <SIP/TwilioIn0-00000002>AGI Script sangomacrm.agi completed, returning 0
[2018-02-22 14:27:47] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:8] Return("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:47] VERBOSE[6341][C-00000001] app_stack.c: == Spawn extension (macro-dial-one, h, 1) exited non-zero on 'SIP/TwilioIn0-00000002'
[2018-02-22 14:27:47] VERBOSE[6341][C-00000001] app_stack.c: -- SIP/TwilioIn0-00000002 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2018-02-22 14:27:47] VERBOSE[6341][C-00000001] app_stack.c: -- SIP/501-00000003 Internal Gosub(crm-hangup,s,1) start
[2018-02-22 14:27:47] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:1] NoOp("SIP/501-00000003", "Sending Hangup to CRM") in new stack
[2018-02-22 14:27:47] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:2] NoOp("SIP/501-00000003", "HANGUP CAUSE: 16") in new stack
[2018-02-22 14:27:47] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:3] ExecIf("SIP/501-00000003", "0?Set(__CRM_VOICEMAIL=)") in new stack
[2018-02-22 14:27:47] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:4] NoOp("SIP/501-00000003", "MASTER CHANNEL: 1519331247.3 = 1519331241.2") in new stack
[2018-02-22 14:27:47] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:5] GotoIf("SIP/501-00000003", "1?return") in new stack
[2018-02-22 14:27:47] VERBOSE[6341][C-00000001] pbx.c: -- Goto (crm-hangup,s,8)
[2018-02-22 14:27:47] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:8] Return("SIP/501-00000003", "") in new stack
[2018-02-22 14:27:47] VERBOSE[6341][C-00000001] app_stack.c: == Spawn extension (macro-dial-one, s, 1) exited non-zero on 'SIP/501-00000003'
[2018-02-22 14:27:47] VERBOSE[6341][C-00000001] app_stack.c: -- SIP/501-00000003 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2018-02-22 14:27:47] VERBOSE[6341][C-00000001] app_macro.c: == Spawn extension (macro-dial-one, s, 52) exited non-zero on 'SIP/TwilioIn0-00000002' in macro 'dial-one'
[2018-02-22 14:27:47] VERBOSE[6341][C-00000001] app_macro.c: == Spawn extension (macro-simple-dial, s, 6) exited non-zero on 'SIP/TwilioIn0-00000002' in macro 'simple-dial'
[2018-02-22 14:27:47] VERBOSE[6341][C-00000001] pbx.c: == Spawn extension (followme-sub, 501, 27) exited non-zero on 'SIP/TwilioIn0-00000002'

Hi @shelton:

We can see that the dial line for ext 501 looks like this:

[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [[email protected]:52] Dial("SIP/TwilioIn0-00000002", "SIP/501,15,trIpM(auto-blkvm)Ib(func-apply-sipheaders^s^1)") in new stack

with these dial options:

trIpM(auto-blkvm)Ib(func-apply-sipheaders^s^1)

The lower case p is what sets privacy mode, and it is written properly, but the call still goes on to ring 501 without prompting the caller to record their name. It works in my testing. Perhaps the reason it’s not working for you might be because of the double I or perhaps it’s the M(auto-blkvm). I don’t have time to chase this further, but it looks like it might be a bug, so feel free to file a report at http://issues.freepbx.org/

@lgaetz OK thanks for at least looking at it and trying to help me out!

When I toggle FMFM on for the extension, I see what you see, Privacy manager fails. Can you provide a trace with FMFM disabled.

FYI the p option in the dial tells asterisk to start the privacy application. Unfortunately this is written in pure C and so FreePBX does not control this except to add or not add the p option.

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