The strange thing is it was working perfectly before.
Attached is what I have in the log for the incoming call. If there is a better way to log please let me know.
Since this log was taken, i’ve disabled Google portion and cleared credentials. Reactivated…Run the “debug” followed the link to get the activation code, put it back in. And again the same issue.
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [12896344334@from-trunk:1] Set("SIP/FPLOuT-00000049", "__DIRECTION=INBOUND") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [12896344334@from-trunk:2] Gosub("SIP/FPLOuT-00000049", "sub-record-check,s,1(in,12896344334,force)") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@sub-record-check:1] GotoIf("SIP/FPLOuT-00000049", "0?initialized") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@sub-record-check:2] Set("SIP/FPLOuT-00000049", "__REC_STATUS=INITIALIZED") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@sub-record-check:3] Set("SIP/FPLOuT-00000049", "NOW=1553186590") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@sub-record-check:4] Set("SIP/FPLOuT-00000049", "__DAY=21") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@sub-record-check:5] Set("SIP/FPLOuT-00000049", "__MONTH=03") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@sub-record-check:6] Set("SIP/FPLOuT-00000049", "__YEAR=2019") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@sub-record-check:7] Set("SIP/FPLOuT-00000049", "__TIMESTR=20190321-124310") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@sub-record-check:8] Set("SIP/FPLOuT-00000049", "__FROMEXTEN=unknown") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@sub-record-check:9] Set("SIP/FPLOuT-00000049", "__MON_FMT=wav") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@sub-record-check:10] NoOp("SIP/FPLOuT-00000049", "Recordings initialized") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@sub-record-check:11] ExecIf("SIP/FPLOuT-00000049", "0?Set(ARG3=dontcare)") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@sub-record-check:12] Set("SIP/FPLOuT-00000049", "REC_POLICY_MODE_SAVE=") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@sub-record-check:13] ExecIf("SIP/FPLOuT-00000049", "0?Set(REC_STATUS=NO)") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@sub-record-check:14] GotoIf("SIP/FPLOuT-00000049", "2?checkaction") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx_builtins.c: Goto (sub-record-check,s,17)
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@sub-record-check:17] GotoIf("SIP/FPLOuT-00000049", "1?sub-record-check,in,1") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx_builtins.c: Goto (sub-record-check,in,1)
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [in@sub-record-check:1] NoOp("SIP/FPLOuT-00000049", "Inbound Recording Check to 12891234567") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [in@sub-record-check:2] Set("SIP/FPLOuT-00000049", "FROMEXTEN=unknown") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [in@sub-record-check:3] ExecIf("SIP/FPLOuT-00000049", "10?Set(FROMEXTEN=9051237918)") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [in@sub-record-check:4] Gosub("SIP/FPLOuT-00000049", "recordcheck,1(force,in,12891234567)") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("SIP/FPLOuT-00000049", "Starting recording check against force") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("SIP/FPLOuT-00000049", "force") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx_builtins.c: Goto (sub-record-check,recordcheck,5)
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [recordcheck@sub-record-check:5] Set("SIP/FPLOuT-00000049", "__REC_POLICY_MODE=FORCE") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [recordcheck@sub-record-check:6] GotoIf("SIP/FPLOuT-00000049", "1?startrec") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx_builtins.c: Goto (sub-record-check,recordcheck,16)
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [recordcheck@sub-record-check:16] NoOp("SIP/FPLOuT-00000049", "Starting recording: in, 12891234567") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [recordcheck@sub-record-check:17] Set("SIP/FPLOuT-00000049", "__CALLFILENAME=in-12891234567-9051237918-20190321-124310-1553186590.89") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [recordcheck@sub-record-check:18] MixMonitor("SIP/FPLOuT-00000049", "2019/03/21/in-12891234567-9051237918-20190321-124310-1553186590.89.wav,abi(LOCAL_MIXMON_ID),") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [recordcheck@sub-record-check:19] Set("SIP/FPLOuT-00000049", "__MIXMON_ID=0x7fe3e0049e60") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [recordcheck@sub-record-check:20] Set("SIP/FPLOuT-00000049", "__RECORD_ID=SIP/FPLOuT-00000049") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [recordcheck@sub-record-check:21] Set("SIP/FPLOuT-00000049", "__REC_STATUS=RECORDING") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [recordcheck@sub-record-check:22] Set("SIP/FPLOuT-00000049", "CDR(recordingfile)=in-12891234567-9051237918-20190321-124310-1553186590.89.wav") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [recordcheck@sub-record-check:23] Return("SIP/FPLOuT-00000049", "") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [in@sub-record-check:5] Return("SIP/FPLOuT-00000049", "") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [12891234567@from-trunk:3] Set("SIP/FPLOuT-00000049", "CHANNEL(tonezone)=us") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [12891234567@from-trunk:4] Set("SIP/FPLOuT-00000049", "__FROM_DID=12891234567") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [12891234567@from-trunk:5] Set("SIP/FPLOuT-00000049", "returnhere=1") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [12891234567@from-trunk:6] Gosub("SIP/FPLOuT-00000049", "app-blacklist-check,s,1()") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@app-blacklist-check:1] GotoIf("SIP/FPLOuT-00000049", "0?blacklisted") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@app-blacklist-check:2] Set("SIP/FPLOuT-00000049", "CALLED_BLACKLIST=1") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@app-blacklist-check:3] Return("SIP/FPLOuT-00000049", "") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [12891234567@from-trunk:7] Set("SIP/FPLOuT-00000049", "CDR(did)=12891234567") in new stack
> [2019-03-21 12:43:10] VERBOSE[18681][C-0000002a] app_mixmonitor.c: Begin MixMonitor Recording SIP/FPLOuT-00000049
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [12891234567@from-trunk:8] GotoIf("SIP/FPLOuT-00000049", "0?") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [12891234567@from-trunk:9] ExecIf("SIP/FPLOuT-00000049", "0 ?Set(CALLERID(name)=9051237918)") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [12891234567@from-trunk:10] Set("SIP/FPLOuT-00000049", "__MOHCLASS=") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [12891234567@from-trunk:11] Set("SIP/FPLOuT-00000049", "__REVERSAL_REJECT=FALSE") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [12891234567@from-trunk:12] GotoIf("SIP/FPLOuT-00000049", "1?post-reverse-charge") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx_builtins.c: Goto (from-trunk,12891234567,14)
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [12891234567@from-trunk:14] NoOp("SIP/FPLOuT-00000049", "") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [12891234567@from-trunk:15] Macro("SIP/FPLOuT-00000049", "privacy-mgr,3,10") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-privacy-mgr:1] Set("SIP/FPLOuT-00000049", "KEEPCID=9051237918") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-privacy-mgr:2] Set("SIP/FPLOuT-00000049", "TESTCID=9056979188.000000") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-privacy-mgr:3] ExecIf("SIP/FPLOuT-00000049", "0?Set(CALLERID(num)=)") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-privacy-mgr:4] PrivacyManager("SIP/FPLOuT-00000049", "3,10") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] app_privacy.c: CallerID number present: Skipping
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-privacy-mgr:5] GotoIf("SIP/FPLOuT-00000049", "0?fail") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-privacy-mgr:6] GosubIf("SIP/FPLOuT-00000049", "1?app-blacklist-check,s,1()") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@app-blacklist-check:1] GotoIf("SIP/FPLOuT-00000049", "0?blacklisted") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@app-blacklist-check:2] Set("SIP/FPLOuT-00000049", "CALLED_BLACKLIST=1") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@app-blacklist-check:3] Return("SIP/FPLOuT-00000049", "") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-privacy-mgr:7] Set("SIP/FPLOuT-00000049", "CALLERID(num-pres)=allowed_passed_screen") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-privacy-mgr:8] MacroExit("SIP/FPLOuT-00000049", "") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [12891234567@from-trunk:16] Set("SIP/FPLOuT-00000049", "CIDSFSCHEME=YmFzZV9EZWZhdWx0") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] pbx.c: Executing [12891234567@from-trunk:17] AGI("SIP/FPLOuT-00000049", "/var/www/html/admin/modules/superfecta/agi/superfecta.agi") in new stack
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] res_agi.c: Launched AGI Script /var/www/html/admin/modules/superfecta/agi/superfecta.agi
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] res_agi.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: Executing Scheme..
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] res_agi.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: Scheme Asked is: Default
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] res_agi.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: The DID is: 12891234567
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] res_agi.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: The CNUM is: 9051237918
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] res_agi.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: The CNAME is: Smith D .
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] res_agi.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi:
> [2019-03-21 12:43:10] VERBOSE[18678][C-0000002a] res_agi.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: Starting scheme Default
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] res_agi.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: No callerid found
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] res_agi.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Determined to be: 'Smith D .'
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] res_agi.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: Attempting to set lookupcid
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] res_agi.c: <SIP/FPLOuT-00000049>AGI Script /var/www/html/admin/modules/superfecta/agi/superfecta.agi completed, returning 0
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [12891234567@from-trunk:18] Set("SIP/FPLOuT-00000049", "CALLERID(name)=Smith D .") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [12891234567@from-trunk:19] NoOp("SIP/FPLOuT-00000049", "CallerID Entry Point") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [12891234567@from-trunk:20] Goto("SIP/FPLOuT-00000049", "timeconditions,1,1") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx_builtins.c: Goto (timeconditions,1,1)
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [1@timeconditions:1] Set("SIP/FPLOuT-00000049", "DB(TC/1/INUSESTATE)=INUSE") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [1@timeconditions:2] Set("SIP/FPLOuT-00000049", "DB(TC/1/NOT_INUSESTATE)=NOT_INUSE") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [1@timeconditions:3] NoOp("SIP/FPLOuT-00000049", "TIMENOW: 12:43,Thu,21,Mar,America/Toronto") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [1@timeconditions:4] NoOp("SIP/FPLOuT-00000049", "TIMEMATCHED: FALSE") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [1@timeconditions:5] GotoIfTime("SIP/FPLOuT-00000049", "22:10-07:15,mon-fri,*,*,America/Toronto?truestate") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [1@timeconditions:6] NoOp("SIP/FPLOuT-00000049", "TIMENOW: 12:43,Thu,21,Mar,America/Toronto") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [1@timeconditions:7] NoOp("SIP/FPLOuT-00000049", "TIMEMATCHED: FALSE") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [1@timeconditions:8] GotoIfTime("SIP/FPLOuT-00000049", "22:30-09:00,sat-sun,*,*,America/Toronto?truestate") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [1@timeconditions:9] GotoIf("SIP/FPLOuT-00000049", "0?truegoto") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [1@timeconditions:10] ExecIf("SIP/FPLOuT-00000049", "0?Set(DB(TC/1)=)") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [1@timeconditions:11] Set("SIP/FPLOuT-00000049", "DEVICE_STATE(Custom:TC1)=INUSE") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [1@timeconditions:12] ExecIf("SIP/FPLOuT-00000049", "0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [1@timeconditions:13] GotoIf("SIP/FPLOuT-00000049", "1?ext-group,600,1") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx_builtins.c: Goto (ext-group,600,1)
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [600@ext-group:1] GotoIf("SIP/FPLOuT-00000049", "0?cid") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [600@ext-group:2] PlayTones("SIP/FPLOuT-00000049", "ring") in new stack
> [2019-03-21 12:43:38] WARNING[18678][C-0000002a] translate.c: no samples for ulawtolin
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [600@ext-group:3] Progress("SIP/FPLOuT-00000049", "") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [600@ext-group:4] Macro("SIP/FPLOuT-00000049", "user-callerid,") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-user-callerid:1] Set("SIP/FPLOuT-00000049", "TOUCH_MONITOR=1553186590.89") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-user-callerid:2] Set("SIP/FPLOuT-00000049", "AMPUSER=9051237918") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("SIP/FPLOuT-00000049", "0?report") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-user-callerid:4] ExecIf("SIP/FPLOuT-00000049", "1?Set(REALCALLERIDNUM=9051237918)") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-user-callerid:5] Set("SIP/FPLOuT-00000049", "AMPUSER=") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-user-callerid:6] GotoIf("SIP/FPLOuT-00000049", "0?limit") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-user-callerid:7] Set("SIP/FPLOuT-00000049", "AMPUSERCIDNAME=") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-user-callerid:8] ExecIf("SIP/FPLOuT-00000049", "0?Set(__CIDMASQUERADING=TRUE)") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-user-callerid:9] GotoIf("SIP/FPLOuT-00000049", "1?report") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx_builtins.c: Goto (macro-user-callerid,s,16)
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-user-callerid:16] NoOp("SIP/FPLOuT-00000049", "Macro Depth is 1") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-user-callerid:17] GotoIf("SIP/FPLOuT-00000049", "1?report2:macroerror") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx_builtins.c: Goto (macro-user-callerid,s,18)
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-user-callerid:18] GotoIf("SIP/FPLOuT-00000049", "0?continue") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-user-callerid:19] ExecIf("SIP/FPLOuT-00000049", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-user-callerid:20] Set("SIP/FPLOuT-00000049", "__TTL=64") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-user-callerid:21] GotoIf("SIP/FPLOuT-00000049", "1?continue") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx_builtins.c: Goto (macro-user-callerid,s,37)
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-user-callerid:37] Set("SIP/FPLOuT-00000049", "CALLERID(number)=9051237918") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-user-callerid:38] Set("SIP/FPLOuT-00000049", "CALLERID(name)=Smith D .") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-user-callerid:39] GotoIf("SIP/FPLOuT-00000049", "0?cnum") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-user-callerid:40] Set("SIP/FPLOuT-00000049", "CDR(cnam)=Smith D .") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [h@ext-group:1] Macro("SIP/FPLOuT-00000049", "hangupcall,") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("SIP/FPLOuT-00000049", "1?theend") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx_builtins.c: Goto (macro-hangupcall,s,3)
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("SIP/FPLOuT-00000049", "0?Set(CDR(recordingfile)=)") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-hangupcall:4] NoOp("SIP/FPLOuT-00000049", " monior file= /var/spool/asterisk/monitor/2019/03/21/in-12891231234-9051237918-20190321-124310-1553186590.89.wav") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-hangupcall:5] AGI("SIP/FPLOuT-00000049", "attendedtransfer-rec-restart.php,,/var/spool/asterisk/monitor/2019/03/21/in-12891231234-9051237918-20190321-124310-1553186590.89.wav") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/attendedtransfer-rec-restart.php
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] res_agi.c: <SIP/FPLOuT-00000049>AGI Script attendedtransfer-rec-restart.php completed, returning 0
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Executing [s@macro-hangupcall:6] Hangup("SIP/FPLOuT-00000049", "") in new stack
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] app_macro.c: Spawn extension (macro-hangupcall, s, 6) exited non-zero on 'SIP/FPLOuT-00000049' in macro 'hangupcall'
> [2019-03-21 12:43:38] VERBOSE[18678][C-0000002a] pbx.c: Spawn extension (ext-group, h, 1) exited non-zero on 'SIP/FPLOuT-00000049'
> [2019-03-21 12:43:38] VERBOSE[18681][C-0000002a] app_mixmonitor.c: MixMonitor close filestream (mixed)
> [2019-03-21 12:43:38] VERBOSE[18681][C-0000002a] app_mixmonitor.c: End MixMonitor Recording SIP/FPLOuT-00000049
> [2019-03-21 12:44:03] VERBOSE[2270][C-0000002b] netsock2.c: Using SIP RTP TOS bits 184
> [2019-03-21 12:44:03] VERBOSE[2270][C-0000002b] netsock2.c: Using SIP RTP CoS mark 5