Jun 11 15:55:54 VERBOSE[29027] logger.c: -- Starting simple switch on 'Zap/5-1'
Jun 11 15:55:55 DEBUG[29027] pbx.c: Function result is '5023260'
Jun 11 15:55:55 DEBUG[29027] pbx.c: Function result is '7'
Jun 11 15:55:55 DEBUG[29027] pbx.c: Expression result is '1'
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing GosubIf("Zap/5-1", "1?set02|1") in new stack
Jun 11 15:55:55 DEBUG[29027] pbx.c: Function result is '5023260'
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing Set("Zap/5-1", "CALLERID(num)=025023260") in new stack
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing Return("Zap/5-1", "") in new stack
Jun 11 15:55:55 DEBUG[29027] pbx.c: Function result is '025023260'
Jun 11 15:55:55 DEBUG[29027] pbx.c: Function result is '9'
Jun 11 15:55:55 DEBUG[29027] pbx.c: Expression result is '0'
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing GosubIf("Zap/5-1", "0?set0|1") in new stack
Jun 11 15:55:55 DEBUG[29027] pbx.c: Expression result is '0'
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing GosubIf("Zap/5-1", "0?set1800|1") in new stack
Jun 11 15:55:55 DEBUG[29027] pbx.c: Expression result is '0'
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing GosubIf("Zap/5-1", "0?set1800|1") in new stack
Jun 11 15:55:55 DEBUG[29027] pbx.c: Expression result is '0'
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing GosubIf("Zap/5-1", "0?set1800|1") in new stack
Jun 11 15:55:55 DEBUG[29027] pbx.c: Expression result is '0'
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing GosubIf("Zap/5-1", "0?set1800|1") in new stack
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing Macro("Zap/5-1", "hangup") in new stack
Jun 11 15:55:55 WARNING[29027] app_macro.c: No such context 'macro-hangup' for macro 'hangup'
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing NoOp("Zap/5-1", "Is a Zaptel Channel") in new stack
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing Set("Zap/5-1", "CHAN=5-1") in new stack
Jun 11 15:55:55 DEBUG[29027] pbx.c: Function result is '5'
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing Set("Zap/5-1", "CHAN=5") in new stack
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing Macro("Zap/5-1", "from-zaptel-5||1") in new stack
Jun 11 15:55:55 WARNING[29027] app_macro.c: No such context 'macro-from-zaptel-5' for macro 'from-zaptel-5'
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing NoOp("Zap/5-1", "Returned from Macro from-zaptel-5") in new stack
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing Goto("Zap/5-1", "from-pstn||1") in new stack
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Goto (from-pstn,s,1)
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing Set("Zap/5-1", "FROM_DID=s") in new stack
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing Gosub("Zap/5-1", "cidlookup|cidlookup_4|1") in new stack
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing MYSQL("Zap/5-1", "Connect connid 192.168.0.50 asteriskuser amp109 test") in new stack
Jun 11 15:55:55 DEBUG[29027] pbx.c: Function result is '025023260'
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing MYSQL("Zap/5-1", "Query resultid 1 SELECT name FROM Callers WHERE Phone = '025023260' ") in new stack
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing MYSQL("Zap/5-1", "Fetch fetchid 2 CALLERID(name)") in new stack
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing MYSQL("Zap/5-1", "Clear 2") in new stack
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing MYSQL("Zap/5-1", "Disconnect 1") in new stack
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing Return("Zap/5-1", "") in new stack
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing Gosub("Zap/5-1", "app-blacklist-check|s|1") in new stack
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing LookupBlacklist("Zap/5-1", "") in new stack
Jun 11 15:55:55 DEBUG[29027] db.c: Unable to find key '025023260' in family 'blacklist'
Jun 11 15:55:55 DEBUG[29027] pbx.c: Expression result is '0'
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing GotoIf("Zap/5-1", "0?blacklisted") in new stack
Jun 11 15:55:55 DEBUG[29027] pbx.c: Not taking any branch
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing Return("Zap/5-1", "") in new stack
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing Goto("Zap/5-1", "timeconditions|3|1") in new stack
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Goto (timeconditions,3,1)
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing GotoIfTime("Zap/5-1", "09:38-10:14|sun-fri|*|*?ivr-4|s|1") in new stack
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing Goto("Zap/5-1", "timeconditions|1|1") in new stack
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Goto (timeconditions,1,1)
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing GotoIfTime("Zap/5-1", "10:14-19:59|sun-thu|*|*?ivr-2|s|1") in new stack
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Goto (ivr-2,s,1)
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing Set("Zap/5-1", "LOOPCOUNT=0") in new stack
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing Set("Zap/5-1", "__DIR-CONTEXT=default") in new stack
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing Set("Zap/5-1", "_IVR_CONTEXT_ivr-2=") in new stack
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing Set("Zap/5-1", "_IVR_CONTEXT=ivr-2") in new stack
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing Answer("Zap/5-1", "") in new stack
Jun 11 15:55:55 DEBUG[29027] chan_zap.c: Took Zap/5-1 off hook
Jun 11 15:55:55 DEBUG[29027] chan_zap.c: Enabled echo cancellation on channel 5
Jun 11 15:55:55 WARNING[29027] chan_zap.c: Unable to request echo training on channel 5
Jun 11 15:55:55 VERBOSE[29027] logger.c: -- Executing Wait("Zap/5-1", "1") in new stack
Jun 11 15:55:56 VERBOSE[29027] logger.c: -- Executing Set("Zap/5-1", "TIMEOUT(digit)=3") in new stack
Jun 11 15:55:56 VERBOSE[29027] logger.c: -- Digit timeout set to 3
Jun 11 15:55:56 VERBOSE[29027] logger.c: -- Executing Set("Zap/5-1", "TIMEOUT(response)=1") in new stack
Jun 11 15:55:56 VERBOSE[29027] logger.c: -- Response timeout set to 1
Jun 11 15:55:56 VERBOSE[29027] logger.c: -- Executing BackGround("Zap/5-1", "custom/Main-Day&he/transfer") in new stack
Jun 11 15:55:56 DEBUG[29027] channel.c: Scheduling timer at 160 sample intervals
Jun 11 15:55:56 VERBOSE[29027] logger.c: -- Playing 'custom/Main-Day' (language 'he')
Jun 11 15:56:04 DEBUG[29027] channel.c: Scheduling timer at 58 sample intervals
Jun 11 15:56:04 DEBUG[29027] channel.c: Scheduling timer at 0 sample intervals
Jun 11 15:56:04 DEBUG[29027] channel.c: Scheduling timer at 0 sample intervals
Jun 11 15:56:05 DEBUG[29027] channel.c: Scheduling timer at 160 sample intervals
Jun 11 15:56:05 VERBOSE[29027] logger.c: -- Playing 'he/transfer' (language 'he')
Jun 11 15:56:06 DEBUG[29027] channel.c: Scheduling timer at 0 sample intervals
Jun 11 15:56:06 DEBUG[29027] channel.c: Scheduling timer at 0 sample intervals
Jun 11 15:56:07 VERBOSE[29027] logger.c: -- Timeout on Zap/5-1
Jun 11 15:56:07 VERBOSE[29027] logger.c: == CDR updated on Zap/5-1
Jun 11 15:56:07 VERBOSE[29027] logger.c: -- Executing DBdel("Zap/5-1", "") in new stack
Jun 11 15:56:07 DEBUG[29027] app_db.c: Ignoring, no parameters
Jun 11 15:56:07 VERBOSE[29027] logger.c: -- Executing Set("Zap/5-1", "__NODEST=") in new stack
Jun 11 15:56:07 VERBOSE[29027] logger.c: -- Executing Goto("Zap/5-1", "ext-queues|1|1") in new stack
Jun 11 15:56:07 VERBOSE[29027] logger.c: -- Goto (ext-queues,1,1)
Jun 11 15:56:07 VERBOSE[29027] logger.c: -- Executing Answer("Zap/5-1", "") in new stack
Jun 11 15:56:07 VERBOSE[29027] logger.c: -- Executing Set("Zap/5-1", "__BLKVM_OVERRIDE=BLKVM/1/Zap/5-1") in new stack
Jun 11 15:56:07 VERBOSE[29027] logger.c: -- Executing Set("Zap/5-1", "__BLKVM_BASE=1") in new stack
Jun 11 15:56:07 VERBOSE[29027] logger.c: -- Executing Set("Zap/5-1", "DB(BLKVM/1/Zap/5-1)=TRUE") in new stack
Jun 11 15:56:07 VERBOSE[29027] logger.c: -- Executing Set("Zap/5-1", "_DIAL_OPTIONS=TtWM(auto-blkvm)") in new stack
Jun 11 15:56:07 VERBOSE[29027] logger.c: -- Executing Set("Zap/5-1", "__NODEST=1") in new stack
Jun 11 15:56:07 DEBUG[29027] pbx.c: Expression result is '0'
Jun 11 15:56:07 VERBOSE[29027] logger.c: -- Executing GotoIf("Zap/5-1", "0?USERCID:SETCID") in new stack
Jun 11 15:56:07 VERBOSE[29027] logger.c: -- Goto (ext-queues,1,9)
Jun 11 15:56:07 VERBOSE[29027] logger.c: -- Executing Set("Zap/5-1", "CALLERID(name)=") in new stack
Jun 11 15:56:07 VERBOSE[29027] logger.c: -- Executing Set("Zap/5-1", "MONITOR_FILENAME=/var/spool/asterisk/monitor/q1-20070611-155607-1181566554.26687") in new stack
Jun 11 15:56:07 VERBOSE[29027] logger.c: -- Executing Queue("Zap/5-1", "1|t|||1200") in new stack
Jun 11 15:56:07 VERBOSE[29027] logger.c: -- Started music on hold, class 'default', on Zap/5-1
Jun 11 15:56:07 DEBUG[29027] channel.c: Scheduling timer at 160 sample intervals
Jun 11 15:56:07 VERBOSE[29027] logger.c: -- Called Local/201@from-internal/n
Jun 11 15:56:07 VERBOSE[29027] logger.c: -- Called Local/202@from-internal/n
Jun 11 15:56:07 VERBOSE[29027] logger.c: -- Called Local/203@from-internal/n
Jun 11 15:56:07 VERBOSE[29027] logger.c: -- Called Local/204@from-internal/n
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Executing Macro("Local/201@from-internal-deab,2", "exten-vm|201|201") in new stack
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Executing Macro("Local/201@from-internal-deab,2", "user-callerid") in new stack
Jun 11 15:56:07 DEBUG[29031] pbx.c: Function result is ''
Jun 11 15:56:07 DEBUG[29031] pbx.c: Function result is '025023260'
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Executing NoOp("Local/201@from-internal-deab,2", "user-callerid: 025023260") in new stack
Jun 11 15:56:07 DEBUG[29031] app_macro.c: Executed application: Noop
Jun 11 15:56:07 DEBUG[29031] pbx.c: Expression result is '1'
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Executing GotoIf("Local/201@from-internal-deab,2", "1?report") in new stack
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Goto (macro-user-callerid,s,11)
Jun 11 15:56:07 DEBUG[29031] app_macro.c: Executed application: GotoIf
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Executing NoOp("Local/201@from-internal-deab,2", "TTL: ARG1: 201") in new stack
Jun 11 15:56:07 DEBUG[29031] app_macro.c: Executed application: Noop
Jun 11 15:56:07 DEBUG[29031] pbx.c: Expression result is '0'
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Executing GotoIf("Local/201@from-internal-deab,2", "0?continue") in new stack
Jun 11 15:56:07 DEBUG[29031] pbx.c: Not taking any branch
Jun 11 15:56:07 DEBUG[29031] app_macro.c: Executed application: GotoIf
Jun 11 15:56:07 DEBUG[29031] pbx.c: Expression result is '1'
Jun 11 15:56:07 DEBUG[29031] pbx.c: Expression result is '-1'
Jun 11 15:56:07 DEBUG[29031] pbx.c: Function result is '64'
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Executing Set("Local/201@from-internal-deab,2", "_TTL=64") in new stack
Jun 11 15:56:07 DEBUG[29031] app_macro.c: Executed application: Set
Jun 11 15:56:07 DEBUG[29031] pbx.c: Expression result is '1'
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Executing GotoIf("Local/201@from-internal-deab,2", "1?continue") in new stack
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Goto (macro-user-callerid,s,21)
Jun 11 15:56:07 DEBUG[29031] app_macro.c: Executed application: GotoIf
Jun 11 15:56:07 DEBUG[29031] pbx.c: Function result is '"" <025023260>'
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Executing NoOp("Local/201@from-internal-deab,2", "Using CallerID "" <025023260>") in new stack
Jun 11 15:56:07 DEBUG[29031] app_macro.c: Executed application: NoOp
Jun 11 15:56:07 DEBUG[29031] app_macro.c: Executed application: Macro
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Executing Set("Local/201@from-internal-deab,2", "FROMCONTEXT=exten-vm") in new stack
Jun 11 15:56:07 DEBUG[29031] app_macro.c: Executed application: Set
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Executing Set("Local/201@from-internal-deab,2", "VMBOX=201") in new stack
Jun 11 15:56:07 DEBUG[29031] app_macro.c: Executed application: Set
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Executing Set("Local/201@from-internal-deab,2", "EXTTOCALL=201") in new stack
Jun 11 15:56:07 DEBUG[29031] app_macro.c: Executed application: Set
Jun 11 15:56:07 DEBUG[29031] db.c: Unable to find key '201' in family 'CFU'
Jun 11 15:56:07 DEBUG[29031] func_db.c: DB: CFU/201 not found in database.
Jun 11 15:56:07 DEBUG[29031] pbx.c: Function result is ''
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Executing Set("Local/201@from-internal-deab,2", "CFUEXT=") in new stack
Jun 11 15:56:07 DEBUG[29031] app_macro.c: Executed application: Set
Jun 11 15:56:07 DEBUG[29031] db.c: Unable to find key '201' in family 'CFB'
Jun 11 15:56:07 DEBUG[29031] func_db.c: DB: CFB/201 not found in database.
Jun 11 15:56:07 DEBUG[29031] pbx.c: Function result is ''
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Executing Set("Local/201@from-internal-deab,2", "CFBEXT=") in new stack
Jun 11 15:56:07 DEBUG[29031] app_macro.c: Executed application: Set
Jun 11 15:56:07 DEBUG[29031] pbx.c: Expression result is '1'
Jun 11 15:56:07 DEBUG[29031] pbx.c: Expression result is '0'
Jun 11 15:56:07 DEBUG[29031] pbx.c: Expression result is '1'
Jun 11 15:56:07 DEBUG[29031] pbx.c: Function result is '60'
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Executing Set("Local/201@from-internal-deab,2", "RT=60") in new stack
Jun 11 15:56:07 DEBUG[29031] app_macro.c: Executed application: Set
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Executing Macro("Local/201@from-internal-deab,2", "record-enable|201|IN") in new stack
Jun 11 15:56:07 DEBUG[29031] pbx.c: Function result is '0'
Jun 11 15:56:07 DEBUG[29031] pbx.c: Expression result is '0'
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Executing GotoIf("Local/201@from-internal-deab,2", "0?2:4") in new stack
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Goto (macro-record-enable,s,4)
Jun 11 15:56:07 DEBUG[29031] app_macro.c: Executed application: GotoIf
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Executing DeadAGI("Local/201@from-internal-deab,2", "recordingcheck|20070611-155607|1181566567.26689") in new stack
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Executing Macro("Local/202@from-internal-4399,2", "exten-vm|novm|202") in new stack
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Executing Macro("Local/202@from-internal-4399,2", "user-callerid") in new stack
Jun 11 15:56:07 DEBUG[29032] pbx.c: Function result is ''
Jun 11 15:56:07 DEBUG[29032] pbx.c: Function result is '025023260'
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Executing NoOp("Local/202@from-internal-4399,2", "user-callerid: 025023260") in new stack
Jun 11 15:56:07 DEBUG[29032] app_macro.c: Executed application: Noop
Jun 11 15:56:07 DEBUG[29032] pbx.c: Expression result is '1'
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Executing GotoIf("Local/202@from-internal-4399,2", "1?report") in new stack
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Goto (macro-user-callerid,s,11)
Jun 11 15:56:07 DEBUG[29032] app_macro.c: Executed application: GotoIf
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Executing NoOp("Local/202@from-internal-4399,2", "TTL: ARG1: novm") in new stack
Jun 11 15:56:07 DEBUG[29032] app_macro.c: Executed application: Noop
Jun 11 15:56:07 DEBUG[29032] pbx.c: Expression result is '0'
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Executing GotoIf("Local/202@from-internal-4399,2", "0?continue") in new stack
Jun 11 15:56:07 DEBUG[29032] pbx.c: Not taking any branch
Jun 11 15:56:07 DEBUG[29032] app_macro.c: Executed application: GotoIf
Jun 11 15:56:07 DEBUG[29032] pbx.c: Expression result is '1'
Jun 11 15:56:07 DEBUG[29032] pbx.c: Expression result is '-1'
Jun 11 15:56:07 DEBUG[29032] pbx.c: Function result is '64'
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Executing Set("Local/202@from-internal-4399,2", "_TTL=64") in new stack
Jun 11 15:56:07 DEBUG[29032] app_macro.c: Executed application: Set
Jun 11 15:56:07 DEBUG[29032] pbx.c: Expression result is '1'
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Executing GotoIf("Local/202@from-internal-4399,2", "1?continue") in new stack
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Goto (macro-user-callerid,s,21)
Jun 11 15:56:07 DEBUG[29032] app_macro.c: Executed application: GotoIf
Jun 11 15:56:07 DEBUG[29032] pbx.c: Function result is '"" <025023260>'
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Executing NoOp("Local/202@from-internal-4399,2", "Using CallerID "" <025023260>") in new stack
Jun 11 15:56:07 DEBUG[29032] app_macro.c: Executed application: NoOp
Jun 11 15:56:07 DEBUG[29032] app_macro.c: Executed application: Macro
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Executing Set("Local/202@from-internal-4399,2", "FROMCONTEXT=exten-vm") in new stack
Jun 11 15:56:07 DEBUG[29032] app_macro.c: Executed application: Set
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Executing Set("Local/202@from-internal-4399,2", "VMBOX=novm") in new stack
Jun 11 15:56:07 DEBUG[29032] app_macro.c: Executed application: Set
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Executing Set("Local/202@from-internal-4399,2", "EXTTOCALL=202") in new stack
Jun 11 15:56:07 DEBUG[29032] app_macro.c: Executed application: Set
Jun 11 15:56:07 DEBUG[29032] db.c: Unable to find key '202' in family 'CFU'
Jun 11 15:56:07 DEBUG[29032] func_db.c: DB: CFU/202 not found in database.
Jun 11 15:56:07 DEBUG[29032] pbx.c: Function result is ''
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Executing Set("Local/202@from-internal-4399,2", "CFUEXT=") in new stack
Jun 11 15:56:07 DEBUG[29032] app_macro.c: Executed application: Set
Jun 11 15:56:07 DEBUG[29032] db.c: Unable to find key '202' in family 'CFB'
Jun 11 15:56:07 DEBUG[29032] func_db.c: DB: CFB/202 not found in database.
Jun 11 15:56:07 DEBUG[29032] pbx.c: Function result is ''
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Executing Set("Local/202@from-internal-4399,2", "CFBEXT=") in new stack
Jun 11 15:56:07 DEBUG[29032] app_macro.c: Executed application: Set
Jun 11 15:56:07 DEBUG[29032] pbx.c: Expression result is '0'
Jun 11 15:56:07 DEBUG[29032] pbx.c: Expression result is '0'
Jun 11 15:56:07 DEBUG[29032] pbx.c: Expression result is '0'
Jun 11 15:56:07 DEBUG[29032] pbx.c: Function result is ''
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Executing Set("Local/202@from-internal-4399,2", "RT=") in new stack
Jun 11 15:56:07 DEBUG[29032] app_macro.c: Executed application: Set
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Executing Macro("Local/202@from-internal-4399,2", "record-enable|202|IN") in new stack
Jun 11 15:56:07 DEBUG[29032] pbx.c: Function result is '0'
Jun 11 15:56:07 DEBUG[29032] pbx.c: Expression result is '0'
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Executing GotoIf("Local/202@from-internal-4399,2", "0?2:4") in new stack
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Goto (macro-record-enable,s,4)
Jun 11 15:56:07 DEBUG[29032] app_macro.c: Executed application: GotoIf
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Executing DeadAGI("Local/202@from-internal-4399,2", "recordingcheck|20070611-155607|1181566567.26691") in new stack
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Executing Macro("Local/203@from-internal-eabc,2", "exten-vm|novm|203") in new stack
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Executing Macro("Local/203@from-internal-eabc,2", "user-callerid") in new stack
Jun 11 15:56:07 DEBUG[29033] pbx.c: Function result is ''
Jun 11 15:56:07 DEBUG[29033] pbx.c: Function result is '025023260'
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Executing NoOp("Local/203@from-internal-eabc,2", "user-callerid: 025023260") in new stack
Jun 11 15:56:07 DEBUG[29033] app_macro.c: Executed application: Noop
Jun 11 15:56:07 DEBUG[29033] pbx.c: Expression result is '1'
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Executing GotoIf("Local/203@from-internal-eabc,2", "1?report") in new stack
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Goto (macro-user-callerid,s,11)
Jun 11 15:56:07 DEBUG[29033] app_macro.c: Executed application: GotoIf
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Executing NoOp("Local/203@from-internal-eabc,2", "TTL: ARG1: novm") in new stack
Jun 11 15:56:07 DEBUG[29033] app_macro.c: Executed application: Noop
Jun 11 15:56:07 DEBUG[29033] pbx.c: Expression result is '0'
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Executing GotoIf("Local/203@from-internal-eabc,2", "0?continue") in new stack
Jun 11 15:56:07 DEBUG[29033] pbx.c: Not taking any branch
Jun 11 15:56:07 DEBUG[29033] app_macro.c: Executed application: GotoIf
Jun 11 15:56:07 DEBUG[29033] pbx.c: Expression result is '1'
Jun 11 15:56:07 DEBUG[29033] pbx.c: Expression result is '-1'
Jun 11 15:56:07 DEBUG[29033] pbx.c: Function result is '64'
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Executing Set("Local/203@from-internal-eabc,2", "_TTL=64") in new stack
Jun 11 15:56:07 DEBUG[29033] app_macro.c: Executed application: Set
Jun 11 15:56:07 DEBUG[29033] pbx.c: Expression result is '1'
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Executing GotoIf("Local/203@from-internal-eabc,2", "1?continue") in new stack
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Goto (macro-user-callerid,s,21)
Jun 11 15:56:07 DEBUG[29033] app_macro.c: Executed application: GotoIf
Jun 11 15:56:07 DEBUG[29033] pbx.c: Function result is '"" <025023260>'
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Executing NoOp("Local/203@from-internal-eabc,2", "Using CallerID "" <025023260>") in new stack
Jun 11 15:56:07 DEBUG[29033] app_macro.c: Executed application: NoOp
Jun 11 15:56:07 DEBUG[29033] app_macro.c: Executed application: Macro
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Executing Set("Local/203@from-internal-eabc,2", "FROMCONTEXT=exten-vm") in new stack
Jun 11 15:56:07 DEBUG[29033] app_macro.c: Executed application: Set
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Executing Set("Local/203@from-internal-eabc,2", "VMBOX=novm") in new stack
Jun 11 15:56:07 DEBUG[29033] app_macro.c: Executed application: Set
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Executing Set("Local/203@from-internal-eabc,2", "EXTTOCALL=203") in new stack
Jun 11 15:56:07 DEBUG[29033] app_macro.c: Executed application: Set
Jun 11 15:56:07 DEBUG[29033] db.c: Unable to find key '203' in family 'CFU'
Jun 11 15:56:07 DEBUG[29033] func_db.c: DB: CFU/203 not found in database.
Jun 11 15:56:07 DEBUG[29033] pbx.c: Function result is ''
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Executing Set("Local/203@from-internal-eabc,2", "CFUEXT=") in new stack
Jun 11 15:56:07 DEBUG[29033] app_macro.c: Executed application: Set
Jun 11 15:56:07 DEBUG[29033] db.c: Unable to find key '203' in family 'CFB'
Jun 11 15:56:07 DEBUG[29033] func_db.c: DB: CFB/203 not found in database.
Jun 11 15:56:07 DEBUG[29033] pbx.c: Function result is ''
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Executing Set("Local/203@from-internal-eabc,2", "CFBEXT=") in new stack
Jun 11 15:56:07 DEBUG[29033] app_macro.c: Executed application: Set
Jun 11 15:56:07 DEBUG[29033] pbx.c: Expression result is '0'
Jun 11 15:56:07 DEBUG[29033] pbx.c: Expression result is '0'
Jun 11 15:56:07 DEBUG[29033] pbx.c: Expression result is '0'
Jun 11 15:56:07 DEBUG[29033] pbx.c: Function result is ''
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Executing Set("Local/203@from-internal-eabc,2", "RT=") in new stack
Jun 11 15:56:07 DEBUG[29033] app_macro.c: Executed application: Set
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Executing Macro("Local/203@from-internal-eabc,2", "record-enable|203|IN") in new stack
Jun 11 15:56:07 DEBUG[29033] pbx.c: Function result is '0'
Jun 11 15:56:07 DEBUG[29033] pbx.c: Expression result is '0'
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Executing GotoIf("Local/203@from-internal-eabc,2", "0?2:4") in new stack
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Goto (macro-record-enable,s,4)
Jun 11 15:56:07 DEBUG[29033] app_macro.c: Executed application: GotoIf
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Executing DeadAGI("Local/203@from-internal-eabc,2", "recordingcheck|20070611-155607|1181566567.26693") in new stack
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Jun 11 15:56:07 VERBOSE[29034] logger.c: -- Executing Macro("Local/204@from-internal-b87c,2", "exten-vm|novm|204") in new stack
Jun 11 15:56:07 VERBOSE[29034] logger.c: -- Executing Macro("Local/204@from-internal-b87c,2", "user-callerid") in new stack
Jun 11 15:56:07 DEBUG[29034] pbx.c: Function result is ''
Jun 11 15:56:07 DEBUG[29034] pbx.c: Function result is '025023260'
Jun 11 15:56:07 VERBOSE[29034] logger.c: -- Executing NoOp("Local/204@from-internal-b87c,2", "user-callerid: 025023260") in new stack
Jun 11 15:56:07 DEBUG[29034] app_macro.c: Executed application: Noop
Jun 11 15:56:07 DEBUG[29034] pbx.c: Expression result is '1'
Jun 11 15:56:07 VERBOSE[29034] logger.c: -- Executing GotoIf("Local/204@from-internal-b87c,2", "1?report") in new stack
Jun 11 15:56:07 VERBOSE[29034] logger.c: -- Goto (macro-user-callerid,s,11)
Jun 11 15:56:07 DEBUG[29034] app_macro.c: Executed application: GotoIf
Jun 11 15:56:07 VERBOSE[29034] logger.c: -- Executing NoOp("Local/204@from-internal-b87c,2", "TTL: ARG1: novm") in new stack
Jun 11 15:56:07 DEBUG[29034] app_macro.c: Executed application: Noop
Jun 11 15:56:07 DEBUG[29034] pbx.c: Expression result is '0'
Jun 11 15:56:07 VERBOSE[29034] logger.c: -- Executing GotoIf("Local/204@from-internal-b87c,2", "0?continue") in new stack
Jun 11 15:56:07 DEBUG[29034] pbx.c: Not taking any branch
Jun 11 15:56:07 DEBUG[29034] app_macro.c: Executed application: GotoIf
Jun 11 15:56:07 DEBUG[29034] pbx.c: Expression result is '1'
Jun 11 15:56:07 DEBUG[29034] pbx.c: Expression result is '-1'
Jun 11 15:56:07 DEBUG[29034] pbx.c: Function result is '64'
Jun 11 15:56:07 VERBOSE[29034] logger.c: -- Executing Set("Local/204@from-internal-b87c,2", "_TTL=64") in new stack
Jun 11 15:56:07 DEBUG[29034] app_macro.c: Executed application: Set
Jun 11 15:56:07 DEBUG[29034] pbx.c: Expression result is '1'
Jun 11 15:56:07 VERBOSE[29034] logger.c: -- Executing GotoIf("Local/204@from-internal-b87c,2", "1?continue") in new stack
Jun 11 15:56:07 VERBOSE[29034] logger.c: -- Goto (macro-user-callerid,s,21)
Jun 11 15:56:07 DEBUG[29034] app_macro.c: Executed application: GotoIf
Jun 11 15:56:07 DEBUG[29034] pbx.c: Function result is '"" <025023260>'
Jun 11 15:56:07 VERBOSE[29034] logger.c: -- Executing NoOp("Local/204@from-internal-b87c,2", "Using CallerID "" <025023260>") in new stack
Jun 11 15:56:07 DEBUG[29034] app_macro.c: Executed application: NoOp
Jun 11 15:56:07 DEBUG[29034] app_macro.c: Executed application: Macro
Jun 11 15:56:07 VERBOSE[29034] logger.c: -- Executing Set("Local/204@from-internal-b87c,2", "FROMCONTEXT=exten-vm") in new stack
Jun 11 15:56:07 DEBUG[29034] app_macro.c: Executed application: Set
Jun 11 15:56:07 VERBOSE[29034] logger.c: -- Executing Set("Local/204@from-internal-b87c,2", "VMBOX=novm") in new stack
Jun 11 15:56:07 DEBUG[29034] app_macro.c: Executed application: Set
Jun 11 15:56:07 VERBOSE[29034] logger.c: -- Executing Set("Local/204@from-internal-b87c,2", "EXTTOCALL=204") in new stack
Jun 11 15:56:07 DEBUG[29034] app_macro.c: Executed application: Set
Jun 11 15:56:07 DEBUG[29034] db.c: Unable to find key '204' in family 'CFU'
Jun 11 15:56:07 DEBUG[29034] func_db.c: DB: CFU/204 not found in database.
Jun 11 15:56:07 DEBUG[29034] pbx.c: Function result is ''
Jun 11 15:56:07 VERBOSE[29034] logger.c: -- Executing Set("Local/204@from-internal-b87c,2", "CFUEXT=") in new stack
Jun 11 15:56:07 DEBUG[29034] app_macro.c: Executed application: Set
Jun 11 15:56:07 DEBUG[29034] db.c: Unable to find key '204' in family 'CFB'
Jun 11 15:56:07 DEBUG[29034] func_db.c: DB: CFB/204 not found in database.
Jun 11 15:56:07 DEBUG[29034] pbx.c: Function result is ''
Jun 11 15:56:07 VERBOSE[29034] logger.c: -- Executing Set("Local/204@from-internal-b87c,2", "CFBEXT=") in new stack
Jun 11 15:56:07 DEBUG[29034] app_macro.c: Executed application: Set
Jun 11 15:56:07 DEBUG[29034] pbx.c: Expression result is '0'
Jun 11 15:56:07 DEBUG[29034] pbx.c: Expression result is '0'
Jun 11 15:56:07 DEBUG[29034] pbx.c: Expression result is '0'
Jun 11 15:56:07 DEBUG[29034] pbx.c: Function result is ''
Jun 11 15:56:07 VERBOSE[29034] logger.c: -- Executing Set("Local/204@from-internal-b87c,2", "RT=") in new stack
Jun 11 15:56:07 DEBUG[29034] app_macro.c: Executed application: Set
Jun 11 15:56:07 VERBOSE[29034] logger.c: -- Executing Macro("Local/204@from-internal-b87c,2", "record-enable|204|IN") in new stack
Jun 11 15:56:07 DEBUG[29034] pbx.c: Function result is '0'
Jun 11 15:56:07 DEBUG[29034] pbx.c: Expression result is '0'
Jun 11 15:56:07 VERBOSE[29034] logger.c: -- Executing GotoIf("Local/204@from-internal-b87c,2", "0?2:4") in new stack
Jun 11 15:56:07 VERBOSE[29034] logger.c: -- Goto (macro-record-enable,s,4)
Jun 11 15:56:07 DEBUG[29034] app_macro.c: Executed application: GotoIf
Jun 11 15:56:07 VERBOSE[29034] logger.c: -- Executing DeadAGI("Local/204@from-internal-b87c,2", "recordingcheck|20070611-155607|1181566567.26695") in new stack
Jun 11 15:56:07 VERBOSE[29034] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Jun 11 15:56:07 DEBUG[29027] channel.c: Generator got voice, switching to phase locked mode
Jun 11 15:56:07 DEBUG[29027] channel.c: Scheduling timer at 0 sample intervals
Jun 11 15:56:07 VERBOSE[29033] logger.c: recordingcheck|20070611-155607|1181566567.26693: Inbound recording enabled.
Jun 11 15:56:07 VERBOSE[29033] logger.c: recordingcheck|20070611-155607|1181566567.26693: CALLFILENAME=20070611-155607-1181566567.26693
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- AGI Script recordingcheck completed, returning 0
Jun 11 15:56:07 DEBUG[29033] app_macro.c: Executed application: DeadAGI
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Executing MixMonitor("Local/203@from-internal-eabc,2", "20070611-155607-1181566567.26693.WAV") in new stack
Jun 11 15:56:07 DEBUG[29033] channel.c: Spy MixMonitor added to channel Local/203@from-internal-eabc,2
Jun 11 15:56:07 DEBUG[29033] app_macro.c: Executed application: MixMonitor
Jun 11 15:56:07 DEBUG[29033] app_macro.c: Executed application: Macro
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Executing Macro("Local/203@from-internal-eabc,2", "dial||TtWM(auto-blkvm)|203") in new stack
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Executing DeadAGI("Local/203@from-internal-eabc,2", "dialparties.agi") in new stack
Jun 11 15:56:07 VERBOSE[29033] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Jun 11 15:56:07 VERBOSE[29043] logger.c: == Begin MixMonitor Recording Local/203@from-internal-eabc,2
Jun 11 15:56:07 VERBOSE[29031] logger.c: recordingcheck|20070611-155607|1181566567.26689: Inbound recording enabled.
Jun 11 15:56:07 VERBOSE[29031] logger.c: recordingcheck|20070611-155607|1181566567.26689: CALLFILENAME=20070611-155607-1181566567.26689
Jun 11 15:56:07 VERBOSE[29032] logger.c: recordingcheck|20070611-155607|1181566567.26691: Inbound recording enabled.
Jun 11 15:56:07 VERBOSE[29032] logger.c: recordingcheck|20070611-155607|1181566567.26691: CALLFILENAME=20070611-155607-1181566567.26691
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- AGI Script recordingcheck completed, returning 0
Jun 11 15:56:07 DEBUG[29032] app_macro.c: Executed application: DeadAGI
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Executing MixMonitor("Local/202@from-internal-4399,2", "20070611-155607-1181566567.26691.WAV") in new stack
Jun 11 15:56:07 DEBUG[29032] channel.c: Spy MixMonitor added to channel Local/202@from-internal-4399,2
Jun 11 15:56:07 DEBUG[29032] app_macro.c: Executed application: MixMonitor
Jun 11 15:56:07 DEBUG[29032] app_macro.c: Executed application: Macro
Jun 11 15:56:07 VERBOSE[29045] logger.c: == Begin MixMonitor Recording Local/202@from-internal-4399,2
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Executing Macro("Local/202@from-internal-4399,2", "dial||TtWM(auto-blkvm)|202") in new stack
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Executing DeadAGI("Local/202@from-internal-4399,2", "dialparties.agi") in new stack
Jun 11 15:56:07 VERBOSE[29032] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- AGI Script recordingcheck completed, returning 0
Jun 11 15:56:07 DEBUG[29031] app_macro.c: Executed application: DeadAGI
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Executing MixMonitor("Local/201@from-internal-deab,2", "20070611-155607-1181566567.26689.WAV") in new stack
Jun 11 15:56:07 DEBUG[29031] channel.c: Spy MixMonitor added to channel Local/201@from-internal-deab,2
Jun 11 15:56:07 DEBUG[29031] app_macro.c: Executed application: MixMonitor
Jun 11 15:56:07 DEBUG[29031] app_macro.c: Executed application: Macro
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Executing Macro("Local/201@from-internal-deab,2", "dial|60|TtWM(auto-blkvm)|201") in new stack
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Executing DeadAGI("Local/201@from-internal-deab,2", "dialparties.agi") in new stack
Jun 11 15:56:07 VERBOSE[29031] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Jun 11 15:56:07 VERBOSE[29047] logger.c: == Begin MixMonitor Recording Local/201@from-internal-deab,2
Jun 11 15:56:08 VERBOSE[29031] logger.c: dialparties.agi: Starting New Dialparties.agi
Jun 11 15:56:08 VERBOSE[29031] logger.c: dialparties.agi: priority is 1
Jun 11 15:56:08 VERBOSE[29031] logger.c: dialparties.agi: Caller ID name is 'unknown' number is '025023260'
Jun 11 15:56:08 VERBOSE[29031] logger.c: dialparties.agi: Methodology of ring is 'none'
Jun 11 15:56:08 VERBOSE[29031] logger.c: > dialparties.agi: USE_CONFIRMATION: 'FALSE'
Jun 11 15:56:08 VERBOSE[29031] logger.c: > dialparties.agi: RINGGROUP_INDEX: ''
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- dialparties.agi: Added extension 201 to extension map
Jun 11 15:56:08 DEBUG[29031] db.c: Unable to find key '201' in family 'CF'
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- dialparties.agi: Extension 201 cf is disabled
Jun 11 15:56:08 DEBUG[29031] db.c: Unable to find key '201' in family 'DND'
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- dialparties.agi: Extension 201 do not disturb is disabled
Jun 11 15:56:08 DEBUG[29031] db.c: Unable to find key '201' in family 'CW'
Jun 11 15:56:08 DEBUG[29031] db.c: Unable to find key '201' in family 'CFB'
Jun 11 15:56:08 DEBUG[29031] db.c: Unable to find key '201' in family 'CFU'
Jun 11 15:56:08 VERBOSE[29031] logger.c: > dialparties.agi: extnum: 201
Jun 11 15:56:08 VERBOSE[29031] logger.c: > dialparties.agi: exthascw: 0
Jun 11 15:56:08 VERBOSE[29031] logger.c: > dialparties.agi: exthascfb: 0
Jun 11 15:56:08 VERBOSE[29031] logger.c: > dialparties.agi: extcfb:
Jun 11 15:56:08 VERBOSE[29031] logger.c: > dialparties.agi: exthascfu: 0
Jun 11 15:56:08 VERBOSE[29031] logger.c: > dialparties.agi: extcfu:
Jun 11 15:56:08 DEBUG[29049] manager.c: Manager received command 'login'
Jun 11 15:56:08 VERBOSE[29049] logger.c: == Parsing '/etc/asterisk/manager.conf': Jun 11 15:56:08 VERBOSE[29049] logger.c: == Parsing '/etc/asterisk/manager.conf': Found
Jun 11 15:56:08 VERBOSE[29049] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Jun 11 15:56:08 VERBOSE[29049] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Found
Jun 11 15:56:08 DEBUG[29049] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Jun 11 15:56:08 DEBUG[29049] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Jun 11 15:56:08 DEBUG[29049] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Jun 11 15:56:08 DEBUG[29049] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Jun 11 15:56:08 VERBOSE[29049] logger.c: == Manager 'admin' logged on from 127.0.0.1
Jun 11 15:56:08 DEBUG[29049] manager.c: Manager received command 'ExtensionState'
Jun 11 15:56:08 DEBUG[29049] manager.c: Manager received command 'Logoff'
Jun 11 15:56:08 VERBOSE[29049] logger.c: == Manager 'admin' logged off from 127.0.0.1
Jun 11 15:56:08 VERBOSE[29031] logger.c: > dialparties.agi: ExtensionState: 0
Jun 11 15:56:08 VERBOSE[29031] logger.c: dialparties.agi: Extension 201 has ExtensionState: 0
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- dialparties.agi: Checking CW and CFB status for extension 201
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- dialparties.agi: dbset CALLTRACE/201 to 025023260
Jun 11 15:56:08 VERBOSE[29031] logger.c: > dialparties.agi: NODEST: 1 blkvm enabled macro already in dialopts: TtWM(auto-blkvm)
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- AGI Script dialparties.agi completed, returning 0
Jun 11 15:56:08 DEBUG[29031] app_macro.c: Executed application: DeadAGI
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- Executing Dial("Local/201@from-internal-deab,2", "SIP/201|60|TtWM(auto-blkvm)") in new stack
Jun 11 15:56:08 DEBUG[29031] chan_sip.c: Setting NAT on RTP to 524288
Jun 11 15:56:08 DEBUG[29031] chan_sip.c: Outgoing Call for 201
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- Called 201
Jun 11 15:56:08 DEBUG[25351] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '20c82bea181bca437edcd38a56ca16b4@192.168.0.50' Request 102: Found
Jun 11 15:56:08 DEBUG[25351] chan_sip.c: Acked pending invite 102
Jun 11 15:56:08 DEBUG[25351] chan_sip.c: Stopping retransmission on '20c82bea181bca437edcd38a56ca16b4@192.168.0.50' of Request 102: Match Found
Jun 11 15:56:08 VERBOSE[25351] logger.c: -- Got SIP response 486 "Busy" back from 192.168.0.18
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- SIP/201-0934d040 is busy
Jun 11 15:56:08 DEBUG[29031] chan_sip.c: update_call_counter(201) - decrement call limit counter
Jun 11 15:56:08 VERBOSE[29031] logger.c: == Everyone is busy/congested at this time (1:1/0/0)
Jun 11 15:56:08 DEBUG[29031] app_dial.c: Exiting with DIALSTATUS=BUSY.
Jun 11 15:56:08 DEBUG[29031] app_macro.c: Executed application: Dial
Jun 11 15:56:08 DEBUG[29031] app_macro.c: Executed application: Macro
Jun 11 15:56:08 DEBUG[29031] pbx.c: Expression result is '0'
Jun 11 15:56:08 DEBUG[29031] pbx.c: Expression result is '0'
Jun 11 15:56:08 DEBUG[29031] pbx.c: Expression result is '0'
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- Executing GosubIf("Local/201@from-internal-deab,2", "0?docfu|1") in new stack
Jun 11 15:56:08 DEBUG[29031] app_macro.c: Executed application: GosubIf
Jun 11 15:56:08 DEBUG[29031] pbx.c: Expression result is '0'
Jun 11 15:56:08 DEBUG[29031] pbx.c: Expression result is '0'
Jun 11 15:56:08 DEBUG[29031] pbx.c: Expression result is '0'
Jun 11 15:56:08 DEBUG[29031] pbx.c: Expression result is '1'
Jun 11 15:56:08 DEBUG[29031] pbx.c: Expression result is '0'
Jun 11 15:56:08 DEBUG[29031] pbx.c: Expression result is '0'
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- Executing GosubIf("Local/201@from-internal-deab,2", "0?docfb|1") in new stack
Jun 11 15:56:08 DEBUG[29031] app_macro.c: Executed application: GosubIf
Jun 11 15:56:08 DEBUG[29031] pbx.c: Expression result is '1'
Jun 11 15:56:08 DEBUG[29031] pbx.c: Expression result is '0'
Jun 11 15:56:08 DEBUG[29031] pbx.c: Expression result is '0'
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- Executing NoOp("Local/201@from-internal-deab,2", "Voicemail is 201") in new stack
Jun 11 15:56:08 DEBUG[29031] app_macro.c: Executed application: NoOp
Jun 11 15:56:08 DEBUG[29031] pbx.c: Expression result is '0'
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- Executing GotoIf("Local/201@from-internal-deab,2", "0?s-BUSY|1") in new stack
Jun 11 15:56:08 DEBUG[29031] pbx.c: Not taking any branch
Jun 11 15:56:08 DEBUG[29031] app_macro.c: Executed application: GotoIf
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- Executing NoOp("Local/201@from-internal-deab,2", "Sending to Voicemail box 201") in new stack
Jun 11 15:56:08 DEBUG[29031] app_macro.c: Executed application: NoOp
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- Executing Macro("Local/201@from-internal-deab,2", "vm|201|BUSY") in new stack
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- Executing Macro("Local/201@from-internal-deab,2", "user-callerid|SKIPTTL") in new stack
Jun 11 15:56:08 DEBUG[29031] pbx.c: Function result is ''
Jun 11 15:56:08 DEBUG[29031] pbx.c: Function result is '025023260'
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- Executing NoOp("Local/201@from-internal-deab,2", "user-callerid: 025023260") in new stack
Jun 11 15:56:08 DEBUG[29031] app_macro.c: Executed application: Noop
Jun 11 15:56:08 DEBUG[29031] pbx.c: Expression result is '1'
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- Executing GotoIf("Local/201@from-internal-deab,2", "1?report") in new stack
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- Goto (macro-user-callerid,s,11)
Jun 11 15:56:08 DEBUG[29031] app_macro.c: Executed application: GotoIf
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- Executing NoOp("Local/201@from-internal-deab,2", "TTL: 64 ARG1: SKIPTTL") in new stack
Jun 11 15:56:08 DEBUG[29031] app_macro.c: Executed application: Noop
Jun 11 15:56:08 DEBUG[29031] pbx.c: Expression result is '1'
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- Executing GotoIf("Local/201@from-internal-deab,2", "1?continue") in new stack
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- Goto (macro-user-callerid,s,21)
Jun 11 15:56:08 DEBUG[29031] app_macro.c: Executed application: GotoIf
Jun 11 15:56:08 DEBUG[29031] pbx.c: Function result is '"" <025023260>'
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- Executing NoOp("Local/201@from-internal-deab,2", "Using CallerID "" <025023260>") in new stack
Jun 11 15:56:08 DEBUG[29031] app_macro.c: Executed application: NoOp
Jun 11 15:56:08 DEBUG[29031] app_macro.c: Executed application: Macro
Jun 11 15:56:08 DEBUG[29031] pbx.c: Expression result is '0'
Jun 11 15:56:08 DEBUG[29031] pbx.c: Function result is ''
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- Executing Set("Local/201@from-internal-deab,2", "VMGAIN=") in new stack
Jun 11 15:56:08 DEBUG[29031] app_macro.c: Executed application: Set
Jun 11 15:56:08 DEBUG[29031] pbx.c: Function result is 'TRUE'
Jun 11 15:56:08 DEBUG[29031] pbx.c: Expression result is '0'
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- Executing GotoIf("Local/201@from-internal-deab,2", "0?s-BUSY|1") in new stack
Jun 11 15:56:08 DEBUG[29031] pbx.c: Not taking any branch
Jun 11 15:56:08 DEBUG[29031] app_macro.c: Executed application: GotoIf
Jun 11 15:56:08 WARNING[29031] func_db.c: DB requires an argument, DB(/)
Jun 11 15:56:08 DEBUG[29031] pbx.c: Function result is ''
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- Executing NoOp("Local/201@from-internal-deab,2", "CAME FROM: 1 - Blocking VM cause of key: ") in new stack
Jun 11 15:56:08 DEBUG[29031] app_macro.c: Executed application: Noop
Jun 11 15:56:08 DEBUG[29031] app_macro.c: Executed application: Macro
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- Executing Hangup("Local/201@from-internal-deab,2", "") in new stack
Jun 11 15:56:08 VERBOSE[29031] logger.c: == Spawn extension (from-internal, 201, 2) exited non-zero on 'Local/201@from-internal-deab,2'
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- Executing Macro("Local/201@from-internal-deab,2", "hangupcall") in new stack
Jun 11 15:56:08 VERBOSE[29031] logger.c: -- Executing ResetCDR("Local/201@from-internal-deab,2", "w") in new stack
Jun 11 15:56:08 DEBUG[29031] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Jun 11 15:56:08 DEBUG[29031] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid) VALUES ('2007-06-11 15:56:07','5023260','5023260','201','from-internal', 'Local/201@from-internal-deab,2','SIP/201-0934d040','ResetCDR','w',1,0,'BUSY',3,'','1181566567.26689')
Jun 11 15:56:08 DEBUG[29031] app_macro.c: Executed application: ResetCDR