Dec 26 10:03:24 VERBOSE[30966] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Dec 26 10:03:24 VERBOSE[30966] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Found
Dec 26 10:03:24 WARNING[30966] config.c: Unknown directive 'permit=127.0.0.1/255.255.255.0' at line 18 of manager_custom.conf
Dec 26 10:03:24 DEBUG[30966] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Dec 26 10:03:24 DEBUG[30966] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Dec 26 10:03:24 DEBUG[30966] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Dec 26 10:03:24 DEBUG[30966] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Dec 26 10:03:24 VERBOSE[30966] logger.c: == Manager 'admin' logged on from 127.0.0.1
Dec 26 10:03:24 DEBUG[30966] manager.c: Manager received command 'ExtensionState'
Dec 26 10:03:24 DEBUG[30966] manager.c: Manager received command 'Logoff'
Dec 26 10:03:24 VERBOSE[30966] logger.c: == Manager 'admin' logged off from 127.0.0.1
Dec 26 10:03:24 VERBOSE[30962] logger.c: > dialparties.agi: ExtensionState: 0
Dec 26 10:03:24 VERBOSE[30962] logger.c: dialparties.agi: Extension 201 has ExtensionState: 0
Dec 26 10:03:24 VERBOSE[30962] logger.c: -- dialparties.agi: Checking CW and CFB status for extension 201
Dec 26 10:03:24 VERBOSE[30962] logger.c: -- dialparties.agi: dbset CALLTRACE/201 to 4142787911
Dec 26 10:03:24 VERBOSE[30962] logger.c: -- AGI Script dialparties.agi completed, returning 0
Dec 26 10:03:24 VERBOSE[30962] logger.c: -- Executing Dial("SIP/10.0.0.7-b78237b0", "SIP/201|4|trwW") in new stack
Dec 26 10:03:24 DEBUG[30962] chan_sip.c: Setting NAT on RTP to 0
Dec 26 10:03:24 DEBUG[30962] chan_sip.c: Outgoing Call for 201
Dec 26 10:03:24 VERBOSE[30962] logger.c: -- Called 201
Dec 26 10:03:24 DEBUG[3405] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '1cb52ec0561be0984ea4a8d97f4fa391@10.0.0.7' Request 102: Found
Dec 26 10:03:24 DEBUG[3405] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '1cb52ec0561be0984ea4a8d97f4fa391@10.0.0.7' Request 102: Found
Dec 26 10:03:24 DEBUG[3384] channel.c: Avoiding initial deadlock for 'SIP/201-09ce0538'
Dec 26 10:03:24 VERBOSE[30962] logger.c: -- SIP/201-09ce0538 is ringing
Dec 26 10:03:24 DEBUG[3405] chan_sip.c: Stopping retransmission on '86078e4c-1280da6-9b3e28cd@10.0.0.208' of Request 832: Match Found
Dec 26 10:03:26 DEBUG[30962] chan_sip.c: update_call_counter(201) - decrement call limit counter
Dec 26 10:03:26 DEBUG[30962] chan_sip.c: Acked pending invite 102
Dec 26 10:03:26 DEBUG[30962] chan_sip.c: Stopping retransmission on '1cb52ec0561be0984ea4a8d97f4fa391@10.0.0.7' of Request 102: Match Found
Dec 26 10:03:26 DEBUG[30962] app_dial.c: Exiting with DIALSTATUS=CANCEL.
Dec 26 10:03:26 VERBOSE[30962] logger.c: == Spawn extension (macro-dial, s, 10) exited non-zero on 'SIP/10.0.0.7-b78237b0' in macro 'dial'
Dec 26 10:03:26 VERBOSE[30962] logger.c: == Spawn extension (macro-dial, s, 10) exited non-zero on 'SIP/10.0.0.7-b78237b0'
Dec 26 10:03:26 VERBOSE[30962] logger.c: -- Executing Macro("SIP/10.0.0.7-b78237b0", "hangupcall") in new stack
Dec 26 10:03:26 VERBOSE[30962] logger.c: -- Executing ResetCDR("SIP/10.0.0.7-b78237b0", "w") in new stack
Dec 26 10:03:26 DEBUG[30962] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Dec 26 10:03:26 DEBUG[30962] 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 ('2006-12-26 10:03:24','4142787911','4142787911','200','ext-group', 'SIP/10.0.0.7-b78237b0','SIP/201-09ce0538','ResetCDR','w',2,0,'NO ANSWER',3,'','1167149004.11004')
Dec 26 10:03:26 VERBOSE[30962] logger.c: -- Executing NoCDR("SIP/10.0.0.7-b78237b0", "") in new stack
Dec 26 10:03:26 WARNING[30962] cdr.c: CDR on channel 'SIP/10.0.0.7-b78237b0' not posted
Dec 26 10:03:26 WARNING[30962] cdr.c: CDR on channel 'SIP/10.0.0.7-b78237b0' lacks end
Dec 26 10:03:26 DEBUG[30962] pbx.c: Expression result is '1'
Dec 26 10:03:26 VERBOSE[30962] logger.c: -- Executing GotoIf("SIP/10.0.0.7-b78237b0", "1?theend") in new stack
Dec 26 10:03:26 VERBOSE[30962] logger.c: -- Goto (macro-hangupcall,s,6)
Dec 26 10:03:26 VERBOSE[30962] logger.c: -- Executing Wait("SIP/10.0.0.7-b78237b0", "5") in new stack
Dec 26 10:03:26 VERBOSE[30962] logger.c: == Spawn extension (macro-hangupcall, s, 6) exited non-zero on 'SIP/10.0.0.7-b78237b0' in macro 'hangupcall'
Dec 26 10:03:26 VERBOSE[30962] logger.c: == Spawn extension (macro-hangupcall, s, 6) exited non-zero on 'SIP/10.0.0.7-b78237b0'
Dec 26 10:03:26 DEBUG[30962] chan_sip.c: update_call_counter() - decrement call limit counter
Dec 26 10:03:26 DEBUG[3405] chan_sip.c: Stopping retransmission on 'call-71AE7EA7-F176-2910-081D-1EC@10.0.0.21' of Response 1: Match Found
Dec 26 10:03:26 DEBUG[3405] chan_sip.c: Stopping retransmission on '1cb52ec0561be0984ea4a8d97f4fa391@10.0.0.7' of Request 102: Match Found
Dec 26 10:03:26 DEBUG[3405] chan_sip.c: Stopping retransmission on '86078e4c-1280da6-9b3e28cd@10.0.0.208' of Request 833: Match Found
Dec 26 10:03:26 DEBUG[3405] chan_sip.c: Stopping retransmission on '1cb52ec0561be0984ea4a8d97f4fa391@10.0.0.7' of Request 102: Match Not Found
Dec 26 10:03:32 DEBUG[3405] chan_sip.c: Setting NAT on RTP to 0
Dec 26 10:03:32 DEBUG[3405] chan_sip.c: Checking SIP call limits for device
Dec 26 10:03:32 DEBUG[3405] chan_sip.c: build_route: Contact hop:
Dec 26 10:03:32 DEBUG[3384] channel.c: Avoiding initial deadlock for 'SIP/10.0.0.7-b78237b0'
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing Set("SIP/10.0.0.7-b78237b0", "FROM_DID=s") in new stack
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing Goto("SIP/10.0.0.7-b78237b0", "timeconditions|1|1") in new stack
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Goto (timeconditions,1,1)
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing GotoIfTime("SIP/10.0.0.7-b78237b0", "08:00-16:30|mon-fri|*|*?ext-group|200|1") in new stack
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Goto (ext-group,200,1)
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing Macro("SIP/10.0.0.7-b78237b0", "user-callerid|") in new stack
Dec 26 10:03:32 DEBUG[30970] pbx.c: Expression result is '0'
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing GotoIf("SIP/10.0.0.7-b78237b0", "0?report") in new stack
Dec 26 10:03:32 DEBUG[30970] pbx.c: Not taking any branch
Dec 26 10:03:32 DEBUG[30970] pbx.c: Expression result is '0'
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing GotoIf("SIP/10.0.0.7-b78237b0", "0?start") in new stack
Dec 26 10:03:32 DEBUG[30970] pbx.c: Not taking any branch
Dec 26 10:03:32 DEBUG[30970] pbx.c: Function result is ''
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing Set("SIP/10.0.0.7-b78237b0", "REALCALLERIDNUM=") in new stack
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing NoOp("SIP/10.0.0.7-b78237b0", "REALCALLERIDNUM is ") in new stack
Dec 26 10:03:32 DEBUG[30970] db.c: Unable to find key '/user' in family 'DEVICE'
Dec 26 10:03:32 DEBUG[30970] func_db.c: DB: DEVICE//user not found in database.
Dec 26 10:03:32 DEBUG[30970] pbx.c: Function result is ''
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing Set("SIP/10.0.0.7-b78237b0", "AMPUSER=") in new stack
Dec 26 10:03:32 DEBUG[30970] db.c: Unable to find key '/cidname' in family 'AMPUSER'
Dec 26 10:03:32 DEBUG[30970] func_db.c: DB: AMPUSER//cidname not found in database.
Dec 26 10:03:32 DEBUG[30970] pbx.c: Function result is ''
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing Set("SIP/10.0.0.7-b78237b0", "AMPUSERCIDNAME=") in new stack
Dec 26 10:03:32 DEBUG[30970] pbx.c: Expression result is '1'
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing GotoIf("SIP/10.0.0.7-b78237b0", "1?report") in new stack
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Goto (macro-user-callerid,s,10)
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing NoOp("SIP/10.0.0.7-b78237b0", "TTL: ARG1: ") in new stack
Dec 26 10:03:32 DEBUG[30970] pbx.c: Expression result is '0'
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing GotoIf("SIP/10.0.0.7-b78237b0", "0?continue") in new stack
Dec 26 10:03:32 DEBUG[30970] pbx.c: Not taking any branch
Dec 26 10:03:32 DEBUG[30970] pbx.c: Expression result is '1'
Dec 26 10:03:32 DEBUG[30970] pbx.c: Expression result is '-1'
Dec 26 10:03:32 DEBUG[30970] pbx.c: Function result is '64'
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing Set("SIP/10.0.0.7-b78237b0", "_TTL=64") in new stack
Dec 26 10:03:32 DEBUG[30970] pbx.c: Expression result is '1'
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing GotoIf("SIP/10.0.0.7-b78237b0", "1?continue") in new stack
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Goto (macro-user-callerid,s,20)
Dec 26 10:03:32 DEBUG[30970] pbx.c: Function result is '"" <>'
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing NoOp("SIP/10.0.0.7-b78237b0", "Using CallerID "" <>") in new stack
Dec 26 10:03:32 DEBUG[30970] pbx.c: Expression result is '1'
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing GotoIf("SIP/10.0.0.7-b78237b0", "1?skipdb") in new stack
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Goto (ext-group,200,4)
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing Set("SIP/10.0.0.7-b78237b0", "__NODEST=") in new stack
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing Set("SIP/10.0.0.7-b78237b0", "__BLKVM_OVERRIDE=BLKVM/200/SIP/10.0.0.7-b78237b0") in new stack
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing Set("SIP/10.0.0.7-b78237b0", "__BLKVM_BASE=200") in new stack
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing Set("SIP/10.0.0.7-b78237b0", "DB(BLKVM/200/SIP/10.0.0.7-b78237b0)=TRUE") in new stack
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing Set("SIP/10.0.0.7-b78237b0", "RRNODEST=") in new stack
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing Set("SIP/10.0.0.7-b78237b0", "__NODEST=200") in new stack
Dec 26 10:03:32 DEBUG[30970] pbx.c: Expression result is '1'
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing GotoIf("SIP/10.0.0.7-b78237b0", "1?REPCID") in new stack
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Goto (ext-group,200,14)
Dec 26 10:03:32 DEBUG[30970] pbx.c: Function result is ''
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing NoOp("SIP/10.0.0.7-b78237b0", "CALLERID(name) is ") in new stack
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing Set("SIP/10.0.0.7-b78237b0", "RecordMethod=Group") in new stack
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing Macro("SIP/10.0.0.7-b78237b0", "record-enable|201|Group") in new stack
Dec 26 10:03:32 DEBUG[30970] pbx.c: Function result is '0'
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing GotoIf("SIP/10.0.0.7-b78237b0", "0 > 0?2:4") in new stack
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Goto (macro-record-enable,s,4)
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing DeadAGI("SIP/10.0.0.7-b78237b0", "recordingcheck|20061226-100332|1167149012.11006") in new stack
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- AGI Script recordingcheck completed, returning 0
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing NoOp("SIP/10.0.0.7-b78237b0", "No recording needed") in new stack
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing Set("SIP/10.0.0.7-b78237b0", "RingGroupMethod=ringall") in new stack
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing Macro("SIP/10.0.0.7-b78237b0", "dial|4|trwW|201") in new stack
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing DeadAGI("SIP/10.0.0.7-b78237b0", "dialparties.agi") in new stack
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Dec 26 10:03:32 VERBOSE[30970] logger.c: dialparties.agi: Starting New Dialparties.agi
Dec 26 10:03:32 VERBOSE[30970] logger.c: dialparties.agi: priority is 1
Dec 26 10:03:32 VERBOSE[30970] logger.c: dialparties.agi: Caller ID name is 'unknown' number is 'unknown'
Dec 26 10:03:32 VERBOSE[30970] logger.c: dialparties.agi: Methodology of ring is 'ringall'
Dec 26 10:03:32 VERBOSE[30970] logger.c: > dialparties.agi: USE_CONFIRMATION: 'FALSE'
Dec 26 10:03:32 VERBOSE[30970] logger.c: > dialparties.agi: RINGGROUP_INDEX: ''
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- dialparties.agi: Added extension 201 to extension map
Dec 26 10:03:32 DEBUG[30970] db.c: Unable to find key '201' in family 'CF'
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- dialparties.agi: Extension 201 cf is disabled
Dec 26 10:03:32 DEBUG[30970] db.c: Unable to find key '201' in family 'DND'
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- dialparties.agi: Extension 201 do not disturb is disabled
Dec 26 10:03:32 DEBUG[30970] db.c: Unable to find key '201' in family 'CFU'
Dec 26 10:03:32 VERBOSE[30970] logger.c: > dialparties.agi: extnum: 201
Dec 26 10:03:32 VERBOSE[30970] logger.c: > dialparties.agi: exthascw: 1
Dec 26 10:03:32 VERBOSE[30970] logger.c: > dialparties.agi: exthascfb: 1
Dec 26 10:03:32 VERBOSE[30970] logger.c: > dialparties.agi: extcfb: 201
Dec 26 10:03:32 VERBOSE[30970] logger.c: > dialparties.agi: exthascfu: 0
Dec 26 10:03:32 VERBOSE[30970] logger.c: > dialparties.agi: extcfu:
Dec 26 10:03:32 DEBUG[30974] manager.c: Manager received command 'login'
Dec 26 10:03:32 VERBOSE[30974] logger.c: == Parsing '/etc/asterisk/manager.conf': Dec 26 10:03:32 VERBOSE[30974] logger.c: == Parsing '/etc/asterisk/manager.conf': Found
Dec 26 10:03:32 VERBOSE[30974] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Dec 26 10:03:32 VERBOSE[30974] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Found
Dec 26 10:03:32 WARNING[30974] config.c: Unknown directive 'permit=127.0.0.1/255.255.255.0' at line 18 of manager_custom.conf
Dec 26 10:03:32 DEBUG[30974] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Dec 26 10:03:32 DEBUG[30974] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Dec 26 10:03:32 DEBUG[30974] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Dec 26 10:03:32 DEBUG[30974] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Dec 26 10:03:32 VERBOSE[30974] logger.c: == Manager 'admin' logged on from 127.0.0.1
Dec 26 10:03:32 DEBUG[30974] manager.c: Manager received command 'ExtensionState'
Dec 26 10:03:32 DEBUG[30974] manager.c: Manager received command 'Logoff'
Dec 26 10:03:32 VERBOSE[30974] logger.c: == Manager 'admin' logged off from 127.0.0.1
Dec 26 10:03:32 VERBOSE[30970] logger.c: > dialparties.agi: ExtensionState: 0
Dec 26 10:03:32 VERBOSE[30970] logger.c: dialparties.agi: Extension 201 has ExtensionState: 0
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- dialparties.agi: Checking CW and CFB status for extension 201
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- dialparties.agi: DbDel CALLTRACE/201 - Caller ID is not defined
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- AGI Script dialparties.agi completed, returning 0
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Executing Dial("SIP/10.0.0.7-b78237b0", "SIP/201|4|trwW") in new stack
Dec 26 10:03:32 DEBUG[30970] chan_sip.c: Setting NAT on RTP to 0
Dec 26 10:03:32 DEBUG[30970] chan_sip.c: Outgoing Call for 201
Dec 26 10:03:32 VERBOSE[30970] logger.c: -- Called 201