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
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 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 [s@sub-record-check:1] GotoIf("SIP/TwilioIn0-00000002", "0?initialized") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@sub-record-check:2] Set("SIP/TwilioIn0-00000002", "__REC_STATUS=INITIALIZED") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@sub-record-check:3] Set("SIP/TwilioIn0-00000002", "NOW=1519331241") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@sub-record-check:4] Set("SIP/TwilioIn0-00000002", "__DAY=22") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@sub-record-check:5] Set("SIP/TwilioIn0-00000002", "__MONTH=02") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@sub-record-check:6] Set("SIP/TwilioIn0-00000002", "__YEAR=2018") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@sub-record-check:7] Set("SIP/TwilioIn0-00000002", "__TIMESTR=20180222-142721") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@sub-record-check:8] Set("SIP/TwilioIn0-00000002", "__FROMEXTEN=unknown") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@sub-record-check:9] Set("SIP/TwilioIn0-00000002", "__MON_FMT=wav") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@sub-record-check:10] NoOp("SIP/TwilioIn0-00000002", "Recordings initialized") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [in@sub-record-check: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 [in@sub-record-check:2] Set("SIP/TwilioIn0-00000002", "FROMEXTEN=unknown") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [in@sub-record-check: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 [in@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check:3] Return("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [in@sub-record-check: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 [s@app-blacklist-check:1] GotoIf("SIP/TwilioIn0-00000002", "0?blacklisted") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@app-blacklist-check:2] Set("SIP/TwilioIn0-00000002", "CALLED_BLACKLIST=1") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@app-blacklist-check: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 [s@macro-privacy-mgr:1] Set("SIP/TwilioIn0-00000002", "KEEPCID=+1615*******") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-privacy-mgr:2] Set("SIP/TwilioIn0-00000002", "TESTCID=16155795879.000000") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-privacy-mgr: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 [s@macro-privacy-mgr: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 [s@macro-privacy-mgr:5] GotoIf("SIP/TwilioIn0-00000002", "0?fail") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-privacy-mgr: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 [s@app-blacklist-check:1] GotoIf("SIP/TwilioIn0-00000002", "0?blacklisted") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@app-blacklist-check:2] Set("SIP/TwilioIn0-00000002", "CALLED_BLACKLIST=1") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@app-blacklist-check:3] Return("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:21] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-privacy-mgr: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 [s@macro-privacy-mgr: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 [cidlookup_2@cidlookup:1] Set("SIP/TwilioIn0-00000002", "CURLOPT(httptimeout)=7") in new stack
[2018-02-22 14:27:22] VERBOSE[6341][C-00000001] pbx.c: -- Executing [cidlookup_2@cidlookup: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 [cidlookup_2@cidlookup: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 [501@from-did-direct: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 [501@followme-check: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 [501@followme-sub:1] Macro("SIP/TwilioIn0-00000002", "user-callerid,") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-user-callerid: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 [s@macro-user-callerid:2] Set("SIP/TwilioIn0-00000002", "AMPUSER=+1615*******") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-user-callerid:3] GotoIf("SIP/TwilioIn0-00000002", "0?report") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-user-callerid: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 [s@macro-user-callerid:5] Set("SIP/TwilioIn0-00000002", "AMPUSER=") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/TwilioIn0-00000002", "0?limit") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-user-callerid:7] Set("SIP/TwilioIn0-00000002", "AMPUSERCIDNAME=") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-user-callerid: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 [s@macro-user-callerid:15] GotoIf("SIP/TwilioIn0-00000002", "0?continue") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-user-callerid: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 [s@macro-user-callerid:17] Set("SIP/TwilioIn0-00000002", "__TTL=64") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-user-callerid: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 [s@macro-user-callerid:29] Set("SIP/TwilioIn0-00000002", "CALLERID(number)=+1615*******") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-user-callerid: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 [s@macro-user-callerid:31] GotoIf("SIP/TwilioIn0-00000002", "0?cnum") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-user-callerid: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 [s@macro-user-callerid:33] Set("SIP/TwilioIn0-00000002", "CDR(cnum)=+1615*******") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-user-callerid:34] Set("SIP/TwilioIn0-00000002", "CHANNEL(language)=en") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [501@followme-sub:2] Set("SIP/TwilioIn0-00000002", "DIAL_OPTIONS=TtrI") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [501@followme-sub: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 [501@followme-sub: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 [s@sub-presencestate-display: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 [state-not_set@sub-presencestate-display:1] Set("SIP/TwilioIn0-00000002", "PRESENCESTATE_DISPLAY=") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [state-not_set@sub-presencestate-display:2] Return("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [501@followme-sub: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 [501@followme-sub: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 [501@followme-sub:7] Set("SIP/TwilioIn0-00000002", "__EXTTOCALL=501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [501@followme-sub:8] Set("SIP/TwilioIn0-00000002", "__PICKUPMARK=501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [501@followme-sub:9] Macro("SIP/TwilioIn0-00000002", "blkvm-setifempty,") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-blkvm-setifempty: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 [s@macro-blkvm-setifempty: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 [s@macro-blkvm-setifempty: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 [s@macro-blkvm-setifempty:6] Set("SIP/TwilioIn0-00000002", "GOSUB_RETVAL=TRUE") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-blkvm-setifempty:7] MacroExit("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [501@followme-sub: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 [501@followme-sub:13] Set("SIP/TwilioIn0-00000002", "RRNODEST=") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [501@followme-sub:14] Set("SIP/TwilioIn0-00000002", "__NODEST=501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [501@followme-sub: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 [501@followme-sub: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 [501@followme-sub:18] Set("SIP/TwilioIn0-00000002", "RecordMethod=Group") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [501@followme-sub: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 [s@sub-record-check: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 [s@sub-record-check:10] NoOp("SIP/TwilioIn0-00000002", "Recordings initialized") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [exten@sub-record-check: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 [exten@sub-record-check:2] Set("SIP/TwilioIn0-00000002", "CALLTYPE=external") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [exten@sub-record-check:3] ExecIf("SIP/TwilioIn0-00000002", "0?Set(CALLTYPE=)") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [exten@sub-record-check:4] Set("SIP/TwilioIn0-00000002", "CALLEE=dontcare") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [exten@sub-record-check: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 [exten@sub-record-check: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 [exten@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check:3] Return("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [exten@sub-record-check:12] Return("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [501@followme-sub: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 [501@followme-sub:23] Set("SIP/TwilioIn0-00000002", "STRATEGY=hunt") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [501@followme-sub:24] Set("SIP/TwilioIn0-00000002", "__RVOL=") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [501@followme-sub:25] GotoIf("SIP/TwilioIn0-00000002", "0?skipsimple") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [501@followme-sub:26] GotoIf("SIP/TwilioIn0-00000002", "0 ?skipsimple") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [501@followme-sub: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 [s@macro-simple-dial:1] Set("SIP/TwilioIn0-00000002", "__EXTTOCALL=501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-simple-dial:2] Set("SIP/TwilioIn0-00000002", "RT=15") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-simple-dial:3] Set("SIP/TwilioIn0-00000002", "CFUEXT=") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-simple-dial:4] Set("SIP/TwilioIn0-00000002", "CFBEXT=") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-simple-dial:5] Set("SIP/TwilioIn0-00000002", "CWI_TMP=") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-simple-dial: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 [s@macro-dial-one:1] Set("SIP/TwilioIn0-00000002", "DEXTEN=501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-dial-one:2] Set("SIP/TwilioIn0-00000002", "__CRM_SOURCE=+1615*******") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-dial-one: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 [s@macro-dial-one:4] Set("SIP/TwilioIn0-00000002", "DIALSTATUS_CW=") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-dial-one:5] GosubIf("SIP/TwilioIn0-00000002", "1?screen,1()") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [screen@macro-dial-one: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 [screen@macro-dial-one:3] Set("SIP/TwilioIn0-00000002", "__SCREEN=memory") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [screen@macro-dial-one:4] Set("SIP/TwilioIn0-00000002", "__SCREEN_EXTEN=501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [screen@macro-dial-one:5] Set("SIP/TwilioIn0-00000002", "ARG2=TtrIp") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [screen@macro-dial-one:6] Return("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-dial-one:6] GosubIf("SIP/TwilioIn0-00000002", "0?cf,1()") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-dial-one: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 [s@macro-dial-one:10] GotoIf("SIP/TwilioIn0-00000002", "0?nodial") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-dial-one:11] GotoIf("SIP/TwilioIn0-00000002", "0?continue") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-dial-one:12] Set("SIP/TwilioIn0-00000002", "EXTHASCW=ENABLED") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dial-one:27] GotoIf("SIP/TwilioIn0-00000002", "0?nodial") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-dial-one: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 [dstring@macro-dial-one:1] Set("SIP/TwilioIn0-00000002", "DSTRING=") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [dstring@macro-dial-one:2] Set("SIP/TwilioIn0-00000002", "DEVICES=501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [dstring@macro-dial-one:3] ExecIf("SIP/TwilioIn0-00000002", "0?Return()") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [dstring@macro-dial-one: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 [dstring@macro-dial-one:5] Set("SIP/TwilioIn0-00000002", "LOOPCNT=1") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [dstring@macro-dial-one:6] Set("SIP/TwilioIn0-00000002", "ITER=1") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [dstring@macro-dial-one:7] Set("SIP/TwilioIn0-00000002", "THISDIAL=SIP/501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [dstring@macro-dial-one:8] GosubIf("SIP/TwilioIn0-00000002", "1?zap2dahdi,1()") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [zap2dahdi@macro-dial-one:1] ExecIf("SIP/TwilioIn0-00000002", "0?Return()") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [zap2dahdi@macro-dial-one:2] Set("SIP/TwilioIn0-00000002", "NEWDIAL=") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [zap2dahdi@macro-dial-one:3] Set("SIP/TwilioIn0-00000002", "LOOPCNT2=1") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [zap2dahdi@macro-dial-one:4] Set("SIP/TwilioIn0-00000002", "ITER2=1") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [zap2dahdi@macro-dial-one:5] Set("SIP/TwilioIn0-00000002", "THISPART2=SIP/501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [zap2dahdi@macro-dial-one: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 [zap2dahdi@macro-dial-one:7] Set("SIP/TwilioIn0-00000002", "NEWDIAL=SIP/501&") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [zap2dahdi@macro-dial-one:8] Set("SIP/TwilioIn0-00000002", "ITER2=2") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [zap2dahdi@macro-dial-one:9] GotoIf("SIP/TwilioIn0-00000002", "0?begin2") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [zap2dahdi@macro-dial-one:10] Set("SIP/TwilioIn0-00000002", "THISDIAL=SIP/501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [zap2dahdi@macro-dial-one:11] Return("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [dstring@macro-dial-one: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 [dstring@macro-dial-one:14] GotoIf("SIP/TwilioIn0-00000002", "0?skipset") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [dstring@macro-dial-one:15] Set("SIP/TwilioIn0-00000002", "DSTRING=SIP/501&") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [dstring@macro-dial-one:16] Set("SIP/TwilioIn0-00000002", "ITER=2") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [dstring@macro-dial-one:17] GotoIf("SIP/TwilioIn0-00000002", "0?begin") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [dstring@macro-dial-one:18] ExecIf("SIP/TwilioIn0-00000002", "0?Return()") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [dstring@macro-dial-one:19] Set("SIP/TwilioIn0-00000002", "DSTRING=SIP/501") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [dstring@macro-dial-one:20] Return("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-dial-one:29] GotoIf("SIP/TwilioIn0-00000002", "0?nodial") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-dial-one:30] GotoIf("SIP/TwilioIn0-00000002", "0?skiptrace") in new stack
[2018-02-22 14:27:26] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-dial-one: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 [ctset@macro-dial-one: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 [ctset@macro-dial-one:2] Return("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dial-one:41] GosubIf("SIP/TwilioIn0-00000002", "0?qwait,1()") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-dial-one:42] Set("SIP/TwilioIn0-00000002", "__CWIGNORE=") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-dial-one:43] Set("SIP/TwilioIn0-00000002", "__KEEPCID=TRUE") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-dial-one:44] GotoIf("SIP/TwilioIn0-00000002", "0?usegoto,1") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dialout-one-predial-hook:1] MacroExit("SIP/TwilioIn0-00000002", "") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-dial-one: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 [s@macro-dial-one: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 [s@func-apply-sipheaders: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 [s@func-apply-sipheaders: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 [s@func-apply-sipheaders:3] Set("SIP/501-00000003", "SIPHEADERKEYS=") in new stack
[2018-02-22 14:27:27] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@func-apply-sipheaders: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 [s@func-apply-sipheaders: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 [s@macro-auto-blkvm:1] Set("SIP/501-00000003", "__MACRO_RESULT=") in new stack
[2018-02-22 14:27:41] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-auto-blkvm:2] Set("SIP/501-00000003", "CFIGNORE=") in new stack
[2018-02-22 14:27:41] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-auto-blkvm:3] Set("SIP/501-00000003", "MASTER_CHANNEL(CFIGNORE)=") in new stack
[2018-02-22 14:27:41] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-auto-blkvm: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 [s@macro-auto-blkvm: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 [s@macro-auto-blkvm:6] Macro("SIP/501-00000003", "blkvm-clr,") in new stack
[2018-02-22 14:27:41] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-blkvm-clr: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 [s@macro-blkvm-clr:2] Set("SIP/501-00000003", "GOSUB_RETVAL=") in new stack
[2018-02-22 14:27:41] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-blkvm-clr:3] MacroExit("SIP/501-00000003", "") in new stack
[2018-02-22 14:27:41] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-auto-blkvm: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 [s@macro-auto-blkvm: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 [h@macro-dial-one:1] Macro("SIP/TwilioIn0-00000002", "hangupcall,") in new stack
[2018-02-22 14:27:44] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@macro-hangupcall: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 [s@macro-hangupcall: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 [s@macro-hangupcall: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 [s@macro-hangupcall: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 [s@crm-hangup: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 [s@crm-hangup:2] NoOp("SIP/TwilioIn0-00000002", "HANGUP CAUSE: 16") in new stack
[2018-02-22 14:27:44] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@crm-hangup: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 [s@crm-hangup: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 [s@crm-hangup:5] GotoIf("SIP/TwilioIn0-00000002", "0?return") in new stack
[2018-02-22 14:27:44] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@crm-hangup:6] Set("SIP/TwilioIn0-00000002", "__CRM_HANGUP=1") in new stack
[2018-02-22 14:27:44] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@crm-hangup: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 [s@crm-hangup: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 [s@crm-hangup: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 [s@crm-hangup:2] NoOp("SIP/501-00000003", "HANGUP CAUSE: 16") in new stack
[2018-02-22 14:27:47] VERBOSE[6341][C-00000001] pbx.c: -- Executing [s@crm-hangup: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 [s@crm-hangup: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 [s@crm-hangup: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 [s@crm-hangup: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 [s@macro-dial-one: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/
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.