[2015-08-23 18:34:38] VERBOSE[15113][C-00000469] netsock2.c: == Using SIP RTP TOS bits 184 [2015-08-23 18:34:38] VERBOSE[15113][C-00000469] netsock2.c: == Using SIP RTP CoS mark 5 [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [2062422011@from-tr unk:1] Set("SIP/from-trunk-00000bcb", "__FROM_DID=2062422011") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [2062422011@from-tr unk:2] Gosub("SIP/from-trunk-00000bcb", "sub-record-check,s,1(in,2062422011,dontcare)") in n ew stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :1] GotoIf("SIP/from-trunk-00000bcb", "0?initialized") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :2] Set("SIP/from-trunk-00000bcb", "__REC_STATUS=INITIALIZED") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :3] Set("SIP/from-trunk-00000bcb", "NOW=1440380078") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :4] Set("SIP/from-trunk-00000bcb", "__DAY=23") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :5] Set("SIP/from-trunk-00000bcb", "__MONTH=08") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :6] Set("SIP/from-trunk-00000bcb", "__YEAR=2015") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :7] Set("SIP/from-trunk-00000bcb", "__TIMESTR=20150823-183438") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :8] Set("SIP/from-trunk-00000bcb", "__FROMEXTEN=unknown") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :9] Set("SIP/from-trunk-00000bcb", "__MON_FMT=wav") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :10] NoOp("SIP/from-trunk-00000bcb", "Recordings initialized") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :11] ExecIf("SIP/from-trunk-00000bcb", "0?Set(ARG3=dontcare)") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :12] Set("SIP/from-trunk-00000bcb", "REC_POLICY_MODE_SAVE=") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :13] ExecIf("SIP/from-trunk-00000bcb", "0?Set(REC_STATUS=NO)") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :14] GotoIf("SIP/from-trunk-00000bcb", "2?checkaction") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Goto (sub-record-check,s,17) [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :17] GotoIf("SIP/from-trunk-00000bcb", "1?sub-record-check,in,1") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Goto (sub-record-check,in,1) [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [in@sub-record-chec k:1] NoOp("SIP/from-trunk-00000bcb", "Inbound Recording Check to 2062422011") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [in@sub-record-chec k:2] Set("SIP/from-trunk-00000bcb", "FROMEXTEN=unknown") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [in@sub-record-chec k:3] ExecIf("SIP/from-trunk-00000bcb", "10?Set(FROMEXTEN=2066969038)") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [in@sub-record-chec k:4] Gosub("SIP/from-trunk-00000bcb", "recordcheck,1(dontcare,in,2062422011)") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [recordcheck@sub-re cord-check:1] NoOp("SIP/from-trunk-00000bcb", "Starting recording check against dontcare") i n new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [recordcheck@sub-re cord-check:2] Goto("SIP/from-trunk-00000bcb", "dontcare") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Goto (sub-record-check,record check,3) [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [recordcheck@sub-re cord-check:3] Return("SIP/from-trunk-00000bcb", "") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [in@sub-record-chec k:5] Return("SIP/from-trunk-00000bcb", "") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [2062422011@from-tr unk:3] Gosub("SIP/from-trunk-00000bcb", "app-blacklist-check,s,1()") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@app-blacklist-ch eck:1] GotoIf("SIP/from-trunk-00000bcb", "0?blacklisted") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@app-blacklist-ch eck:2] Set("SIP/from-trunk-00000bcb", "CALLED_BLACKLIST=1") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@app-blacklist-ch eck:3] Return("SIP/from-trunk-00000bcb", "") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [2062422011@from-tr unk:4] Set("SIP/from-trunk-00000bcb", "CDR(did)=2062422011") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [2062422011@from-tr unk:5] ExecIf("SIP/from-trunk-00000bcb", "0 ?Set(CALLERID(name)=2066969038)") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [2062422011@from-tr unk:6] Set("SIP/from-trunk-00000bcb", "CHANNEL(musicclass)=default") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [2062422011@from-tr unk:7] Set("SIP/from-trunk-00000bcb", "__MOHCLASS=default") in new stack [2015-08-23 18:34:38] WARNING[30164][C-00000469] func_channel.c: Unknown or unavailable item requested: 'reversecharge' [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [2062422011@from-tr unk:8] GotoIf("SIP/from-trunk-00000bcb", "0?macro-hangupcall") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [2062422011@from-tr unk:9] Set("SIP/from-trunk-00000bcb", "__CALLINGPRES_SV=allowed_not_screened") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [2062422011@from-tr unk:10] Set("SIP/from-trunk-00000bcb", "CALLERPRES()=allowed_not_screened") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [2062422011@from-tr unk:11] Goto("SIP/from-trunk-00000bcb", "timeconditions,3,1") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Goto (timeconditions,3,1) [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [3@timeconditions:1 ] Set("SIP/from-trunk-00000bcb", "DB(TC/3/INUSESTATE)=INUSE") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [3@timeconditions:2 ] Set("SIP/from-trunk-00000bcb", "DB(TC/3/NOT_INUSESTATE)=NOT_INUSE") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [3@timeconditions:3 ] GotoIfTime("SIP/from-trunk-00000bcb", "07:00-22:01,mon-sun,*,*?truestate") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Goto (timeconditions,3,12) [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [3@timeconditions:1 2] GotoIf("SIP/from-trunk-00000bcb", "0?falsegoto") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [3@timeconditions:1 3] ExecIf("SIP/from-trunk-00000bcb", "0?Set(DB(TC/3)=)") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [3@timeconditions:1 4] Set("SIP/from-trunk-00000bcb", "DEVICE_STATE(Custom:TC3)=NOT_INUSE") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [3@timeconditions:1 5] ExecIf("SIP/from-trunk-00000bcb", "0?Set(NOT_INUSE)") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [3@timeconditions:1 6] GotoIf("SIP/from-trunk-00000bcb", "1?ext-queues,5149,1") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Goto (ext-queues,5149,1) [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:1] Macro("SIP/from-trunk-00000bcb", "user-callerid,") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:1] Set("SIP/from-trunk-00000bcb", "TOUCH_MONITOR=1440380078.50112") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:2] Set("SIP/from-trunk-00000bcb", "AMPUSER=2066969038") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:3] GotoIf("SIP/from-trunk-00000bcb", "0?report") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:4] ExecIf("SIP/from-trunk-00000bcb", "1?Set(REALCALLERIDNUM=2066969038)") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:5] Set("SIP/from-trunk-00000bcb", "AMPUSER=") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:6] GotoIf("SIP/from-trunk-00000bcb", "0?limit") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:7] Set("SIP/from-trunk-00000bcb", "AMPUSERCIDNAME=") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:8] GotoIf("SIP/from-trunk-00000bcb", "1?report") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Goto (macro-user-callerid,s,1 6) [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:16] GotoIf("SIP/from-trunk-00000bcb", "0?continue") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:17] ExecIf("SIP/from-trunk-00000bcb", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:18] Set("SIP/from-trunk-00000bcb", "__TTL=64") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:19] GotoIf("SIP/from-trunk-00000bcb", "1?continue") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Goto (macro-user-callerid,s,3 0) [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:30] Set("SIP/from-trunk-00000bcb", "CALLERID(number)=2066969038") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:31] Set("SIP/from-trunk-00000bcb", "CALLERID(name)=2066969038") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:32] Set("SIP/from-trunk-00000bcb", "CDR(cnum)=2066969038") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:33] Set("SIP/from-trunk-00000bcb", "CDR(cnam)=2066969038") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:34] Set("SIP/from-trunk-00000bcb", "CHANNEL(language)=en") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:2] Answer("SIP/from-trunk-00000bcb", "") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:3] Macro("SIP/from-trunk-00000bcb", "blkvm-set,reset") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@macro-blkvm-set: 1] ExecIf("SIP/from-trunk-00000bcb", "1?Set(__BLKVM_CHANNEL=SIP/from-trunk-00000bcb)") in ne w stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@macro-blkvm-set: 2] Set("SIP/from-trunk-00000bcb", "SHARED(BLKVM,SIP/from-trunk-00000bcb)=TRUE") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@macro-blkvm-set: 3] Set("SIP/from-trunk-00000bcb", "GOSUB_RETVAL=TRUE") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@macro-blkvm-set: 4] MacroExit("SIP/from-trunk-00000bcb", "") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:4] ExecIf("SIP/from-trunk-00000bcb", "1?Set(_DIAL_OPTIONS=TtrM(auto-blkvm))") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:5] Set("SIP/from-trunk-00000bcb", "__NODEST=5149") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:6] Set("SIP/from-trunk-00000bcb", "QCIDPP=") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:7] Set("SIP/from-trunk-00000bcb", "VQ_CIDPP=") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:8] ExecIf("SIP/from-trunk-00000bcb", "0?Macro(prepend-cid,)") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:9] Set("SIP/from-trunk-00000bcb", "QAINFO=") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:10 ] Set("SIP/from-trunk-00000bcb", "VQ_AINFO=") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:11 ] ExecIf("SIP/from-trunk-00000bcb", "0?Set(__ALERT_INFO=)") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:12 ] Set("SIP/from-trunk-00000bcb", "QJOINMSG=custom/Juba3") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:13 ] Set("SIP/from-trunk-00000bcb", "VQ_JOINMSG=") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:14 ] Set("SIP/from-trunk-00000bcb", "QRINGOPTS=r") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:15 ] Set("SIP/from-trunk-00000bcb", "QRETRY=") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:16 ] Set("SIP/from-trunk-00000bcb", "VQ_RETRY=") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:17 ] Set("SIP/from-trunk-00000bcb", "QOPTIONS=tr") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:18 ] Set("SIP/from-trunk-00000bcb", "VQ_OPTIONS=") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:19 ] Set("SIP/from-trunk-00000bcb", "QGOSUB=") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:20 ] Set("SIP/from-trunk-00000bcb", "VQ_GOSUB=") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:21 ] Set("SIP/from-trunk-00000bcb", "QAGI=") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:22 ] Set("SIP/from-trunk-00000bcb", "VQ_AGI=") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:23 ] Set("SIP/from-trunk-00000bcb", "QRULE=") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:24 ] Set("SIP/from-trunk-00000bcb", "VQ_RULE=") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:25 ] Set("SIP/from-trunk-00000bcb", "QPOSITION=") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:26 ] Set("SIP/from-trunk-00000bcb", "VQ_POSITION=") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:27 ] Gosub("SIP/from-trunk-00000bcb", "sub-record-check,s,1(q,5149,dontcare)") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :1] GotoIf("SIP/from-trunk-00000bcb", "10?initialized") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Goto (sub-record-check,s,10) [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :10] NoOp("SIP/from-trunk-00000bcb", "Recordings initialized") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :11] ExecIf("SIP/from-trunk-00000bcb", "0?Set(ARG3=dontcare)") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :12] Set("SIP/from-trunk-00000bcb", "REC_POLICY_MODE_SAVE=") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :13] ExecIf("SIP/from-trunk-00000bcb", "0?Set(REC_STATUS=NO)") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :14] GotoIf("SIP/from-trunk-00000bcb", "1?checkaction") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Goto (sub-record-check,s,17) [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :17] GotoIf("SIP/from-trunk-00000bcb", "0?sub-record-check,q,1") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :18] NoOp("SIP/from-trunk-00000bcb", "Generic q Recording Check - 2066969038 5149") in new s tack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :19] Gosub("SIP/from-trunk-00000bcb", "recordcheck,1(dontcare,q,5149)") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [recordcheck@sub-re cord-check:1] NoOp("SIP/from-trunk-00000bcb", "Starting recording check against dontcare") i n new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [recordcheck@sub-re cord-check:2] Goto("SIP/from-trunk-00000bcb", "dontcare") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Goto (sub-record-check,record check,3) [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [recordcheck@sub-re cord-check:3] Return("SIP/from-trunk-00000bcb", "") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@sub-record-check :20] Return("SIP/from-trunk-00000bcb", "") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:28 ] Set("SIP/from-trunk-00000bcb", "__CWIGNORE=TRUE") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:29 ] ExecIf("SIP/from-trunk-00000bcb", "1?Playback(custom/Juba3, )") in new stack [2015-08-23 18:34:38] VERBOSE[30164][C-00000469] file.c: -- Pl aying 'custom/Juba3.slin' (language 'en') [2015-08-23 18:34:51] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:30 ] QueueLog("SIP/from-trunk-00000bcb", "5149,1440380078.50112,NONE,DID,2062422011") in new st ack [2015-08-23 18:34:51] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:31 ] Set("SIP/from-trunk-00000bcb", "QAANNOUNCE=") in new stack [2015-08-23 18:34:51] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:32 ] Set("SIP/from-trunk-00000bcb", "VQ_AANNOUNCE=") in new stack [2015-08-23 18:34:51] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:33 ] Set("SIP/from-trunk-00000bcb", "QMOH=") in new stack [2015-08-23 18:34:51] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:34 ] Set("SIP/from-trunk-00000bcb", "VQ_MOH=") in new stack [2015-08-23 18:34:51] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:35 ] ExecIf("SIP/from-trunk-00000bcb", "0?Set(__MOHCLASS=)") in new stack [2015-08-23 18:34:51] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:36 ] ExecIf("SIP/from-trunk-00000bcb", "1?Set(CHANNEL(musicclass)=default)") in new stack [2015-08-23 18:34:51] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:37 ] Set("SIP/from-trunk-00000bcb", "QMAXWAIT=") in new stack [2015-08-23 18:34:51] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:38 ] Set("SIP/from-trunk-00000bcb", "VQ_MAXWAIT=") in new stack [2015-08-23 18:34:51] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:39 ] Set("SIP/from-trunk-00000bcb", "QUEUENUM=5149") in new stack [2015-08-23 18:34:51] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:40 ] Set("SIP/from-trunk-00000bcb", "QUEUEJOINTIME=1440380091") in new stack [2015-08-23 18:34:51] VERBOSE[30164][C-00000469] pbx.c: -- Executing [5149@ext-queues:41 ] Queue("SIP/from-trunk-00000bcb", "5149,tr,,,,,,,,") in new stack [2015-08-23 18:34:51] VERBOSE[30164][C-00000469] app_queue.c: -- Called Local/2@from-que ue/n [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-queue:1] Se t("Local/2@from-queue-000008d2;2", "QAGENT=2") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-queue:2] Go to("Local/2@from-queue-000008d2;2", "5149,1") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Goto (from-queue,5149,1) [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [5149@from-queue:1] Goto("Local/2@from-queue-000008d2;2", "from-internal,2,1") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Goto (from-internal,2,1) [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:1] GotoIf("Local/2@from-queue-000008d2;2", "0?ext-local,2,1") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:2] Macro("Local/2@from-queue-000008d2;2", "user-callerid,") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:1] Set("Local/2@from-queue-000008d2;2", "TOUCH_MONITOR=1440380091.50124") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:2] Set("Local/2@from-queue-000008d2;2", "AMPUSER=2066969038") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:3] GotoIf("Local/2@from-queue-000008d2;2", "1?report") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Goto (macro-user-callerid,s,1 6) [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:16] GotoIf("Local/2@from-queue-000008d2;2", "0?continue") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:17] ExecIf("Local/2@from-queue-000008d2;2", "1?Set(__CALLEE_ACCOUNCODE=1932)") in new st ack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:18] Set("Local/2@from-queue-000008d2;2", "__TTL=63") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:19] GotoIf("Local/2@from-queue-000008d2;2", "1?continue") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Goto (macro-user-callerid,s,3 0) [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:30] Set("Local/2@from-queue-000008d2;2", "CALLERID(number)=2066969038") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:31] Set("Local/2@from-queue-000008d2;2", "CALLERID(name)=2066969038") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:32] Set("Local/2@from-queue-000008d2;2", "CDR(cnum)=2066969038") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:33] Set("Local/2@from-queue-000008d2;2", "CDR(cnam)=2066969038") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:34] Set("Local/2@from-queue-000008d2;2", "CHANNEL(language)=en") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:3] Set("Local/2@from-queue-000008d2;2", "DIAL_OPTIONS=TtrM(auto-blkvm)I") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:4] Set("Local/2@from-queue-000008d2;2", "CONNECTEDLINE(num,i)=2") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:5] Gosub("Local/2@from-queue-000008d2;2", "sub-presencestate-display,s,1(2)") in new stack [2015-08-23 18:34:51] WARNING[30177][C-00000469] func_presencestate.c: PRESENCE_STATE unknow n [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@sub-presencestat e-display:1] Goto("Local/2@from-queue-000008d2;2", "state-,1") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Goto (sub-presencestate-displ ay,state-,1) [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [state-@sub-presenc estate-display:1] Set("Local/2@from-queue-000008d2;2", "PRESENCESTATE_DISPLAY=") in new stac k [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [state-@sub-presenc estate-display:2] Return("Local/2@from-queue-000008d2;2", "") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:6] Set("Local/2@from-queue-000008d2;2", "CONNECTEDLINE(name)=Juba Main") in new stack [2015-08-23 18:34:51] VERBOSE[30164][C-00000469] app_queue.c: -- Local/2@from-queue-0000 08d2;1 connected line has changed. Saving it until answer for SIP/from-trunk-00000bcb [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:7] Set("Local/2@from-queue-000008d2;2", "FM_DIALSTATUS=INUSE") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:8] Set("Local/2@from-queue-000008d2;2", "__EXTTOCALL=2") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:9] Set("Local/2@from-queue-000008d2;2", "__PICKUPMARK=2") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:10 ] Macro("Local/2@from-queue-000008d2;2", "blkvm-setifempty,") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@macro-blkvm-seti fempty:1] GotoIf("Local/2@from-queue-000008d2;2", "0?init") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@macro-blkvm-seti fempty:2] Set("Local/2@from-queue-000008d2;2", "GOSUB_RETVAL=TRUE") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@macro-blkvm-seti fempty:3] MacroExit("Local/2@from-queue-000008d2;2", "") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:11 ] GotoIf("Local/2@from-queue-000008d2;2", "1?skipov") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Goto (from-internal,2,14) [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:14 ] Set("Local/2@from-queue-000008d2;2", "RRNODEST=5149") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:15 ] Set("Local/2@from-queue-000008d2;2", "__NODEST=2") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:16 ] GosubIf("Local/2@from-queue-000008d2;2", "0?sub-fmsetcid,s,1()") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:17 ] Set("Local/2@from-queue-000008d2;2", "RecordMethod=Group") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:18 ] Gosub("Local/2@from-queue-000008d2;2", "sub-record-check,s,1(exten,2,)") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@sub-record-check :1] GotoIf("Local/2@from-queue-000008d2;2", "0?initialized") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@sub-record-check :2] Set("Local/2@from-queue-000008d2;2", "__REC_STATUS=INITIALIZED") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@sub-record-check :3] Set("Local/2@from-queue-000008d2;2", "NOW=1440380091") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@sub-record-check :4] Set("Local/2@from-queue-000008d2;2", "__DAY=23") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@sub-record-check :5] Set("Local/2@from-queue-000008d2;2", "__MONTH=08") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@sub-record-check :6] Set("Local/2@from-queue-000008d2;2", "__YEAR=2015") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@sub-record-check :7] Set("Local/2@from-queue-000008d2;2", "__TIMESTR=20150823-183451") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@sub-record-check :8] Set("Local/2@from-queue-000008d2;2", "__FROMEXTEN=2066969038") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@sub-record-check :9] Set("Local/2@from-queue-000008d2;2", "__MON_FMT=wav") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@sub-record-check :10] NoOp("Local/2@from-queue-000008d2;2", "Recordings initialized") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@sub-record-check :11] ExecIf("Local/2@from-queue-000008d2;2", "1?Set(ARG3=dontcare)") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@sub-record-check :12] Set("Local/2@from-queue-000008d2;2", "REC_POLICY_MODE_SAVE=") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@sub-record-check :13] ExecIf("Local/2@from-queue-000008d2;2", "0?Set(REC_STATUS=NO)") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@sub-record-check :14] GotoIf("Local/2@from-queue-000008d2;2", "5?checkaction") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Goto (sub-record-check,s,17) [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@sub-record-check :17] GotoIf("Local/2@from-queue-000008d2;2", "1?sub-record-check,exten,1") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Goto (sub-record-check,exten, 1) [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:1] NoOp("Local/2@from-queue-000008d2;2", "Exten Recording Check between 2066969038 and 2") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:2] Set("Local/2@from-queue-000008d2;2", "CALLTYPE=external") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:3] ExecIf("Local/2@from-queue-000008d2;2", "0?Set(CALLTYPE=)") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:4] Set("Local/2@from-queue-000008d2;2", "CALLEE=dontcare") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:5] ExecIf("Local/2@from-queue-000008d2;2", "0?Set(CALLEE=dontcare)") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:6] GotoIf("Local/2@from-queue-000008d2;2", "1?callee") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Goto (sub-record-check,exten, 11) [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:11] Gosub("Local/2@from-queue-000008d2;2", "recordcheck,1(dontcare,external,2)") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [recordcheck@sub-re cord-check:1] NoOp("Local/2@from-queue-000008d2;2", "Starting recording check against dontca re") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [recordcheck@sub-re cord-check:2] Goto("Local/2@from-queue-000008d2;2", "dontcare") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Goto (sub-record-check,record check,3) [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [recordcheck@sub-re cord-check:3] Return("Local/2@from-queue-000008d2;2", "") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:12] Return("Local/2@from-queue-000008d2;2", "") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:19 ] Set("Local/2@from-queue-000008d2;2", "RingGroupMethod=ringallv2-prim") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:20 ] Set("Local/2@from-queue-000008d2;2", "_FMGRP=2") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:21 ] GotoIf("Local/2@from-queue-000008d2;2", "0?doconfirm") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:22 ] Macro("Local/2@from-queue-000008d2;2", "dial,20,TtrM(auto-blkvm)I,2-3") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@macro-dial:1] Go toIf("Local/2@from-queue-000008d2;2", "0?dial") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@macro-dial:2] Se t("Local/2@from-queue-000008d2;2", "CHANNEL(musicclass)=default") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@macro-dial:3] AG I("Local/2@from-queue-000008d2;2", "dialparties.agi") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] res_agi.c: -- Launched AGI Script /var/ lib/asterisk/agi-bin/dialparties.agi [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] res_agi.c: dialparties.agi: Starting New D ialparties.agi [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] res_agi.c: dialparties.agi: Caller ID name is '2066969038' number is '2066969038' [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] res_agi.c: dialparties.agi: Methodology of ring is 'ringallv2-prim' [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] res_agi.c: -- dialparties.agi: Added ex tension 2 to extension map [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] res_agi.c: -- dialparties.agi: Added ex tension 3 to extension map [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] res_agi.c: -- dialparties.agi: Extensio n 2 cf is disabled [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] res_agi.c: -- dialparties.agi: Extensio n 3 cf is disabled [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] res_agi.c: -- dialparties.agi: Extensio n 2 do not disturb is disabled [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] res_agi.c: -- dialparties.agi: Extensio n 3 do not disturb is disabled [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] res_agi.c: dialparties.agi: EXTENSION_STAT E: 1 (INUSE) [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] res_agi.c: dialparties.agi: Extension 2 ha s ExtensionState: 1 [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] res_agi.c: dialparties.agi: EXTENSION_STAT E: 1 (INUSE) [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] res_agi.c: dialparties.agi: Extension 2 ha s ExtensionState: 1 [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] res_agi.c: -- dialparties.agi: Checking CW and CFB status for extension 2 [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] res_agi.c: dialparties.agi: Extension 2 is not available to be called [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] res_agi.c: dialparties.agi: Extension 2 ha s call waiting disabled [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] res_agi.c: -- dialparties.agi: Filtered ARG3: [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] res_agi.c: -- AGI Script dialparties.agi completed, returning 0 [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [s@macro-dial:4] No Op("Local/2@from-queue-000008d2;2", "Returned from dialparties with no extensions to call an d DIALSTATUS: BUSY") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:23 ] Goto("Local/2@from-queue-000008d2;2", "nextstep") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Goto (from-internal,2,25) [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:25 ] Set("Local/2@from-queue-000008d2;2", "RingGroupMethod=") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:26 ] GotoIf("Local/2@from-queue-000008d2;2", "1?nodest") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Goto (from-internal,2,32) [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [2@from-internal:32 ] NoOp("Local/2@from-queue-000008d2;2", "SKIPPING DEST, CALL CAME FROM Q/RG: 5149") in new s tack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Auto fallthrough, channel 'Lo cal/2@from-queue-000008d2;2' status is 'BUSY' [2015-08-23 18:34:51] VERBOSE[30164][C-00000469] app_queue.c: -- Local/2@from-queue-0000 08d2;1 is busy [2015-08-23 18:34:51] VERBOSE[30164][C-00000469] app_queue.c: -- Nobody picked up in 0 m s [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: -- Executing [h@from-internal:1] Hangup("Local/2@from-queue-000008d2;2", "") in new stack [2015-08-23 18:34:51] VERBOSE[30177][C-00000469] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on 'Local/2@from-queue-000008d2;2' [2015-08-23 18:34:56] VERBOSE[30164][C-00000469] file.c: -- Pl aying 'queue-youarenext.ulaw' (language 'en') [2015-08-23 18:35:01] VERBOSE[30164][C-00000469] app_queue.c: -- Told SIP/from-trunk-000 00bcb in 5149 their queue position (which was 1) [2015-08-23 18:35:01] VERBOSE[30164][C-00000469] file.c: -- Pl aying 'queue-thankyou.ulaw' (language 'en') [2015-08-23 18:35:03] VERBOSE[30164][C-00000469] app_queue.c: -- Called Local/2@from-que ue/n [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-queue:1] Se t("Local/2@from-queue-000008d3;2", "QAGENT=2") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-queue:2] Go to("Local/2@from-queue-000008d3;2", "5149,1") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Goto (from-queue,5149,1) [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [5149@from-queue:1] Goto("Local/2@from-queue-000008d3;2", "from-internal,2,1") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Goto (from-internal,2,1) [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:1] GotoIf("Local/2@from-queue-000008d3;2", "0?ext-local,2,1") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:2] Macro("Local/2@from-queue-000008d3;2", "user-callerid,") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:1] Set("Local/2@from-queue-000008d3;2", "TOUCH_MONITOR=1440380103.50139") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:2] Set("Local/2@from-queue-000008d3;2", "AMPUSER=2066969038") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:3] GotoIf("Local/2@from-queue-000008d3;2", "1?report") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Goto (macro-user-callerid,s,1 6) [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:16] GotoIf("Local/2@from-queue-000008d3;2", "0?continue") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:17] ExecIf("Local/2@from-queue-000008d3;2", "1?Set(__CALLEE_ACCOUNCODE=1932)") in new st ack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:18] Set("Local/2@from-queue-000008d3;2", "__TTL=63") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:19] GotoIf("Local/2@from-queue-000008d3;2", "1?continue") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Goto (macro-user-callerid,s,3 0) [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:30] Set("Local/2@from-queue-000008d3;2", "CALLERID(number)=2066969038") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:31] Set("Local/2@from-queue-000008d3;2", "CALLERID(name)=2066969038") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:32] Set("Local/2@from-queue-000008d3;2", "CDR(cnum)=2066969038") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:33] Set("Local/2@from-queue-000008d3;2", "CDR(cnam)=2066969038") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:34] Set("Local/2@from-queue-000008d3;2", "CHANNEL(language)=en") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:3] Set("Local/2@from-queue-000008d3;2", "DIAL_OPTIONS=TtrM(auto-blkvm)I") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:4] Set("Local/2@from-queue-000008d3;2", "CONNECTEDLINE(num,i)=2") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:5] Gosub("Local/2@from-queue-000008d3;2", "sub-presencestate-display,s,1(2)") in new stack [2015-08-23 18:35:03] WARNING[30194][C-00000469] func_presencestate.c: PRESENCE_STATE unknow n [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@sub-presencestat e-display:1] Goto("Local/2@from-queue-000008d3;2", "state-,1") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Goto (sub-presencestate-displ ay,state-,1) [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [state-@sub-presenc estate-display:1] Set("Local/2@from-queue-000008d3;2", "PRESENCESTATE_DISPLAY=") in new stac k [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [state-@sub-presenc estate-display:2] Return("Local/2@from-queue-000008d3;2", "") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:6] Set("Local/2@from-queue-000008d3;2", "CONNECTEDLINE(name)=Juba Main") in new stack [2015-08-23 18:35:03] VERBOSE[30164][C-00000469] app_queue.c: -- Local/2@from-queue-0000 08d3;1 connected line has changed. Saving it until answer for SIP/from-trunk-00000bcb [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:7] Set("Local/2@from-queue-000008d3;2", "FM_DIALSTATUS=INUSE") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:8] Set("Local/2@from-queue-000008d3;2", "__EXTTOCALL=2") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:9] Set("Local/2@from-queue-000008d3;2", "__PICKUPMARK=2") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:10 ] Macro("Local/2@from-queue-000008d3;2", "blkvm-setifempty,") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@macro-blkvm-seti fempty:1] GotoIf("Local/2@from-queue-000008d3;2", "0?init") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@macro-blkvm-seti fempty:2] Set("Local/2@from-queue-000008d3;2", "GOSUB_RETVAL=TRUE") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@macro-blkvm-seti fempty:3] MacroExit("Local/2@from-queue-000008d3;2", "") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:11 ] GotoIf("Local/2@from-queue-000008d3;2", "1?skipov") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Goto (from-internal,2,14) [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:14 ] Set("Local/2@from-queue-000008d3;2", "RRNODEST=5149") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:15 ] Set("Local/2@from-queue-000008d3;2", "__NODEST=2") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:16 ] GosubIf("Local/2@from-queue-000008d3;2", "0?sub-fmsetcid,s,1()") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:17 ] Set("Local/2@from-queue-000008d3;2", "RecordMethod=Group") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:18 ] Gosub("Local/2@from-queue-000008d3;2", "sub-record-check,s,1(exten,2,)") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@sub-record-check :1] GotoIf("Local/2@from-queue-000008d3;2", "0?initialized") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@sub-record-check :2] Set("Local/2@from-queue-000008d3;2", "__REC_STATUS=INITIALIZED") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@sub-record-check :3] Set("Local/2@from-queue-000008d3;2", "NOW=1440380103") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@sub-record-check :4] Set("Local/2@from-queue-000008d3;2", "__DAY=23") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@sub-record-check :5] Set("Local/2@from-queue-000008d3;2", "__MONTH=08") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@sub-record-check :6] Set("Local/2@from-queue-000008d3;2", "__YEAR=2015") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@sub-record-check :7] Set("Local/2@from-queue-000008d3;2", "__TIMESTR=20150823-183503") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@sub-record-check :8] Set("Local/2@from-queue-000008d3;2", "__FROMEXTEN=2066969038") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@sub-record-check :9] Set("Local/2@from-queue-000008d3;2", "__MON_FMT=wav") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@sub-record-check :10] NoOp("Local/2@from-queue-000008d3;2", "Recordings initialized") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@sub-record-check :11] ExecIf("Local/2@from-queue-000008d3;2", "1?Set(ARG3=dontcare)") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@sub-record-check :12] Set("Local/2@from-queue-000008d3;2", "REC_POLICY_MODE_SAVE=") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@sub-record-check :13] ExecIf("Local/2@from-queue-000008d3;2", "0?Set(REC_STATUS=NO)") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@sub-record-check :14] GotoIf("Local/2@from-queue-000008d3;2", "5?checkaction") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Goto (sub-record-check,s,17) [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@sub-record-check :17] GotoIf("Local/2@from-queue-000008d3;2", "1?sub-record-check,exten,1") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Goto (sub-record-check,exten, 1) [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:1] NoOp("Local/2@from-queue-000008d3;2", "Exten Recording Check between 2066969038 and 2") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:2] Set("Local/2@from-queue-000008d3;2", "CALLTYPE=external") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:3] ExecIf("Local/2@from-queue-000008d3;2", "0?Set(CALLTYPE=)") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:4] Set("Local/2@from-queue-000008d3;2", "CALLEE=dontcare") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:5] ExecIf("Local/2@from-queue-000008d3;2", "0?Set(CALLEE=dontcare)") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:6] GotoIf("Local/2@from-queue-000008d3;2", "1?callee") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Goto (sub-record-check,exten, 11) [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:11] Gosub("Local/2@from-queue-000008d3;2", "recordcheck,1(dontcare,external,2)") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [recordcheck@sub-re cord-check:1] NoOp("Local/2@from-queue-000008d3;2", "Starting recording check against dontca re") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [recordcheck@sub-re cord-check:2] Goto("Local/2@from-queue-000008d3;2", "dontcare") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Goto (sub-record-check,record check,3) [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [recordcheck@sub-re cord-check:3] Return("Local/2@from-queue-000008d3;2", "") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:12] Return("Local/2@from-queue-000008d3;2", "") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:19 ] Set("Local/2@from-queue-000008d3;2", "RingGroupMethod=ringallv2-prim") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:20 ] Set("Local/2@from-queue-000008d3;2", "_FMGRP=2") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:21 ] GotoIf("Local/2@from-queue-000008d3;2", "0?doconfirm") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:22 ] Macro("Local/2@from-queue-000008d3;2", "dial,20,TtrM(auto-blkvm)I,2-3") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@macro-dial:1] Go toIf("Local/2@from-queue-000008d3;2", "0?dial") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@macro-dial:2] Se t("Local/2@from-queue-000008d3;2", "CHANNEL(musicclass)=default") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@macro-dial:3] AG I("Local/2@from-queue-000008d3;2", "dialparties.agi") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] res_agi.c: -- Launched AGI Script /var/ lib/asterisk/agi-bin/dialparties.agi [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] res_agi.c: dialparties.agi: Starting New D ialparties.agi [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] res_agi.c: dialparties.agi: Caller ID name is '2066969038' number is '2066969038' [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] res_agi.c: dialparties.agi: Methodology of ring is 'ringallv2-prim' [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] res_agi.c: -- dialparties.agi: Added ex tension 2 to extension map [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] res_agi.c: -- dialparties.agi: Added ex tension 3 to extension map [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] res_agi.c: -- dialparties.agi: Extensio n 2 cf is disabled [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] res_agi.c: -- dialparties.agi: Extensio n 3 cf is disabled [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] res_agi.c: -- dialparties.agi: Extensio n 2 do not disturb is disabled [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] res_agi.c: -- dialparties.agi: Extensio n 3 do not disturb is disabled [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] res_agi.c: dialparties.agi: EXTENSION_STAT E: 1 (INUSE) [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] res_agi.c: dialparties.agi: Extension 2 ha s ExtensionState: 1 [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] res_agi.c: dialparties.agi: EXTENSION_STAT E: 1 (INUSE) [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] res_agi.c: dialparties.agi: Extension 2 ha s ExtensionState: 1 [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] res_agi.c: -- dialparties.agi: Checking CW and CFB status for extension 2 [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] res_agi.c: dialparties.agi: Extension 2 is not available to be called [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] res_agi.c: dialparties.agi: Extension 2 ha s call waiting disabled [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] res_agi.c: -- dialparties.agi: Filtered ARG3: [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] res_agi.c: -- AGI Script dialparties.agi completed, returning 0 [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [s@macro-dial:4] No Op("Local/2@from-queue-000008d3;2", "Returned from dialparties with no extensions to call an d DIALSTATUS: BUSY") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:23 ] Goto("Local/2@from-queue-000008d3;2", "nextstep") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Goto (from-internal,2,25) [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:25 ] Set("Local/2@from-queue-000008d3;2", "RingGroupMethod=") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:26 ] GotoIf("Local/2@from-queue-000008d3;2", "1?nodest") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Goto (from-internal,2,32) [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [2@from-internal:32 ] NoOp("Local/2@from-queue-000008d3;2", "SKIPPING DEST, CALL CAME FROM Q/RG: 5149") in new s tack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Auto fallthrough, channel 'Lo cal/2@from-queue-000008d3;2' status is 'BUSY' [2015-08-23 18:35:03] VERBOSE[30164][C-00000469] app_queue.c: -- Local/2@from-queue-0000 08d3;1 is busy [2015-08-23 18:35:03] VERBOSE[30164][C-00000469] app_queue.c: -- Nobody picked up in 0 m s [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: -- Executing [h@from-internal:1] Hangup("Local/2@from-queue-000008d3;2", "") in new stack [2015-08-23 18:35:03] VERBOSE[30194][C-00000469] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on 'Local/2@from-queue-000008d3;2' [2015-08-23 18:35:05] VERBOSE[30164][C-00000469] pbx.c: == Spawn extension (ext-queues, 51 49, 41) exited non-zero on 'SIP/from-trunk-00000bcb' [2015-08-23 18:35:05] VERBOSE[30164][C-00000469] pbx.c: -- Executing [h@ext-queues:1] Ma cro("SIP/from-trunk-00000bcb", "hangupcall,") in new stack [2015-08-23 18:35:05] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@macro-hangupcall :1] GotoIf("SIP/from-trunk-00000bcb", "1?theend") in new stack [2015-08-23 18:35:05] VERBOSE[30164][C-00000469] pbx.c: -- Goto (macro-hangupcall,s,3) [2015-08-23 18:35:05] VERBOSE[30164][C-00000469] pbx.c: -- Executing [s@macro-hangupcall :3] Hangup("SIP/from-trunk-00000bcb", "") in new stack [2015-08-23 18:35:05] VERBOSE[30164][C-00000469] app_macro.c: == Spawn extension (macro-ha ngupcall, s, 3) exited non-zero on 'SIP/from-trunk-00000bcb' in macro 'hangupcall' [2015-08-23 18:35:05] VERBOSE[30164][C-00000469] pbx.c: == Spawn extension (ext-queues, h, 1) exited non-zero on 'SIP/from-trunk-00000bcb' [2015-08-26 09:12:58] VERBOSE[2392][C-00000469] netsock2.c: == Using SIP RTP TOS bits 184 [2015-08-26 09:12:58] VERBOSE[2392][C-00000469] netsock2.c: == Using SIP RTP CoS mark 5 [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [2063952600@from-tr unk:1] Set("SIP/from-trunk-00000604", "__FROM_DID=2063952600") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [2063952600@from-tr unk:2] Gosub("SIP/from-trunk-00000604", "sub-record-check,s,1(in,2063952600,dontcare)") in n ew stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@sub-record-check :1] GotoIf("SIP/from-trunk-00000604", "0?initialized") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@sub-record-check :2] Set("SIP/from-trunk-00000604", "__REC_STATUS=INITIALIZED") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@sub-record-check :3] Set("SIP/from-trunk-00000604", "NOW=1440605578") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@sub-record-check :4] Set("SIP/from-trunk-00000604", "__DAY=26") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@sub-record-check :5] Set("SIP/from-trunk-00000604", "__MONTH=08") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@sub-record-check :6] Set("SIP/from-trunk-00000604", "__YEAR=2015") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@sub-record-check :7] Set("SIP/from-trunk-00000604", "__TIMESTR=20150826-091258") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@sub-record-check :8] Set("SIP/from-trunk-00000604", "__FROMEXTEN=unknown") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@sub-record-check :9] Set("SIP/from-trunk-00000604", "__MON_FMT=wav") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@sub-record-check :10] NoOp("SIP/from-trunk-00000604", "Recordings initialized") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@sub-record-check :11] ExecIf("SIP/from-trunk-00000604", "0?Set(ARG3=dontcare)") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@sub-record-check :12] Set("SIP/from-trunk-00000604", "REC_POLICY_MODE_SAVE=") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@sub-record-check :13] ExecIf("SIP/from-trunk-00000604", "0?Set(REC_STATUS=NO)") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@sub-record-check :14] GotoIf("SIP/from-trunk-00000604", "2?checkaction") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Goto (sub-record-check,s,17) [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@sub-record-check :17] GotoIf("SIP/from-trunk-00000604", "1?sub-record-check,in,1") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Goto (sub-record-check,in,1) [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [in@sub-record-chec k:1] NoOp("SIP/from-trunk-00000604", "Inbound Recording Check to 2063952600") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [in@sub-record-chec k:2] Set("SIP/from-trunk-00000604", "FROMEXTEN=unknown") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [in@sub-record-chec k:3] ExecIf("SIP/from-trunk-00000604", "10?Set(FROMEXTEN=2066337888)") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [in@sub-record-chec k:4] Gosub("SIP/from-trunk-00000604", "recordcheck,1(dontcare,in,2063952600)") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [recordcheck@sub-re cord-check:1] NoOp("SIP/from-trunk-00000604", "Starting recording check against dontcare") i n new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [recordcheck@sub-re cord-check:2] Goto("SIP/from-trunk-00000604", "dontcare") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Goto (sub-record-check,record check,3) [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [recordcheck@sub-re cord-check:3] Return("SIP/from-trunk-00000604", "") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [in@sub-record-chec k:5] Return("SIP/from-trunk-00000604", "") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [2063952600@from-tr unk:3] Gosub("SIP/from-trunk-00000604", "app-blacklist-check,s,1()") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@app-blacklist-ch eck:1] GotoIf("SIP/from-trunk-00000604", "0?blacklisted") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@app-blacklist-ch eck:2] Set("SIP/from-trunk-00000604", "CALLED_BLACKLIST=1") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@app-blacklist-ch eck:3] Return("SIP/from-trunk-00000604", "") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [2063952600@from-tr unk:4] Set("SIP/from-trunk-00000604", "CDR(did)=2063952600") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [2063952600@from-tr unk:5] ExecIf("SIP/from-trunk-00000604", "0 ?Set(CALLERID(name)=2066337888)") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [2063952600@from-tr unk:6] Set("SIP/from-trunk-00000604", "CHANNEL(musicclass)=default") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [2063952600@from-tr unk:7] Set("SIP/from-trunk-00000604", "__MOHCLASS=default") in new stack [2015-08-26 09:12:58] WARNING[18320][C-00000469] func_channel.c: Unknown or unavailable item requested: 'reversecharge' [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [2063952600@from-tr unk:8] GotoIf("SIP/from-trunk-00000604", "0?macro-hangupcall") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [2063952600@from-tr unk:9] Set("SIP/from-trunk-00000604", "__CALLINGPRES_SV=allowed_not_screened") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [2063952600@from-tr unk:10] Set("SIP/from-trunk-00000604", "CALLERPRES()=allowed_not_screened") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [2063952600@from-tr unk:11] Set("SIP/from-trunk-00000604", "FAX_DEST=from-did-direct^712^1") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [2063952600@from-tr unk:12] Set("SIP/from-trunk-00000604", "FAXOPT(faxdetect)=yes") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [2063952600@from-tr unk:13] Answer("SIP/from-trunk-00000604", "") in new stack [2015-08-26 09:12:58] VERBOSE[18320][C-00000469] pbx.c: -- Executing [2063952600@from-tr unk:14] Wait("SIP/from-trunk-00000604", "5") in new stack [2015-08-26 09:13:03] VERBOSE[18320][C-00000469] pbx.c: -- Executing [2063952600@from-tr unk:15] Goto("SIP/from-trunk-00000604", "ivr-1,s,1") in new stack [2015-08-26 09:13:03] VERBOSE[18320][C-00000469] pbx.c: -- Goto (ivr-1,s,1) [2015-08-26 09:13:03] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@ivr-1:1] Set("SI P/from-trunk-00000604", "TIMEOUT_LOOPCOUNT=0") in new stack [2015-08-26 09:13:03] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@ivr-1:2] Set("SI P/from-trunk-00000604", "INVALID_LOOPCOUNT=0") in new stack [2015-08-26 09:13:03] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@ivr-1:3] Set("SI P/from-trunk-00000604", "_IVR_CONTEXT_ivr-1=") in new stack [2015-08-26 09:13:03] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@ivr-1:4] Set("SI P/from-trunk-00000604", "_IVR_CONTEXT=ivr-1") in new stack [2015-08-26 09:13:03] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@ivr-1:5] Set("SI P/from-trunk-00000604", "__IVR_RETVM=") in new stack [2015-08-26 09:13:03] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@ivr-1:6] GotoIf( "SIP/from-trunk-00000604", "0?skip") in new stack [2015-08-26 09:13:03] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@ivr-1:7] Answer( "SIP/from-trunk-00000604", "") in new stack [2015-08-26 09:13:03] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@ivr-1:8] Wait("S IP/from-trunk-00000604", "1") in new stack [2015-08-26 09:13:04] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@ivr-1:9] Set("SI P/from-trunk-00000604", "IVR_MSG=custom/MatisiaAA") in new stack [2015-08-26 09:13:04] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@ivr-1:10] Set("S IP/from-trunk-00000604", "TIMEOUT(digit)=3") in new stack [2015-08-26 09:13:04] VERBOSE[18320][C-00000469] func_timeout.c: -- Digit timeout set to 3.000 [2015-08-26 09:13:04] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@ivr-1:11] ExecIf ("SIP/from-trunk-00000604", "1?Background(custom/MatisiaAA)") in new stack [2015-08-26 09:13:04] VERBOSE[18320][C-00000469] file.c: -- Pl aying 'custom/MatisiaAA.slin' (language 'en') [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [709@ivr-1:1] Macro ("SIP/from-trunk-00000604", "blkvm-clr,") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-blkvm-clr: 1] Set("SIP/from-trunk-00000604", "SHARED(BLKVM,)=") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-blkvm-clr: 2] Set("SIP/from-trunk-00000604", "GOSUB_RETVAL=") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-blkvm-clr: 3] MacroExit("SIP/from-trunk-00000604", "") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [709@ivr-1:2] Set(" SIP/from-trunk-00000604", "__NODEST=") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [709@ivr-1:3] Goto( "SIP/from-trunk-00000604", "from-internal,709,1") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Goto (from-internal,709,1) [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [709@from-internal: 1] Set("SIP/from-trunk-00000604", "__RINGTIMER=15") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [709@from-internal: 2] Macro("SIP/from-trunk-00000604", "exten-vm,709,709,0,0,0") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-exten-vm:1 ] Macro("SIP/from-trunk-00000604", "user-callerid,") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:1] Set("SIP/from-trunk-00000604", "TOUCH_MONITOR=1440605578.24768") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:2] Set("SIP/from-trunk-00000604", "AMPUSER=2066337888") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:3] GotoIf("SIP/from-trunk-00000604", "0?report") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:4] ExecIf("SIP/from-trunk-00000604", "1?Set(REALCALLERIDNUM=2066337888)") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:5] Set("SIP/from-trunk-00000604", "AMPUSER=") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:6] GotoIf("SIP/from-trunk-00000604", "0?limit") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:7] Set("SIP/from-trunk-00000604", "AMPUSERCIDNAME=") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:8] GotoIf("SIP/from-trunk-00000604", "1?report") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Goto (macro-user-callerid,s,1 6) [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:16] GotoIf("SIP/from-trunk-00000604", "0?continue") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:17] ExecIf("SIP/from-trunk-00000604", "1?Set(__CALLEE_ACCOUNCODE=878)") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:18] Set("SIP/from-trunk-00000604", "__TTL=64") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:19] GotoIf("SIP/from-trunk-00000604", "1?continue") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Goto (macro-user-callerid,s,3 0) [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:30] Set("SIP/from-trunk-00000604", "CALLERID(number)=2066337888") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:31] Set("SIP/from-trunk-00000604", "CALLERID(name)=2066337888") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:32] Set("SIP/from-trunk-00000604", "CDR(cnum)=2066337888") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:33] Set("SIP/from-trunk-00000604", "CDR(cnam)=2066337888") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-user-calle rid:34] Set("SIP/from-trunk-00000604", "CHANNEL(language)=en") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-exten-vm:2 ] Set("SIP/from-trunk-00000604", "RingGroupMethod=none") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-exten-vm:3 ] Set("SIP/from-trunk-00000604", "__EXTTOCALL=709") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-exten-vm:4 ] Set("SIP/from-trunk-00000604", "__PICKUPMARK=709") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-exten-vm:5 ] Set("SIP/from-trunk-00000604", "RT=15") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-exten-vm:6 ] ExecIf("SIP/from-trunk-00000604", "0?Macro(vm,709,DIRECTDIAL,)") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-exten-vm:7 ] ExecIf("SIP/from-trunk-00000604", "0?MacroExit()") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-exten-vm:8 ] Gosub("SIP/from-trunk-00000604", "sub-record-check,s,1(exten,709,dontcare)") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@sub-record-check :1] GotoIf("SIP/from-trunk-00000604", "10?initialized") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Goto (sub-record-check,s,10) [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@sub-record-check :10] NoOp("SIP/from-trunk-00000604", "Recordings initialized") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@sub-record-check :11] ExecIf("SIP/from-trunk-00000604", "0?Set(ARG3=dontcare)") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@sub-record-check :12] Set("SIP/from-trunk-00000604", "REC_POLICY_MODE_SAVE=") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@sub-record-check :13] ExecIf("SIP/from-trunk-00000604", "0?Set(REC_STATUS=NO)") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@sub-record-check :14] GotoIf("SIP/from-trunk-00000604", "5?checkaction") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Goto (sub-record-check,s,17) [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@sub-record-check :17] GotoIf("SIP/from-trunk-00000604", "1?sub-record-check,exten,1") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Goto (sub-record-check,exten, 1) [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:1] NoOp("SIP/from-trunk-00000604", "Exten Recording Check between 2066337888 and 709") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:2] Set("SIP/from-trunk-00000604", "CALLTYPE=external") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:3] ExecIf("SIP/from-trunk-00000604", "0?Set(CALLTYPE=)") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:4] Set("SIP/from-trunk-00000604", "CALLEE=dontcare") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:5] ExecIf("SIP/from-trunk-00000604", "0?Set(CALLEE=dontcare)") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:6] GotoIf("SIP/from-trunk-00000604", "1?callee") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Goto (sub-record-check,exten, 11) [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:11] Gosub("SIP/from-trunk-00000604", "recordcheck,1(dontcare,external,709)") in new sta ck [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [recordcheck@sub-re cord-check:1] NoOp("SIP/from-trunk-00000604", "Starting recording check against dontcare") i n new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [recordcheck@sub-re cord-check:2] Goto("SIP/from-trunk-00000604", "dontcare") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Goto (sub-record-check,record check,3) [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [recordcheck@sub-re cord-check:3] Return("SIP/from-trunk-00000604", "") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [exten@sub-record-c heck:12] Return("SIP/from-trunk-00000604", "") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-exten-vm:9 ] GotoIf("SIP/from-trunk-00000604", "1?macrodial") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Goto (macro-exten-vm,s,15) [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-exten-vm:1 5] GosubIf("SIP/from-trunk-00000604", "0?clrheader,1()") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-exten-vm:1 6] Macro("SIP/from-trunk-00000604", "dial-one,15,Ttr,709") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:1 ] Set("SIP/from-trunk-00000604", "DEXTEN=709") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:2 ] Set("SIP/from-trunk-00000604", "DIALSTATUS_CW=") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:3 ] GosubIf("SIP/from-trunk-00000604", "1?screen,1()") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [screen@macro-dial- one:1] GotoIf("SIP/from-trunk-00000604", "0?memory") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [screen@macro-dial- one:2] ExecIf("SIP/from-trunk-00000604", "1?System(rm -f /var/lib/asterisk/sounds/priv-calle rintros/2066337888.*)") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [screen@macro-dial- one:3] Set("SIP/from-trunk-00000604", "__SCREEN=nomemory") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [screen@macro-dial- one:4] Set("SIP/from-trunk-00000604", "__SCREEN_EXTEN=709") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [screen@macro-dial- one:5] Set("SIP/from-trunk-00000604", "ARG2=Ttrp") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [screen@macro-dial- one:6] Return("SIP/from-trunk-00000604", "") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:4 ] GosubIf("SIP/from-trunk-00000604", "0?cf,1()") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:5 ] GotoIf("SIP/from-trunk-00000604", "1?skip1") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Goto (macro-dial-one,s,8) [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:8 ] GotoIf("SIP/from-trunk-00000604", "0?nodial") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:9 ] GotoIf("SIP/from-trunk-00000604", "0?continue") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:1 0] Set("SIP/from-trunk-00000604", "EXTHASCW=ENABLED") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:1 1] GotoIf("SIP/from-trunk-00000604", "0?next1:cwinusebusy") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Goto (macro-dial-one,s,23) [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:2 3] GotoIf("SIP/from-trunk-00000604", "1?next3:continue") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Goto (macro-dial-one,s,24) [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:2 4] ExecIf("SIP/from-trunk-00000604", "0?Set(DIALSTATUS_CW=BUSY)") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:2 5] GotoIf("SIP/from-trunk-00000604", "0?nodial") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:2 6] GosubIf("SIP/from-trunk-00000604", "1?dstring,1():dlocal,1()") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [dstring@macro-dial -one:1] Set("SIP/from-trunk-00000604", "DSTRING=") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [dstring@macro-dial -one:2] Set("SIP/from-trunk-00000604", "DEVICES=709") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [dstring@macro-dial -one:3] ExecIf("SIP/from-trunk-00000604", "0?Return()") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [dstring@macro-dial -one:4] ExecIf("SIP/from-trunk-00000604", "0?Set(DEVICES=09)") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [dstring@macro-dial -one:5] Set("SIP/from-trunk-00000604", "LOOPCNT=1") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [dstring@macro-dial -one:6] Set("SIP/from-trunk-00000604", "ITER=1") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [dstring@macro-dial -one:7] Set("SIP/from-trunk-00000604", "THISDIAL=SIP/709") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [dstring@macro-dial -one:8] GosubIf("SIP/from-trunk-00000604", "1?zap2dahdi,1()") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [zap2dahdi@macro-di al-one:1] ExecIf("SIP/from-trunk-00000604", "0?Return()") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [zap2dahdi@macro-di al-one:2] Set("SIP/from-trunk-00000604", "NEWDIAL=") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [zap2dahdi@macro-di al-one:3] Set("SIP/from-trunk-00000604", "LOOPCNT2=1") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [zap2dahdi@macro-di al-one:4] Set("SIP/from-trunk-00000604", "ITER2=1") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [zap2dahdi@macro-di al-one:5] Set("SIP/from-trunk-00000604", "THISPART2=SIP/709") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [zap2dahdi@macro-di al-one:6] ExecIf("SIP/from-trunk-00000604", "0?Set(THISPART2=DAHDI/709)") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [zap2dahdi@macro-di al-one:7] Set("SIP/from-trunk-00000604", "NEWDIAL=SIP/709&") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [zap2dahdi@macro-di al-one:8] Set("SIP/from-trunk-00000604", "ITER2=2") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [zap2dahdi@macro-di al-one:9] GotoIf("SIP/from-trunk-00000604", "0?begin2") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [zap2dahdi@macro-di al-one:10] Set("SIP/from-trunk-00000604", "THISDIAL=SIP/709") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [zap2dahdi@macro-di al-one:11] Return("SIP/from-trunk-00000604", "") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [dstring@macro-dial -one:9] GotoIf("SIP/from-trunk-00000604", "1?doset") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Goto (macro-dial-one,dstring, 12) [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [dstring@macro-dial -one:12] Set("SIP/from-trunk-00000604", "DSTRING=SIP/709&") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [dstring@macro-dial -one:13] Set("SIP/from-trunk-00000604", "ITER=2") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [dstring@macro-dial -one:14] GotoIf("SIP/from-trunk-00000604", "0?begin") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [dstring@macro-dial -one:15] Set("SIP/from-trunk-00000604", "DSTRING=SIP/709") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [dstring@macro-dial -one:16] Return("SIP/from-trunk-00000604", "") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:2 7] GotoIf("SIP/from-trunk-00000604", "0?nodial") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:2 8] GotoIf("SIP/from-trunk-00000604", "0?skiptrace") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:2 9] GosubIf("SIP/from-trunk-00000604", "1?ctset,1():ctclear,1()") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [ctset@macro-dial-o ne:1] Set("SIP/from-trunk-00000604", "DB(CALLTRACE/709)=2066337888") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [ctset@macro-dial-o ne:2] Return("SIP/from-trunk-00000604", "") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:3 0] Set("SIP/from-trunk-00000604", "D_OPTIONS=Ttrp") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:3 1] ExecIf("SIP/from-trunk-00000604", "0?SIPAddHeader(Alert-Info: )") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:3 2] ExecIf("SIP/from-trunk-00000604", "0?SIPAddHeader()") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:3 3] ExecIf("SIP/from-trunk-00000604", "1?Set(CHANNEL(musicclass)=default)") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:3 4] GosubIf("SIP/from-trunk-00000604", "0?qwait,1()") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:3 5] Set("SIP/from-trunk-00000604", "__CWIGNORE=") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:3 6] Set("SIP/from-trunk-00000604", "__KEEPCID=TRUE") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:3 7] GotoIf("SIP/from-trunk-00000604", "0?usegoto,1") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:3 8] GotoIf("SIP/from-trunk-00000604", "1?godial") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Goto (macro-dial-one,s,43) [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:4 3] Macro("SIP/from-trunk-00000604", "dialout-one-predial-hook,") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dialout-on e-predial-hook:1] MacroExit("SIP/from-trunk-00000604", "") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] pbx.c: -- Executing [s@macro-dial-one:4 4] Dial("SIP/from-trunk-00000604", "SIP/709,15,Ttrp") in new stack [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] app_dial.c: -- Privacy Screening, clid is '2066337888' [2015-08-26 09:13:11] VERBOSE[18320][C-00000469] file.c: -- Pl aying 'priv-recordintro.ulaw' (language 'en') [2015-08-26 09:13:13] VERBOSE[18320][C-00000469] file.c: -- Pl aying 'beep.ulaw' (language 'en') [2015-08-26 09:13:13] VERBOSE[18320][C-00000469] app.c: -- x=0, open writing: priv-call erintros/2066337888 format: sln, 0x7fd1acb97ae8 [2015-08-26 09:13:16] VERBOSE[18320][C-00000469] app.c: -- Recording automatically stopp ed after a silence of 2 seconds [2015-08-26 09:13:16] VERBOSE[18320][C-00000469] file.c: -- Pl aying 'auth-thankyou.ulaw' (language 'en') [2015-08-26 09:13:17] VERBOSE[18320][C-00000469] file.c: -- Pl aying 'vm-dialout.ulaw' (language 'en') [2015-08-26 09:13:19] VERBOSE[18320][C-00000469] netsock2.c: == Using SIP RTP TOS bits 184 [2015-08-26 09:13:19] VERBOSE[18320][C-00000469] netsock2.c: == Using SIP RTP CoS mark 5 [2015-08-26 09:13:19] VERBOSE[18320][C-00000469] app_dial.c: -- Called SIP/709 [2015-08-26 09:13:20] VERBOSE[18320][C-00000469] app_dial.c: -- SIP/709-00000605 is ring ing [2015-08-26 09:13:25] VERBOSE[18320][C-00000469] app_dial.c: -- SIP/709-00000605 answere d SIP/from-trunk-00000604 [2015-08-26 09:13:25] VERBOSE[18320][C-00000469] file.c: -- Playing ' priv-callpending.ulaw' (language 'en') [2015-08-26 09:13:30] VERBOSE[18320][C-00000469] file.c: -- Playing ' priv-callerintros/2066337888.slin' (language 'en') [2015-08-26 09:13:31] VERBOSE[18320][C-00000469] file.c: -- Playing ' screen-callee-options.ulaw' (language 'en') [2015-08-26 09:13:38] ERROR[18320][C-00000469] astobj2.c: bad magic number for object 0x7fd1 acb994e8. Object is likely destroyed. [2015-08-26 09:13:38] ERROR[18320][C-00000469] astobj2.c: bad magic number for object 0x7fd1 acb994e8. Object is likely destroyed.