Jul 13 01:36:36 DEBUG[1964] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
Jul 13 01:36:36 DEBUG[1964] chan_sip.c: Setting NAT on RTP to 0
Jul 13 01:36:36 DEBUG[1964] chan_sip.c: Checking SIP call limits for device 300
Jul 13 01:36:36 DEBUG[1964] chan_sip.c: Updating call counter for incoming call
Jul 13 01:36:36 DEBUG[1964] chan_sip.c: build_route: Contact hop: <sip:300@10.1.2.101:5060>
Jul 13 01:36:36 DEBUG[1886] chan_sip.c: Checking device state for peer 300
Jul 13 01:36:36 DEBUG[1886] devicestate.c: Changing state for SIP/300 - state 2 (In use)
Jul 13 01:36:36 DEBUG[1886] chan_sip.c: Checking device state for peer 300
Jul 13 01:36:36 DEBUG[4105] pbx.c: Launching 'Macro'
Jul 13 01:36:36 VERBOSE[4105] logger.c:     -- Executing Macro("SIP/300-0137", "dialout-trunk|2|1989*******||") in new stack
Jul 13 01:36:36 DEBUG[4105] pbx.c: Expression result is '1'
Jul 13 01:36:36 DEBUG[4105] pbx.c: Launching 'GotoIf'
Jul 13 01:36:36 VERBOSE[4105] logger.c:     -- Executing GotoIf("SIP/300-0137", "1?3:2") in new stack
Jul 13 01:36:36 VERBOSE[4105] logger.c:     -- Goto (macro-dialout-trunk,s,3)
Jul 13 01:36:36 DEBUG[4105] pbx.c: Launching 'Macro'
Jul 13 01:36:36 VERBOSE[4105] logger.c:     -- Executing Macro("SIP/300-0137", "user-callerid") in new stack
Jul 13 01:36:36 DEBUG[4106] app_queue.c: Device 'SIP/300' changed to state '2' (In use)
Jul 13 01:36:36 DEBUG[4105] pbx.c: Expression result is '0'
Jul 13 01:36:36 DEBUG[4105] pbx.c: Launching 'GotoIf'
Jul 13 01:36:36 VERBOSE[4105] logger.c:     -- Executing GotoIf("SIP/300-0137", "0?report") in new stack
Jul 13 01:36:36 DEBUG[4105] pbx.c: Not taking any branch
Jul 13 01:36:36 DEBUG[4105] pbx.c: Expression result is '0'
Jul 13 01:36:36 DEBUG[4105] pbx.c: Launching 'GotoIf'
Jul 13 01:36:36 VERBOSE[4105] logger.c:     -- Executing GotoIf("SIP/300-0137", "0?start") in new stack
Jul 13 01:36:36 DEBUG[4105] pbx.c: Not taking any branch
Jul 13 01:36:36 DEBUG[4105] pbx.c: Function result is '300'
Jul 13 01:36:36 DEBUG[4105] pbx.c: Launching 'Set'
Jul 13 01:36:36 VERBOSE[4105] logger.c:     -- Executing Set("SIP/300-0137", "REALCALLERIDNUM=300") in new stack
Jul 13 01:36:36 DEBUG[4105] pbx.c: Launching 'NoOp'
Jul 13 01:36:36 VERBOSE[4105] logger.c:     -- Executing NoOp("SIP/300-0137", "REALCALLERIDNUM is 300") in new stack
Jul 13 01:36:36 DEBUG[4105] pbx.c: Function result is '300'
Jul 13 01:36:36 DEBUG[4105] pbx.c: Launching 'Set'
Jul 13 01:36:36 VERBOSE[4105] logger.c:     -- Executing Set("SIP/300-0137", "AMPUSER=300") in new stack
Jul 13 01:36:36 DEBUG[4105] pbx.c: Function result is 'Andrew Lemstrom'
Jul 13 01:36:36 DEBUG[4105] pbx.c: Launching 'Set'
Jul 13 01:36:36 VERBOSE[4105] logger.c:     -- Executing Set("SIP/300-0137", "AMPUSERCIDNAME=Andrew Lemstrom") in new stack
Jul 13 01:36:36 DEBUG[4105] pbx.c: Expression result is '0'
Jul 13 01:36:36 DEBUG[4105] pbx.c: Launching 'GotoIf'
Jul 13 01:36:36 VERBOSE[4105] logger.c:     -- Executing GotoIf("SIP/300-0137", "0?report") in new stack
Jul 13 01:36:36 DEBUG[4105] pbx.c: Not taking any branch
Jul 13 01:36:36 DEBUG[4105] pbx.c: Launching 'Set'
Jul 13 01:36:36 VERBOSE[4105] logger.c:     -- Executing Set("SIP/300-0137", "CALLERID(all)=Andrew Lemstrom <300>") in new stack
Jul 13 01:36:36 DEBUG[4105] pbx.c: Function result is '"Andrew Lemstrom" <300>'
Jul 13 01:36:36 DEBUG[4105] pbx.c: Launching 'NoOp'
Jul 13 01:36:36 VERBOSE[4105] logger.c:     -- Executing NoOp("SIP/300-0137", "Using CallerID "Andrew Lemstrom" <300>") in new stack
Jul 13 01:36:36 DEBUG[4105] pbx.c: Function result is '300'
Jul 13 01:36:36 DEBUG[4105] pbx.c: Launching 'Macro'
Jul 13 01:36:36 VERBOSE[4105] logger.c:     -- Executing Macro("SIP/300-0137", "record-enable|300|OUT") in new stack
Jul 13 01:36:36 DEBUG[4105] pbx.c: Function result is '0'
Jul 13 01:36:36 DEBUG[4105] pbx.c: Launching 'GotoIf'
Jul 13 01:36:36 VERBOSE[4105] logger.c:     -- Executing GotoIf("SIP/300-0137", "0 > 0?2:4") in new stack
Jul 13 01:36:36 VERBOSE[4105] logger.c:     -- Goto (macro-record-enable,s,4)
Jul 13 01:36:36 DEBUG[4105] pbx.c: Launching 'AGI'
Jul 13 01:36:36 VERBOSE[4105] logger.c:     -- Executing AGI("SIP/300-0137", "recordingcheck|20060713-013636|1152768996.31") in new stack
Jul 13 01:36:36 VERBOSE[4105] logger.c:     -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Jul 13 01:36:36 VERBOSE[4105] logger.c:   recordingcheck|20060713-013636|1152768996.31: Outbound recording not enabled
Jul 13 01:36:36 VERBOSE[4105] logger.c:     -- AGI Script recordingcheck completed, returning 0
Jul 13 01:36:37 DEBUG[4105] pbx.c: Launching 'NoOp'
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Executing NoOp("SIP/300-0137", "No recording needed") in new stack
Jul 13 01:36:37 DEBUG[4105] pbx.c: Launching 'Macro'
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Executing Macro("SIP/300-0137", "outbound-callerid|2") in new stack
Jul 13 01:36:37 DEBUG[4105] pbx.c: Expression result is '1'
Jul 13 01:36:37 DEBUG[4105] pbx.c: Launching 'GotoIf'
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Executing GotoIf("SIP/300-0137", "1?start") in new stack
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Goto (macro-outbound-callerid,s,3)
Jul 13 01:36:37 DEBUG[4105] pbx.c: Launching 'NoOp'
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Executing NoOp("SIP/300-0137", "REALCALLERIDNUM is 300") in new stack
Jul 13 01:36:37 DEBUG[4105] pbx.c: Function result is ''
Jul 13 01:36:37 DEBUG[4105] pbx.c: Launching 'Set'
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Executing Set("SIP/300-0137", "USEROUTCID=") in new stack
Jul 13 01:36:37 DEBUG[4105] db.c: Unable to find key '300/emergency_cid' in family 'DEVICE'
Jul 13 01:36:37 DEBUG[4105] func_db.c: DB: DEVICE/300/emergency_cid not found in database.
Jul 13 01:36:37 DEBUG[4105] pbx.c: Function result is ''
Jul 13 01:36:37 DEBUG[4105] pbx.c: Launching 'Set'
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Executing Set("SIP/300-0137", "EMERGENCYCID=") in new stack
Jul 13 01:36:37 DEBUG[4105] pbx.c: Launching 'Set'
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Executing Set("SIP/300-0137", "TRUNKOUTCID=") in new stack
Jul 13 01:36:37 DEBUG[4105] pbx.c: Expression result is '1'
Jul 13 01:36:37 DEBUG[4105] pbx.c: Launching 'GotoIf'
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Executing GotoIf("SIP/300-0137", "1?trunkcid") in new stack
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Goto (macro-outbound-callerid,s,11)
Jul 13 01:36:37 DEBUG[4105] pbx.c: Expression result is '1'
Jul 13 01:36:37 DEBUG[4105] pbx.c: Launching 'GotoIf'
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Executing GotoIf("SIP/300-0137", "1?usercid") in new stack
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Goto (macro-outbound-callerid,s,13)
Jul 13 01:36:37 DEBUG[4105] pbx.c: Expression result is '1'
Jul 13 01:36:37 DEBUG[4105] pbx.c: Launching 'GotoIf'
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Executing GotoIf("SIP/300-0137", "1?report") in new stack
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Goto (macro-outbound-callerid,s,15)
Jul 13 01:36:37 DEBUG[4105] pbx.c: Function result is '"Andrew Lemstrom" <300>'
Jul 13 01:36:37 DEBUG[4105] pbx.c: Launching 'NoOp'
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Executing NoOp("SIP/300-0137", "CallerID set to "Andrew Lemstrom" <300>") in new stack
Jul 13 01:36:37 DEBUG[4105] pbx.c: Launching 'Set'
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Executing Set("SIP/300-0137", "GROUP()=OUT_2") in new stack
Jul 13 01:36:37 DEBUG[4105] pbx.c: Function result is '1'
Jul 13 01:36:37 DEBUG[4105] pbx.c: Expression result is '0'
Jul 13 01:36:37 DEBUG[4105] pbx.c: Launching 'GotoIf'
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Executing GotoIf("SIP/300-0137", "0?108") in new stack
Jul 13 01:36:37 DEBUG[4105] pbx.c: Not taking any branch
Jul 13 01:36:37 DEBUG[4105] pbx.c: Launching 'Set'
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Executing Set("SIP/300-0137", "DIAL_NUMBER=1989*******") in new stack
Jul 13 01:36:37 DEBUG[4105] pbx.c: Launching 'Set'
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Executing Set("SIP/300-0137", "DIAL_TRUNK=2") in new stack
Jul 13 01:36:37 DEBUG[4105] pbx.c: Launching 'AGI'
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Executing AGI("SIP/300-0137", "fixlocalprefix") in new stack
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- AGI Script fixlocalprefix completed, returning 0
Jul 13 01:36:37 DEBUG[4105] pbx.c: Launching 'Set'
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Executing Set("SIP/300-0137", "OUTNUM=91989*******") in new stack
Jul 13 01:36:37 DEBUG[4105] pbx.c: Function result is 'SIP/123-Net-Line1'
Jul 13 01:36:37 DEBUG[4105] pbx.c: Launching 'Set'
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Executing Set("SIP/300-0137", "custom=SIP/123-Net-Line1") in new stack
Jul 13 01:36:37 DEBUG[4105] pbx.c: Expression result is '0'
Jul 13 01:36:37 DEBUG[4105] pbx.c: Launching 'GotoIf'
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Executing GotoIf("SIP/300-0137", "0?16") in new stack
Jul 13 01:36:37 DEBUG[4105] pbx.c: Not taking any branch
Jul 13 01:36:37 DEBUG[4105] pbx.c: Launching 'Dial'
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Executing Dial("SIP/300-0137", "SIP/123-Net-Line1/91989*******|120|r") in new stack
Jul 13 01:36:37 DEBUG[4105] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP)
Jul 13 01:36:37 DEBUG[4105] chan_sip.c: Setting NAT on RTP to 524288
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-dialout-trunk-s-14.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable MACRO_DEPTH.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-dialout-trunk-s-13.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable custom.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-dialout-trunk-s-12.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable OUTNUM.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-dialout-trunk-s-11.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-dialout-trunk-s-10.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable DIAL_TRUNK.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-dialout-trunk-s-9.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable DIAL_NUMBER.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-dialout-trunk-s-8.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-dialout-trunk-s-7.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable GROUP.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-dialout-trunk-s-6.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable MACRO_PRIORITY.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable MACRO_CONTEXT.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable MACRO_EXTEN.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable ARG1.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-outbound-callerid-s-15.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-outbound-callerid-s-13.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-outbound-callerid-s-11.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-outbound-callerid-s-7.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable TRUNKOUTCID.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-outbound-callerid-s-6.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable EMERGENCYCID.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-outbound-callerid-s-5.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable USEROUTCID.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-outbound-callerid-s-4.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable DB_RESULT.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-outbound-callerid-s-3.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-outbound-callerid-s-1.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-dialout-trunk-s-5.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable ARG2.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-record-enable-s-5.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-record-enable-s-4.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-record-enable-s-1.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-dialout-trunk-s-4.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-user-callerid-s-9.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-user-callerid-s-8.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-user-callerid-s-7.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable AMPUSERCIDNAME.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-user-callerid-s-6.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable AMPUSER.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-user-callerid-s-5.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-user-callerid-s-4.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable REALCALLERIDNUM.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-user-callerid-s-3.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-user-callerid-s-2.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-user-callerid-s-1.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-dialout-trunk-s-3.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-macro-dialout-trunk-s-1.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable ARG4.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable ARG3.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable STACK-from-internal-91989*******-1.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable SIPCALLID.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable SIPUSERAGENT.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable SIPDOMAIN.
Jul 13 01:36:37 DEBUG[4105] channel.c: Not copying variable SIPURI.
Jul 13 01:36:37 DEBUG[4105] chan_sip.c: Outgoing Call for 91989*******
Jul 13 01:36:37 DEBUG[4105] chan_sip.c: Updating call counter for outgoing call
Jul 13 01:36:37 VERBOSE[4105] logger.c:     -- Called 123-Net-Line1/91989*******
Jul 13 01:36:38 DEBUG[1964] chan_sip.c: ** SIP timers: Rescheduling retransmission 2 to 1000 ms (t1 500 ms (Retrans id #306))
Jul 13 01:36:39 DEBUG[1964] chan_sip.c: ** SIP timers: Rescheduling retransmission 3 to 2000 ms (t1 500 ms (Retrans id #306))
Jul 13 01:36:41 DEBUG[1964] chan_sip.c: ** SIP timers: Rescheduling retransmission 4 to 4000 ms (t1 500 ms (Retrans id #306))
Jul 13 01:36:45 DEBUG[1964] chan_sip.c: ** SIP timers: Rescheduling retransmission 5 to 8000 ms (t1 500 ms (Retrans id #306))
Jul 13 01:36:48 DEBUG[1964] chan_sip.c: Allocating new SIP dialog for 43423a4e-d7e08d84@10.1.2.3 - NOTIFY (No RTP)
Jul 13 01:36:48 DEBUG[1964] chan_sip.c: **** Received NOTIFY (4) - Command in SIP NOTIFY
Jul 13 01:36:48 DEBUG[1964] chan_sip.c: Allocating new SIP dialog for 845063c6-defb26c@10.1.2.3 - NOTIFY (No RTP)
Jul 13 01:36:48 DEBUG[1964] chan_sip.c: **** Received NOTIFY (4) - Command in SIP NOTIFY
Jul 13 01:36:53 DEBUG[1964] chan_sip.c: ** SIP timers: Rescheduling retransmission 6 to 16000 ms (t1 500 ms (Retrans id #306))
Jul 13 01:36:54 DEBUG[1964] chan_sip.c: **** Received CANCEL (14) - Command in SIP CANCEL
Jul 13 01:36:54 DEBUG[4105] channel.c: Hanging up channel 'SIP/123-Net-Line1-b7ca'
Jul 13 01:36:54 DEBUG[4105] chan_sip.c: Hangup call SIP/123-Net-Line1-b7ca, SIP callid 72e0ac284ad803975771dc32482ec8d0@10.1.2.2)
Jul 13 01:36:54 DEBUG[4105] chan_sip.c: update_call_counter(91989*******) - decrement call limit counter
Jul 13 01:36:54 DEBUG[4105] chan_sip.c: Updating call counter for outgoing call
Jul 13 01:36:54 DEBUG[4105] chan_sip.c: Acked pending invite 102
Jul 13 01:36:54 DEBUG[4105] chan_sip.c: Stopping retransmission on '72e0ac284ad803975771dc32482ec8d0@10.1.2.2' of Request 102: Match Found
Jul 13 01:36:54 DEBUG[4105] app_dial.c: Exiting with DIALSTATUS=CANCEL.
Jul 13 01:36:54 DEBUG[4105] app_macro.c: Spawn extension (macro-dialout-trunk,s,14) exited non-zero on 'SIP/300-0137' in macro 'dialout-trunk'
Jul 13 01:36:54 DEBUG[4105] pbx.c: Spawn extension (macro-dialout-trunk,s,14) exited non-zero on 'SIP/300-0137'
Jul 13 01:36:54 DEBUG[1886] chan_sip.c: Checking device state for peer 123-Net-Line1
Jul 13 01:36:54 DEBUG[1886] devicestate.c: Changing state for SIP/123-Net-Line1 - state 1 (Not in use)
Jul 13 01:36:54 DEBUG[1964] chan_sip.c: Failed to grab lock, trying again...
Jul 13 01:36:54 DEBUG[4105] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Jul 13 01:36:54 DEBUG[4105] 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-07-13 01:36:36','\"Andrew Lemstrom\" <300>','300','91989*******','from-internal', 'SIP/300-0137','SIP/123-Net-Line1-b7ca','Dial','SIP/123-Net-Line1/91989*******|120|r',18,0,'NO ANSWER',3,'','1152768996.31')
Jul 13 01:36:54 DEBUG[4105] channel.c: Hanging up channel 'SIP/300-0137'
Jul 13 01:36:54 DEBUG[4105] chan_sip.c: Hangup call SIP/300-0137, SIP callid F4F1E403-AE6E-4D9C-A778-5C5CDE5FE534@10.1.2.101)
Jul 13 01:36:54 DEBUG[4105] chan_sip.c: update_call_counter(300) - decrement call limit counter
Jul 13 01:36:54 DEBUG[4105] chan_sip.c: Updating call counter for incoming call
Jul 13 01:36:54 DEBUG[1964] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
Jul 13 01:36:54 DEBUG[1964] chan_sip.c: Stopping retransmission on 'F4F1E403-AE6E-4D9C-A778-5C5CDE5FE534@10.1.2.101' of Response 56198: Match Found
Jul 13 01:36:54 DEBUG[1964] chan_sip.c: Allocating new SIP dialog for F4F1E403-AE6E-4D9C-A778-5C5CDE5FE534@10.1.2.101 - ACK (No RTP)
Jul 13 01:36:54 DEBUG[1964] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
Jul 13 01:36:54 DEBUG[1886] chan_sip.c: Checking device state for peer 300
Jul 13 01:36:54 DEBUG[1886] devicestate.c: Changing state for SIP/300 - state 1 (Not in use)
Jul 13 01:36:54 DEBUG[1886] chan_sip.c: Checking device state for peer 300
Jul 13 01:36:54 DEBUG[4109] app_queue.c: Device 'SIP/123-Net-Line1' changed to state '1' (Not in use)
Jul 13 01:36:54 DEBUG[4110] app_queue.c: Device 'SIP/300' changed to state '1' (Not in use)
Jul 13 01:36:55 DEBUG[1964] chan_sip.c: ** SIP timers: Rescheduling retransmission 2 to 1000 ms (t1 500 ms (Retrans id #308))
Jul 13 01:36:56 DEBUG[1964] chan_sip.c: ** SIP timers: Rescheduling retransmission 3 to 2000 ms (t1 500 ms (Retrans id #308))
Jul 13 01:36:58 DEBUG[1964] chan_sip.c: ** SIP timers: Rescheduling retransmission 4 to 4000 ms (t1 500 ms (Retrans id #308))