Mar 16 21:06:02 VERBOSE[6380] logger.c:     -- Accepting AUTHENTICATED call from
 67.160.162.122:
       > requested format = gsm,
       > requested prefs = (),
       > actual format = ulaw,
       > host prefs = (ulaw|alaw|gsm),
       > priority = mine
Mar 16 21:06:02 DEBUG[6325] chan_iax2.c: Checking device state for device 8001
Mar 16 21:06:02 DEBUG[6325] chan_iax2.c: iax2_devicestate: Found peer. What's device state of 8001? addr=2057478211, defaddr=0 maxms=2000, lastms=42
Mar 16 21:06:02 DEBUG[6325] devicestate.c: Changing state for IAX2/8001 - state 2 (In use)
Mar 16 21:06:02 DEBUG[6325] chan_iax2.c: Checking device state for device 8001
Mar 16 21:06:02 DEBUG[6325] chan_iax2.c: iax2_devicestate: Found peer. What's device state of 8001? addr=2057478211, defaddr=0 maxms=2000, lastms=42
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'Macro'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing Macro("IAX2/8001-5", "exten-vm|novm|8888") in new stack
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'Macro'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing Macro("IAX2/8001-5", "user-callerid") in new stack
Mar 16 21:06:02 DEBUG[27055] pbx.c: Function result is 'device'
Mar 16 21:06:02 DEBUG[27055] pbx.c: Function result is '8001'
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'NoOp'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing NoOp("IAX2/8001-5", "user-callerid: device 8001") in new stack
Mar 16 21:06:02 DEBUG[27055] pbx.c: Expression result is '0'
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'GotoIf'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing GotoIf("IAX2/8001-5", "0?report") in new stack
Mar 16 21:06:02 DEBUG[27055] pbx.c: Not taking any branch
Mar 16 21:06:02 DEBUG[27055] pbx.c: Expression result is '1'
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'GotoIf'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing GotoIf("IAX2/8001-5", "1?start") in new stack
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Goto (macro-user-callerid,s,5)
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'NoOp'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing NoOp("IAX2/8001-5", "REALCALLERIDNUM is 8001") in new stack
Mar 16 21:06:02 DEBUG[27055] db.c: Unable to find key '8001/user' in family 'DEVICE'
Mar 16 21:06:02 DEBUG[27055] func_db.c: DB: DEVICE/8001/user not found in database.
Mar 16 21:06:02 DEBUG[27055] pbx.c: Function result is ''
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'Set'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing Set("IAX2/8001-5", "AMPUSER=") in new stack
Mar 16 21:06:02 DEBUG[27055] db.c: Unable to find key '/cidname' in family 'AMPUSER'
Mar 16 21:06:02 DEBUG[27055] func_db.c: DB: AMPUSER//cidname not found in database.
Mar 16 21:06:02 DEBUG[27055] pbx.c: Function result is ''
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'Set'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing Set("IAX2/8001-5", "AMPUSERCIDNAME=") in new stack
Mar 16 21:06:02 DEBUG[27055] pbx.c: Expression result is '1'
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'GotoIf'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing GotoIf("IAX2/8001-5", "1?report") in new stack
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Goto (macro-user-callerid,s,11)
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'NoOp'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing NoOp("IAX2/8001-5", "TTL:  ARG1: novm") in new stack
Mar 16 21:06:02 DEBUG[27055] pbx.c: Expression result is '0'
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'GotoIf'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing GotoIf("IAX2/8001-5", "0?continue") in new stack
Mar 16 21:06:02 DEBUG[27055] pbx.c: Not taking any branch
Mar 16 21:06:02 DEBUG[27055] pbx.c: Expression result is '1'
Mar 16 21:06:02 DEBUG[27055] pbx.c: Expression result is '-1'
Mar 16 21:06:02 DEBUG[27055] pbx.c: Function result is '64'
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'Set'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing Set("IAX2/8001-5", "_TTL=64") in new stack
Mar 16 21:06:02 DEBUG[27055] pbx.c: Expression result is '1'
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'GotoIf'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing GotoIf("IAX2/8001-5", "1?continue") in new stack
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Goto (macro-user-callerid,s,21)
Mar 16 21:06:02 DEBUG[27055] pbx.c: Function result is '"device" <8001>'
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'NoOp'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing NoOp("IAX2/8001-5", "Using CallerID "device" <8001>") in new stack
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'Set'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing Set("IAX2/8001-5", "FROMCONTEXT=exten-vm") in new stack
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'Set'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing Set("IAX2/8001-5", "VMBOX=novm") in new stack
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'Set'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing Set("IAX2/8001-5", "EXTTOCALL=8888") in new stack
Mar 16 21:06:02 DEBUG[27055] db.c: Unable to find key '8888' in family 'CFU'
Mar 16 21:06:02 DEBUG[27055] func_db.c: DB: CFU/8888 not found in database.
Mar 16 21:06:02 DEBUG[27055] pbx.c: Function result is ''
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'Set'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing Set("IAX2/8001-5", "CFUEXT=") in new stack
Mar 16 21:06:02 DEBUG[27055] db.c: Unable to find key '8888' in family 'CFB'
Mar 16 21:06:02 DEBUG[27055] func_db.c: DB: CFB/8888 not found in database.
Mar 16 21:06:02 DEBUG[27055] pbx.c: Function result is ''
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'Set'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing Set("IAX2/8001-5", "CFBEXT=") in new stack
Mar 16 21:06:02 DEBUG[27055] pbx.c: Expression result is '0'
Mar 16 21:06:02 DEBUG[27055] pbx.c: Expression result is '0'
Mar 16 21:06:02 DEBUG[27055] pbx.c: Expression result is '0'
Mar 16 21:06:02 DEBUG[27055] pbx.c: Function result is ''
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'Set'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing Set("IAX2/8001-5", "RT=") in new stack
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'Macro'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing Macro("IAX2/8001-5", "record-enable|8888|IN") in new stack
Mar 16 21:06:02 DEBUG[27055] pbx.c: Function result is '0'
Mar 16 21:06:02 DEBUG[27055] pbx.c: Expression result is '0'
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'GotoIf'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing GotoIf("IAX2/8001-5", "0?2:4") in new stack
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Goto (macro-record-enable,s,4)
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'DeadAGI'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing DeadAGI("IAX2/8001-5", "recordingcheck|20070316-210602|1174104362.68") in new stack
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Launched AGI Script /usr/share/asterisk/agi-bin/recordingcheck
Mar 16 21:06:02 DEBUG[27056] app_queue.c: Device 'IAX2/8001' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Mar 16 21:06:02 DEBUG[27055] db.c: Unable to find key '8888/recording' in family 'AMPUSER'
Mar 16 21:06:02 VERBOSE[27055] logger.c:   recordingcheck|20070316-210602|1174104362.68: No AMPUSER db entry for 8888. Not recording
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- AGI Script recordingcheck completed, returning 0
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'NoOp'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing NoOp("IAX2/8001-5", "No recording needed") in new stack
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'Macro'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing Macro("IAX2/8001-5", "dial||tr|8888") in new stack
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'DeadAGI'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing DeadAGI("IAX2/8001-5", "dialparties.agi") in new stack
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Launched AGI Script /usr/share/asterisk/agi-bin/dialparties.agi
Mar 16 21:06:02 VERBOSE[27055] logger.c:   dialparties.agi: Starting New Dialparties.agi
Mar 16 21:06:02 VERBOSE[27055] logger.c:   dialparties.agi: priority is 1
Mar 16 21:06:02 VERBOSE[27055] logger.c:   dialparties.agi: Caller ID name is 'device' number is '8001'
Mar 16 21:06:02 VERBOSE[27055] logger.c:   dialparties.agi: Methodology of ring is  'none'
Mar 16 21:06:02 VERBOSE[27055] logger.c:        >  dialparties.agi: USE_CONFIRMATION:  'FALSE'
Mar 16 21:06:02 VERBOSE[27055] logger.c:        >  dialparties.agi: RINGGROUP_INDEX:   ''
Mar 16 21:06:02 VERBOSE[27055] logger.c:     --  dialparties.agi: Added extension 8888 to extension map
Mar 16 21:06:02 DEBUG[27055] db.c: Unable to find key '8888' in family 'CF'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     --  dialparties.agi: Extension 8888 cf is disabled
Mar 16 21:06:02 DEBUG[27055] db.c: Unable to find key '8888' in family 'DND'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     --  dialparties.agi: Extension 8888 do not disturb is disabled
Mar 16 21:06:02 DEBUG[27055] db.c: Unable to find key '8888' in family 'CW'
Mar 16 21:06:02 DEBUG[27055] db.c: Unable to find key '8888' in family 'CFB'
Mar 16 21:06:02 DEBUG[27055] db.c: Unable to find key '8888' in family 'CFU'
Mar 16 21:06:02 VERBOSE[27055] logger.c:        >  dialparties.agi: extnum: 8888
Mar 16 21:06:02 VERBOSE[27055] logger.c:        >  dialparties.agi: exthascw: 0
Mar 16 21:06:02 VERBOSE[27055] logger.c:        >  dialparties.agi: exthascfb: 0
Mar 16 21:06:02 VERBOSE[27055] logger.c:        >  dialparties.agi: extcfb:
Mar 16 21:06:02 VERBOSE[27055] logger.c:        >  dialparties.agi: exthascfu: 0
Mar 16 21:06:02 VERBOSE[27055] logger.c:        >  dialparties.agi: extcfu:
Mar 16 21:06:02 DEBUG[27059] manager.c: Manager received command 'login'
Mar 16 21:06:02 VERBOSE[27059] logger.c:   == Parsing '/etc/asterisk/manager.conf': Mar 16 21:06:02 DEBUG[27059] config.c: Parsing /etc/asterisk/manager.conf
Mar 16 21:06:02 VERBOSE[27059] logger.c:   == Parsing '/etc/asterisk/manager.conf': Found
Mar 16 21:06:02 DEBUG[27059] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Mar 16 21:06:02 DEBUG[27059] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Mar 16 21:06:02 DEBUG[27059] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Mar 16 21:06:02 DEBUG[27059] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Mar 16 21:06:02 VERBOSE[27059] logger.c:   == Manager 'admin' logged on from 127.0.0.1
Mar 16 21:06:02 DEBUG[27059] manager.c: Manager received command 'ExtensionState'
Mar 16 21:06:02 DEBUG[27059] chan_iax2.c: Checking device state for device 8888
Mar 16 21:06:02 DEBUG[27059] chan_iax2.c: iax2_devicestate: Found peer. What's device state of 8888? addr=1482885642, defaddr=0 maxms=2000, lastms=4
Mar 16 21:06:02 DEBUG[27059] manager.c: Manager received command 'Logoff'
Mar 16 21:06:02 VERBOSE[27059] logger.c:   == Manager 'admin' logged off from 127.0.0.1
Mar 16 21:06:02 VERBOSE[27055] logger.c:        >  dialparties.agi: ExtensionState: 0
Mar 16 21:06:02 VERBOSE[27055] logger.c:   dialparties.agi: Extension 8888 has ExtensionState: 0
Mar 16 21:06:02 VERBOSE[27055] logger.c:     --  dialparties.agi: Checking CW and CFB status for extension 8888
Mar 16 21:06:02 DEBUG[27055] db.c: Unable to find key '8888/device' in family 'AMPUSER'
Mar 16 21:06:02 DEBUG[27055] db.c: Unable to find key '/dial' in family 'DEVICE'
Mar 16 21:06:02 VERBOSE[27055] logger.c:   dialparties.agi: Got Dialstring: (8888,FALSE,) ''
Mar 16 21:06:02 VERBOSE[27055] logger.c:     --  dialparties.agi: dbset CALLTRACE/8888 to 8001
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- AGI Script dialparties.agi completed, returning 0
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'NoOp'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing NoOp("IAX2/8001-5", "Returned from dialparties with no extensions to call") in new stack
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'NoOp'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing NoOp("IAX2/8001-5", "DIALSTATUS is ") in new stack
Mar 16 21:06:02 DEBUG[27055] pbx.c: Expression result is '0'
Mar 16 21:06:02 DEBUG[27055] pbx.c: Expression result is '0'
Mar 16 21:06:02 DEBUG[27055] pbx.c: Expression result is '0'
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'GosubIf'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing GosubIf("IAX2/8001-5", "0?docfu|1") in new stack
Mar 16 21:06:02 DEBUG[27055] pbx.c: Expression result is '0'
Mar 16 21:06:02 DEBUG[27055] pbx.c: Expression result is '0'
Mar 16 21:06:02 DEBUG[27055] pbx.c: Expression result is '0'
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'GosubIf'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing GosubIf("IAX2/8001-5", "0?docfb|1") in new stack
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'NoOp'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing NoOp("IAX2/8001-5", "Voicemail is novm") in new stack
Mar 16 21:06:02 DEBUG[27055] pbx.c: Expression result is '1'
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'GotoIf'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing GotoIf("IAX2/8001-5", "1?s-|1") in new stack
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Goto (macro-exten-vm,s-,1)
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'PlayTones'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing PlayTones("IAX2/8001-5", "congestion") in new stack
Mar 16 21:06:02 DEBUG[27055] channel.c: Prodding channel 'IAX2/8001-5'
Mar 16 21:06:02 DEBUG[27055] channel.c: Set channel IAX2/8001-5 to write format slin
Mar 16 21:06:02 DEBUG[27055] channel.c: Scheduling timer at 160 sample intervals
Mar 16 21:06:02 DEBUG[27055] pbx.c: Launching 'Congestion'
Mar 16 21:06:02 VERBOSE[27055] logger.c:     -- Executing Congestion("IAX2/8001-5", "10") in new stack
Mar 16 21:06:02 DEBUG[6325] chan_iax2.c: Checking device state for device 8001
Mar 16 21:06:02 DEBUG[6325] chan_iax2.c: iax2_devicestate: Found peer. What's device state of 8001? addr=2057478211, defaddr=0 maxms=2000, lastms=42
Mar 16 21:06:02 DEBUG[6325] devicestate.c: Changing state for IAX2/8001 - state 2 (In use)
Mar 16 21:06:02 DEBUG[6325] chan_iax2.c: Checking device state for device 8001
Mar 16 21:06:02 DEBUG[6325] chan_iax2.c: iax2_devicestate: Found peer. What's device state of 8001? addr=2057478211, defaddr=0 maxms=2000, lastms=42
Mar 16 21:06:02 DEBUG[27060] app_queue.c: Device 'IAX2/8001' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Mar 16 21:06:03 DEBUG[6380] chan_iax2.c: Immediately destroying 5, having received hangup
Mar 16 21:06:03 DEBUG[27055] channel.c: Set channel IAX2/8001-5 to write format ulaw
Mar 16 21:06:03 DEBUG[27055] channel.c: Scheduling timer at 0 sample intervals
Mar 16 21:06:03 DEBUG[27055] app_macro.c: Spawn extension (macro-exten-vm,s-,2) exited non-zero on 'IAX2/8001-5' in macro 'exten-vm'
Mar 16 21:06:03 VERBOSE[27055] logger.c:   == Spawn extension (macro-exten-vm, s-, 2) exited non-zero on 'IAX2/8001-5' in macro 'exten-vm'
Mar 16 21:06:03 DEBUG[27055] pbx.c: Spawn extension (macro-exten-vm,s-,2) exited non-zero on 'IAX2/8001-5'
Mar 16 21:06:03 VERBOSE[27055] logger.c:   == Spawn extension (macro-exten-vm, s-, 2) exited non-zero on 'IAX2/8001-5'
Mar 16 21:06:03 DEBUG[27055] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Mar 16 21:06:03 DEBUG[27055] 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 ('2007-03-16 21:06:02','\"device\" <8001>','8001','8888','from-internal', 'IAX2/8001-5','','Congestion','10',1,0,'NO ANSWER',3,'')
Mar 16 21:06:03 DEBUG[27055] channel.c: Hanging up channel 'IAX2/8001-5'
Mar 16 21:06:03 DEBUG[27055] chan_iax2.c: We're hanging up IAX2/8001-5 now...
Mar 16 21:06:03 DEBUG[27055] chan_iax2.c: Really destroying IAX2/8001-5 now...
Mar 16 21:06:03 VERBOSE[27055] logger.c:     -- Hungup 'IAX2/8001-5'
Mar 16 21:06:03 DEBUG[6325] chan_iax2.c: Checking device state for device 8001
Mar 16 21:06:03 DEBUG[6325] chan_iax2.c: iax2_devicestate: Found peer. What's device state of 8001? addr=2057478211, defaddr=0 maxms=2000, lastms=42
Mar 16 21:06:03 DEBUG[6325] devicestate.c: Changing state for IAX2/8001 - state 1 (Not in use)
Mar 16 21:06:03 DEBUG[6325] chan_iax2.c: Checking device state for device 8001
Mar 16 21:06:03 DEBUG[6325] chan_iax2.c: iax2_devicestate: Found peer. What's device state of 8001? addr=2057478211, defaddr=0 maxms=2000, lastms=42
Mar 16 21:06:03 DEBUG[27061] app_queue.c: Device 'IAX2/8001' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
Mar 16 21:06:05 DEBUG[6380] chan_iax2.c: Peer lastms 40, historicms 40, maxms 2000
Mar 16 21:06:09 DEBUG[6325] chan_iax2.c: Checking device state for device 8888
Mar 16 21:06:09 DEBUG[6325] chan_iax2.c: iax2_devicestate: Found peer. What's device state of 8888? addr=1482885642, defaddr=0 maxms=2000, lastms=4
Mar 16 21:06:09 DEBUG[6325] devicestate.c: Changing state for IAX2/8888 - state 1 (Not in use)
Mar 16 21:06:09 DEBUG[6325] chan_iax2.c: Checking device state for device 8888
Mar 16 21:06:09 DEBUG[6325] chan_iax2.c: iax2_devicestate: Found peer. What's device state of 8888? addr=1482885642, defaddr=0 maxms=2000, lastms=4
Mar 16 21:06:09 DEBUG[27062] app_queue.c: Device 'IAX2/8888' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
Mar 16 21:06:09 DEBUG[6325] chan_iax2.c: Checking device state for device 8888
Mar 16 21:06:09 DEBUG[6325] chan_iax2.c: iax2_devicestate: Found peer. What's device state of 8888? addr=1482885642, defaddr=0 maxms=2000, lastms=4
Mar 16 21:06:09 DEBUG[6325] devicestate.c: Changing state for IAX2/8888 - state 1 (Not in use)
Mar 16 21:06:09 DEBUG[6325] chan_iax2.c: Checking device state for device 8888
Mar 16 21:06:09 DEBUG[6325] chan_iax2.c: iax2_devicestate: Found peer. What's device state of 8888? addr=1482885642, defaddr=0 maxms=2000, lastms=4
Mar 16 21:06:09 DEBUG[27063] app_queue.c: Device 'IAX2/8888' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
Mar 16 21:06:23 DEBUG[6357] chan_sip.c: Allocating new SIP dMar 16 21:06:23 DEBUG[6357] chan_sip.c: = Found Their Call ID: 43061ae43127b95a6acfb2ab19b7bdaf@198.145.1.114 Their Tag  Our tag: as4c73964c
Mar 16 21:06:23 DEBUG[6357] chan_sip.c: Stopping retransmission on '43061ae43127b95a6acfb2ab19b7bdaf@198.145.1.114' of Request 102: Match Found
Mar 16 21:06:29 DEBUG[6380] chan_iax2.c: Peer lastms 3, historicms 3, maxms 2000ialog for (No Call-ID) - OPTIONS (No RTP)