Aug 7 11:21:45 NOTICE[15594] chan_zap.c: Got event 2 (Ring/Answered)...
Aug 7 11:21:46 NOTICE[15594] chan_zap.c: Got event 18 (Ring Begin)...
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Executing Set("Zap/4-1", "FROM_DID=s") in new stack
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Executing Goto("Zap/4-1", "ext-group|1|1") in new stack
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Goto (ext-group,1,1)
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Executing Macro("Zap/4-1", "user-callerid|") in new stack
Aug 7 11:21:46 DEBUG[15594] pbx.c: Expression result is '0'
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Executing GotoIf("Zap/4-1", "0?report") in new stack
Aug 7 11:21:46 DEBUG[15594] pbx.c: Not taking any branch
Aug 7 11:21:46 DEBUG[15594] pbx.c: Expression result is '0'
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Executing GotoIf("Zap/4-1", "0?start") in new stack
Aug 7 11:21:46 DEBUG[15594] pbx.c: Not taking any branch
Aug 7 11:21:46 DEBUG[15594] pbx.c: Function result is ''
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Executing Set("Zap/4-1", "REALCALLERIDNUM=") in new stack
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Executing NoOp("Zap/4-1", "REALCALLERIDNUM is ") in new stack
Aug 7 11:21:46 DEBUG[15594] db.c: Unable to find key '/user' in family 'DEVICE'
Aug 7 11:21:46 DEBUG[15594] func_db.c: DB: DEVICE//user not found in database.
Aug 7 11:21:46 DEBUG[15594] pbx.c: Function result is ''
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Executing Set("Zap/4-1", "AMPUSER=") in new stack
Aug 7 11:21:46 DEBUG[15594] db.c: Unable to find key '/cidname' in family 'AMPUSER'
Aug 7 11:21:46 DEBUG[15594] func_db.c: DB: AMPUSER//cidname not found in database.
Aug 7 11:21:46 DEBUG[15594] pbx.c: Function result is ''
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Executing Set("Zap/4-1", "AMPUSERCIDNAME=") in new stack
Aug 7 11:21:46 DEBUG[15594] pbx.c: Expression result is '1'
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Executing GotoIf("Zap/4-1", "1?report") in new stack
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Goto (macro-user-callerid,s,9)
Aug 7 11:21:46 DEBUG[15594] pbx.c: Function result is '"" <>'
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Executing NoOp("Zap/4-1", "Using CallerID "" <>") in new stack
Aug 7 11:21:46 DEBUG[15594] pbx.c: Function result is '0'
Aug 7 11:21:46 DEBUG[15594] pbx.c: Function result is ''
Aug 7 11:21:46 DEBUG[15594] pbx.c: Expression result is '0'
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Executing GotoIf("Zap/4-1", "0?NEWPREFIX") in new stack
Aug 7 11:21:46 DEBUG[15594] pbx.c: Not taking any branch
Aug 7 11:21:46 DEBUG[15594] pbx.c: Function result is '0'
Aug 7 11:21:46 DEBUG[15594] pbx.c: Function result is ''
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Executing Set("Zap/4-1", "CALLERID(name)=") in new stack
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Executing Set("Zap/4-1", "RGPREFIX=") in new stack
Aug 7 11:21:46 DEBUG[15594] pbx.c: Function result is ''
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Executing Set("Zap/4-1", "CALLERID(name)=") in new stack
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Executing Set("Zap/4-1", "RecordMethod=Group") in new stack
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Executing Macro("Zap/4-1", "record-enable|10-11-13-14-15-16-17|Group") in new stack
Aug 7 11:21:46 DEBUG[15594] pbx.c: Function result is '0'
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Executing GotoIf("Zap/4-1", "0 > 0?2:4") in new stack
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Goto (macro-record-enable,s,4)
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Executing AGI("Zap/4-1", "recordingcheck|20060807-112146|1154964101.14148") in new stack
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Aug 7 11:21:46 VERBOSE[15594] logger.c: recordingcheck|20060807-112146|1154964101.14148: Recording enable for 10
Aug 7 11:21:46 VERBOSE[15594] logger.c: recordingcheck|20060807-112146|1154964101.14148: CALLFILENAME=g10-20060807-112146-1154964101.14148
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- AGI Script recordingcheck completed, returning 0
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Executing Monitor("Zap/4-1", "wav49|g10-20060807-112146-1154964101.14148| mb") in new stack
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Executing Set("Zap/4-1", "RingGroupMethod=ringall") in new stack
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Executing Macro("Zap/4-1", "dial|20|tr|10-11-13-14-15-16-17") in new stack
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Executing AGI("Zap/4-1", "dialparties.agi") in new stack
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Aug 7 11:21:46 VERBOSE[15594] logger.c: dialparties.agi: Starting New Dialparties.agi
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- dialparties.agi: priority is 1
Aug 7 11:21:46 VERBOSE[15594] logger.c: dialparties.agi: Caller ID name is 'unknown' number is 'unknown'
Aug 7 11:21:46 VERBOSE[15594] logger.c: dialparties.agi: Methodology of ring is 'ringall'
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- dialparties.agi: Added extension 10 to extension map
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- dialparties.agi: Added extension 11 to extension map
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- dialparties.agi: Added extension 13 to extension map
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- dialparties.agi: Added extension 14 to extension map
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- dialparties.agi: Added extension 15 to extension map
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- dialparties.agi: Added extension 16 to extension map
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- dialparties.agi: Added extension 17 to extension map
Aug 7 11:21:46 DEBUG[15594] db.c: Unable to find key '10' in family 'CF'
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- dialparties.agi: Extension 10 cf is disabled
Aug 7 11:21:46 DEBUG[15594] db.c: Unable to find key '11' in family 'CF'
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- dialparties.agi: Extension 11 cf is disabled
Aug 7 11:21:46 DEBUG[15594] db.c: Unable to find key '13' in family 'CF'
Aug 7 11:21:46 VERBOSE[15594] logger.c: -- dialparties.agi: Extension 13 cf is disabled
Aug 7 11:21:46 DEBUG[15594] db.c: Unable to find key '14' in family 'CF'
Aug 8 01:21:59 DEBUG[15594] 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) VALUES ('2006-08-07 11:21:46','','','1','ext-group', 'Zap/4-1','SIP/17-083b9d60','Monitor','wav49|g10-20060807-112146-1154964101.14148| mX',50413,50405,'ANSWERED',3,'')
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- dialparties.agi: Extension 14 cf is disabled
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '15' in family 'CF'
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- dialparties.agi: Extension 15 cf is disabled
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '16' in family 'CF'
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- dialparties.agi: Extension 16 cf is disabled
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '17' in family 'CF'
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- dialparties.agi: Extension 17 cf is disabled
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '10' in family 'DND'
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- dialparties.agi: Extension 10 do not disturb is disabled
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '11' in family 'DND'
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- dialparties.agi: Extension 11 do not disturb is disabled
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '13' in family 'DND'
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- dialparties.agi: Extension 13 do not disturb is disabled
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '14' in family 'DND'
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- dialparties.agi: Extension 14 do not disturb is disabled
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '15' in family 'DND'
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- dialparties.agi: Extension 15 do not disturb is disabled
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '16' in family 'DND'
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- dialparties.agi: Extension 16 do not disturb is disabled
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '17' in family 'DND'
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- dialparties.agi: Extension 17 do not disturb is disabled
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '10' in family 'CFB'
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '10' in family 'CFU'
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- dialparties.agi: DbSet CALLTRACE/10 to unknown
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '11' in family 'CFB'
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '11' in family 'CFU'
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- dialparties.agi: DbSet CALLTRACE/11 to unknown
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '13' in family 'CW'
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '13' in family 'CFB'
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '13' in family 'CFU'
Aug 7 11:21:47 DEBUG[15598] manager.c: Manager received command 'login'
Aug 7 11:21:47 VERBOSE[15598] logger.c: == Parsing '/etc/asterisk/manager.conf': Aug 7 11:21:47 VERBOSE[15598] logger.c: == Parsing '/etc/asterisk/manager.conf': Found
Aug 7 11:21:47 VERBOSE[15598] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Aug 7 11:21:47 VERBOSE[15598] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Found
Aug 7 11:21:47 WARNING[15598] config.c: Unknown directive 'permit=192.168.1.0/255.255.255.0' at line 18 of manager_custom.conf
Aug 7 11:21:47 DEBUG[15598] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Aug 7 11:21:47 DEBUG[15598] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Aug 7 11:21:47 DEBUG[15598] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Aug 7 11:21:47 DEBUG[15598] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Aug 7 11:21:47 VERBOSE[15598] logger.c: == Manager 'admin' logged on from 127.0.0.1
Aug 7 11:21:47 DEBUG[15598] manager.c: Manager received command 'ExtensionState'
Aug 7 11:21:47 DEBUG[15598] manager.c: Manager received command 'Logoff'
Aug 7 11:21:47 VERBOSE[15598] logger.c: == Manager 'admin' logged off from 127.0.0.1
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- dialparties.agi: Checking CW and CFB status for extension 13
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- dialparties.agi: DbSet CALLTRACE/13 to unknown
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '14' in family 'CW'
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '14' in family 'CFB'
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '14' in family 'CFU'
Aug 7 11:21:47 DEBUG[15599] manager.c: Manager received command 'login'
Aug 7 11:21:47 VERBOSE[15599] logger.c: == Parsing '/etc/asterisk/manager.conf': Aug 7 11:21:47 VERBOSE[15599] logger.c: == Parsing '/etc/asterisk/manager.conf': Found
Aug 7 11:21:47 VERBOSE[15599] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Aug 7 11:21:47 VERBOSE[15599] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Found
Aug 7 11:21:47 WARNING[15599] config.c: Unknown directive 'permit=192.168.1.0/255.255.255.0' at line 18 of manager_custom.conf
Aug 7 11:21:47 DEBUG[15599] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Aug 7 11:21:47 DEBUG[15599] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Aug 7 11:21:47 DEBUG[15599] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Aug 7 11:21:47 DEBUG[15599] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Aug 7 11:21:47 VERBOSE[15599] logger.c: == Manager 'admin' logged on from 127.0.0.1
Aug 7 11:21:47 DEBUG[15599] manager.c: Manager received command 'ExtensionState'
Aug 7 11:21:47 DEBUG[15599] manager.c: Manager received command 'Logoff'
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- dialparties.agi: Checking CW and CFB status for extension 14
Aug 7 11:21:47 VERBOSE[15599] logger.c: == Manager 'admin' logged off from 127.0.0.1
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- dialparties.agi: DbSet CALLTRACE/14 to unknown
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '15' in family 'CFB'
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '15' in family 'CFU'
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- dialparties.agi: DbSet CALLTRACE/15 to unknown
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '16' in family 'CFB'
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '16' in family 'CFU'
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- dialparties.agi: DbSet CALLTRACE/16 to unknown
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '17' in family 'CFB'
Aug 7 11:21:47 DEBUG[15594] db.c: Unable to find key '17' in family 'CFU'
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- dialparties.agi: DbSet CALLTRACE/17 to unknown
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- AGI Script dialparties.agi completed, returning 0
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- Executing Dial("Zap/4-1", "SIP/10&SIP/11&SIP/13&SIP/14&SIP/15&SIP/16&SIP/17|20|tr") in new stack
Aug 7 11:21:47 DEBUG[15594] chan_sip.c: Setting NAT on RTP to 0
Aug 7 11:21:47 DEBUG[15594] chan_sip.c: Outgoing Call for 10
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- Called 10
Aug 7 11:21:47 DEBUG[15594] chan_sip.c: Setting NAT on RTP to 0
Aug 7 11:21:47 DEBUG[15594] chan_sip.c: Outgoing Call for 11
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- Called 11
Aug 7 11:21:47 DEBUG[15594] chan_sip.c: Setting NAT on RTP to 0
Aug 7 11:21:47 DEBUG[15594] chan_sip.c: Outgoing Call for 13
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- Called 13
Aug 7 11:21:47 DEBUG[15594] chan_sip.c: Setting NAT on RTP to 0
Aug 7 11:21:47 DEBUG[15594] chan_sip.c: Outgoing Call for 14
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- Called 14
Aug 7 11:21:47 DEBUG[15594] chan_sip.c: Setting NAT on RTP to 0
Aug 7 11:21:47 DEBUG[15594] chan_sip.c: Outgoing Call for 15
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- Called 15
Aug 7 11:21:47 DEBUG[15594] chan_sip.c: Setting NAT on RTP to 0
Aug 7 11:21:47 DEBUG[15594] chan_sip.c: Outgoing Call for 16
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- Called 16
Aug 7 11:21:47 DEBUG[15594] chan_sip.c: Setting NAT on RTP to 0
Aug 7 11:21:47 DEBUG[15594] chan_sip.c: Outgoing Call for 17
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- Called 17
Aug 7 11:21:47 DEBUG[15594] chan_zap.c: Requested indication 3 on channel Zap/4-1
Aug 7 11:21:47 DEBUG[2886] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '08fa486c5aabb03071efe41478ea3b7a@192.168.0.70' Request 102: Found
Aug 7 11:21:47 DEBUG[2886] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '31cec8d04cfdb478199965ab527556db@192.168.0.70' Request 102: Found
Aug 7 11:21:47 DEBUG[2886] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '2da218257ecef0723c2633d766cb5b71@192.168.0.70' Request 102: Found
Aug 7 11:21:47 DEBUG[2886] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '03ec5c0e1ac79f0a6c769f4001faa919@192.168.0.70' Request 102: Found
Aug 7 11:21:47 DEBUG[2886] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '4dc7b70f6a2d2d4e6855ca56047acaeb@192.168.0.70' Request 102: Found
Aug 7 11:21:47 DEBUG[2886] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '4b3f414d09c543be5646f2f3542e6bfe@192.168.0.70' Request 102: Found
Aug 7 11:21:47 DEBUG[2886] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '5598ef731eae720b5241db1539620748@192.168.0.70' Request 102: Found
Aug 7 11:21:47 DEBUG[2886] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '08fa486c5aabb03071efe41478ea3b7a@192.168.0.70' Request 102: Found
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- SIP/13-083a4920 is ringing
Aug 7 11:21:47 DEBUG[2886] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '4dc7b70f6a2d2d4e6855ca56047acaeb@192.168.0.70' Request 102: Found
Aug 7 11:21:47 DEBUG[2886] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '31cec8d04cfdb478199965ab527556db@192.168.0.70' Request 102: Found
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- SIP/10-0837e008 is ringing
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- SIP/16-083b4850 is ringing
Aug 7 11:21:47 DEBUG[2886] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '03ec5c0e1ac79f0a6c769f4001faa919@192.168.0.70' Request 102: Found
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- SIP/17-083b9d60 is ringing
Aug 7 11:21:47 DEBUG[2886] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '4b3f414d09c543be5646f2f3542e6bfe@192.168.0.70' Request 102: Found
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- SIP/15-083af340 is ringing
Aug 7 11:21:47 DEBUG[2886] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '2da218257ecef0723c2633d766cb5b71@192.168.0.70' Request 102: Found
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- SIP/11-0839f410 is ringing
Aug 7 11:21:47 DEBUG[2886] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '5598ef731eae720b5241db1539620748@192.168.0.70' Request 102: Found
Aug 7 11:21:47 VERBOSE[15594] logger.c: -- SIP/14-083a9e30 is ringing
Aug 7 11:21:48 DEBUG[15594] chan_zap.c: Exception on 21, channel 4
Aug 7 11:21:48 DEBUG[15594] chan_zap.c: Got event Ring/Answered(2) on channel 4 (index 0)
Aug 7 11:21:48 DEBUG[15594] chan_zap.c: Setting IDLE polarity due to ring. Old polarity was 0
Aug 7 11:21:49 DEBUG[15594] chan_zap.c: Exception on 21, channel 4
Aug 7 11:21:49 DEBUG[15594] chan_zap.c: Got event Ring Begin(18) on channel 4 (index 0)
Aug 7 11:21:51 DEBUG[15594] chan_zap.c: Exception on 21, channel 4
Aug 7 11:21:51 DEBUG[15594] chan_zap.c: Got event Ring/Answered(2) on channel 4 (index 0)
Aug 7 11:21:51 DEBUG[15594] chan_zap.c: Setting IDLE polarity due to ring. Old polarity was 0
Aug 7 11:21:52 DEBUG[15594] chan_zap.c: Exception on 21, channel 4
Aug 7 11:21:52 DEBUG[15594] chan_zap.c: Got event Ring Begin(18) on channel 4 (index 0)
Aug 7 11:21:54 DEBUG[2886] chan_sip.c: Acked pending invite 102
Aug 7 11:21:54 DEBUG[2886] chan_sip.c: Stopping retransmission on '03ec5c0e1ac79f0a6c769f4001faa919@192.168.0.70' of Request 102: Match Found
Aug 7 11:21:54 DEBUG[2886] chan_sip.c: build_route: Contact hop: "Naresh" <sip:17@192.168.0.108:5060>
Aug 7 11:21:54 VERBOSE[15594] logger.c: -- SIP/17-083b9d60 answered Zap/4-1
Aug 7 11:21:54 DEBUG[15594] chan_sip.c: update_call_counter(16) - decrement call limit counter
Aug 7 11:21:54 DEBUG[15594] chan_sip.c: Acked pending invite 102
Aug 7 11:21:54 DEBUG[15594] chan_sip.c: Stopping retransmission on '31cec8d04cfdb478199965ab527556db@192.168.0.70' of Request 102: Match Found
Aug 7 11:21:54 DEBUG[15594] chan_sip.c: update_call_counter(15) - decrement call limit counter
Aug 7 11:21:54 DEBUG[15594] chan_sip.c: Acked pending invite 102
Aug 7 11:21:54 DEBUG[15594] chan_sip.c: Stopping retransmission on '4b3f414d09c543be5646f2f3542e6bfe@192.168.0.70' of Request 102: Match Found
Aug 7 11:21:54 DEBUG[15594] chan_sip.c: update_call_counter(14) - decrement call limit counter
Aug 7 11:21:54 DEBUG[15594] chan_sip.c: Acked pending invite 102
Aug 7 11:21:54 DEBUG[15594] chan_sip.c: Stopping retransmission on '5598ef731eae720b5241db1539620748@192.168.0.70' of Request 102: Match Found
Aug 7 11:21:54 DEBUG[15594] chan_sip.c: update_call_counter(13) - decrement call limit counter
Aug 7 11:21:54 DEBUG[15594] chan_sip.c: Acked pending invite 102
Aug 7 11:21:54 DEBUG[15594] chan_sip.c: Stopping retransmission on '08fa486c5aabb03071efe41478ea3b7a@192.168.0.70' of Request 102: Match Found
Aug 7 11:21:54 DEBUG[15594] chan_sip.c: update_call_counter(11) - decrement call limit counter
Aug 7 11:21:54 DEBUG[15594] chan_sip.c: Acked pending invite 102
Aug 7 11:21:54 DEBUG[15594] chan_sip.c: Stopping retransmission on '2da218257ecef0723c2633d766cb5b71@192.168.0.70' of Request 102: Match Found
Aug 7 11:21:54 DEBUG[15594] chan_sip.c: update_call_counter(10) - decrement call limit counter
Aug 7 11:21:54 DEBUG[15594] chan_sip.c: Acked pending invite 102
Aug 7 11:21:54 DEBUG[15594] chan_sip.c: Stopping retransmission on '4dc7b70f6a2d2d4e6855ca56047acaeb@192.168.0.70' of Request 102: Match Found
Aug 7 11:21:54 DEBUG[15594] chan_zap.c: Requested indication -1 on channel Zap/4-1
Aug 7 11:21:54 DEBUG[15594] chan_zap.c: Took Zap/4-1 off hook
Aug 7 11:21:54 DEBUG[15594] chan_zap.c: Enabled echo cancellation on channel 4
Aug 7 11:21:54 DEBUG[15594] chan_zap.c: Engaged echo training on channel 4
Aug 7 11:21:54 DEBUG[2886] chan_sip.c: Stopping retransmission on '08fa486c5aabb03071efe41478ea3b7a@192.168.0.70' of Request 102: Match Not Found
Aug 7 11:21:54 DEBUG[2886] chan_sip.c: Stopping retransmission on '08fa486c5aabb03071efe41478ea3b7a@192.168.0.70' of Request 102: Match Found
Aug 7 11:21:54 DEBUG[2886] chan_sip.c: Stopping retransmission on '2da218257ecef0723c2633d766cb5b71@192.168.0.70' of Request 102: Match Not Found
Aug 7 11:21:54 DEBUG[15594] chan_zap.c: Exception on 21, channel 4
Aug 7 11:21:54 DEBUG[15594] chan_zap.c: Got event Ring/Answered(2) on channel 4 (index 0)
Aug 7 11:21:54 DEBUG[15594] chan_zap.c: Setting IDLE polarity due to ring. Old polarity was 0
Aug 7 11:21:54 WARNING[15594] chan_zap.c: Ring/Off-hook in strange state 6 on channel 4
Aug 7 11:21:54 DEBUG[2886] chan_sip.c: Stopping retransmission on '4b3f414d09c543be5646f2f3542e6bfe@192.168.0.70' of Request 102: Match Not Found
Aug 7 11:21:54 DEBUG[2886] chan_sip.c: Stopping retransmission on '4dc7b70f6a2d2d4e6855ca56047acaeb@192.168.0.70' of Request 102: Match Not Found
Aug 7 11:21:54 DEBUG[2886] chan_sip.c: Stopping retransmission on '2da218257ecef0723c2633d766cb5b71@192.168.0.70' of Request 102: Match Found
Aug 7 11:21:54 DEBUG[2886] chan_sip.c: Stopping retransmission on '31cec8d04cfdb478199965ab527556db@192.168.0.70' of Request 102: Match Not Found
Aug 7 11:21:54 DEBUG[2886] chan_sip.c: Stopping retransmission on '4b3f414d09c543be5646f2f3542e6bfe@192.168.0.70' of Request 102: Match Found
Aug 7 11:21:54 DEBUG[2886] chan_sip.c: Stopping retransmission on '4dc7b70f6a2d2d4e6855ca56047acaeb@192.168.0.70' of Request 102: Match Found
Aug 7 11:21:54 DEBUG[2886] chan_sip.c: Stopping retransmission on '31cec8d04cfdb478199965ab527556db@192.168.0.70' of Request 102: Match Found
Aug 7 11:21:54 DEBUG[2886] chan_sip.c: Stopping retransmission on '5598ef731eae720b5241db1539620748@192.168.0.70' of Request 102: Match Not Found
Aug 7 11:21:54 DEBUG[2886] chan_sip.c: Stopping retransmission on '5598ef731eae720b5241db1539620748@192.168.0.70' of Request 102: Match Found
:Aug 7 11:21:57 DEBUG[2886] chan_sip.c: Stopping retransmission on '2fca0e164251ed575bcdc6da64bcf05d@192.168.0.70' of Request 102: Match Found
Aug 7 11:22:01 DEBUG[2886] chan_sip.c: Setting NAT on RTP to 0
Aug 7 11:22:01 DEBUG[2886] chan_sip.c: Stopping retransmission on '7258784f-9a78b1af@192.168.0.108' of Response 101: Match Found
Aug 7 11:22:01 DEBUG[2886] chan_sip.c: Setting NAT on RTP to 0
Aug 7 11:22:01 DEBUG[2886] chan_sip.c: Checking SIP call limits for device 17
Aug 7 11:22:01 DEBUG[2886] chan_sip.c: build_route: Contact hop: "Naresh" <sip:17@192.168.0.108:5060>
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing Macro("SIP/17-0839caf0", "dialout-trunk|2|3539932||") in new stack
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing Set("SIP/17-0839caf0", "DIAL_TRUNK=2") in new stack
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing Set("SIP/17-0839caf0", "DIAL_NUMBER=3539932") in new stack
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing Set("SIP/17-0839caf0", "ROUTE_PASSWD=") in new stack
Aug 7 11:22:01 DEBUG[15618] pbx.c: Expression result is '1'
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing GotoIf("SIP/17-0839caf0", "1?noauth") in new stack
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Goto (macro-dialout-trunk,s,6)
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing Set("SIP/17-0839caf0", "GROUP()=OUT_2") in new stack
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing Macro("SIP/17-0839caf0", "user-callerid") in new stack
Aug 7 11:22:01 DEBUG[15618] pbx.c: Expression result is '0'
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing GotoIf("SIP/17-0839caf0", "0?report") in new stack
Aug 7 11:22:01 DEBUG[15618] pbx.c: Not taking any branch
Aug 7 11:22:01 DEBUG[15618] pbx.c: Expression result is '0'
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing GotoIf("SIP/17-0839caf0", "0?start") in new stack
Aug 7 11:22:01 DEBUG[15618] pbx.c: Not taking any branch
Aug 7 11:22:01 DEBUG[15618] pbx.c: Function result is '17'
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing Set("SIP/17-0839caf0", "REALCALLERIDNUM=17") in new stack
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing NoOp("SIP/17-0839caf0", "REALCALLERIDNUM is 17") in new stack
Aug 7 11:22:01 DEBUG[15618] pbx.c: Function result is '17'
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing Set("SIP/17-0839caf0", "AMPUSER=17") in new stack
Aug 7 11:22:01 DEBUG[15618] pbx.c: Function result is 'Naresh'
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing Set("SIP/17-0839caf0", "AMPUSERCIDNAME=Naresh") in new stack
Aug 7 11:22:01 DEBUG[15618] pbx.c: Expression result is '0'
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing GotoIf("SIP/17-0839caf0", "0?report") in new stack
Aug 7 11:22:01 DEBUG[15618] pbx.c: Not taking any branch
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing Set("SIP/17-0839caf0", "CALLERID(all)=Naresh <17>") in new stack
Aug 7 11:22:01 DEBUG[15618] pbx.c: Function result is '"Naresh" <17>'
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing NoOp("SIP/17-0839caf0", "Using CallerID "Naresh" <17>") in new stack
Aug 7 11:22:01 DEBUG[15618] pbx.c: Function result is '17'
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing Macro("SIP/17-0839caf0", "record-enable|17|OUT") in new stack
Aug 7 11:22:01 DEBUG[15618] pbx.c: Function result is '0'
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing GotoIf("SIP/17-0839caf0", "0 > 0?2:4") in new stack
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Goto (macro-record-enable,s,4)
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing AGI("SIP/17-0839caf0", "recordingcheck|20060807-112201|1154964121.14156") in new stack
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Aug 7 11:22:01 VERBOSE[15618] logger.c: recordingcheck|20060807-112201|1154964121.14156: Outbound recording enabled.
Aug 7 11:22:01 VERBOSE[15618] logger.c: recordingcheck|20060807-112201|1154964121.14156: CALLFILENAME=OUT17-20060807-112201-1154964121.14156
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- AGI Script recordingcheck completed, returning 0
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing Monitor("SIP/17-0839caf0", "wav49|OUT17-20060807-112201-1154964121.14156| mb") in new stack
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing Macro("SIP/17-0839caf0", "outbound-callerid|2") in new stack
Aug 7 11:22:01 DEBUG[15618] pbx.c: Expression result is '1'
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing GotoIf("SIP/17-0839caf0", "1?start") in new stack
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Goto (macro-outbound-callerid,s,3)
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing NoOp("SIP/17-0839caf0", "REALCALLERIDNUM is 17") in new stack
Aug 7 11:22:01 DEBUG[15618] pbx.c: Function result is ''
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing Set("SIP/17-0839caf0", "USEROUTCID=") in new stack
Aug 7 11:22:01 DEBUG[15618] db.c: Unable to find key '17/emergency_cid' in family 'DEVICE'
Aug 7 11:22:01 DEBUG[15618] func_db.c: DB: DEVICE/17/emergency_cid not found in database.
Aug 7 11:22:01 DEBUG[15618] pbx.c: Function result is ''
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing Set("SIP/17-0839caf0", "EMERGENCYCID=") in new stack
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing Set("SIP/17-0839caf0", "TRUNKOUTCID=") in new stack
Aug 7 11:22:01 DEBUG[15618] pbx.c: Expression result is '1'
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing GotoIf("SIP/17-0839caf0", "1?trunkcid") in new stack
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Goto (macro-outbound-callerid,s,11)
Aug 7 11:22:01 DEBUG[15618] pbx.c: Expression result is '1'
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing GotoIf("SIP/17-0839caf0", "1?usercid") in new stack
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Goto (macro-outbound-callerid,s,13)
Aug 7 11:22:01 DEBUG[15618] pbx.c: Expression result is '1'
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing GotoIf("SIP/17-0839caf0", "1?report") in new stack
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Goto (macro-outbound-callerid,s,15)
Aug 7 11:22:01 DEBUG[15618] pbx.c: Function result is '"Naresh" <17>'
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing NoOp("SIP/17-0839caf0", "CallerID set to "Naresh" <17>") in new stack
Aug 7 11:22:01 DEBUG[15618] pbx.c: Expression result is '1'
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing GotoIf("SIP/17-0839caf0", "1?nomax") in new stack
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Goto (macro-dialout-trunk,s,12)
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing AGI("SIP/17-0839caf0", "fixlocalprefix") in new stack
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
Aug 7 11:22:01 VERBOSE[15618] logger.c: fixlocalprefix: Could not parse /etc/asterisk/localprefixes.conf
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- AGI Script fixlocalprefix completed, returning 0
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing Set("SIP/17-0839caf0", "OUTNUM=3539932") in new stack
Aug 7 11:22:01 DEBUG[15618] pbx.c: Function result is 'ZAP/1-1'
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing Set("SIP/17-0839caf0", "custom=ZAP/1-1") in new stack
Aug 7 11:22:01 DEBUG[15618] pbx.c: Expression result is '0'
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing GotoIf("SIP/17-0839caf0", "0?customtrunk") in new stack
Aug 7 11:22:01 DEBUG[15618] pbx.c: Not taking any branch
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Executing Dial("SIP/17-0839caf0", "ZAP/1-1/3539932|120|r") in new stack
Aug 7 11:22:01 WARNING[15618] chan_zap.c: Unknown option '-' in '1-1/3539932'
Aug 7 11:22:01 DEBUG[15618] chan_zap.c: Dialing '3539932'
Aug 7 11:22:01 DEBUG[15618] chan_zap.c: Deferring dialing...
Aug 7 11:22:01 DEBUG[2877] channel.c: Avoiding initial deadlock for 'Zap/1-1'
Aug 7 11:22:01 VERBOSE[15618] logger.c: -- Called 1-1/3539932
Aug 7 11:23:24 DEBUG[15618] 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) VALUES ('2006-08-07 11:22:01','\"Naresh\" <17>','17','3539932','from-internal', 'SIP/17-0839caf0','Zap/1-1','Monitor','wav49|OUT17-20060807-112201-1154964121.14156| mX',83,79,'ANSWERED',3,'')
Aug 7 11:22:02 DEBUG[15618] chan_zap.c: Exception on 17, channel 1
Aug 7 11:22:02 DEBUG[15618] chan_zap.c: Got event Hook Transition Complete(12) on channel 1 (index 0)
Aug 7 11:22:03 DEBUG[15618] chan_zap.c: Exception on 17, channel 1
Aug 7 11:22:03 DEBUG[15618] chan_zap.c: Got event Dial Complete(9) on channel 1 (index 0)
Aug 7 11:22:03 DEBUG[15618] chan_zap.c: Enabled echo cancellation on channel 1
Aug 7 11:22:03 DEBUG[15618] chan_zap.c: Engaged echo training on channel 1
Aug 7 11:22:05 DEBUG[15618] chan_zap.c: Exception on 17, channel 1
Aug 7 11:22:05 DEBUG[15618] chan_zap.c: Got event Dial Complete(9) on channel 1 (index 0)
Aug 7 11:22:05 DEBUG[15618] chan_zap.c: Echo cancellation already on
Aug 7 11:22:05 VERBOSE[15618] logger.c: -- Zap/1-1 answered SIP/17-0839caf0
Aug 7 11:22:05 DEBUG[2886] chan_sip.c: Stopping retransmission on '7258784f-9a78b1af@192.168.0.108' of Response 102: Match Found