[Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [6107342734@from-pstn:1] Set("SIP/ewrinf-b703b500", "__FROM_DID=6107342734") in new stack [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [6107342734@from-pstn:2] Set("SIP/ewrinf-b703b500", "CDR(accountcode)=6107342734") in new stack [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [6107342734@from-pstn:3] Set("SIP/ewrinf-b703b500", "__CALLINGCHANNEL=SIP/ewrinf-b703b500") in new stack [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [6107342734@from-pstn:4] SetCallerPres("SIP/ewrinf-b703b500", "allowed_not_screened") in new stack [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [6107342734@from-pstn:5] Goto("SIP/ewrinf-b703b500", "app-queueprio|1|1") in new stack [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Goto (app-queueprio,1,1) [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [1@app-queueprio:1] NoOp("SIP/ewrinf-b703b500", "Changing Channel to queueprio: 7 (Check In)") in new stack [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [1@app-queueprio:2] Set("SIP/ewrinf-b703b500", "_QUEUE_PRIO=7") in new stack [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [1@app-queueprio:3] Goto("SIP/ewrinf-b703b500", "ext-queues|600|1") in new stack [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Goto (ext-queues,600,1) [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [600@ext-queues:1] Macro("SIP/ewrinf-b703b500", "user-callerid|") in new stack [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [s@macro-user-callerid:1] Set("SIP/ewrinf-b703b500", "AMPUSER=+16109606103") in new stack [Oct 7 14:47:49] DEBUG[2266] app_macro.c: Executed application: Set [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [s@macro-user-callerid:2] GotoIf("SIP/ewrinf-b703b500", "0?report") in new stack [Oct 7 14:47:49] DEBUG[2266] app_macro.c: Executed application: GotoIf [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [s@macro-user-callerid:3] ExecIf("SIP/ewrinf-b703b500", "1|Set|REALCALLERIDNUM=+16109606103") in new stack [Oct 7 14:47:49] DEBUG[2266] app_macro.c: Executed application: ExecIf [Oct 7 14:47:49] DEBUG[2266] func_db.c: DB: DEVICE/+16109606103/user not found in database. [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [s@macro-user-callerid:4] Set("SIP/ewrinf-b703b500", "AMPUSER=") in new stack [Oct 7 14:47:49] DEBUG[2266] app_macro.c: Executed application: Set [Oct 7 14:47:49] DEBUG[2266] func_db.c: DB: AMPUSER//cidname not found in database. [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [s@macro-user-callerid:5] Set("SIP/ewrinf-b703b500", "AMPUSERCIDNAME=") in new stack [Oct 7 14:47:49] DEBUG[2266] app_macro.c: Executed application: Set [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/ewrinf-b703b500", "1?report") in new stack [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Goto (macro-user-callerid,s,10) [Oct 7 14:47:49] DEBUG[2266] app_macro.c: Executed application: GotoIf [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [s@macro-user-callerid:10] GotoIf("SIP/ewrinf-b703b500", "0?continue") in new stack [Oct 7 14:47:49] DEBUG[2266] app_macro.c: Executed application: GotoIf [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [s@macro-user-callerid:11] Set("SIP/ewrinf-b703b500", "__TTL=64") in new stack [Oct 7 14:47:49] DEBUG[2266] app_macro.c: Executed application: Set [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [s@macro-user-callerid:12] GotoIf("SIP/ewrinf-b703b500", "1?continue") in new stack [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Goto (macro-user-callerid,s,19) [Oct 7 14:47:49] DEBUG[2266] app_macro.c: Executed application: GotoIf [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [s@macro-user-callerid:19] NoOp("SIP/ewrinf-b703b500", "Using CallerID "DBK ANSWERING S" <+16109606103>") in new stack [Oct 7 14:47:49] DEBUG[2266] app_macro.c: Executed application: Noop [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [600@ext-queues:2] Answer("SIP/ewrinf-b703b500", "") in new stack [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [600@ext-queues:3] Set("SIP/ewrinf-b703b500", "__BLKVM_OVERRIDE=BLKVM/600/SIP/ewrinf-b703b500") in new stack [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [600@ext-queues:4] Set("SIP/ewrinf-b703b500", "__BLKVM_BASE=600") in new stack [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [600@ext-queues:5] Set("SIP/ewrinf-b703b500", "DB(BLKVM/600/SIP/ewrinf-b703b500)=TRUE") in new stack [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [600@ext-queues:6] ExecIf("SIP/ewrinf-b703b500", "1|Set|_DIAL_OPTIONS=trM(auto-blkvm)") in new stack [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [600@ext-queues:7] Set("SIP/ewrinf-b703b500", "__NODEST=600") in new stack [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [600@ext-queues:8] Set("SIP/ewrinf-b703b500", "__ALERT_INFO=AA") in new stack [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [600@ext-queues:9] Set("SIP/ewrinf-b703b500", "MONITOR_FILENAME=/var/spool/asterisk/monitor/q600-20091007-144749-1254941269.100308") in new stack [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [600@ext-queues:10] Set("SIP/ewrinf-b703b500", "__MOHCLASS=default") in new stack [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [600@ext-queues:11] Set("SIP/ewrinf-b703b500", "__CWIGNORE=TRUE") in new stack [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Executing [600@ext-queues:12] Queue("SIP/ewrinf-b703b500", "600|tr||custom/infra_announce|20") in new stack [Oct 7 14:47:49] ERROR[2266] chan_sip.c: Call to peer '506' rejected due to usage limit of 1 [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Couldn't call SIP/506 [Oct 7 14:47:49] WARNING[2266] chan_sip.c: No such host: 101 [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- SIP/113-0a224848 is busy [Oct 7 14:47:49] VERBOSE[2266] logger.c: -- Nobody picked up in 0 ms [Oct 7 14:47:50] VERBOSE[2266] logger.c: -- SIP/110-0a283310 is ringing [Oct 7 14:47:51] VERBOSE[2266] logger.c: -- SIP/110-0a283310 answered SIP/ewrinf-b703b500 [Oct 7 14:47:51] VERBOSE[2266] logger.c: -- Playing 'custom/infra_announce' (language 'en') [Oct 7 14:47:53] NOTICE[2266] app_queue.c: Caller was about to talk to agent on SIP/110-0a283310 but the caller hungup. [Oct 7 14:47:53] VERBOSE[2266] logger.c: == Spawn extension (from-internal, 2014, 0) exited non-zero on 'SIP/ewrinf-b703b500' [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [2014@from-internal:1] Macro("SIP/ewrinf-b703b500", "exten-vm|novm|2014") in new stack [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-exten-vm:1] Macro("SIP/ewrinf-b703b500", "user-callerid") in new stack [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-user-callerid:1] Set("SIP/ewrinf-b703b500", "AMPUSER=+16109606103") in new stack [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: Set [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-user-callerid:2] GotoIf("SIP/ewrinf-b703b500", "0?report") in new stack [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: GotoIf [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-user-callerid:3] ExecIf("SIP/ewrinf-b703b500", "0|Set|REALCALLERIDNUM=+16109606103") in new stack [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: ExecIf [Oct 7 14:47:53] DEBUG[2266] func_db.c: DB: DEVICE/+16109606103/user not found in database. [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-user-callerid:4] Set("SIP/ewrinf-b703b500", "AMPUSER=") in new stack [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: Set [Oct 7 14:47:53] DEBUG[2266] func_db.c: DB: AMPUSER//cidname not found in database. [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-user-callerid:5] Set("SIP/ewrinf-b703b500", "AMPUSERCIDNAME=") in new stack [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: Set [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/ewrinf-b703b500", "1?report") in new stack [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Goto (macro-user-callerid,s,10) [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: GotoIf [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-user-callerid:10] GotoIf("SIP/ewrinf-b703b500", "0?continue") in new stack [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: GotoIf [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-user-callerid:11] Set("SIP/ewrinf-b703b500", "__TTL=63") in new stack [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: Set [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-user-callerid:12] GotoIf("SIP/ewrinf-b703b500", "1?continue") in new stack [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Goto (macro-user-callerid,s,19) [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: GotoIf [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-user-callerid:19] NoOp("SIP/ewrinf-b703b500", "Using CallerID "DBK ANSWERING S" <+16109606103>") in new stack [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: Noop [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: Macro [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-exten-vm:2] Set("SIP/ewrinf-b703b500", "RingGroupMethod=none") in new stack [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: Set [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-exten-vm:3] Set("SIP/ewrinf-b703b500", "VMBOX=novm") in new stack [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: Set [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-exten-vm:4] Set("SIP/ewrinf-b703b500", "EXTTOCALL=2014") in new stack [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: Set [Oct 7 14:47:53] DEBUG[2266] func_db.c: DB: CFU/2014 not found in database. [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-exten-vm:5] Set("SIP/ewrinf-b703b500", "CFUEXT=") in new stack [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: Set [Oct 7 14:47:53] DEBUG[2266] func_db.c: DB: CFB/2014 not found in database. [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-exten-vm:6] Set("SIP/ewrinf-b703b500", "CFBEXT=") in new stack [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: Set [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-exten-vm:7] Set("SIP/ewrinf-b703b500", "RT=""") in new stack [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: Set [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-exten-vm:8] Macro("SIP/ewrinf-b703b500", "record-enable|2014|IN") in new stack [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-record-enable:1] GotoIf("SIP/ewrinf-b703b500", "1?check") in new stack [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Goto (macro-record-enable,s,4) [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: GotoIf [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-record-enable:4] AGI("SIP/ewrinf-b703b500", "recordingcheck|20091007-144753|1254941269.100308") in new stack [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck [Oct 7 14:47:53] DEBUG[2266] res_agi.c: SIP/ewrinf-b703b500 hungup [Oct 7 14:47:53] VERBOSE[2266] logger.c: == Spawn extension (macro-record-enable, s, 4) exited non-zero on 'SIP/ewrinf-b703b500' in macro 'record-enable' [Oct 7 14:47:53] VERBOSE[2266] logger.c: == Spawn extension (macro-exten-vm, s, 8) exited non-zero on 'SIP/ewrinf-b703b500' in macro 'exten-vm' [Oct 7 14:47:53] VERBOSE[2266] logger.c: == Spawn extension (from-internal, 2014, 1) exited non-zero on 'SIP/ewrinf-b703b500' [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [h@from-internal:1] Macro("SIP/ewrinf-b703b500", "hangupcall") in new stack [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-hangupcall:1] ResetCDR("SIP/ewrinf-b703b500", "vw") in new stack [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: ResetCDR [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-hangupcall:2] NoCDR("SIP/ewrinf-b703b500", "") in new stack [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: NoCDR [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-hangupcall:3] GotoIf("SIP/ewrinf-b703b500", "1?skiprg") in new stack [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Goto (macro-hangupcall,s,6) [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: GotoIf [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-hangupcall:6] GotoIf("SIP/ewrinf-b703b500", "0?skipblkvm") in new stack [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: GotoIf [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-hangupcall:7] NoOp("SIP/ewrinf-b703b500", "Cleaning Up Block VM Flag: BLKVM/600/SIP/ewrinf-b703b500") in new stack [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: Noop [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-hangupcall:8] DBdel("SIP/ewrinf-b703b500", "BLKVM/600/SIP/ewrinf-b703b500") in new stack [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- DBdel: family=BLKVM, key=600/SIP/ewrinf-b703b500 [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: DBDel [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-hangupcall:9] GotoIf("SIP/ewrinf-b703b500", "1?theend") in new stack [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Goto (macro-hangupcall,s,11) [Oct 7 14:47:53] DEBUG[2266] app_macro.c: Executed application: GotoIf [Oct 7 14:47:53] VERBOSE[2266] logger.c: -- Executing [s@macro-hangupcall:11] Hangup("SIP/ewrinf-b703b500", "") in new stack [Oct 7 14:47:53] VERBOSE[2266] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/ewrinf-b703b500' in macro 'hangupcall' [Oct 7 14:47:53] VERBOSE[2266] logger.c: == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/ewrinf-b703b500'