[2019-09-17 12:34:59] VERBOSE[11558] asterisk.c: Remote UNIX connection disconnected [2019-09-17 12:35:21] VERBOSE[8199] asterisk.c: Remote UNIX connection [2019-09-17 12:35:21] VERBOSE[11619] asterisk.c: Remote UNIX connection disconnected [2019-09-17 12:35:21] VERBOSE[8199] asterisk.c: Remote UNIX connection [2019-09-17 12:35:21] VERBOSE[11621] asterisk.c: Remote UNIX connection disconnected [2019-09-17 12:35:21] VERBOSE[8199] asterisk.c: Remote UNIX connection [2019-09-17 12:35:21] VERBOSE[11623] asterisk.c: Remote UNIX connection disconnected [2019-09-17 12:35:34] VERBOSE[8199] asterisk.c: Remote UNIX connection [2019-09-17 12:35:34] VERBOSE[11731] asterisk.c: Remote UNIX connection disconnected [2019-09-17 12:35:34] VERBOSE[8199] asterisk.c: Remote UNIX connection [2019-09-17 12:35:34] VERBOSE[11733] asterisk.c: Remote UNIX connection disconnected [2019-09-17 12:35:34] VERBOSE[8199] asterisk.c: Remote UNIX connection [2019-09-17 12:35:34] VERBOSE[11735] asterisk.c: Remote UNIX connection disconnected [2019-09-17 12:36:07] VERBOSE[8872][C-0000001e] netsock2.c: Using SIP RTP TOS bits 184 [2019-09-17 12:36:07] VERBOSE[8872][C-0000001e] netsock2.c: Using SIP RTP CoS mark 5 [2019-09-17 12:36:07] VERBOSE[8270] chan_sip.c: Extension Changed 26[ext-local] new state InUse for Notify User 33 [2019-09-17 12:36:07] VERBOSE[8270] chan_sip.c: Extension Changed 26[ext-local] new state InUse for Notify User 30 [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [25@from-internal:1] GotoIf("SIP/26-00000044", "1?ext-local,25,1:followme-check,25,1") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx_builtins.c: Goto (ext-local,25,1) [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [25@ext-local:1] Set("SIP/26-00000044", "__RINGTIMER=15") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [25@ext-local:2] Macro("SIP/26-00000044", "exten-vm,25,25,0,0,0") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-exten-vm:1] Macro("SIP/26-00000044", "user-callerid,") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:1] Set("SIP/26-00000044", "TOUCH_MONITOR=1568741767.238") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:2] Set("SIP/26-00000044", "AMPUSER=26") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("SIP/26-00000044", "0?report") in new stack [2019-09-17 12:36:07] VERBOSE[8270] chan_sip.c: Extension Changed 26[ext-local] new state InUse for Notify User 21 [2019-09-17 12:36:07] VERBOSE[8270] chan_sip.c: Extension Changed 26[ext-local] new state InUse for Notify User 31 [2019-09-17 12:36:07] VERBOSE[8270] chan_sip.c: Extension Changed 26[ext-local] new state InUse for Notify User 24 [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:4] ExecIf("SIP/26-00000044", "1?Set(REALCALLERIDNUM=26)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:5] Set("SIP/26-00000044", "AMPUSER=26") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:6] GotoIf("SIP/26-00000044", "0?limit") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:7] Set("SIP/26-00000044", "AMPUSERCIDNAME=Jill") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:8] ExecIf("SIP/26-00000044", "0?Set(__CIDMASQUERADING=TRUE)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:9] GotoIf("SIP/26-00000044", "0?report") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:10] Set("SIP/26-00000044", "AMPUSERCID=26") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:11] Set("SIP/26-00000044", "__DIAL_OPTIONS=HhTtr") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:12] Set("SIP/26-00000044", "CALLERID(all)="Jill" <26>") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:13] GotoIf("SIP/26-00000044", "0?limit") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:14] ExecIf("SIP/26-00000044", "0?Set(GROUP(concurrency_limit)=26)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:15] ExecIf("SIP/26-00000044", "0?Set(CHANNEL(language)=)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:16] NoOp("SIP/26-00000044", "Macro Depth is 2") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:17] GotoIf("SIP/26-00000044", "1?report2:macroerror") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx_builtins.c: Goto (macro-user-callerid,s,18) [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:18] GotoIf("SIP/26-00000044", "0?continue") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:19] ExecIf("SIP/26-00000044", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:20] Set("SIP/26-00000044", "__TTL=64") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:21] GotoIf("SIP/26-00000044", "1?continue") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx_builtins.c: Goto (macro-user-callerid,s,37) [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:37] Set("SIP/26-00000044", "CALLERID(number)=26") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:38] Set("SIP/26-00000044", "CALLERID(name)=Jill") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:39] GotoIf("SIP/26-00000044", "0?cnum") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:40] Set("SIP/26-00000044", "CDR(cnam)=Jill") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:41] Set("SIP/26-00000044", "CDR(cnum)=26") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:42] Set("SIP/26-00000044", "CHANNEL(language)=en") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:43] GosubIf("SIP/26-00000044", "0?app-check-classofservce,s,1()") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-exten-vm:2] Set("SIP/26-00000044", "RingGroupMethod=none") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-exten-vm:3] Set("SIP/26-00000044", "__EXTTOCALL=25") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-exten-vm:4] Set("SIP/26-00000044", "__PICKUPMARK=25") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-exten-vm:5] Set("SIP/26-00000044", "RT=15") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-exten-vm:6] Gosub("SIP/26-00000044", "sub-record-check,s,1(exten,25,dontcare)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@sub-record-check:1] GotoIf("SIP/26-00000044", "0?initialized") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@sub-record-check:2] Set("SIP/26-00000044", "__REC_STATUS=INITIALIZED") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@sub-record-check:3] Set("SIP/26-00000044", "NOW=1568741767") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@sub-record-check:4] Set("SIP/26-00000044", "__DAY=17") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@sub-record-check:5] Set("SIP/26-00000044", "__MONTH=09") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@sub-record-check:6] Set("SIP/26-00000044", "__YEAR=2019") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@sub-record-check:7] Set("SIP/26-00000044", "__TIMESTR=20190917-123607") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@sub-record-check:8] Set("SIP/26-00000044", "__FROMEXTEN=26") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@sub-record-check:9] Set("SIP/26-00000044", "__MON_FMT=wav") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@sub-record-check:10] NoOp("SIP/26-00000044", "Recordings initialized") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@sub-record-check:11] ExecIf("SIP/26-00000044", "0?Set(ARG3=dontcare)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@sub-record-check:12] Set("SIP/26-00000044", "REC_POLICY_MODE_SAVE=") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@sub-record-check:13] ExecIf("SIP/26-00000044", "0?Set(REC_STATUS=NO)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@sub-record-check:14] GotoIf("SIP/26-00000044", "5?checkaction") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx_builtins.c: Goto (sub-record-check,s,17) [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@sub-record-check:17] GotoIf("SIP/26-00000044", "1?sub-record-check,exten,1") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx_builtins.c: Goto (sub-record-check,exten,1) [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [exten@sub-record-check:1] NoOp("SIP/26-00000044", "Exten Recording Check between 26 and 25") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [exten@sub-record-check:2] Set("SIP/26-00000044", "CALLTYPE=internal") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [exten@sub-record-check:3] ExecIf("SIP/26-00000044", "0?Set(CALLTYPE=)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [exten@sub-record-check:4] Set("SIP/26-00000044", "CALLEE=dontcare") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [exten@sub-record-check:5] ExecIf("SIP/26-00000044", "0?Set(CALLEE=dontcare)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [exten@sub-record-check:6] GotoIf("SIP/26-00000044", "0?callee") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [exten@sub-record-check:7] GotoIf("SIP/26-00000044", "1?caller") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx_builtins.c: Goto (sub-record-check,exten,13) [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [exten@sub-record-check:13] Set("SIP/26-00000044", "RECMODE=dontcare") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [exten@sub-record-check:14] ExecIf("SIP/26-00000044", "0?Set(RECMODE=dontcare)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [exten@sub-record-check:15] ExecIf("SIP/26-00000044", "1?Set(RECMODE=dontcare)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [exten@sub-record-check:16] Gosub("SIP/26-00000044", "recordcheck,1(dontcare,internal,25)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("SIP/26-00000044", "Starting recording check against dontcare") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("SIP/26-00000044", "dontcare") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx_builtins.c: Goto (sub-record-check,recordcheck,3) [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [recordcheck@sub-record-check:3] Return("SIP/26-00000044", "") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [exten@sub-record-check:17] Return("SIP/26-00000044", "") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-exten-vm:7] GotoIf("SIP/26-00000044", "1?macrodial") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx_builtins.c: Goto (macro-exten-vm,s,13) [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-exten-vm:13] GosubIf("SIP/26-00000044", "0?clrheader,1()") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-exten-vm:14] Macro("SIP/26-00000044", "dial-one,15,HhTtr,25") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:1] Set("SIP/26-00000044", "DEXTEN=25") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:2] Set("SIP/26-00000044", "__CRM_SOURCE=26") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:3] UserEvent("SIP/26-00000044", "zulu-inbound-call,type:macro-dial-one,from:26,to:25") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:4] ExecIf("SIP/26-00000044", "0?Set(__EXTTOCALL=25)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:5] Set("SIP/26-00000044", "DIALSTATUS_CW=") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:6] GosubIf("SIP/26-00000044", "0?screen,1()") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:7] GosubIf("SIP/26-00000044", "0?cf,1()") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:8] GotoIf("SIP/26-00000044", "1?skip1") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx_builtins.c: Goto (macro-dial-one,s,11) [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:11] GotoIf("SIP/26-00000044", "0?nodial") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:12] GotoIf("SIP/26-00000044", "0?continue") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:13] Set("SIP/26-00000044", "EXTHASCW=ENABLED") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:14] GotoIf("SIP/26-00000044", "0?next1:cwinusebusy") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx_builtins.c: Goto (macro-dial-one,s,26) [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:26] GotoIf("SIP/26-00000044", "0?next3:continue") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx_builtins.c: Goto (macro-dial-one,s,28) [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:28] GotoIf("SIP/26-00000044", "0?nodial") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:29] GosubIf("SIP/26-00000044", "1?dstring,1():dlocal,1()") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [dstring@macro-dial-one:1] Set("SIP/26-00000044", "DSTRING=") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [dstring@macro-dial-one:2] Set("SIP/26-00000044", "DEVICES=25") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [dstring@macro-dial-one:3] ExecIf("SIP/26-00000044", "0?Return()") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [dstring@macro-dial-one:4] ExecIf("SIP/26-00000044", "0?Set(DEVICES=5)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [dstring@macro-dial-one:5] Set("SIP/26-00000044", "LOOPCNT=1") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [dstring@macro-dial-one:6] Set("SIP/26-00000044", "ITER=1") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [dstring@macro-dial-one:7] Set("SIP/26-00000044", "THISDIAL=SIP/25") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [dstring@macro-dial-one:8] GosubIf("SIP/26-00000044", "1?zap2dahdi,1()") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [zap2dahdi@macro-dial-one:1] ExecIf("SIP/26-00000044", "0?Return()") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [zap2dahdi@macro-dial-one:2] Set("SIP/26-00000044", "NEWDIAL=") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [zap2dahdi@macro-dial-one:3] Set("SIP/26-00000044", "LOOPCNT2=1") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [zap2dahdi@macro-dial-one:4] Set("SIP/26-00000044", "ITER2=1") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [zap2dahdi@macro-dial-one:5] Set("SIP/26-00000044", "THISPART2=SIP/25") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [zap2dahdi@macro-dial-one:6] ExecIf("SIP/26-00000044", "0?Set(THISPART2=DAHDI/25)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [zap2dahdi@macro-dial-one:7] Set("SIP/26-00000044", "NEWDIAL=SIP/25&") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [zap2dahdi@macro-dial-one:8] Set("SIP/26-00000044", "ITER2=2") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [zap2dahdi@macro-dial-one:9] GotoIf("SIP/26-00000044", "0?begin2") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [zap2dahdi@macro-dial-one:10] Set("SIP/26-00000044", "THISDIAL=SIP/25") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [zap2dahdi@macro-dial-one:11] Return("SIP/26-00000044", "") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [dstring@macro-dial-one:9] GotoIf("SIP/26-00000044", "1?docheck") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx_builtins.c: Goto (macro-dial-one,dstring,15) [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [dstring@macro-dial-one:15] GotoIf("SIP/26-00000044", "0?skipset") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [dstring@macro-dial-one:16] Set("SIP/26-00000044", "DSTRING=SIP/25&") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [dstring@macro-dial-one:17] Set("SIP/26-00000044", "ITER=2") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [dstring@macro-dial-one:18] GotoIf("SIP/26-00000044", "0?begin") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [dstring@macro-dial-one:19] ExecIf("SIP/26-00000044", "0?Return()") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [dstring@macro-dial-one:20] Set("SIP/26-00000044", "DSTRING=SIP/25") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [dstring@macro-dial-one:21] Return("SIP/26-00000044", "") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:30] GotoIf("SIP/26-00000044", "0?nodial") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:31] GotoIf("SIP/26-00000044", "0?skiptrace") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:32] GosubIf("SIP/26-00000044", "1?ctset,1():ctclear,1()") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [ctset@macro-dial-one:1] Set("SIP/26-00000044", "DB(CALLTRACE/25)=26") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [ctset@macro-dial-one:2] Return("SIP/26-00000044", "") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:33] Set("SIP/26-00000044", "D_OPTIONS=HhTtr") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:34] GosubIf("SIP/26-00000044", "0?func-set-sipheader,s,1(Alert-Info,)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:35] NoOp("SIP/26-00000044", "Blind Transfer: , Attended Transfer: , User: 26, Alert Info: ") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:36] ExecIf("SIP/26-00000044", "1?Set(ALERT_INFO=)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:37] ExecIf("SIP/26-00000044", "0?Set(ALERT_INFO=)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:38] ExecIf("SIP/26-00000044", "0?Set(ALERT_INFO=)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:39] ExecIf("SIP/26-00000044", "0?Set(ALERT_INFO=Normal;volume=)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:40] ExecIf("SIP/26-00000044", "0?Set(ALERT_INFO=Normal;volume=)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:41] GosubIf("SIP/26-00000044", "0?func-set-sipheader,s,1(Alert-Info,)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:42] ExecIf("SIP/26-00000044", "0?Set(CHANNEL(musicclass)=)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:43] GosubIf("SIP/26-00000044", "0?qwait,1()") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:44] Set("SIP/26-00000044", "__CWIGNORE=") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:45] Set("SIP/26-00000044", "__KEEPCID=TRUE") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:46] GotoIf("SIP/26-00000044", "0?usegoto,1") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:47] GotoIf("SIP/26-00000044", "0?godial") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:48] Gosub("SIP/26-00000044", "sub-presencestate-display,s,1(25)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@sub-presencestate-display:1] Goto("SIP/26-00000044", "state-not_set,1") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx_builtins.c: Goto (sub-presencestate-display,state-not_set,1) [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [state-not_set@sub-presencestate-display:1] Set("SIP/26-00000044", "PRESENCESTATE_DISPLAY=") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [state-not_set@sub-presencestate-display:2] Return("SIP/26-00000044", "") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:49] Set("SIP/26-00000044", "CONNECTEDLINE(name,i)=Lauren") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:50] Set("SIP/26-00000044", "CONNECTEDLINE(num)=25") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:51] Set("SIP/26-00000044", "D_OPTIONS=HhTtrI") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:52] Macro("SIP/26-00000044", "dialout-one-predial-hook,") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dialout-one-predial-hook:1] MacroExit("SIP/26-00000044", "") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:53] ExecIf("SIP/26-00000044", "0?Set(D_OPTIONS=HhtrII)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:54] Set("SIP/26-00000044", "__ZULU_TIMEOUT=15") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:55] Set("SIP/26-00000044", "__ZULU_FROMEXTEN=26") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:56] Set("SIP/26-00000044", "__ZULU_DIALOPTS=HhTtr") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:57] NoOp("SIP/26-00000044", "Finished") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:58] NoOp("SIP/26-00000044", "") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:59] ExecIf("SIP/26-00000044", "0?Set(D_OPTIONS=HhTtrIg)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-dial-one:60] Dial("SIP/26-00000044", "SIP/25,15,HhTtrIb(func-apply-sipheaders^s^1)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] netsock2.c: Using SIP RTP TOS bits 184 [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] netsock2.c: Using SIP RTP CoS mark 5 [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] app_stack.c: SIP/25-00000045 Internal Gosub(func-apply-sipheaders,s,1) start [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf("SIP/25-00000045", "0?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp("SIP/25-00000045", "Applying SIP Headers to channel SIP/25-00000045") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@func-apply-sipheaders:3] Set("SIP/25-00000045", "TECH=SIP") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@func-apply-sipheaders:4] Set("SIP/25-00000045", "SIPHEADERKEYS=") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@func-apply-sipheaders:5] While("SIP/25-00000045", "0") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] app_while.c: Jumping to priority 12 [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@func-apply-sipheaders:13] Return("SIP/25-00000045", "") in new stack [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] app_stack.c: Spawn extension (from-internal, 25, 1) exited non-zero on 'SIP/25-00000045' [2019-09-17 12:36:07] VERBOSE[11846][C-0000001e] app_stack.c: SIP/25-00000045 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL= [2019-09-17 12:36:08] VERBOSE[11846][C-0000001e] app_dial.c: Called SIP/25 [2019-09-17 12:36:08] VERBOSE[11846][C-0000001e] app_dial.c: Connected line update to SIP/26-00000044 prevented. [2019-09-17 12:36:08] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state Ringing for Notify User 33 [2019-09-17 12:36:08] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state Ringing for Notify User 30 [2019-09-17 12:36:08] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state Ringing for Notify User 21 [2019-09-17 12:36:08] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state Ringing for Notify User 31 [2019-09-17 12:36:08] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state Ringing for Notify User 24 [2019-09-17 12:36:08] VERBOSE[11846][C-0000001e] app_dial.c: SIP/25-00000045 is ringing [2019-09-17 12:36:08] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state Ringing for Notify User 33 [2019-09-17 12:36:08] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state Ringing for Notify User 30 [2019-09-17 12:36:08] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state Ringing for Notify User 21 [2019-09-17 12:36:08] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state Ringing for Notify User 31 [2019-09-17 12:36:08] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state Ringing for Notify User 24 [2019-09-17 12:36:11] VERBOSE[11846][C-0000001e] app_dial.c: Connected line update to SIP/26-00000044 prevented. [2019-09-17 12:36:11] VERBOSE[11846][C-0000001e] app_dial.c: SIP/25-00000045 answered SIP/26-00000044 [2019-09-17 12:36:11] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state InUse for Notify User 33 [2019-09-17 12:36:11] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state InUse for Notify User 30 [2019-09-17 12:36:11] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state InUse for Notify User 21 [2019-09-17 12:36:11] VERBOSE[11901][C-0000001e] bridge_channel.c: Channel SIP/25-00000045 joined 'simple_bridge' basic-bridge <69f72e80-0cab-4b95-9f68-7fb54b3a042e> [2019-09-17 12:36:11] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state InUse for Notify User 31 [2019-09-17 12:36:11] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state InUse for Notify User 24 [2019-09-17 12:36:11] VERBOSE[11846][C-0000001e] bridge_channel.c: Channel SIP/26-00000044 joined 'simple_bridge' basic-bridge <69f72e80-0cab-4b95-9f68-7fb54b3a042e> [2019-09-17 12:36:14] VERBOSE[11846][C-0000001e] res_musiconhold.c: Started music on hold, class 'default', on channel 'SIP/26-00000044' [2019-09-17 12:36:14] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state Hold for Notify User 33 [2019-09-17 12:36:14] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state Hold for Notify User 30 [2019-09-17 12:36:14] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state Hold for Notify User 21 [2019-09-17 12:36:14] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state Hold for Notify User 31 [2019-09-17 12:36:14] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state Hold for Notify User 24 [2019-09-17 12:36:16] VERBOSE[11901][C-0000001e] bridge_channel.c: Channel SIP/25-00000045 left 'simple_bridge' basic-bridge <69f72e80-0cab-4b95-9f68-7fb54b3a042e> [2019-09-17 12:36:16] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state Idle for Notify User 33 [2019-09-17 12:36:16] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state Idle for Notify User 30 [2019-09-17 12:36:16] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state Idle for Notify User 21 [2019-09-17 12:36:16] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state Idle for Notify User 31 [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] res_musiconhold.c: Stopped music on hold on SIP/26-00000044 [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] bridge_channel.c: Channel SIP/26-00000044 left 'simple_bridge' basic-bridge <69f72e80-0cab-4b95-9f68-7fb54b3a042e> [2019-09-17 12:36:16] VERBOSE[8270] chan_sip.c: Extension Changed 25[ext-local] new state Idle for Notify User 24 [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] app_macro.c: Channel 'SIP/26-00000044' jumping out of macro 'dial-one' [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] app_macro.c: Channel 'SIP/26-00000044' jumping out of macro 'exten-vm' [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [*30@from-internal-xfer:1] Set("SIP/26-00000044", "CONNECTEDLINE(name-charset,i)=utf8") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [*30@from-internal-xfer:2] Set("SIP/26-00000044", "CONNECTEDLINE(name,i)=30 Voicemail") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [*30@from-internal-xfer:3] Set("SIP/26-00000044", "CONNECTEDLINE(num,i)=30") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [*30@from-internal-xfer:4] Macro("SIP/26-00000044", "vm,30,DIRECTDIAL,") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-vm:1] Macro("SIP/26-00000044", "user-callerid,SKIPTTL") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:1] Set("SIP/26-00000044", "TOUCH_MONITOR=1568741767.238") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:2] Set("SIP/26-00000044", "AMPUSER=26") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("SIP/26-00000044", "4?report") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx_builtins.c: Goto (macro-user-callerid,s,16) [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:16] NoOp("SIP/26-00000044", "Macro Depth is 2") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:17] GotoIf("SIP/26-00000044", "1?report2:macroerror") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx_builtins.c: Goto (macro-user-callerid,s,18) [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:18] GotoIf("SIP/26-00000044", "1?continue") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx_builtins.c: Goto (macro-user-callerid,s,37) [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:37] Set("SIP/26-00000044", "CALLERID(number)=26") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:38] Set("SIP/26-00000044", "CALLERID(name)=Jill") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:39] GotoIf("SIP/26-00000044", "0?cnum") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:40] Set("SIP/26-00000044", "CDR(cnam)=Jill") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:41] Set("SIP/26-00000044", "CDR(cnum)=26") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:42] Set("SIP/26-00000044", "CHANNEL(language)=en") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-user-callerid:43] GosubIf("SIP/26-00000044", "0?app-check-classofservce,s,1()") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-vm:2] Set("SIP/26-00000044", "VMGAIN=") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-vm:3] Macro("SIP/26-00000044", "blkvm-check,") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-blkvm-check:1] Set("SIP/26-00000044", "GOSUB_RETVAL=") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-blkvm-check:2] ExecIf("SIP/26-00000044", "0?Set(GOSUB_RETVAL=TRUE)") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-blkvm-check:3] MacroExit("SIP/26-00000044", "") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-vm:4] GotoIf("SIP/26-00000044", "1?vmx,1") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx_builtins.c: Goto (macro-vm,vmx,1) [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [vmx@macro-vm:1] Set("SIP/26-00000044", "__EXTTOCALL=30") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [vmx@macro-vm:2] Set("SIP/26-00000044", "__CRM_VOICEMAIL=30") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [vmx@macro-vm:3] Set("SIP/26-00000044", "MEXTEN=30") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [vmx@macro-vm:4] Set("SIP/26-00000044", "MMODE=DIRECTDIAL") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [vmx@macro-vm:5] Set("SIP/26-00000044", "RETVM=") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [vmx@macro-vm:6] Set("SIP/26-00000044", "MODE=unavail") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [vmx@macro-vm:7] Macro("SIP/26-00000044", "get-vmcontext,30") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-get-vmcontext:1] Set("SIP/26-00000044", "VMCONTEXT=default") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-get-vmcontext:2] GotoIf("SIP/26-00000044", "0?200:300") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx_builtins.c: Goto (macro-get-vmcontext,s,300) [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-get-vmcontext:300] NoOp("SIP/26-00000044", "") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [vmx@macro-vm:8] Set("SIP/26-00000044", "MODE=unavail") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [vmx@macro-vm:9] NoOp("SIP/26-00000044", "MODE IS: unavail") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [vmx@macro-vm:10] GotoIf("SIP/26-00000044", "1?chknomsg") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx_builtins.c: Goto (macro-vm,vmx,12) [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [vmx@macro-vm:12] GotoIf("SIP/26-00000044", "0?s-DIRECTDIAL,1") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [vmx@macro-vm:13] GotoIf("SIP/26-00000044", "0?notdirect") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [vmx@macro-vm:14] Set("SIP/26-00000044", "MODE=unavail") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [vmx@macro-vm:15] NoOp("SIP/26-00000044", "Checking if ext 30 is enabled: ") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [vmx@macro-vm:16] GotoIf("SIP/26-00000044", "1?s-DIRECTDIAL,1") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx_builtins.c: Goto (macro-vm,s-DIRECTDIAL,1) [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s-DIRECTDIAL@macro-vm:1] Gosub("SIP/26-00000044", "zulu-no-interaction,s,1()") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@zulu-no-interaction:1] Set("SIP/26-00000044", "__ZULU_CALLVAR_NO_INTERACTION=true") in new stack [2019-09-17 12:36:16] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@zulu-no-interaction:2] Return("SIP/26-00000044", "") in new stack [2019-09-17 12:36:17] VERBOSE[11846][C-0000001e] pbx.c: Executing [s-DIRECTDIAL@macro-vm:2] NoOp("SIP/26-00000044", "DIRECTDIAL voicemail") in new stack [2019-09-17 12:36:17] VERBOSE[11846][C-0000001e] pbx.c: Executing [s-DIRECTDIAL@macro-vm:3] Macro("SIP/26-00000044", "get-vmcontext,30") in new stack [2019-09-17 12:36:17] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-get-vmcontext:1] Set("SIP/26-00000044", "VMCONTEXT=default") in new stack [2019-09-17 12:36:17] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-get-vmcontext:2] GotoIf("SIP/26-00000044", "0?200:300") in new stack [2019-09-17 12:36:17] VERBOSE[11846][C-0000001e] pbx_builtins.c: Goto (macro-get-vmcontext,s,300) [2019-09-17 12:36:17] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-get-vmcontext:300] NoOp("SIP/26-00000044", "") in new stack [2019-09-17 12:36:17] VERBOSE[11846][C-0000001e] pbx.c: Executing [s-DIRECTDIAL@macro-vm:4] VoiceMail("SIP/26-00000044", "30@default,u") in new stack [2019-09-17 12:36:17] VERBOSE[11846][C-0000001e] file.c: Playing 'vm-theperson.ulaw' (language 'en') [2019-09-17 12:36:19] VERBOSE[11846][C-0000001e] file.c: Playing 'digits/3.ulaw' (language 'en') [2019-09-17 12:36:19] VERBOSE[11846][C-0000001e] file.c: Playing 'digits/0.ulaw' (language 'en') [2019-09-17 12:36:20] VERBOSE[11846][C-0000001e] file.c: Playing 'vm-isunavail.ulaw' (language 'en') [2019-09-17 12:36:22] VERBOSE[11846][C-0000001e] file.c: Playing 'vm-intro.ulaw' (language 'en') [2019-09-17 12:36:27] VERBOSE[11846][C-0000001e] file.c: Playing 'beep.ulaw' (language 'en') [2019-09-17 12:36:28] VERBOSE[11846][C-0000001e] app_voicemail.c: Recording the message [2019-09-17 12:36:28] VERBOSE[11846][C-0000001e] app.c: x=0, open writing: /var/spool/asterisk/voicemail/default/30/tmp/ezcGj1 format: wav, 0x7fb420027f88 [2019-09-17 12:36:33] VERBOSE[11846][C-0000001e] app.c: User hung up [2019-09-17 12:36:33] VERBOSE[11846][C-0000001e] app_macro.c: Spawn extension (macro-vm, s-DIRECTDIAL, 4) exited non-zero on 'SIP/26-00000044' in macro 'vm' [2019-09-17 12:36:33] VERBOSE[11846][C-0000001e] pbx.c: Spawn extension (from-internal-xfer, *30, 4) exited non-zero on 'SIP/26-00000044' [2019-09-17 12:36:33] VERBOSE[11846][C-0000001e] pbx.c: Executing [h@from-internal-xfer:1] Macro("SIP/26-00000044", "hangupcall") in new stack [2019-09-17 12:36:33] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("SIP/26-00000044", "1?theend") in new stack [2019-09-17 12:36:33] VERBOSE[11846][C-0000001e] pbx_builtins.c: Goto (macro-hangupcall,s,3) [2019-09-17 12:36:33] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("SIP/26-00000044", "0?Set(CDR(recordingfile)=)") in new stack [2019-09-17 12:36:33] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-hangupcall:4] NoOp("SIP/26-00000044", " montior file= ") in new stack [2019-09-17 12:36:33] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-hangupcall:5] GotoIf("SIP/26-00000044", "1?skipagi") in new stack [2019-09-17 12:36:33] VERBOSE[11846][C-0000001e] pbx_builtins.c: Goto (macro-hangupcall,s,7) [2019-09-17 12:36:33] VERBOSE[11846][C-0000001e] pbx.c: Executing [s@macro-hangupcall:7] Hangup("SIP/26-00000044", "") in new stack [2019-09-17 12:36:33] VERBOSE[11846][C-0000001e] app_macro.c: Spawn extension (macro-hangupcall, s, 7) exited non-zero on 'SIP/26-00000044' in macro 'hangupcall' [2019-09-17 12:36:33] VERBOSE[11846][C-0000001e] pbx.c: Spawn extension (from-internal-xfer, h, 1) exited non-zero on 'SIP/26-00000044' [2019-09-17 12:36:33] VERBOSE[8270] chan_sip.c: Extension Changed 26[ext-local] new state Idle for Notify User 33 [2019-09-17 12:36:33] VERBOSE[8270] chan_sip.c: Extension Changed 26[ext-local] new state Idle for Notify User 30 [2019-09-17 12:36:33] VERBOSE[8270] chan_sip.c: Extension Changed 26[ext-local] new state Idle for Notify User 21 [2019-09-17 12:36:33] VERBOSE[8270] chan_sip.c: Extension Changed 26[ext-local] new state Idle for Notify User 31 [2019-09-17 12:36:33] VERBOSE[8270] chan_sip.c: Extension Changed 26[ext-local] new state Idle for Notify User 24 Copyright 2008-2019 Sangoma Technologies, Inc Version 12.7.6-1904-1.sng7