c 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'Command'
Dec 17 10:02:06 DEBUG[26850] db.c: Unable to find key 'PARK/71' in family 'dnd'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'Command'
Dec 17 10:02:06 DEBUG[26850] db.c: Unable to find key 'SIP/2011' in family 'dnd'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'Command'
Dec 17 10:02:06 DEBUG[26850] db.c: Unable to find key 'SIP/2026' in family 'dnd'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'Command'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'QueueStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'Status'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'ZapShowChannels'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'Command'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'MailboxStatus'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'Command'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'Command'
Dec 17 10:02:06 DEBUG[26850] manager.c: Manager received command 'Command'
Dec 17 10:02:07 DEBUG[26851] manager.c: Manager received command 'login'
Dec 17 10:02:07 VERBOSE[26851] logger.c: == Parsing '/etc/asterisk/manager.conf': Dec 17 10:02:07 VERBOSE[26851] logger.c: == Parsing '/etc/asterisk/manager.conf': Found
Dec 17 10:02:07 VERBOSE[26851] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Dec 17 10:02:07 VERBOSE[26851] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Found
Dec 17 10:02:07 WARNING[26851] config.c: Unknown directive 'permit=192.168.1.0/255.255.255.0' at line 18 of manager_custom.conf
Dec 17 10:02:07 DEBUG[26851] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Dec 17 10:02:07 DEBUG[26851] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Dec 17 10:02:07 DEBUG[26851] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Dec 17 10:02:07 DEBUG[26851] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Dec 17 10:02:07 VERBOSE[26851] logger.c: == Manager 'admin' logged on from 127.0.0.1
Dec 17 10:02:07 DEBUG[26850] manager.c: Manager received command 'Command'
Dec 17 10:02:07 DEBUG[26850] manager.c: Manager received command 'Command'
Dec 17 10:02:07 DEBUG[26850] manager.c: Manager received command 'Command'
Dec 17 10:02:08 VERBOSE[26851] logger.c: == Manager 'admin' logged off from 127.0.0.1
Dec 17 10:02:27 DEBUG[2862] acl.c: ##### Testing 203.81.209.75 with 192.168.0.0
Dec 17 10:02:27 DEBUG[2862] chan_sip.c: Target address 203.81.209.75 is not local, substituting externip
Dec 17 10:02:28 DEBUG[26855] manager.c: Manager received command 'login'
Dec 17 10:02:28 VERBOSE[26855] logger.c: == Parsing '/etc/asterisk/manager.conf': Dec 17 10:02:28 VERBOSE[26855] logger.c: == Parsing '/etc/asterisk/manager.conf': Found
Dec 17 10:02:28 VERBOSE[26855] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Dec 17 10:02:28 VERBOSE[26855] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Found
Dec 17 10:02:28 WARNING[26855] config.c: Unknown directive 'permit=192.168.1.0/255.255.255.0' at line 18 of manager_custom.conf
Dec 17 10:02:28 DEBUG[26855] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Dec 17 10:02:28 DEBUG[26855] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Dec 17 10:02:28 DEBUG[26855] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Dec 17 10:02:28 DEBUG[26855] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Dec 17 10:02:28 VERBOSE[26855] logger.c: == Manager 'admin' logged on from 127.0.0.1
Dec 17 10:02:28 VERBOSE[26855] logger.c: == Manager 'admin' logged off from 127.0.0.1
Dec 17 10:02:28 DEBUG[26857] manager.c: Manager received command 'login'
Dec 17 10:02:28 VERBOSE[26857] logger.c: == Parsing '/etc/asterisk/manager.conf': Dec 17 10:02:28 VERBOSE[26857] logger.c: == Parsing '/etc/asterisk/manager.conf': Found
Dec 17 10:02:28 VERBOSE[26857] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Dec 17 10:02:28 VERBOSE[26857] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Found
Dec 17 10:02:28 WARNING[26857] config.c: Unknown directive 'permit=192.168.1.0/255.255.255.0' at line 18 of manager_custom.conf
Dec 17 10:02:28 DEBUG[26857] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Dec 17 10:02:28 DEBUG[26857] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Dec 17 10:02:28 DEBUG[26857] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Dec 17 10:02:28 DEBUG[26857] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Dec 17 10:02:28 VERBOSE[26857] logger.c: == Manager 'admin' logged on from 127.0.0.1
Dec 17 10:02:28 VERBOSE[26857] logger.c: == Manager 'admin' logged off from 127.0.0.1
Dec 17 10:02:34 DEBUG[2862] chan_sip.c: Auto destroying call '66b41337148f7f6f01fe5bf20194ecca@127.0.0.1'
Dec 17 10:02:42 DEBUG[2862] chan_sip.c: Auto destroying call 'e774d85cb634d333'
Dec 17 10:02:44 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: NEW 
Dec 17 10:02:44 VERBOSE[2865] logger.c: Timestamp: 00001ms SCall: 00988 DCall: 00000 [192.246.69.186:4569]
Dec 17 10:02:44 VERBOSE[2865] logger.c: VERSION : 2
Dec 17 10:02:44 VERBOSE[2865] logger.c: CALLED NUMBER : 817352
Dec 17 10:02:44 VERBOSE[2865] logger.c: CODEC_PREFS : (ulaw)
Dec 17 10:02:44 VERBOSE[2865] logger.c: CALLING NUMBER : 513
Dec 17 10:02:44 VERBOSE[2865] logger.c: CALLING PRESNTN : 0
Dec 17 10:02:44 VERBOSE[2865] logger.c: CALLING TYPEOFN : 0
Dec 17 10:02:44 VERBOSE[2865] logger.c: CALLING TRANSIT : 0
Dec 17 10:02:44 VERBOSE[2865] logger.c: CALLING NAME : fwdusers@pulver.com
Dec 17 10:02:44 VERBOSE[2865] logger.c: LANGUAGE : en
Dec 17 10:02:44 VERBOSE[2865] logger.c: USERNAME : iaxfwd
Dec 17 10:02:44 VERBOSE[2865] logger.c: FORMAT : 4
Dec 17 10:02:44 VERBOSE[2865] logger.c: CAPABILITY : 63492
Dec 17 10:02:44 VERBOSE[2865] logger.c: ADSICPE : 2
Dec 17 10:02:44 VERBOSE[2865] logger.c: DATE TIME : 2006-12-17 00:12:52
Dec 17 10:02:44 VERBOSE[2865] logger.c: 
Dec 17 10:02:44 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: AUTHREQ
Dec 17 10:02:44 VERBOSE[2865] logger.c: Timestamp: 00009ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:02:44 VERBOSE[2865] logger.c: AUTHMETHODS : 4
Dec 17 10:02:44 VERBOSE[2865] logger.c: CHALLENGE : 205877344
Dec 17 10:02:44 VERBOSE[2865] logger.c: USERNAME : iaxfwd
Dec 17 10:02:44 VERBOSE[2865] logger.c: 
Dec 17 10:02:44 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 001 Type: IAX Subclass: AUTHREP
Dec 17 10:02:44 VERBOSE[2865] logger.c: Timestamp: 00262ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:02:44 VERBOSE[2865] logger.c: RSA RESULT : TWa7QvwTQ82ZpqTBQt3In/HfQF2bCjfUZFsN4N1e1K+e8YzpXbAmbnY+rUAO3cDnu7GJmvAXeixl7hztdOCXcisUBp06hCoeNUJJ9f+yvx2joSw82NbB+zB7fJ88MzOLnBnIMKwx+e4zZPuLqABZyHgKk5LxuXjicEwQNfWnSQs
Dec 17 10:02:44 VERBOSE[2865] logger.c: 
Dec 17 10:02:44 VERBOSE[2865] logger.c: -- Accepting AUTHENTICATED call from 192.246.69.186:
> requested format = ulaw,
> requested prefs = (ulaw),
> actual format = ulaw,
> host prefs = (g729|ulaw|alaw),
> priority = mine
Dec 17 10:02:44 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 002 Type: IAX Subclass: ACCEPT 
Dec 17 10:02:44 VERBOSE[2865] logger.c: Timestamp: 00270ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:02:44 VERBOSE[2865] logger.c: FORMAT : 4
Dec 17 10:02:44 VERBOSE[2865] logger.c: 
Dec 17 10:02:44 VERBOSE[26860] logger.c: -- Executing NoOp("IAX2/FWD-USA-3", "Catch-All DID Match - Found 817352 - You probably want a DID for this.") in new stack
Dec 17 10:02:44 VERBOSE[26860] logger.c: -- Executing Goto("IAX2/FWD-USA-3", "ext-did|s|1") in new stack
Dec 17 10:02:44 VERBOSE[26860] logger.c: -- Goto (ext-did,s,1)
Dec 17 10:02:44 VERBOSE[26860] logger.c: -- Executing Set("IAX2/FWD-USA-3", "FROM_DID=s") in new stack
Dec 17 10:02:44 VERBOSE[26860] logger.c: -- Executing Goto("IAX2/FWD-USA-3", "ext-queues|300|1") in new stack
Dec 17 10:02:44 VERBOSE[26860] logger.c: -- Goto (ext-queues,300,1)
Dec 17 10:02:44 VERBOSE[26860] logger.c: -- Executing Answer("IAX2/FWD-USA-3", "") in new stack
Dec 17 10:02:44 VERBOSE[26860] logger.c: -- Executing Set("IAX2/FWD-USA-3", "_NODEST=300") in new stack
Dec 17 10:02:44 DEBUG[26860] pbx.c: Expression result is '0'
Dec 17 10:02:44 VERBOSE[26860] logger.c: -- Executing GotoIf("IAX2/FWD-USA-3", "0?USERCID:SETCID") in new stack
Dec 17 10:02:44 VERBOSE[26860] logger.c: -- Goto (ext-queues,300,5)
Dec 17 10:02:44 VERBOSE[26860] logger.c: -- Executing Set("IAX2/FWD-USA-3", "CALLERID(name)=fwdusers@pulver.com") in new stack
Dec 17 10:02:44 VERBOSE[26860] logger.c: -- Executing Set("IAX2/FWD-USA-3", "MONITOR_FILENAME=/var/spool/asterisk/monitor/q300-20061217-100244-1166331764.124") in new stack
Dec 17 10:02:44 VERBOSE[26860] logger.c: -- Executing Queue("IAX2/FWD-USA-3", "300|t||") in new stack
Dec 17 10:02:44 VERBOSE[26860] logger.c: -- Started music on hold, class 'default', on IAX2/FWD-USA-3
Dec 17 10:02:44 DEBUG[26860] channel.c: Scheduling timer at 160 sample intervals
Dec 17 10:02:44 VERBOSE[26860] logger.c: -- Called Local/3001@from-internal/n
Dec 17 10:02:44 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 002 Type: CONTROL Subclass: ANSWER 
Dec 17 10:02:44 VERBOSE[2865] logger.c: Timestamp: 00273ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:02:44 VERBOSE[26862] logger.c: -- Executing Macro("Local/3001@from-internal-4e54,2", "exten-vm|novm|3001") in new stack
Dec 17 10:02:44 VERBOSE[26862] logger.c: -- Executing Macro("Local/3001@from-internal-4e54,2", "user-callerid") in new stack
Dec 17 10:02:44 DEBUG[26862] pbx.c: Expression result is '1'
Dec 17 10:02:44 VERBOSE[26862] logger.c: -- Executing GotoIf("Local/3001@from-internal-4e54,2", "1?report") in new stack
Dec 17 10:02:44 VERBOSE[26862] logger.c: -- Goto (macro-user-callerid,s,10)
Dec 17 10:02:44 VERBOSE[26862] logger.c: -- Executing NoOp("Local/3001@from-internal-4e54,2", "TTL: ARG1: novm") in new stack
Dec 17 10:02:44 DEBUG[26862] pbx.c: Expression result is '0'
Dec 17 10:02:44 VERBOSE[26862] logger.c: -- Executing GotoIf("Local/3001@from-internal-4e54,2", "0?continue") in new stack
Dec 17 10:02:44 DEBUG[26862] pbx.c: Not taking any branch
Dec 17 10:02:44 DEBUG[26862] pbx.c: Expression result is '1'
Dec 17 10:02:44 DEBUG[26862] pbx.c: Expression result is '-1'
Dec 17 10:02:44 DEBUG[26862] pbx.c: Function result is '64'
Dec 17 10:02:44 VERBOSE[26862] logger.c: -- Executing Set("Local/3001@from-internal-4e54,2", "_TTL=64") in new stack
Dec 17 10:02:44 DEBUG[26862] pbx.c: Expression result is '1'
Dec 17 10:02:44 VERBOSE[26862] logger.c: -- Executing GotoIf("Local/3001@from-internal-4e54,2", "1?continue") in new stack
Dec 17 10:02:44 VERBOSE[26862] logger.c: -- Goto (macro-user-callerid,s,20)
Dec 17 10:02:44 DEBUG[26862] pbx.c: Function result is '"fwdusers@pulver.com" <513>'
Dec 17 10:02:44 VERBOSE[26862] logger.c: -- Executing NoOp("Local/3001@from-internal-4e54,2", "Using CallerID "fwdusers@pulver.com" <513>") in new stack
Dec 17 10:02:44 VERBOSE[26862] logger.c: -- Executing NoOp("Local/3001@from-internal-4e54,2", "CAME FROM: 300") in new stack
Dec 17 10:02:44 VERBOSE[26862] logger.c: -- Executing Set("Local/3001@from-internal-4e54,2", "RRNODEST=300") in new stack
Dec 17 10:02:44 VERBOSE[26862] logger.c: -- Executing Set("Local/3001@from-internal-4e54,2", "_NODEST=") in new stack
Dec 17 10:02:44 VERBOSE[26862] logger.c: -- Executing Set("Local/3001@from-internal-4e54,2", "FROMCONTEXT=exten-vm") in new stack
Dec 17 10:02:44 VERBOSE[26862] logger.c: -- Executing Set("Local/3001@from-internal-4e54,2", "VMBOX=novm") in new stack
Dec 17 10:02:44 VERBOSE[26862] logger.c: -- Executing Set("Local/3001@from-internal-4e54,2", "EXTTOCALL=3001") in new stack
Dec 17 10:02:44 DEBUG[26862] db.c: Unable to find key '3001' in family 'CFU'
Dec 17 10:02:44 DEBUG[26862] func_db.c: DB: CFU/3001 not found in database.
Dec 17 10:02:44 DEBUG[26862] pbx.c: Function result is ''
Dec 17 10:02:44 VERBOSE[26862] logger.c: -- Executing Set("Local/3001@from-internal-4e54,2", "CFUEXT=") in new stack
Dec 17 10:02:44 DEBUG[26862] pbx.c: Expression result is '0'
Dec 17 10:02:44 DEBUG[26862] pbx.c: Expression result is '0'
Dec 17 10:02:44 DEBUG[26862] pbx.c: Expression result is '0'
Dec 17 10:02:44 DEBUG[26862] pbx.c: Function result is ''
Dec 17 10:02:44 VERBOSE[26862] logger.c: -- Executing Set("Local/3001@from-internal-4e54,2", "RT=") in new stack
Dec 17 10:02:44 VERBOSE[26862] logger.c: -- Executing Macro("Local/3001@from-internal-4e54,2", "record-enable|3001|IN") in new stack
Dec 17 10:02:44 DEBUG[26862] pbx.c: Function result is '0'
Dec 17 10:02:44 VERBOSE[26862] logger.c: -- Executing GotoIf("Local/3001@from-internal-4e54,2", "0 > 0?2:4") in new stack
Dec 17 10:02:44 VERBOSE[26862] logger.c: -- Goto (macro-record-enable,s,4)
Dec 17 10:02:44 VERBOSE[26862] logger.c: -- Executing DeadAGI("Local/3001@from-internal-4e54,2", "recordingcheck|20061217-100244|1166331764.126") in new stack
Dec 17 10:02:44 VERBOSE[26862] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Dec 17 10:02:44 DEBUG[26860] chan_iax2.c: predicted timestamp skew (291) > max (160), using real ts instead.
Dec 17 10:02:44 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 003 ISeqno: 002 Type: VOICE Subclass: 4
Dec 17 10:02:44 VERBOSE[2865] logger.c: Timestamp: 00300ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:02:45 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 002 Type: IAX Subclass: ACK 
Dec 17 10:02:45 VERBOSE[2865] logger.c: Timestamp: 00270ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:02:45 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 003 Type: IAX Subclass: ACK 
Dec 17 10:02:45 VERBOSE[2865] logger.c: Timestamp: 00273ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:02:45 VERBOSE[26862] logger.c: recordingcheck|20061217-100244|1166331764.126: Inbound recording not enabled
Dec 17 10:02:45 VERBOSE[26862] logger.c: -- AGI Script recordingcheck completed, returning 0
Dec 17 10:02:45 VERBOSE[26862] logger.c: -- Executing NoOp("Local/3001@from-internal-4e54,2", "No recording needed") in new stack
Dec 17 10:02:45 DEBUG[26862] pbx.c: Expression result is '1'
Dec 17 10:02:45 VERBOSE[26862] logger.c: -- Executing GotoIf("Local/3001@from-internal-4e54,2", "1?dolocaldial|1") in new stack
Dec 17 10:02:45 VERBOSE[26862] logger.c: -- Goto (macro-exten-vm,dolocaldial,1)
Dec 17 10:02:45 VERBOSE[26862] logger.c: -- Executing Macro("Local/3001@from-internal-4e54,2", "dial||tr|3001") in new stack
Dec 17 10:02:45 VERBOSE[26862] logger.c: -- Executing DeadAGI("Local/3001@from-internal-4e54,2", "dialparties.agi") in new stack
Dec 17 10:02:45 VERBOSE[26862] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Dec 17 10:02:45 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 004 Type: IAX Subclass: ACK 
Dec 17 10:02:45 VERBOSE[2865] logger.c: Timestamp: 00300ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:02:45 VERBOSE[26862] logger.c: dialparties.agi: Starting New Dialparties.agi
Dec 17 10:02:45 VERBOSE[26862] logger.c: dialparties.agi: priority is 1
Dec 17 10:02:45 VERBOSE[26862] logger.c: dialparties.agi: Caller ID name is 'fwdusers@pulver.com' number is '513'
Dec 17 10:02:45 VERBOSE[26862] logger.c: dialparties.agi: Methodology of ring is 'none'
Dec 17 10:02:45 VERBOSE[26862] logger.c: > dialparties.agi: USE_CONFIRMATION: 'FALSE'
Dec 17 10:02:45 VERBOSE[26862] logger.c: > dialparties.agi: RINGGROUP_INDEX: ''
Dec 17 10:02:45 VERBOSE[26862] logger.c: -- dialparties.agi: Added extension 3001 to extension map
Dec 17 10:02:45 DEBUG[26862] db.c: Unable to find key '3001' in family 'CF'
Dec 17 10:02:45 VERBOSE[26862] logger.c: -- dialparties.agi: Extension 3001 cf is disabled
Dec 17 10:02:45 DEBUG[26862] db.c: Unable to find key '3001' in family 'DND'
Dec 17 10:02:45 VERBOSE[26862] logger.c: -- dialparties.agi: Extension 3001 do not disturb is disabled
Dec 17 10:02:45 DEBUG[26862] db.c: Unable to find key '3001' in family 'CFB'
Dec 17 10:02:45 DEBUG[26862] db.c: Unable to find key '3001' in family 'CFU'
Dec 17 10:02:45 VERBOSE[26862] logger.c: > dialparties.agi: extnum: 3001
Dec 17 10:02:45 VERBOSE[26862] logger.c: > dialparties.agi: exthascw: 1
Dec 17 10:02:45 VERBOSE[26862] logger.c: > dialparties.agi: exthascfb: 0
Dec 17 10:02:45 VERBOSE[26862] logger.c: > dialparties.agi: extcfb: 
Dec 17 10:02:45 VERBOSE[26862] logger.c: > dialparties.agi: exthascfu: 0
Dec 17 10:02:45 VERBOSE[26862] logger.c: > dialparties.agi: extcfu: 
Dec 17 10:02:45 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 004 Type: VOICE Subclass: 4
Dec 17 10:02:45 VERBOSE[2865] logger.c: Timestamp: 00624ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:02:45 DEBUG[2865] chan_iax2.c: Ooh, voice format changed to 4
Dec 17 10:02:45 VERBOSE[2865] logger.c: Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 003 Type: IAX Subclass: ACK 
Dec 17 10:02:45 VERBOSE[2865] logger.c: Timestamp: 00624ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:02:45 DEBUG[26860] channel.c: Generator got voice, switching to phase locked mode
Dec 17 10:02:45 DEBUG[26860] channel.c: Scheduling timer at 0 sample intervals
Dec 17 10:02:45 VERBOSE[26862] logger.c: -- dialparties.agi: dbset CALLTRACE/3001 to 513
Dec 17 10:02:45 VERBOSE[26862] logger.c: -- AGI Script dialparties.agi completed, returning 0
Dec 17 10:02:45 VERBOSE[26862] logger.c: -- Executing Dial("Local/3001@from-internal-4e54,2", "SIP/3001||tr") in new stack
Dec 17 10:02:45 DEBUG[26862] chan_sip.c: Setting NAT on RTP to 524288
Dec 17 10:02:45 DEBUG[26862] acl.c: ##### Testing 203.81.233.202 with 192.168.0.0
Dec 17 10:02:45 DEBUG[26862] chan_sip.c: Target address 203.81.233.202 is not local, substituting externip
Dec 17 10:02:45 DEBUG[26862] chan_sip.c: Outgoing Call for 3001
Dec 17 10:02:45 VERBOSE[26862] logger.c: -- Called 3001
Dec 17 10:02:45 VERBOSE[26860] logger.c: -- Local/3001@from-internal-4e54,1 is ringing
Dec 17 10:02:45 DEBUG[2862] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '31c53c781af27548647169670968b58b@202.142.150.12' Request 102: Found
Dec 17 10:02:45 DEBUG[2862] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '31c53c781af27548647169670968b58b@202.142.150.12' Request 102: Found
Dec 17 10:02:45 DEBUG[2862] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '31c53c781af27548647169670968b58b@202.142.150.12' Request 102: Found
Dec 17 10:02:45 DEBUG[2862] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '31c53c781af27548647169670968b58b@202.142.150.12' Request 102: Found
Dec 17 10:02:45 DEBUG[2862] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '31c53c781af27548647169670968b58b@202.142.150.12' Request 102: Found
Dec 17 10:02:45 VERBOSE[26862] logger.c: -- SIP/3001-08bb3030 is ringing
Dec 17 10:02:51 DEBUG[2862] chan_sip.c: Acked pending invite 102
Dec 17 10:02:51 DEBUG[2862] chan_sip.c: Stopping retransmission on '31c53c781af27548647169670968b58b@202.142.150.12' of Request 102: Match Found
Dec 17 10:02:51 VERBOSE[2862] logger.c: -- Got SIP response 480 "Temporarily Unavailable" back from 203.81.233.202
Dec 17 10:02:51 VERBOSE[26862] logger.c: -- SIP/3001-08bb3030 is circuit-busy
Dec 17 10:02:51 DEBUG[26862] chan_sip.c: update_call_counter(3001) - decrement call limit counter
Dec 17 10:02:51 VERBOSE[26862] logger.c: == Everyone is busy/congested at this time (1:0/1/0)
Dec 17 10:02:51 DEBUG[26862] app_dial.c: Exiting with DIALSTATUS=CONGESTION.
Dec 17 10:02:51 VERBOSE[26862] logger.c: -- Executing NoOp("Local/3001@from-internal-4e54,2", "Returned to dolocaldial with DIALSTATUS CONGESTION") in new stack
Dec 17 10:02:51 VERBOSE[26862] logger.c: -- Executing Hangup("Local/3001@from-internal-4e54,2", "") in new stack
Dec 17 10:02:51 VERBOSE[26862] logger.c: == Spawn extension (from-internal, 3001, 2) exited non-zero on 'Local/3001@from-internal-4e54,2'
Dec 17 10:02:51 VERBOSE[26862] logger.c: -- Executing Macro("Local/3001@from-internal-4e54,2", "hangupcall") in new stack
Dec 17 10:02:51 VERBOSE[26862] logger.c: -- Executing ResetCDR("Local/3001@from-internal-4e54,2", "w") in new stack
Dec 17 10:02:51 DEBUG[26860] app_queue.c: Dunno what to do with control type -1
Dec 17 10:02:51 DEBUG[26862] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Dec 17 10:02:51 DEBUG[26862] 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-17 10:02:44','\"fwdusers@pulver.com\" <513>','513','3001','from-internal', 'Local/3001@from-internal-4e54,2','SIP/3001-08bb3030','ResetCDR','w',7,0,'FAILED',3,'','1166331764.126')
Dec 17 10:02:51 VERBOSE[26862] logger.c: -- Executing NoCDR("Local/3001@from-internal-4e54,2", "") in new stack
Dec 17 10:02:51 WARNING[26862] cdr.c: CDR on channel 'Local/3001@from-internal-4e54,2' not posted
Dec 17 10:02:51 WARNING[26862] cdr.c: CDR on channel 'Local/3001@from-internal-4e54,2' lacks end
Dec 17 10:02:51 DEBUG[26862] pbx.c: Expression result is '1'
Dec 17 10:02:51 VERBOSE[26862] logger.c: -- Executing GotoIf("Local/3001@from-internal-4e54,2", "1?theend") in new stack
Dec 17 10:02:51 VERBOSE[26862] logger.c: -- Goto (macro-hangupcall,s,6)
Dec 17 10:02:51 VERBOSE[26862] logger.c: -- Executing Wait("Local/3001@from-internal-4e54,2", "5") in new stack
Dec 17 10:02:51 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: REGREQ 
Dec 17 10:02:51 VERBOSE[2865] logger.c: Timestamp: 00005ms SCall: 00004 DCall: 00000 [192.246.69.186:4569]
Dec 17 10:02:51 VERBOSE[2865] logger.c: USERNAME : 817352
Dec 17 10:02:51 VERBOSE[2865] logger.c: REFRESH : 60
Dec 17 10:02:51 VERBOSE[2865] logger.c: 
Dec 17 10:02:51 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: REGREQ 
Dec 17 10:02:51 VERBOSE[2865] logger.c: Timestamp: 00009ms SCall: 00009 DCall: 00000 [192.246.69.186:4569]
Dec 17 10:02:51 VERBOSE[2865] logger.c: USERNAME : 820382
Dec 17 10:02:51 VERBOSE[2865] logger.c: REFRESH : 60
Dec 17 10:02:51 VERBOSE[2865] logger.c: 
Dec 17 10:02:52 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: REGAUTH
Dec 17 10:02:52 VERBOSE[2865] logger.c: Timestamp: 00017ms SCall: 02948 DCall: 00004 [192.246.69.186:4569]
Dec 17 10:02:52 VERBOSE[2865] logger.c: AUTHMETHODS : 3
Dec 17 10:02:52 VERBOSE[2865] logger.c: CHALLENGE : 490601094
Dec 17 10:02:52 VERBOSE[2865] logger.c: USERNAME : 817352
Dec 17 10:02:52 VERBOSE[2865] logger.c: 
Dec 17 10:02:52 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 001 Type: IAX Subclass: REGREQ 
Dec 17 10:02:52 VERBOSE[2865] logger.c: Timestamp: 00262ms SCall: 00004 DCall: 02948 [192.246.69.186:4569]
Dec 17 10:02:52 VERBOSE[2865] logger.c: USERNAME : 817352
Dec 17 10:02:52 VERBOSE[2865] logger.c: REFRESH : 60
Dec 17 10:02:52 VERBOSE[2865] logger.c: MD5 RESULT : 2898401941d141f2225a9427fd0a4614
Dec 17 10:02:52 VERBOSE[2865] logger.c: 
Dec 17 10:02:52 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: REGAUTH
Dec 17 10:02:52 VERBOSE[2865] logger.c: Timestamp: 00003ms SCall: 03009 DCall: 00009 [192.246.69.186:4569]
Dec 17 10:02:52 VERBOSE[2865] logger.c: AUTHMETHODS : 3
Dec 17 10:02:52 VERBOSE[2865] logger.c: CHALLENGE : 165382189
Dec 17 10:02:52 VERBOSE[2865] logger.c: USERNAME : 820382
Dec 17 10:02:52 VERBOSE[2865] logger.c: 
Dec 17 10:02:52 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 001 Type: IAX Subclass: REGREQ 
Dec 17 10:02:52 VERBOSE[2865] logger.c: Timestamp: 00265ms SCall: 00009 DCall: 03009 [192.246.69.186:4569]
Dec 17 10:02:52 VERBOSE[2865] logger.c: USERNAME : 820382
Dec 17 10:02:52 VERBOSE[2865] logger.c: REFRESH : 60
Dec 17 10:02:52 VERBOSE[2865] logger.c: MD5 RESULT : 4363943769b1f793c9e505f1499e9344
Dec 17 10:02:52 VERBOSE[2865] logger.c: 
Dec 17 10:02:52 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 002 Type: IAX Subclass: REGACK 
Dec 17 10:02:52 VERBOSE[2865] logger.c: Timestamp: 00279ms SCall: 02948 DCall: 00004 [192.246.69.186:4569]
Dec 17 10:02:52 VERBOSE[2865] logger.c: USERNAME : 817352
Dec 17 10:02:52 VERBOSE[2865] logger.c: DATE TIME : 2006-12-17 00:12:58
Dec 17 10:02:52 VERBOSE[2865] logger.c: REFRESH : 60
Dec 17 10:02:52 VERBOSE[2865] logger.c: APPARENT ADDRES : IPV4 202.142.150.12:4569
Dec 17 10:02:52 VERBOSE[2865] logger.c: 
Dec 17 10:02:52 VERBOSE[2865] logger.c: Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 002 Type: IAX Subclass: ACK 
Dec 17 10:02:52 VERBOSE[2865] logger.c: Timestamp: 00279ms SCall: 00004 DCall: 02948 [192.246.69.186:4569]
Dec 17 10:02:52 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 002 Type: IAX Subclass: REGACK 
Dec 17 10:02:52 VERBOSE[2865] logger.c: Timestamp: 00263ms SCall: 03009 DCall: 00009 [192.246.69.186:4569]
Dec 17 10:02:52 VERBOSE[2865] logger.c: USERNAME : 820382
Dec 17 10:02:52 VERBOSE[2865] logger.c: DATE TIME : 2006-12-17 00:12:58
Dec 17 10:02:52 VERBOSE[2865] logger.c: REFRESH : 60
Dec 17 10:02:52 VERBOSE[2865] logger.c: APPARENT ADDRES : IPV4 202.142.150.12:4569
Dec 17 10:02:52 VERBOSE[2865] logger.c: 
Dec 17 10:02:52 VERBOSE[2865] logger.c: Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 002 Type: IAX Subclass: ACK 
Dec 17 10:02:52 VERBOSE[2865] logger.c: Timestamp: 00263ms SCall: 00009 DCall: 03009 [192.246.69.186:4569]
Dec 17 10:02:54 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 004 Type: IAX Subclass: LAGRQ 
Dec 17 10:02:54 VERBOSE[2865] logger.c: Timestamp: 10027ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:02:54 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 004 ISeqno: 004 Type: IAX Subclass: LAGRP 
Dec 17 10:02:54 VERBOSE[2865] logger.c: Timestamp: 10027ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:02:54 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 005 ISeqno: 004 Type: IAX Subclass: LAGRQ 
Dec 17 10:02:54 VERBOSE[2865] logger.c: Timestamp: 10063ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:02:54 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 005 Type: IAX Subclass: ACK 
Dec 17 10:02:54 VERBOSE[2865] logger.c: Timestamp: 10027ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:02:54 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 006 Type: IAX Subclass: LAGRP 
Dec 17 10:02:54 VERBOSE[2865] logger.c: Timestamp: 10063ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:02:54 VERBOSE[2865] logger.c: Tx-Frame Retry[-01] -- OSeqno: 006 ISeqno: 005 Type: IAX Subclass: ACK 
Dec 17 10:02:54 VERBOSE[2865] logger.c: Timestamp: 10063ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:02:56 VERBOSE[26862] logger.c: -- Executing Hangup("Local/3001@from-internal-4e54,2", "") in new stack
Dec 17 10:02:56 VERBOSE[26862] logger.c: == Spawn extension (macro-hangupcall, s, 7) exited non-zero on 'Local/3001@from-internal-4e54,2' in macro 'hangupcall'
Dec 17 10:02:56 VERBOSE[26862] logger.c: == Spawn extension (macro-hangupcall, s, 7) exited non-zero on 'Local/3001@from-internal-4e54,2'
Dec 17 10:02:56 NOTICE[26860] app_queue.c: No one is answering queue '300' (1/0/0)
Dec 17 10:03:01 DEBUG[2862] acl.c: ##### Testing 203.81.209.75 with 192.168.0.0
Dec 17 10:03:01 DEBUG[2862] chan_sip.c: Target address 203.81.209.75 is not local, substituting externip
Dec 17 10:03:01 DEBUG[2862] acl.c: ##### Testing 203.81.233.202 with 192.168.0.0
Dec 17 10:03:01 DEBUG[2862] chan_sip.c: Target address 203.81.233.202 is not local, substituting externip
Dec 17 10:03:01 DEBUG[2862] chan_sip.c: Stopping retransmission on '07c29c4426af13a04fbf407a5263424c@202.142.150.12' of Request 102: Match Found
Dec 17 10:03:01 DEBUG[2862] chan_sip.c: Stopping retransmission on '2d56b0aa5e40fbfd212195b02fc83fa7@202.142.150.12' of Request 102: Match Found
Dec 17 10:03:01 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: POKE 
Dec 17 10:03:01 VERBOSE[2865] logger.c: Timestamp: 00012ms SCall: 00005 DCall: 00000 [192.246.69.186:4569]
Dec 17 10:03:01 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: POKE 
Dec 17 10:03:01 VERBOSE[2865] logger.c: Timestamp: 00013ms SCall: 00006 DCall: 00000 [192.246.69.186:4569]
Dec 17 10:03:01 DEBUG[2862] acl.c: ##### Testing 203.81.233.202 with 192.168.0.0
Dec 17 10:03:01 DEBUG[2862] chan_sip.c: Target address 203.81.233.202 is not local, substituting externip
Dec 17 10:03:01 DEBUG[2862] chan_sip.c: Setting NAT on RTP to 524288
Dec 17 10:03:01 DEBUG[2862] chan_sip.c: Stopping retransmission on 'f1576a0fe00a8b70' of Response 1: Match Found
Dec 17 10:03:01 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: PONG 
Dec 17 10:03:01 VERBOSE[2865] logger.c: Timestamp: 00012ms SCall: 02795 DCall: 00005 [192.246.69.186:4569]
Dec 17 10:03:01 VERBOSE[2865] logger.c: Tx-Frame Retry[-01] -- OSeqno: 001 ISeqno: 001 Type: IAX Subclass: ACK 
Dec 17 10:03:01 VERBOSE[2865] logger.c: Timestamp: 00012ms SCall: 00005 DCall: 02795 [192.246.69.186:4569]
Dec 17 10:03:01 DEBUG[2865] chan_iax2.c: Peer lastms 259, historicms 259, maxms 2000
Dec 17 10:03:01 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: PONG 
Dec 17 10:03:01 VERBOSE[2865] logger.c: Timestamp: 00013ms SCall: 02809 DCall: 00006 [192.246.69.186:4569]
Dec 17 10:03:01 VERBOSE[2865] logger.c: Tx-Frame Retry[-01] -- OSeqno: 001 ISeqno: 001 Type: IAX Subclass: ACK 
Dec 17 10:03:01 VERBOSE[2865] logger.c: Timestamp: 00013ms SCall: 00006 DCall: 02809 [192.246.69.186:4569]
Dec 17 10:03:01 DEBUG[2865] chan_iax2.c: Peer lastms 258, historicms 258, maxms 2000
Dec 17 10:03:01 DEBUG[2862] chan_sip.c: Setting NAT on RTP to 524288
Dec 17 10:03:01 DEBUG[2862] chan_sip.c: Checking SIP call limits for device 3001
Dec 17 10:03:01 DEBUG[2862] chan_sip.c: build_route: Contact hop: 
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing Macro("SIP/3001-08baf028", "dialout-trunk|2|14259063321||") in new stack
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing Set("SIP/3001-08baf028", "DIAL_TRUNK=2") in new stack
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing Set("SIP/3001-08baf028", "_NODEST=") in new stack
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing Set("SIP/3001-08baf028", "DIAL_NUMBER=14259063321") in new stack
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing Set("SIP/3001-08baf028", "ROUTE_PASSWD=") in new stack
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing Set("SIP/3001-08baf028", "DIAL_TRUNK_OPTIONS=tr") in new stack
Dec 17 10:03:01 DEBUG[26871] pbx.c: Expression result is '1'
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing GotoIf("SIP/3001-08baf028", "1?noauth") in new stack
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Goto (macro-dialout-trunk,s,8)
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing Set("SIP/3001-08baf028", "GROUP()=OUT_2") in new stack
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing Macro("SIP/3001-08baf028", "user-callerid|SKIPTTL") in new stack
Dec 17 10:03:01 DEBUG[26871] pbx.c: Expression result is '0'
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing GotoIf("SIP/3001-08baf028", "0?report") in new stack
Dec 17 10:03:01 DEBUG[26871] pbx.c: Not taking any branch
Dec 17 10:03:01 DEBUG[26871] pbx.c: Expression result is '0'
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing GotoIf("SIP/3001-08baf028", "0?start") in new stack
Dec 17 10:03:01 DEBUG[26871] pbx.c: Not taking any branch
Dec 17 10:03:01 DEBUG[26871] pbx.c: Function result is '3001'
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing Set("SIP/3001-08baf028", "REALCALLERIDNUM=3001") in new stack
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing NoOp("SIP/3001-08baf028", "REALCALLERIDNUM is 3001") in new stack
Dec 17 10:03:01 DEBUG[26871] pbx.c: Function result is '3001'
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing Set("SIP/3001-08baf028", "AMPUSER=3001") in new stack
Dec 17 10:03:01 DEBUG[26871] pbx.c: Function result is 'Syed Omer Ali'
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing Set("SIP/3001-08baf028", "AMPUSERCIDNAME=Syed Omer Ali") in new stack
Dec 17 10:03:01 DEBUG[26871] pbx.c: Expression result is '0'
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing GotoIf("SIP/3001-08baf028", "0?report") in new stack
Dec 17 10:03:01 DEBUG[26871] pbx.c: Not taking any branch
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing Set("SIP/3001-08baf028", "CALLERID(all)=Syed Omer Ali <3001>") in new stack
Dec 17 10:03:01 DEBUG[26871] pbx.c: Function result is '3001'
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing Set("SIP/3001-08baf028", "REALCALLERIDNUM=3001") in new stack
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing NoOp("SIP/3001-08baf028", "TTL: ARG1: SKIPTTL") in new stack
Dec 17 10:03:01 DEBUG[26871] pbx.c: Expression result is '1'
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing GotoIf("SIP/3001-08baf028", "1?continue") in new stack
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Goto (macro-user-callerid,s,20)
Dec 17 10:03:01 DEBUG[26871] pbx.c: Function result is '"Syed Omer Ali" <3001>'
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing NoOp("SIP/3001-08baf028", "Using CallerID "Syed Omer Ali" <3001>") in new stack
Dec 17 10:03:01 DEBUG[26871] pbx.c: Function result is '3001'
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing Macro("SIP/3001-08baf028", "record-enable|3001|OUT") in new stack
Dec 17 10:03:01 DEBUG[26871] pbx.c: Function result is '0'
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing GotoIf("SIP/3001-08baf028", "0 > 0?2:4") in new stack
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Goto (macro-record-enable,s,4)
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Executing DeadAGI("SIP/3001-08baf028", "recordingcheck|20061217-100301|1166331781.128") in new stack
Dec 17 10:03:01 VERBOSE[26871] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Dec 17 10:03:01 VERBOSE[26860] logger.c: -- Called Local/3001@from-internal/n
Dec 17 10:03:01 VERBOSE[26874] logger.c: -- Executing Macro("Local/3001@from-internal-ac0a,2", "exten-vm|novm|3001") in new stack
Dec 17 10:03:01 VERBOSE[26874] logger.c: -- Executing Macro("Local/3001@from-internal-ac0a,2", "user-callerid") in new stack
Dec 17 10:03:01 DEBUG[26874] pbx.c: Expression result is '1'
Dec 17 10:03:01 VERBOSE[26874] logger.c: -- Executing GotoIf("Local/3001@from-internal-ac0a,2", "1?report") in new stack
Dec 17 10:03:01 VERBOSE[26874] logger.c: -- Goto (macro-user-callerid,s,10)
Dec 17 10:03:01 VERBOSE[26874] logger.c: -- Executing NoOp("Local/3001@from-internal-ac0a,2", "TTL: ARG1: novm") in new stack
Dec 17 10:03:01 DEBUG[26874] pbx.c: Expression result is '0'
Dec 17 10:03:01 VERBOSE[26874] logger.c: -- Executing GotoIf("Local/3001@from-internal-ac0a,2", "0?continue") in new stack
Dec 17 10:03:01 DEBUG[26874] pbx.c: Not taking any branch
Dec 17 10:03:01 DEBUG[26874] pbx.c: Expression result is '1'
Dec 17 10:03:01 DEBUG[26874] pbx.c: Expression result is '-1'
Dec 17 10:03:01 DEBUG[26874] pbx.c: Function result is '64'
Dec 17 10:03:01 VERBOSE[26874] logger.c: -- Executing Set("Local/3001@from-internal-ac0a,2", "_TTL=64") in new stack
Dec 17 10:03:01 DEBUG[26874] pbx.c: Expression result is '1'
Dec 17 10:03:01 VERBOSE[26874] logger.c: -- Executing GotoIf("Local/3001@from-internal-ac0a,2", "1?continue") in new stack
Dec 17 10:03:01 VERBOSE[26874] logger.c: -- Goto (macro-user-callerid,s,20)
Dec 17 10:03:01 DEBUG[26874] pbx.c: Function result is '"fwdusers@pulver.com" <513>'
Dec 17 10:03:01 VERBOSE[26874] logger.c: -- Executing NoOp("Local/3001@from-internal-ac0a,2", "Using CallerID "fwdusers@pulver.com" <513>") in new stack
Dec 17 10:03:01 VERBOSE[26874] logger.c: -- Executing NoOp("Local/3001@from-internal-ac0a,2", "CAME FROM: 300") in new stack
Dec 17 10:03:01 VERBOSE[26874] logger.c: -- Executing Set("Local/3001@from-internal-ac0a,2", "RRNODEST=300") in new stack
Dec 17 10:03:01 VERBOSE[26874] logger.c: -- Executing Set("Local/3001@from-internal-ac0a,2", "_NODEST=") in new stack
Dec 17 10:03:01 VERBOSE[26874] logger.c: -- Executing Set("Local/3001@from-internal-ac0a,2", "FROMCONTEXT=exten-vm") in new stack
Dec 17 10:03:01 VERBOSE[26874] logger.c: -- Executing Set("Local/3001@from-internal-ac0a,2", "VMBOX=novm") in new stack
Dec 17 10:03:01 VERBOSE[26874] logger.c: -- Executing Set("Local/3001@from-internal-ac0a,2", "EXTTOCALL=3001") in new stack
Dec 17 10:03:01 DEBUG[26874] db.c: Unable to find key '3001' in family 'CFU'
Dec 17 10:03:01 DEBUG[26874] func_db.c: DB: CFU/3001 not found in database.
Dec 17 10:03:01 DEBUG[26874] pbx.c: Function result is ''
Dec 17 10:03:01 VERBOSE[26874] logger.c: -- Executing Set("Local/3001@from-internal-ac0a,2", "CFUEXT=") in new stack
Dec 17 10:03:01 DEBUG[26874] pbx.c: Expression result is '0'
Dec 17 10:03:01 DEBUG[26874] pbx.c: Expression result is '0'
Dec 17 10:03:01 DEBUG[26874] pbx.c: Expression result is '0'
Dec 17 10:03:01 DEBUG[26874] pbx.c: Function result is ''
Dec 17 10:03:01 VERBOSE[26874] logger.c: -- Executing Set("Local/3001@from-internal-ac0a,2", "RT=") in new stack
Dec 17 10:03:01 VERBOSE[26874] logger.c: -- Executing Macro("Local/3001@from-internal-ac0a,2", "record-enable|3001|IN") in new stack
Dec 17 10:03:01 DEBUG[26874] pbx.c: Function result is '0'
Dec 17 10:03:01 VERBOSE[26874] logger.c: -- Executing GotoIf("Local/3001@from-internal-ac0a,2", "0 > 0?2:4") in new stack
Dec 17 10:03:01 VERBOSE[26874] logger.c: -- Goto (macro-record-enable,s,4)
Dec 17 10:03:01 VERBOSE[26874] logger.c: -- Executing DeadAGI("Local/3001@from-internal-ac0a,2", "recordingcheck|20061217-100301|1166331781.130") in new stack
Dec 17 10:03:01 VERBOSE[26874] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Dec 17 10:03:02 VERBOSE[26871] logger.c: recordingcheck|20061217-100301|1166331781.128: Outbound recording not enabled
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- AGI Script recordingcheck completed, returning 0
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Executing NoOp("SIP/3001-08baf028", "No recording needed") in new stack
Dec 17 10:03:02 DEBUG[26871] pbx.c: Expression result is '0'
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Executing GotoIf("SIP/3001-08baf028", "0?skipoutcid") in new stack
Dec 17 10:03:02 DEBUG[26871] pbx.c: Not taking any branch
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Executing Set("SIP/3001-08baf028", "DIAL_TRUNK_OPTIONS=") in new stack
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Executing Macro("SIP/3001-08baf028", "outbound-callerid|2") in new stack
Dec 17 10:03:02 DEBUG[26871] pbx.c: Expression result is '1'
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Executing GotoIf("SIP/3001-08baf028", "1?start") in new stack
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Goto (macro-outbound-callerid,s,3)
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Executing NoOp("SIP/3001-08baf028", "REALCALLERIDNUM is 3001") in new stack
Dec 17 10:03:02 DEBUG[26871] pbx.c: Expression result is '1'
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Executing GotoIf("SIP/3001-08baf028", "1?normcid") in new stack
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Goto (macro-outbound-callerid,s,9)
Dec 17 10:03:02 DEBUG[26871] pbx.c: Function result is ''
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Executing Set("SIP/3001-08baf028", "USEROUTCID=") in new stack
Dec 17 10:03:02 DEBUG[26871] db.c: Unable to find key '3001/emergency_cid' in family 'DEVICE'
Dec 17 10:03:02 DEBUG[26871] func_db.c: DB: DEVICE/3001/emergency_cid not found in database.
Dec 17 10:03:02 DEBUG[26871] pbx.c: Function result is ''
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Executing Set("SIP/3001-08baf028", "EMERGENCYCID=") in new stack
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Executing Set("SIP/3001-08baf028", "TRUNKOUTCID=") in new stack
Dec 17 10:03:02 DEBUG[26871] pbx.c: Expression result is '1'
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Executing GotoIf("SIP/3001-08baf028", "1?trunkcid") in new stack
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Goto (macro-outbound-callerid,s,16)
Dec 17 10:03:02 DEBUG[26871] pbx.c: Expression result is '1'
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Executing GotoIf("SIP/3001-08baf028", "1?usercid") in new stack
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Goto (macro-outbound-callerid,s,18)
Dec 17 10:03:02 DEBUG[26871] pbx.c: Expression result is '1'
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Executing GotoIf("SIP/3001-08baf028", "1?report") in new stack
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Goto (macro-outbound-callerid,s,23)
Dec 17 10:03:02 DEBUG[26871] pbx.c: Function result is '"Syed Omer Ali" <3001>'
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Executing NoOp("SIP/3001-08baf028", "CallerID set to "Syed Omer Ali" <3001>") in new stack
Dec 17 10:03:02 DEBUG[26871] pbx.c: Expression result is '1'
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Executing GotoIf("SIP/3001-08baf028", "1?nomax") in new stack
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Goto (macro-dialout-trunk,s,16)
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Executing DeadAGI("SIP/3001-08baf028", "fixlocalprefix") in new stack
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
Dec 17 10:03:02 VERBOSE[26874] logger.c: recordingcheck|20061217-100301|1166331781.130: Inbound recording not enabled
Dec 17 10:03:02 VERBOSE[26874] logger.c: -- AGI Script recordingcheck completed, returning 0
Dec 17 10:03:02 VERBOSE[26874] logger.c: -- Executing NoOp("Local/3001@from-internal-ac0a,2", "No recording needed") in new stack
Dec 17 10:03:02 DEBUG[26874] pbx.c: Expression result is '1'
Dec 17 10:03:02 VERBOSE[26874] logger.c: -- Executing GotoIf("Local/3001@from-internal-ac0a,2", "1?dolocaldial|1") in new stack
Dec 17 10:03:02 VERBOSE[26874] logger.c: -- Goto (macro-exten-vm,dolocaldial,1)
Dec 17 10:03:02 VERBOSE[26874] logger.c: -- Executing Macro("Local/3001@from-internal-ac0a,2", "dial||tr|3001") in new stack
Dec 17 10:03:02 VERBOSE[26874] logger.c: -- Executing DeadAGI("Local/3001@from-internal-ac0a,2", "dialparties.agi") in new stack
Dec 17 10:03:02 VERBOSE[26874] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- AGI Script fixlocalprefix completed, returning 0
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Executing Set("SIP/3001-08baf028", "OUTNUM=14259063321") in new stack
Dec 17 10:03:02 DEBUG[26871] pbx.c: Function result is 'SIP/OutBound US only'
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Executing Set("SIP/3001-08baf028", "custom=SIP/OutBound US only") in new stack
Dec 17 10:03:02 DEBUG[26871] pbx.c: Expression result is '0'
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Executing GotoIf("SIP/3001-08baf028", "0?customtrunk") in new stack
Dec 17 10:03:02 DEBUG[26871] pbx.c: Not taking any branch
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Executing Dial("SIP/3001-08baf028", "SIP/OutBound US only/14259063321|300|") in new stack
Dec 17 10:03:02 DEBUG[26871] chan_sip.c: Setting NAT on RTP to 524288
Dec 17 10:03:02 DEBUG[26871] acl.c: ##### Testing 64.62.194.247 with 192.168.0.0
Dec 17 10:03:02 DEBUG[26871] chan_sip.c: Target address 64.62.194.247 is not local, substituting externip
Dec 17 10:03:02 DEBUG[26871] chan_sip.c: Outgoing Call for 14259063321
Dec 17 10:03:02 VERBOSE[26871] logger.c: -- Called OutBound US only/14259063321
Dec 17 10:03:02 VERBOSE[26874] logger.c: dialparties.agi: Starting New Dialparties.agi
Dec 17 10:03:02 VERBOSE[26874] logger.c: dialparties.agi: priority is 1
Dec 17 10:03:02 VERBOSE[26874] logger.c: dialparties.agi: Caller ID name is 'fwdusers@pulver.com' number is '513'
Dec 17 10:03:02 VERBOSE[26874] logger.c: dialparties.agi: Methodology of ring is 'none'
Dec 17 10:03:02 VERBOSE[26874] logger.c: > dialparties.agi: USE_CONFIRMATION: 'FALSE'
Dec 17 10:03:02 VERBOSE[26874] logger.c: > dialparties.agi: RINGGROUP_INDEX: ''
Dec 17 10:03:02 VERBOSE[26874] logger.c: -- dialparties.agi: Added extension 3001 to extension map
Dec 17 10:03:02 DEBUG[26874] db.c: Unable to find key '3001' in family 'CF'
Dec 17 10:03:02 VERBOSE[26874] logger.c: -- dialparties.agi: Extension 3001 cf is disabled
Dec 17 10:03:02 DEBUG[26874] db.c: Unable to find key '3001' in family 'DND'
Dec 17 10:03:02 VERBOSE[26874] logger.c: -- dialparties.agi: Extension 3001 do not disturb is disabled
Dec 17 10:03:02 DEBUG[26874] db.c: Unable to find key '3001' in family 'CFB'
Dec 17 10:03:02 DEBUG[26874] db.c: Unable to find key '3001' in family 'CFU'
Dec 17 10:03:02 VERBOSE[26874] logger.c: > dialparties.agi: extnum: 3001
Dec 17 10:03:02 VERBOSE[26874] logger.c: > dialparties.agi: exthascw: 1
Dec 17 10:03:02 VERBOSE[26874] logger.c: > dialparties.agi: exthascfb: 0
Dec 17 10:03:02 VERBOSE[26874] logger.c: > dialparties.agi: extcfb: 
Dec 17 10:03:02 VERBOSE[26874] logger.c: > dialparties.agi: exthascfu: 0
Dec 17 10:03:02 VERBOSE[26874] logger.c: > dialparties.agi: extcfu: 
Dec 17 10:03:02 VERBOSE[26874] logger.c: -- dialparties.agi: dbset CALLTRACE/3001 to 513
Dec 17 10:03:02 VERBOSE[26874] logger.c: -- AGI Script dialparties.agi completed, returning 0
Dec 17 10:03:02 VERBOSE[26874] logger.c: -- Executing Dial("Local/3001@from-internal-ac0a,2", "SIP/3001||tr") in new stack
Dec 17 10:03:02 DEBUG[26874] chan_sip.c: Setting NAT on RTP to 524288
Dec 17 10:03:02 DEBUG[26874] acl.c: ##### Testing 203.81.233.202 with 192.168.0.0
Dec 17 10:03:02 DEBUG[26874] chan_sip.c: Target address 203.81.233.202 is not local, substituting externip
Dec 17 10:03:02 DEBUG[26874] chan_sip.c: Outgoing Call for 3001
Dec 17 10:03:02 VERBOSE[26874] logger.c: -- Called 3001
Dec 17 10:03:02 VERBOSE[26860] logger.c: -- Local/3001@from-internal-ac0a,1 is ringing
Dec 17 10:03:02 DEBUG[2862] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '498d34527a2433003ea988122f72c030@202.142.150.12' Request 102: Found
Dec 17 10:03:02 DEBUG[2862] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '498d34527a2433003ea988122f72c030@202.142.150.12' Request 102: Found
Dec 17 10:03:02 DEBUG[2862] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '498d34527a2433003ea988122f72c030@202.142.150.12' Request 102: Found
Dec 17 10:03:02 VERBOSE[26874] logger.c: -- SIP/3001-08bc0280 is ringing
Dec 17 10:03:02 DEBUG[2862] chan_sip.c: Acked pending invite 102
Dec 17 10:03:02 DEBUG[2862] chan_sip.c: Stopping retransmission on '2133f5bf7d14b64d278c5c7035cffbe4@202.142.150.12' of Request 102: Match Found
Dec 17 10:03:03 DEBUG[2862] chan_sip.c: Acked pending invite 103
Dec 17 10:03:03 DEBUG[2862] chan_sip.c: Stopping retransmission on '2133f5bf7d14b64d278c5c7035cffbe4@202.142.150.12' of Request 103: Match Found
Dec 17 10:03:03 DEBUG[2862] chan_sip.c: build_route: Contact hop: 
Dec 17 10:03:03 VERBOSE[26871] logger.c: -- SIP/OutBound US only-08bb1c48 answered SIP/3001-08baf028
Dec 17 10:03:03 VERBOSE[26871] logger.c: -- Attempting native bridge of SIP/3001-08baf028 and SIP/OutBound US only-08bb1c48
Dec 17 10:03:03 DEBUG[2862] chan_sip.c: Stopping retransmission on 'f1576a0fe00a8b70' of Response 2: Match Found
Dec 17 10:03:04 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 006 Type: IAX Subclass: PING 
Dec 17 10:03:04 VERBOSE[2865] logger.c: Timestamp: 20027ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:03:04 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 006 ISeqno: 006 Type: IAX Subclass: PONG 
Dec 17 10:03:04 VERBOSE[2865] logger.c: Timestamp: 20027ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:03:04 VERBOSE[2865] logger.c: RR_JITTER : 0
Dec 17 10:03:04 VERBOSE[2865] logger.c: RR_LOSS : 0
Dec 17 10:03:04 VERBOSE[2865] logger.c: RR_PKTS : 1
Dec 17 10:03:04 VERBOSE[2865] logger.c: RR_DELAY : 40
Dec 17 10:03:04 VERBOSE[2865] logger.c: RR_DROPPED : 0
Dec 17 10:03:04 VERBOSE[2865] logger.c: RR_OUTOFORDER : 0
Dec 17 10:03:04 VERBOSE[2865] logger.c: 
Dec 17 10:03:04 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 007 ISeqno: 006 Type: IAX Subclass: PING 
Dec 17 10:03:04 VERBOSE[2865] logger.c: Timestamp: 20023ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:03:04 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 008 ISeqno: 006 Type: IAX Subclass: LAGRQ 
Dec 17 10:03:04 VERBOSE[2865] logger.c: Timestamp: 20026ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:03:04 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 006 ISeqno: 006 Type: IAX Subclass: LAGRQ 
Dec 17 10:03:04 VERBOSE[2865] logger.c: Timestamp: 20030ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:03:04 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 009 ISeqno: 007 Type: IAX Subclass: LAGRP 
Dec 17 10:03:04 VERBOSE[2865] logger.c: Timestamp: 20030ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:03:04 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 006 ISeqno: 007 Type: IAX Subclass: ACK 
Dec 17 10:03:04 VERBOSE[2865] logger.c: Timestamp: 20027ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:03:04 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 007 ISeqno: 008 Type: IAX Subclass: PONG 
Dec 17 10:03:04 VERBOSE[2865] logger.c: Timestamp: 20023ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:03:04 VERBOSE[2865] logger.c: RR_JITTER : 0
Dec 17 10:03:04 VERBOSE[2865] logger.c: RR_LOSS : 0
Dec 17 10:03:04 VERBOSE[2865] logger.c: RR_PKTS : 1
Dec 17 10:03:04 VERBOSE[2865] logger.c: RR_DELAY : 40
Dec 17 10:03:04 VERBOSE[2865] logger.c: RR_DROPPED : 0
Dec 17 10:03:04 VERBOSE[2865] logger.c: RR_OUTOFORDER : 0
Dec 17 10:03:04 VERBOSE[2865] logger.c: 
Dec 17 10:03:04 VERBOSE[2865] logger.c: Tx-Frame Retry[-01] -- OSeqno: 008 ISeqno: 008 Type: IAX Subclass: ACK 
Dec 17 10:03:04 VERBOSE[2865] logger.c: Timestamp: 20023ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:03:04 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 008 ISeqno: 009 Type: IAX Subclass: LAGRP 
Dec 17 10:03:04 VERBOSE[2865] logger.c: Timestamp: 20026ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:03:04 VERBOSE[2865] logger.c: Tx-Frame Retry[-01] -- OSeqno: 009 ISeqno: 009 Type: IAX Subclass: ACK 
Dec 17 10:03:04 VERBOSE[2865] logger.c: Timestamp: 20026ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:03:04 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 007 ISeqno: 010 Type: IAX Subclass: ACK 
Dec 17 10:03:04 VERBOSE[2865] logger.c: Timestamp: 20030ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:03:06 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: NEW 
Dec 17 10:03:06 VERBOSE[2865] logger.c: Timestamp: 00001ms SCall: 01437 DCall: 00000 [192.246.69.186:4569]
Dec 17 10:03:06 VERBOSE[2865] logger.c: VERSION : 2
Dec 17 10:03:06 VERBOSE[2865] logger.c: CALLED NUMBER : 820382
Dec 17 10:03:06 VERBOSE[2865] logger.c: CODEC_PREFS : (ulaw)
Dec 17 10:03:06 VERBOSE[2865] logger.c: CALLING NUMBER : 2069731712
Dec 17 10:03:06 VERBOSE[2865] logger.c: CALLING PRESNTN : 0
Dec 17 10:03:06 VERBOSE[2865] logger.c: CALLING TYPEOFN : 0
Dec 17 10:03:06 VERBOSE[2865] logger.c: CALLING TRANSIT : 0
Dec 17 10:03:06 VERBOSE[2865] logger.c: CALLING NAME : 2069731712
Dec 17 10:03:06 VERBOSE[2865] logger.c: LANGUAGE : en
Dec 17 10:03:06 VERBOSE[2865] logger.c: USERNAME : iaxfwd
Dec 17 10:03:06 VERBOSE[2865] logger.c: FORMAT : 4
Dec 17 10:03:06 VERBOSE[2865] logger.c: CAPABILITY : 63492
Dec 17 10:03:06 VERBOSE[2865] logger.c: ADSICPE : 2
Dec 17 10:03:06 VERBOSE[2865] logger.c: DATE TIME : 2006-12-17 00:13:14
Dec 17 10:03:06 VERBOSE[2865] logger.c: 
Dec 17 10:03:06 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: AUTHREQ
Dec 17 10:03:06 VERBOSE[2865] logger.c: Timestamp: 00008ms SCall: 00001 DCall: 01437 [192.246.69.186:4569]
Dec 17 10:03:06 VERBOSE[2865] logger.c: AUTHMETHODS : 4
Dec 17 10:03:06 VERBOSE[2865] logger.c: CHALLENGE : 217746780
Dec 17 10:03:06 VERBOSE[2865] logger.c: USERNAME : iaxfwd
Dec 17 10:03:06 VERBOSE[2865] logger.c: 
Dec 17 10:03:06 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 001 Type: IAX Subclass: AUTHREP
Dec 17 10:03:06 VERBOSE[2865] logger.c: Timestamp: 00266ms SCall: 01437 DCall: 00001 [192.246.69.186:4569]
Dec 17 10:03:06 VERBOSE[2865] logger.c: RSA RESULT : k2SAXkK+FH3cPf/XaFJOaUp/36VJUg1EQUbS/euK6FPixWPJ1j5z6kNynlr6QCtoS9xZKHiE3xUwzg1UNBAowRmHaAICtgBk3TKRer6VuM63ixd/yVTH+wP47Gu6AGq+OGi9ck4B6GJ2lH5hrebFFq9qtZZWlFa+W0q3bjvgrrc
Dec 17 10:03:06 VERBOSE[2865] logger.c: 
Dec 17 10:03:06 VERBOSE[2865] logger.c: -- Accepting AUTHENTICATED call from 192.246.69.186:
> requested format = ulaw,
> requested prefs = (ulaw),
> actual format = ulaw,
> host prefs = (g729|ulaw|alaw),
> priority = mine
Dec 17 10:03:06 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 002 Type: IAX Subclass: ACCEPT 
Dec 17 10:03:06 VERBOSE[2865] logger.c: Timestamp: 00273ms SCall: 00001 DCall: 01437 [192.246.69.186:4569]
Dec 17 10:03:06 VERBOSE[2865] logger.c: FORMAT : 4
Dec 17 10:03:06 VERBOSE[2865] logger.c: 
Dec 17 10:03:06 VERBOSE[26882] logger.c: -- Executing NoOp("IAX2/FWD-USA-1", "Catch-All DID Match - Found 820382 - You probably want a DID for this.") in new stack
Dec 17 10:03:06 VERBOSE[26882] logger.c: -- Executing Goto("IAX2/FWD-USA-1", "ext-did|s|1") in new stack
Dec 17 10:03:06 VERBOSE[26882] logger.c: -- Goto (ext-did,s,1)
Dec 17 10:03:06 VERBOSE[26882] logger.c: -- Executing Set("IAX2/FWD-USA-1", "FROM_DID=s") in new stack
Dec 17 10:03:06 VERBOSE[26882] logger.c: -- Executing Goto("IAX2/FWD-USA-1", "ext-queues|300|1") in new stack
Dec 17 10:03:06 VERBOSE[26882] logger.c: -- Goto (ext-queues,300,1)
Dec 17 10:03:06 VERBOSE[26882] logger.c: -- Executing Answer("IAX2/FWD-USA-1", "") in new stack
Dec 17 10:03:06 VERBOSE[26882] logger.c: -- Executing Set("IAX2/FWD-USA-1", "_NODEST=300") in new stack
Dec 17 10:03:06 DEBUG[26882] pbx.c: Expression result is '0'
Dec 17 10:03:06 VERBOSE[26882] logger.c: -- Executing GotoIf("IAX2/FWD-USA-1", "0?USERCID:SETCID") in new stack
Dec 17 10:03:06 VERBOSE[26882] logger.c: -- Goto (ext-queues,300,5)
Dec 17 10:03:06 VERBOSE[26882] logger.c: -- Executing Set("IAX2/FWD-USA-1", "CALLERID(name)=2069731712") in new stack
Dec 17 10:03:06 VERBOSE[26882] logger.c: -- Executing Set("IAX2/FWD-USA-1", "MONITOR_FILENAME=/var/spool/asterisk/monitor/q300-20061217-100306-1166331786.133") in new stack
Dec 17 10:03:06 VERBOSE[26882] logger.c: -- Executing Queue("IAX2/FWD-USA-1", "300|t||") in new stack
Dec 17 10:03:06 VERBOSE[26882] logger.c: -- Started music on hold, class 'default', on IAX2/FWD-USA-1
Dec 17 10:03:06 DEBUG[26882] channel.c: Scheduling timer at 160 sample intervals
Dec 17 10:03:06 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 002 Type: CONTROL Subclass: ANSWER 
Dec 17 10:03:06 VERBOSE[2865] logger.c: Timestamp: 00276ms SCall: 00001 DCall: 01437 [192.246.69.186:4569]
Dec 17 10:03:06 DEBUG[26882] chan_iax2.c: predicted timestamp skew (294) > max (160), using real ts instead.
Dec 17 10:03:06 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 003 ISeqno: 002 Type: VOICE Subclass: 4
Dec 17 10:03:06 VERBOSE[2865] logger.c: Timestamp: 00300ms SCall: 00001 DCall: 01437 [192.246.69.186:4569]
Dec 17 10:03:07 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 002 Type: IAX Subclass: ACK 
Dec 17 10:03:07 VERBOSE[2865] logger.c: Timestamp: 00273ms SCall: 01437 DCall: 00001 [192.246.69.186:4569]
Dec 17 10:03:07 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 003 Type: IAX Subclass: ACK 
Dec 17 10:03:07 VERBOSE[2865] logger.c: Timestamp: 00276ms SCall: 01437 DCall: 00001 [192.246.69.186:4569]
Dec 17 10:03:07 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 004 Type: IAX Subclass: ACK 
Dec 17 10:03:07 VERBOSE[2865] logger.c: Timestamp: 00300ms SCall: 01437 DCall: 00001 [192.246.69.186:4569]
Dec 17 10:03:07 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 004 Type: VOICE Subclass: 4
Dec 17 10:03:07 VERBOSE[2865] logger.c: Timestamp: 00740ms SCall: 01437 DCall: 00001 [192.246.69.186:4569]
Dec 17 10:03:07 DEBUG[2865] chan_iax2.c: Ooh, voice format changed to 4
Dec 17 10:03:07 VERBOSE[2865] logger.c: Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 003 Type: IAX Subclass: ACK 
Dec 17 10:03:07 VERBOSE[2865] logger.c: Timestamp: 00740ms SCall: 00001 DCall: 01437 [192.246.69.186:4569]
Dec 17 10:03:07 DEBUG[26882] channel.c: Generator got voice, switching to phase locked mode
Dec 17 10:03:07 DEBUG[26882] channel.c: Scheduling timer at 0 sample intervals
Dec 17 10:03:08 DEBUG[26882] chan_iax2.c: predicted timestamp skew (292) > max (160), using real ts instead.
Dec 17 10:03:10 DEBUG[26882] chan_iax2.c: predicted timestamp skew (316) > max (160), using real ts instead.
Dec 17 10:03:14 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 009 ISeqno: 010 Type: IAX Subclass: LAGRQ 
Dec 17 10:03:14 VERBOSE[2865] logger.c: Timestamp: 30027ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:03:14 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 010 ISeqno: 010 Type: IAX Subclass: LAGRP 
Dec 17 10:03:14 VERBOSE[2865] logger.c: Timestamp: 30027ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:03:14 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 011 ISeqno: 010 Type: IAX Subclass: LAGRQ 
Dec 17 10:03:14 VERBOSE[2865] logger.c: Timestamp: 29963ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:03:14 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 010 ISeqno: 011 Type: IAX Subclass: ACK 
Dec 17 10:03:14 VERBOSE[2865] logger.c: Timestamp: 30027ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:03:14 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 010 ISeqno: 012 Type: IAX Subclass: LAGRP 
Dec 17 10:03:14 VERBOSE[2865] logger.c: Timestamp: 29963ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:03:14 VERBOSE[2865] logger.c: Tx-Frame Retry[-01] -- OSeqno: 012 ISeqno: 011 Type: IAX Subclass: ACK 
Dec 17 10:03:14 VERBOSE[2865] logger.c: Timestamp: 29963ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:03:15 DEBUG[26871] channel.c: Didn't get a frame from channel: SIP/3001-08baf028
Dec 17 10:03:15 DEBUG[26871] channel.c: Bridge stops bridging channels SIP/3001-08baf028 and SIP/OutBound US only-08bb1c48
Dec 17 10:03:15 DEBUG[26871] chan_sip.c: update_call_counter(14259063321) - decrement call limit counter
Dec 17 10:03:15 DEBUG[26871] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Dec 17 10:03:15 VERBOSE[26871] logger.c: == Spawn extension (macro-dialout-trunk, s, 20) exited non-zero on 'SIP/3001-08baf028' in macro 'dialout-trunk'
Dec 17 10:03:15 VERBOSE[26871] logger.c: == Spawn extension (macro-dialout-trunk, s, 20) exited non-zero on 'SIP/3001-08baf028'
Dec 17 10:03:15 VERBOSE[26871] logger.c: -- Executing Macro("SIP/3001-08baf028", "hangupcall") in new stack
Dec 17 10:03:15 VERBOSE[26871] logger.c: -- Executing ResetCDR("SIP/3001-08baf028", "w") in new stack
Dec 17 10:03:15 DEBUG[26871] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Dec 17 10:03:15 DEBUG[26871] 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-17 10:03:01','\"Syed Omer Ali\" <3001>','3001','14259063321','from-internal', 'SIP/3001-08baf028','SIP/OutBound US only-08bb1c48','ResetCDR','w',14,12,'ANSWERED',3,'','1166331781.128')
Dec 17 10:03:15 VERBOSE[26871] logger.c: -- Executing NoCDR("SIP/3001-08baf028", "") in new stack
Dec 17 10:03:15 WARNING[26871] cdr.c: CDR on channel 'SIP/3001-08baf028' not posted
Dec 17 10:03:15 WARNING[26871] cdr.c: CDR on channel 'SIP/3001-08baf028' lacks end
Dec 17 10:03:15 DEBUG[26871] pbx.c: Expression result is '1'
Dec 17 10:03:15 VERBOSE[26871] logger.c: -- Executing GotoIf("SIP/3001-08baf028", "1?theend") in new stack
Dec 17 10:03:15 VERBOSE[26871] logger.c: -- Goto (macro-hangupcall,s,6)
Dec 17 10:03:15 VERBOSE[26871] logger.c: -- Executing Wait("SIP/3001-08baf028", "5") in new stack
Dec 17 10:03:15 VERBOSE[26871] logger.c: == Spawn extension (macro-hangupcall, s, 6) exited non-zero on 'SIP/3001-08baf028' in macro 'hangupcall'
Dec 17 10:03:15 VERBOSE[26871] logger.c: == Spawn extension (macro-hangupcall, s, 6) exited non-zero on 'SIP/3001-08baf028'
Dec 17 10:03:15 DEBUG[26871] chan_sip.c: update_call_counter(3001) - decrement call limit counter
Dec 17 10:03:15 DEBUG[2862] chan_sip.c: Stopping retransmission on '2133f5bf7d14b64d278c5c7035cffbe4@202.142.150.12' of Request 104: Match Found
Dec 17 10:03:16 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 004 Type: IAX Subclass: LAGRQ 
Dec 17 10:03:16 VERBOSE[2865] logger.c: Timestamp: 10000ms SCall: 01437 DCall: 00001 [192.246.69.186:4569]
Dec 17 10:03:16 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 004 ISeqno: 004 Type: IAX Subclass: LAGRP 
Dec 17 10:03:16 VERBOSE[2865] logger.c: Timestamp: 10000ms SCall: 00001 DCall: 01437 [192.246.69.186:4569]
Dec 17 10:03:16 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 005 ISeqno: 004 Type: IAX Subclass: LAGRQ 
Dec 17 10:03:16 VERBOSE[2865] logger.c: Timestamp: 09977ms SCall: 00001 DCall: 01437 [192.246.69.186:4569]
Dec 17 10:03:16 DEBUG[26882] chan_iax2.c: predicted timestamp skew (261) > max (160), using real ts instead.
Dec 17 10:03:16 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 005 Type: IAX Subclass: ACK 
Dec 17 10:03:16 VERBOSE[2865] logger.c: Timestamp: 10000ms SCall: 01437 DCall: 00001 [192.246.69.186:4569]
Dec 17 10:03:16 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 006 Type: IAX Subclass: LAGRP 
Dec 17 10:03:16 VERBOSE[2865] logger.c: Timestamp: 09977ms SCall: 01437 DCall: 00001 [192.246.69.186:4569]
Dec 17 10:03:16 VERBOSE[2865] logger.c: Tx-Frame Retry[-01] -- OSeqno: 006 ISeqno: 005 Type: IAX Subclass: ACK 
Dec 17 10:03:16 VERBOSE[2865] logger.c: Timestamp: 09977ms SCall: 00001 DCall: 01437 [192.246.69.186:4569]
Dec 17 10:03:17 VERBOSE[26860] logger.c: -- Nobody picked up in 15000 ms
Dec 17 10:03:17 DEBUG[26874] chan_sip.c: update_call_counter(3001) - decrement call limit counter
Dec 17 10:03:17 DEBUG[26874] chan_sip.c: Acked pending invite 102
Dec 17 10:03:17 DEBUG[26874] chan_sip.c: Stopping retransmission on '498d34527a2433003ea988122f72c030@202.142.150.12' of Request 102: Match Found
Dec 17 10:03:17 DEBUG[26874] app_dial.c: Exiting with DIALSTATUS=CANCEL.
Dec 17 10:03:17 VERBOSE[26874] logger.c: == Spawn extension (macro-dial, s, 10) exited non-zero on 'Local/3001@from-internal-ac0a,2' in macro 'dial'
Dec 17 10:03:17 VERBOSE[26874] logger.c: == Spawn extension (macro-dial, s, 10) exited non-zero on 'Local/3001@from-internal-ac0a,2' in macro 'exten-vm'
Dec 17 10:03:17 VERBOSE[26874] logger.c: == Spawn extension (macro-dial, s, 10) exited non-zero on 'Local/3001@from-internal-ac0a,2'
Dec 17 10:03:17 VERBOSE[26874] logger.c: -- Executing Macro("Local/3001@from-internal-ac0a,2", "hangupcall") in new stack
Dec 17 10:03:17 VERBOSE[26874] logger.c: -- Executing ResetCDR("Local/3001@from-internal-ac0a,2", "w") in new stack
Dec 17 10:03:17 DEBUG[26874] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Dec 17 10:03:17 DEBUG[26874] 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-17 10:03:01','\"fwdusers@pulver.com\" <513>','513','3001','from-internal', 'Local/3001@from-internal-ac0a,2','SIP/3001-08bc0280','ResetCDR','w',16,0,'NO ANSWER',3,'','1166331781.130')
Dec 17 10:03:17 VERBOSE[26874] logger.c: -- Executing NoCDR("Local/3001@from-internal-ac0a,2", "") in new stack
Dec 17 10:03:17 WARNING[26874] cdr.c: CDR on channel 'Local/3001@from-internal-ac0a,2' not posted
Dec 17 10:03:17 WARNING[26874] cdr.c: CDR on channel 'Local/3001@from-internal-ac0a,2' lacks end
Dec 17 10:03:17 DEBUG[26874] pbx.c: Expression result is '1'
Dec 17 10:03:17 VERBOSE[26874] logger.c: -- Executing GotoIf("Local/3001@from-internal-ac0a,2", "1?theend") in new stack
Dec 17 10:03:17 VERBOSE[26874] logger.c: -- Goto (macro-hangupcall,s,6)
Dec 17 10:03:17 VERBOSE[26874] logger.c: -- Executing Wait("Local/3001@from-internal-ac0a,2", "5") in new stack
Dec 17 10:03:17 DEBUG[2862] chan_sip.c: Stopping retransmission on '498d34527a2433003ea988122f72c030@202.142.150.12' of Request 102: Match Found
Dec 17 10:03:17 DEBUG[2862] chan_sip.c: Stopping retransmission on '498d34527a2433003ea988122f72c030@202.142.150.12' of Request 102: Match Not Found
Dec 17 10:03:18 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 006 Type: IAX Subclass: HANGUP 
Dec 17 10:03:18 VERBOSE[2865] logger.c: Timestamp: 11921ms SCall: 01437 DCall: 00001 [192.246.69.186:4569]
Dec 17 10:03:18 VERBOSE[2865] logger.c: CAUSE CODE : 16
Dec 17 10:03:18 VERBOSE[2865] logger.c: 
Dec 17 10:03:18 DEBUG[2865] chan_iax2.c: Immediately destroying 1, having received hangup
Dec 17 10:03:18 VERBOSE[2865] logger.c: Tx-Frame Retry[-01] -- OSeqno: 006 ISeqno: 006 Type: IAX Subclass: ACK 
Dec 17 10:03:18 VERBOSE[2865] logger.c: Timestamp: 11921ms SCall: 00001 DCall: 01437 [192.246.69.186:4569]
Dec 17 10:03:18 VERBOSE[26882] logger.c: -- Stopped music on hold on IAX2/FWD-USA-1
Dec 17 10:03:18 DEBUG[26882] channel.c: Scheduling timer at 0 sample intervals
Dec 17 10:03:18 VERBOSE[26882] logger.c: -- User disconnected from queue 300 while waiting their turn
Dec 17 10:03:18 VERBOSE[26882] logger.c: == Spawn extension (ext-queues, 300, 7) exited non-zero on 'IAX2/FWD-USA-1'
Dec 17 10:03:18 DEBUG[26882] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Dec 17 10:03:18 DEBUG[26882] 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-17 10:03:06','\"2069731712\" <2069731712>','2069731712','300','ext-queues', 'IAX2/FWD-USA-1','','Queue','300|t||',12,12,'ANSWERED',3,'','1166331786.133')
Dec 17 10:03:18 DEBUG[26882] chan_iax2.c: We're hanging up IAX2/FWD-USA-1 now...
Dec 17 10:03:18 DEBUG[26882] chan_iax2.c: Really destroying IAX2/FWD-USA-1 now...
Dec 17 10:03:18 VERBOSE[26882] logger.c: -- Hungup 'IAX2/FWD-USA-1'
Dec 17 10:03:22 VERBOSE[26874] logger.c: -- Executing Hangup("Local/3001@from-internal-ac0a,2", "") in new stack
Dec 17 10:03:22 VERBOSE[26874] logger.c: == Spawn extension (macro-hangupcall, s, 7) exited non-zero on 'Local/3001@from-internal-ac0a,2' in macro 'hangupcall'
Dec 17 10:03:22 VERBOSE[26874] logger.c: == Spawn extension (macro-hangupcall, s, 7) exited non-zero on 'Local/3001@from-internal-ac0a,2'
Dec 17 10:03:22 VERBOSE[26860] logger.c: -- Called Local/3001@from-internal/n
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing Macro("Local/3001@from-internal-110c,2", "exten-vm|novm|3001") in new stack
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing Macro("Local/3001@from-internal-110c,2", "user-callerid") in new stack
Dec 17 10:03:22 DEBUG[26891] pbx.c: Expression result is '1'
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing GotoIf("Local/3001@from-internal-110c,2", "1?report") in new stack
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Goto (macro-user-callerid,s,10)
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing NoOp("Local/3001@from-internal-110c,2", "TTL: ARG1: novm") in new stack
Dec 17 10:03:22 DEBUG[26891] pbx.c: Expression result is '0'
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing GotoIf("Local/3001@from-internal-110c,2", "0?continue") in new stack
Dec 17 10:03:22 DEBUG[26891] pbx.c: Not taking any branch
Dec 17 10:03:22 DEBUG[26891] pbx.c: Expression result is '1'
Dec 17 10:03:22 DEBUG[26891] pbx.c: Expression result is '-1'
Dec 17 10:03:22 DEBUG[26891] pbx.c: Function result is '64'
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing Set("Local/3001@from-internal-110c,2", "_TTL=64") in new stack
Dec 17 10:03:22 DEBUG[26891] pbx.c: Expression result is '1'
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing GotoIf("Local/3001@from-internal-110c,2", "1?continue") in new stack
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Goto (macro-user-callerid,s,20)
Dec 17 10:03:22 DEBUG[26891] pbx.c: Function result is '"fwdusers@pulver.com" <513>'
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing NoOp("Local/3001@from-internal-110c,2", "Using CallerID "fwdusers@pulver.com" <513>") in new stack
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing NoOp("Local/3001@from-internal-110c,2", "CAME FROM: 300") in new stack
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing Set("Local/3001@from-internal-110c,2", "RRNODEST=300") in new stack
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing Set("Local/3001@from-internal-110c,2", "_NODEST=") in new stack
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing Set("Local/3001@from-internal-110c,2", "FROMCONTEXT=exten-vm") in new stack
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing Set("Local/3001@from-internal-110c,2", "VMBOX=novm") in new stack
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing Set("Local/3001@from-internal-110c,2", "EXTTOCALL=3001") in new stack
Dec 17 10:03:22 DEBUG[26891] db.c: Unable to find key '3001' in family 'CFU'
Dec 17 10:03:22 DEBUG[26891] func_db.c: DB: CFU/3001 not found in database.
Dec 17 10:03:22 DEBUG[26891] pbx.c: Function result is ''
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing Set("Local/3001@from-internal-110c,2", "CFUEXT=") in new stack
Dec 17 10:03:22 DEBUG[26891] pbx.c: Expression result is '0'
Dec 17 10:03:22 DEBUG[26891] pbx.c: Expression result is '0'
Dec 17 10:03:22 DEBUG[26891] pbx.c: Expression result is '0'
Dec 17 10:03:22 DEBUG[26891] pbx.c: Function result is ''
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing Set("Local/3001@from-internal-110c,2", "RT=") in new stack
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing Macro("Local/3001@from-internal-110c,2", "record-enable|3001|IN") in new stack
Dec 17 10:03:22 DEBUG[26891] pbx.c: Function result is '0'
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing GotoIf("Local/3001@from-internal-110c,2", "0 > 0?2:4") in new stack
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Goto (macro-record-enable,s,4)
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing DeadAGI("Local/3001@from-internal-110c,2", "recordingcheck|20061217-100322|1166331802.135") in new stack
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Dec 17 10:03:22 VERBOSE[26891] logger.c: recordingcheck|20061217-100322|1166331802.135: Inbound recording not enabled
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- AGI Script recordingcheck completed, returning 0
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing NoOp("Local/3001@from-internal-110c,2", "No recording needed") in new stack
Dec 17 10:03:22 DEBUG[26891] pbx.c: Expression result is '1'
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing GotoIf("Local/3001@from-internal-110c,2", "1?dolocaldial|1") in new stack
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Goto (macro-exten-vm,dolocaldial,1)
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing Macro("Local/3001@from-internal-110c,2", "dial||tr|3001") in new stack
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing DeadAGI("Local/3001@from-internal-110c,2", "dialparties.agi") in new stack
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Dec 17 10:03:22 VERBOSE[26891] logger.c: dialparties.agi: Starting New Dialparties.agi
Dec 17 10:03:22 VERBOSE[26891] logger.c: dialparties.agi: priority is 1
Dec 17 10:03:22 VERBOSE[26891] logger.c: dialparties.agi: Caller ID name is 'fwdusers@pulver.com' number is '513'
Dec 17 10:03:22 VERBOSE[26891] logger.c: dialparties.agi: Methodology of ring is 'none'
Dec 17 10:03:22 VERBOSE[26891] logger.c: > dialparties.agi: USE_CONFIRMATION: 'FALSE'
Dec 17 10:03:22 VERBOSE[26891] logger.c: > dialparties.agi: RINGGROUP_INDEX: ''
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- dialparties.agi: Added extension 3001 to extension map
Dec 17 10:03:22 DEBUG[26891] db.c: Unable to find key '3001' in family 'CF'
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- dialparties.agi: Extension 3001 cf is disabled
Dec 17 10:03:22 DEBUG[26891] db.c: Unable to find key '3001' in family 'DND'
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- dialparties.agi: Extension 3001 do not disturb is disabled
Dec 17 10:03:22 DEBUG[26891] db.c: Unable to find key '3001' in family 'CFB'
Dec 17 10:03:22 DEBUG[26891] db.c: Unable to find key '3001' in family 'CFU'
Dec 17 10:03:22 VERBOSE[26891] logger.c: > dialparties.agi: extnum: 3001
Dec 17 10:03:22 VERBOSE[26891] logger.c: > dialparties.agi: exthascw: 1
Dec 17 10:03:22 VERBOSE[26891] logger.c: > dialparties.agi: exthascfb: 0
Dec 17 10:03:22 VERBOSE[26891] logger.c: > dialparties.agi: extcfb: 
Dec 17 10:03:22 VERBOSE[26891] logger.c: > dialparties.agi: exthascfu: 0
Dec 17 10:03:22 VERBOSE[26891] logger.c: > dialparties.agi: extcfu: 
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- dialparties.agi: dbset CALLTRACE/3001 to 513
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- AGI Script dialparties.agi completed, returning 0
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Executing Dial("Local/3001@from-internal-110c,2", "SIP/3001||tr") in new stack
Dec 17 10:03:22 DEBUG[26891] chan_sip.c: Setting NAT on RTP to 524288
Dec 17 10:03:22 DEBUG[26891] acl.c: ##### Testing 203.81.233.202 with 192.168.0.0
Dec 17 10:03:22 DEBUG[26891] chan_sip.c: Target address 203.81.233.202 is not local, substituting externip
Dec 17 10:03:22 DEBUG[26891] chan_sip.c: Outgoing Call for 3001
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- Called 3001
Dec 17 10:03:22 VERBOSE[26860] logger.c: -- Local/3001@from-internal-110c,1 is ringing
Dec 17 10:03:22 DEBUG[2862] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '692f55537ca2730a796b1b5c012db7a0@202.142.150.12' Request 102: Found
Dec 17 10:03:22 DEBUG[2862] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '692f55537ca2730a796b1b5c012db7a0@202.142.150.12' Request 102: Found
Dec 17 10:03:22 VERBOSE[26891] logger.c: -- SIP/3001-08bb3030 is ringing
Dec 17 10:03:24 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 011 ISeqno: 012 Type: IAX Subclass: PING 
Dec 17 10:03:24 VERBOSE[2865] logger.c: Timestamp: 40027ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:03:24 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 012 ISeqno: 012 Type: IAX Subclass: PONG 
Dec 17 10:03:24 VERBOSE[2865] logger.c: Timestamp: 40027ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:03:24 VERBOSE[2865] logger.c: RR_JITTER : 0
Dec 17 10:03:24 VERBOSE[2865] logger.c: RR_LOSS : 0
Dec 17 10:03:24 VERBOSE[2865] logger.c: RR_PKTS : 1
Dec 17 10:03:24 VERBOSE[2865] logger.c: RR_DELAY : 40
Dec 17 10:03:24 VERBOSE[2865] logger.c: RR_DROPPED : 0
Dec 17 10:03:24 VERBOSE[2865] logger.c: RR_OUTOFORDER : 0
Dec 17 10:03:24 VERBOSE[2865] logger.c: 
Dec 17 10:03:24 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 012 ISeqno: 012 Type: IAX Subclass: LAGRQ 
Dec 17 10:03:24 VERBOSE[2865] logger.c: Timestamp: 40030ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:03:24 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 013 ISeqno: 013 Type: IAX Subclass: LAGRP 
Dec 17 10:03:24 VERBOSE[2865] logger.c: Timestamp: 40030ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:03:24 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 014 ISeqno: 013 Type: IAX Subclass: PING 
Dec 17 10:03:24 VERBOSE[2865] logger.c: Timestamp: 39926ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:03:24 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 015 ISeqno: 013 Type: IAX Subclass: LAGRQ 
Dec 17 10:03:24 VERBOSE[2865] logger.c: Timestamp: 39929ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:03:24 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 012 ISeqno: 013 Type: IAX Subclass: ACK 
Dec 17 10:03:24 VERBOSE[2865] logger.c: Timestamp: 40027ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:03:24 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 013 ISeqno: 014 Type: IAX Subclass: ACK 
Dec 17 10:03:24 VERBOSE[2865] logger.c: Timestamp: 40030ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:03:24 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 013 ISeqno: 015 Type: IAX Subclass: PONG 
Dec 17 10:03:24 VERBOSE[2865] logger.c: Timestamp: 39926ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:03:24 VERBOSE[2865] logger.c: RR_JITTER : 0
Dec 17 10:03:24 VERBOSE[2865] logger.c: RR_LOSS : 0
Dec 17 10:03:24 VERBOSE[2865] logger.c: RR_PKTS : 1
Dec 17 10:03:24 VERBOSE[2865] logger.c: RR_DELAY : 40
Dec 17 10:03:24 VERBOSE[2865] logger.c: RR_DROPPED : 0
Dec 17 10:03:24 VERBOSE[2865] logger.c: RR_OUTOFORDER : 0
Dec 17 10:03:24 VERBOSE[2865] logger.c: 
Dec 17 10:03:24 VERBOSE[2865] logger.c: Tx-Frame Retry[-01] -- OSeqno: 015 ISeqno: 014 Type: IAX Subclass: ACK 
Dec 17 10:03:24 VERBOSE[2865] logger.c: Timestamp: 39926ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:03:24 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 014 ISeqno: 016 Type: IAX Subclass: LAGRP 
Dec 17 10:03:24 VERBOSE[2865] logger.c: Timestamp: 39929ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:03:24 VERBOSE[2865] logger.c: Tx-Frame Retry[-01] -- OSeqno: 016 ISeqno: 015 Type: IAX Subclass: ACK 
Dec 17 10:03:24 VERBOSE[2865] logger.c: Timestamp: 39929ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:03:27 DEBUG[2862] chan_sip.c: Acked pending invite 102
Dec 17 10:03:27 DEBUG[2862] chan_sip.c: Stopping retransmission on '692f55537ca2730a796b1b5c012db7a0@202.142.150.12' of Request 102: Match Found
Dec 17 10:03:27 DEBUG[2862] chan_sip.c: build_route: Contact hop: 
Dec 17 10:03:27 VERBOSE[26891] logger.c: -- SIP/3001-08bb3030 answered Local/3001@from-internal-110c,2
Dec 17 10:03:27 DEBUG[26860] app_queue.c: Dunno what to do with control type -1
Dec 17 10:03:27 VERBOSE[26860] logger.c: -- Local/3001@from-internal-110c,1 answered IAX2/FWD-USA-3
Dec 17 10:03:27 VERBOSE[26860] logger.c: -- Stopped music on hold on IAX2/FWD-USA-3
Dec 17 10:03:27 DEBUG[26860] channel.c: Scheduling timer at 0 sample intervals
Dec 17 10:03:27 DEBUG[26891] chan_sip.c: Oooh, format changed to 4
Dec 17 10:03:29 DEBUG[26891] channel.c: Didn't get a frame from channel: SIP/3001-08bb3030
Dec 17 10:03:29 DEBUG[26891] channel.c: Bridge stops bridging channels Local/3001@from-internal-110c,2 and SIP/3001-08bb3030
Dec 17 10:03:29 DEBUG[26891] chan_sip.c: update_call_counter(3001) - decrement call limit counter
Dec 17 10:03:29 DEBUG[26891] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Dec 17 10:03:29 VERBOSE[26891] logger.c: == Spawn extension (macro-dial, s, 10) exited non-zero on 'Local/3001@from-internal-110c,2' in macro 'dial'
Dec 17 10:03:29 VERBOSE[26891] logger.c: == Spawn extension (macro-dial, s, 10) exited non-zero on 'Local/3001@from-internal-110c,2' in macro 'exten-vm'
Dec 17 10:03:29 VERBOSE[26891] logger.c: == Spawn extension (macro-dial, s, 10) exited non-zero on 'Local/3001@from-internal-110c,2'
Dec 17 10:03:29 VERBOSE[26891] logger.c: -- Executing Macro("Local/3001@from-internal-110c,2", "hangupcall") in new stack
Dec 17 10:03:29 VERBOSE[26891] logger.c: -- Executing ResetCDR("Local/3001@from-internal-110c,2", "w") in new stack
Dec 17 10:03:29 DEBUG[26891] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Dec 17 10:03:29 DEBUG[26891] 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-17 10:03:22','\"fwdusers@pulver.com\" <513>','513','3001','from-internal', 'Local/3001@from-internal-110c,2','SIP/3001-08bb3030','ResetCDR','w',7,2,'ANSWERED',3,'','1166331802.135')
Dec 17 10:03:29 VERBOSE[26891] logger.c: -- Executing NoCDR("Local/3001@from-internal-110c,2", "") in new stack
Dec 17 10:03:29 WARNING[26891] cdr.c: CDR on channel 'Local/3001@from-internal-110c,2' not posted
Dec 17 10:03:29 WARNING[26891] cdr.c: CDR on channel 'Local/3001@from-internal-110c,2' lacks end
Dec 17 10:03:29 DEBUG[26891] pbx.c: Expression result is '1'
Dec 17 10:03:29 VERBOSE[26891] logger.c: -- Executing GotoIf("Local/3001@from-internal-110c,2", "1?theend") in new stack
Dec 17 10:03:29 VERBOSE[26891] logger.c: -- Goto (macro-hangupcall,s,6)
Dec 17 10:03:29 VERBOSE[26891] logger.c: -- Executing Wait("Local/3001@from-internal-110c,2", "5") in new stack
Dec 17 10:03:33 DEBUG[26900] manager.c: Manager received command 'login'
Dec 17 10:03:33 VERBOSE[26900] logger.c: == Parsing '/etc/asterisk/manager.conf': Dec 17 10:03:33 VERBOSE[26900] logger.c: == Parsing '/etc/asterisk/manager.conf': Found
Dec 17 10:03:33 VERBOSE[26900] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Dec 17 10:03:33 VERBOSE[26900] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Found
Dec 17 10:03:33 WARNING[26900] config.c: Unknown directive 'permit=192.168.1.0/255.255.255.0' at line 18 of manager_custom.conf
Dec 17 10:03:33 DEBUG[26900] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Dec 17 10:03:33 DEBUG[26900] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Dec 17 10:03:33 DEBUG[26900] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Dec 17 10:03:33 DEBUG[26900] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Dec 17 10:03:33 VERBOSE[26900] logger.c: == Manager 'admin' logged on from 127.0.0.1
Dec 17 10:03:34 VERBOSE[26900] logger.c: == Manager 'admin' logged off from 127.0.0.1
Dec 17 10:03:34 VERBOSE[26891] logger.c: -- Executing Hangup("Local/3001@from-internal-110c,2", "") in new stack
Dec 17 10:03:34 VERBOSE[26891] logger.c: == Spawn extension (macro-hangupcall, s, 7) exited non-zero on 'Local/3001@from-internal-110c,2' in macro 'hangupcall'
Dec 17 10:03:34 VERBOSE[26891] logger.c: == Spawn extension (macro-hangupcall, s, 7) exited non-zero on 'Local/3001@from-internal-110c,2'
Dec 17 10:03:34 DEBUG[26860] channel.c: Didn't get a frame from channel: Local/3001@from-internal-110c,1
Dec 17 10:03:34 DEBUG[26860] channel.c: Bridge stops bridging channels IAX2/FWD-USA-3 and Local/3001@from-internal-110c,1
Dec 17 10:03:34 VERBOSE[26860] logger.c: == Spawn extension (ext-queues, 300, 7) exited non-zero on 'IAX2/FWD-USA-3'
Dec 17 10:03:34 DEBUG[26860] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Dec 17 10:03:34 DEBUG[26860] 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-17 10:02:44','\"fwdusers@pulver.com\" <513>','513','300','ext-queues', 'IAX2/FWD-USA-3','Local/3001@from-internal-110c,1','Queue','300|t||',50,50,'ANSWERED',3,'','1166331764.124')
Dec 17 10:03:34 DEBUG[26860] chan_iax2.c: We're hanging up IAX2/FWD-USA-3 now...
Dec 17 10:03:34 VERBOSE[26860] logger.c: -- Hungup 'IAX2/FWD-USA-3'
Dec 17 10:03:34 VERBOSE[2865] logger.c: Tx-Frame Retry[000] -- OSeqno: 016 ISeqno: 015 Type: IAX Subclass: HANGUP 
Dec 17 10:03:34 VERBOSE[2865] logger.c: Timestamp: 49607ms SCall: 00003 DCall: 00988 [192.246.69.186:4569]
Dec 17 10:03:34 VERBOSE[2865] logger.c: CAUSE CODE : 0
Dec 17 10:03:34 VERBOSE[2865] logger.c: 
Dec 17 10:03:34 VERBOSE[2865] logger.c: Rx-Frame Retry[ No] -- OSeqno: 015 ISeqno: 017 Type: IAX Subclass: ACK 
Dec 17 10:03:34 VERBOSE[2865] logger.c: Timestamp: 49607ms SCall: 00988 DCall: 00003 [192.246.69.186:4569]
Dec 17 10:03:35 DEBUG[26905] manager.c: Manager received command 'login'
Dec 17 10:03:35 VERBOSE[26905] logger.c: == Parsing '/etc/asterisk/manager.conf': Dec 17 10:03:35 VERBOSE[26905] logger.c: == Parsing '/etc/asterisk/manager.conf': Found
Dec 17 10:03:35 VERBOSE[26905] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Dec 17 10:03:35 VERBOSE[26905] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Found
Dec 17 10:03:35 WARNING[26905] config.c: Unknown directive 'permit=192.168.1.0/255.255.255.0' at line 18 of manager_custom.conf
Dec 17 10:03:35 DEBUG[26905] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Dec 17 10:03:35 DEBUG[26905] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Dec 17 10:03:35 DEBUG[26905] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Dec 17 10:03:35 DEBUG[26905] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Dec 17 10:03:35 VERBOSE[26905] logger.c: == Manager 'admin' logged on from 127.0.0.1
Dec 17 10:03:35 VERBOSE[26905] logger.c: == Manager 'admin' logged off from 127.0.0.1
Dec 17 10:03:40 DEBUG[26907] manager.c: Manager received command 'login'
Dec 17 10:03:40 VERBOSE[26907] logger.c: == Parsing '/etc/asterisk/manager.conf': Dec 17 10:03:40 VERBOSE[26907] logger.c: == Parsing '/etc/asterisk/manager.conf': Found
Dec 17 10:03:40 VERBOSE[26907] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Dec 17 10:03:40 VERBOSE[26907] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Found
Dec 17 10:03:40 WARNING[26907] config.c: Unknown directive 'permit=192.168.1.0/255.255.255.0' at line 18 of manager_custom.conf
Dec 17 10:03:40 DEBUG[26907] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Dec 17 10:03:40 DEBUG[26907] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Dec 17 10:03:40 DEBUG[26907] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Dec 17 10:03:40 DEBUG[26907] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Dec 17 10:03:40 VERBOSE[26907] logger.c: == Manager 'admin' logged on from 127.0.0.1
Dec 17 10:03:40 VERBOSE[26907] logger.c: == Manager 'admin' logged off from 127.0.0.1
Dec 17 10:03:40 VERBOSE[26907] logger.c: == Manager 'admin' logged off from 127.0.0.1