##################################################################################################
################################ CALL SCHEME  ####################################################
##################################################################################################

5511 (Linksys wip330) call's 5512 (Linksys SPA941) and 5512 transfers a call to 5514 (Linksys PAP2T)

##################################################################################################



[root@office ~]# 
[root@office ~]# 
[root@office ~]# 
[root@office ~]# 
[root@office ~]# 
[root@office ~]# 
[root@office ~]# 
[root@office ~]# 
[root@office ~]# asterisk -r
Asterisk 1.4.17, Copyright (C) 1999 - 2007 Digium, Inc. and others.
Created by Mark Spencer <markster@digium.com>
Asterisk comes with ABSOLUTELY NO WARRANTY; type 'core show warranty' for details.
This is free software, with components licensed under the GNU General Public
License version 2 and other licenses; you are welcome to redistribute it under
certain conditions. Type 'core show license' for details.
=========================================================================
Connected to Asterisk 1.4.17 currently running on office (pid = 4188)
Verbosity is at least 3
office*CLI> 
office*CLI> 
office*CLI> core set debug 9                                                                                                                                                      
Core debug was 0 and is now 9
office*CLI> 
office*CLI> 
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:2733 do_setnat: Setting NAT on RTP to Off
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:4509 sip_alloc: Allocating new SIP dialog for 36ce20-1301a8c0-13c4-43747-1b74564-43747@192.168.1.1 - INVITE (With RTP)
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:15154 handle_request: **** Received INVITE (5) - Command in SIP INVITE
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:2733 do_setnat: Setting NAT on RTP to Off
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 36ce20-1301a8c0-13c4-43747-1b74564-43747@192.168.1.1 Their Tag 38d270-1301a8c0-13c4-43747-431e71f
d-43747 Our tag: as1b5d9370
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:15154 handle_request: **** Received ACK (6) - Command in SIP ACK
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:2170 __sip_ack: Stopping retransmission on '36ce20-1301a8c0-13c4-43747-1b74564-43747@192.168.1.1' of Response 1: Match Not Found
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 36ce20-1301a8c0-13c4-43747-1b74564-43747@192.168.1.1 Their Tag 38d270-1301a8c0-13c4-43747-431e71f
d-43747 Our tag: as1b5d9370
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:15154 handle_request: **** Received INVITE (5) - Command in SIP INVITE
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:2733 do_setnat: Setting NAT on RTP to Off
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:5388 process_sdp: T38 state changed to 0 on channel <none>
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:5468 process_sdp: We're settling with these formats: 0x8 (alaw)
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:13834 handle_request_invite: Checking SIP call limits for device 5511
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:3173 update_call_counter: Updating call counter for incoming call
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:3993 sip_new: *** Our native formats are 0x8 (alaw) 
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:3994 sip_new: *** Joint capabilities are 0x8 (alaw) 
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:3995 sip_new: *** Our capabilities are 0x8 (alaw) 
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:3996 sip_new: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) 
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:4019 sip_new: This channel will not be able to handle video.
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:8241 build_route: build_route: Contact hop: <sip:5511@192.168.1.19:5060;transport=UDP>
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:13913 handle_request_invite: SIP/5511-08fd76a0: New call is still down.... Trying... 
[Jan  8 19:05:02] DEBUG[4306]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/5511-08fd76a0
[Jan  8 19:05:02] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5511
[Jan  8 19:05:02] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5511
[Jan  8 19:05:02] DEBUG[4259]: devicestate.c:287 do_state_change: Changing state for SIP/5511 - state 1 (Not in use)
[Jan  8 19:05:02] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5511
[Jan  8 19:05:02] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5511
[Jan  8 19:05:02] DEBUG[5325]: pbx.c:1831 pbx_extension_helper: Launching 'AGI'
    -- Executing [5512@internal:1] AGI("SIP/5511-08fd76a0", "selintra|OutCluster|5512") in new stack
[Jan  8 19:05:02] DEBUG[4325]: app_queue.c:589 handle_statechange: Device 'SIP/5511' changed to state '1' (Not in use) but we don't care because they're not a member of any queue
.
    -- Launched AGI Script /var/lib/asterisk/agi-bin/selintra
    -- AGI Script selintra completed, returning 0
[Jan  8 19:05:02] DEBUG[5325]: pbx.c:1831 pbx_extension_helper: Launching 'AGI'
    -- Executing [5512@default:1] AGI("SIP/5511-08fd76a0", "selintra|InCall|") in new stack
    -- Launched AGI Script /var/lib/asterisk/agi-bin/selintra
[Jan  8 19:05:02] DEBUG[5325]: db.c:198 ast_db_get: Unable to find key 'OCSTAT' in family 'STAT'
[Jan  8 19:05:02] DEBUG[5325]: db.c:198 ast_db_get: Unable to find key '5512' in family 'cfimopen'
[Jan  8 19:05:02] DEBUG[5325]: db.c:198 ast_db_get: Unable to find key '5512' in family 'cfim'
[Jan  8 19:05:02] DEBUG[5325]: db.c:198 ast_db_get: Unable to find key 'OCSTAT' in family 'STAT'
[Jan  8 19:05:02] DEBUG[5325]: db.c:198 ast_db_get: Unable to find key '5512' in family 'cfimopen'
[Jan  8 19:05:02] DEBUG[5325]: db.c:198 ast_db_get: Unable to find key 'OCSTAT' in family 'STAT'
[Jan  8 19:05:02] DEBUG[5325]: db.c:198 ast_db_get: Unable to find key '5512' in family 'cfim'
[Jan  8 19:05:02] DEBUG[5325]: db.c:198 ast_db_get: Unable to find key '5512' in family 'ringdelay'
    -- AGI Script Executing Application: (Dial) Options: (SIP/5512|99|tTwW)
[Jan  8 19:05:02] DEBUG[5325]: chan_sip.c:15857 sip_request_call: Asked to create a SIP channel with formats: 0x8 (alaw)
[Jan  8 19:05:02] DEBUG[5325]: chan_sip.c:4509 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP)
[Jan  8 19:05:02] DEBUG[5325]: chan_sip.c:2733 do_setnat: Setting NAT on RTP to Off
[Jan  8 19:05:02] DEBUG[5325]: chan_sip.c:3993 sip_new: *** Our native formats are 0x8 (alaw) 
[Jan  8 19:05:02] DEBUG[5325]: chan_sip.c:3994 sip_new: *** Joint capabilities are 0x0 (nothing) 
[Jan  8 19:05:02] DEBUG[5325]: chan_sip.c:3995 sip_new: *** Our capabilities are 0x8 (alaw) 
[Jan  8 19:05:02] DEBUG[5325]: chan_sip.c:3996 sip_new: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) 
[Jan  8 19:05:02] DEBUG[5325]: chan_sip.c:3998 sip_new: *** Our preferred formats from the incoming channel are 0x8 (alaw) 
[Jan  8 19:05:02] DEBUG[5325]: chan_sip.c:4019 sip_new: This channel will not be able to handle video.
[Jan  8 19:05:02] DEBUG[5325]: channel.c:3579 ast_channel_inherit_variables: Not copying variable AGISTATUS.
[Jan  8 19:05:02] DEBUG[5325]: channel.c:3579 ast_channel_inherit_variables: Not copying variable SIPCALLID.
[Jan  8 19:05:02] DEBUG[5325]: channel.c:3579 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT.
[Jan  8 19:05:02] DEBUG[5325]: channel.c:3579 ast_channel_inherit_variables: Not copying variable SIPDOMAIN.
[Jan  8 19:05:02] DEBUG[5325]: channel.c:3579 ast_channel_inherit_variables: Not copying variable SIPURI.
[Jan  8 19:05:02] DEBUG[5325]: chan_sip.c:2991 sip_call: Outgoing Call for 5512
[Jan  8 19:05:02] DEBUG[5325]: chan_sip.c:3173 update_call_counter: Updating call counter for outgoing call
[Jan  8 19:05:02] DEBUG[5325]: chan_sip.c:3006 sip_call: Our T38 capability (0), joint T38 capability (0)
[Jan  8 19:05:02] DEBUG[5325]: chan_sip.c:6421 add_sdp: ** Our capability: 0x8 (alaw) Video flag: False
[Jan  8 19:05:02] DEBUG[5325]: chan_sip.c:6422 add_sdp: ** Our prefcodec: 0x8 (alaw) 
[Jan  8 19:05:02] DEBUG[5325]: chan_sip.c:6553 add_sdp: -- Done with adding codecs to SDP
[Jan  8 19:05:02] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:02] DEBUG[5325]: chan_sip.c:6598 add_sdp: Done building SDP. Settling with this capability: 0x8 (alaw)
    -- Called 5512
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 69a718397444071f01870aff7b4c475e@192.168.1.1 Their Tag  Our tag: as578af8a4
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:2212 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '69a718397444071f01870aff7b4c475e@192.168.1.1' Requ
est 102: Found
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:11974 handle_response_invite: SIP response 100 to standard invite
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 69a718397444071f01870aff7b4c475e@192.168.1.1 Their Tag  Our tag: as578af8a4
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:2212 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '69a718397444071f01870aff7b4c475e@192.168.1.1' Requ
est 102: Found
[Jan  8 19:05:02] DEBUG[4306]: chan_sip.c:11974 handle_response_invite: SIP response 180 to standard invite
[Jan  8 19:05:02] DEBUG[4306]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/5512-08fd8f00
[Jan  8 19:05:02] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5512
[Jan  8 19:05:02] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5512
[Jan  8 19:05:02] DEBUG[4259]: devicestate.c:287 do_state_change: Changing state for SIP/5512 - state 1 (Not in use)
[Jan  8 19:05:02] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5512
[Jan  8 19:05:02] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5512
    -- SIP/5512-08fd8f00 is ringing
[Jan  8 19:05:02] DEBUG[4325]: app_queue.c:589 handle_statechange: Device 'SIP/5512' changed to state '1' (Not in use) but we don't care because they're not a member of any queue
.
[Jan  8 19:05:08] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 69a718397444071f01870aff7b4c475e@192.168.1.1 Their Tag df3ab1ba821f69c9i0 Our tag: as578af8a4
[Jan  8 19:05:08] DEBUG[4306]: chan_sip.c:2152 __sip_ack: Acked pending invite 102
[Jan  8 19:05:08] DEBUG[4306]: chan_sip.c:2170 __sip_ack: Stopping retransmission on '69a718397444071f01870aff7b4c475e@192.168.1.1' of Request 102: Match Not Found
[Jan  8 19:05:08] DEBUG[4306]: chan_sip.c:11974 handle_response_invite: SIP response 200 to standard invite
[Jan  8 19:05:08] DEBUG[4306]: chan_sip.c:5388 process_sdp: T38 state changed to 0 on channel SIP/5512-08fd8f00
[Jan  8 19:05:08] DEBUG[4306]: chan_sip.c:5468 process_sdp: We're settling with these formats: 0x8 (alaw)
[Jan  8 19:05:08] DEBUG[4306]: chan_sip.c:5475 process_sdp: We have an owner, now see if we need to change this call
[Jan  8 19:05:08] DEBUG[4306]: chan_sip.c:3173 update_call_counter: Updating call counter for outgoing call
[Jan  8 19:05:08] DEBUG[4306]: chan_sip.c:8241 build_route: build_route: Contact hop: "5512" <sip:5512@192.168.1.189:5060>
[Jan  8 19:05:08] DEBUG[5325]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/5512-08fd8f00
    -- SIP/5512-08fd8f00 answered SIP/5511-08fd76a0
[Jan  8 19:05:08] DEBUG[5325]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/5511-08fd76a0
[Jan  8 19:05:08] DEBUG[5325]: chan_sip.c:3647 sip_answer: SIP answering channel: SIP/5511-08fd76a0
[Jan  8 19:05:08] DEBUG[5325]: chan_sip.c:6657 transmit_response_with_sdp: Setting framing from config on incoming call
[Jan  8 19:05:08] DEBUG[5325]: chan_sip.c:6421 add_sdp: ** Our capability: 0x8 (alaw) Video flag: True
[Jan  8 19:05:08] DEBUG[5325]: chan_sip.c:6422 add_sdp: ** Our prefcodec: 0x0 (nothing) 
[Jan  8 19:05:08] DEBUG[5325]: chan_sip.c:6553 add_sdp: -- Done with adding codecs to SDP
[Jan  8 19:05:08] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:08] DEBUG[5325]: chan_sip.c:6598 add_sdp: Done building SDP. Settling with this capability: 0x8 (alaw)
[Jan  8 19:05:08] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5512
[Jan  8 19:05:08] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5512
[Jan  8 19:05:08] DEBUG[4259]: devicestate.c:287 do_state_change: Changing state for SIP/5512 - state 1 (Not in use)
[Jan  8 19:05:08] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5512
[Jan  8 19:05:08] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5512
[Jan  8 19:05:08] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5511
[Jan  8 19:05:08] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5511
[Jan  8 19:05:08] DEBUG[4259]: devicestate.c:287 do_state_change: Changing state for SIP/5511 - state 1 (Not in use)
[Jan  8 19:05:08] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5511
[Jan  8 19:05:08] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5511
[Jan  8 19:05:08] DEBUG[4325]: app_queue.c:589 handle_statechange: Device 'SIP/5512' changed to state '1' (Not in use) but we don't care because they're not a member of any queue
.
[Jan  8 19:05:08] DEBUG[4325]: app_queue.c:589 handle_statechange: Device 'SIP/5511' changed to state '1' (Not in use) but we don't care because they're not a member of any queue
.
[Jan  8 19:05:08] DEBUG[5325]: rtp.c:2759 ast_rtp_write: Ooh, format changed from unknown to alaw
[Jan  8 19:05:08] DEBUG[5325]: rtp.c:2776 ast_rtp_write: Created smoother: format: 8 ms: 20 len: 160
[Jan  8 19:05:08] DEBUG[4306]: chan_sip.c:4562 find_call: = No match Their Call ID: 69a718397444071f01870aff7b4c475e@192.168.1.1 Their Tag df3ab1ba821f69c9i0 Our tag: as578af8a4
[Jan  8 19:05:08] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 36ce20-1301a8c0-13c4-43747-1b74564-43747@192.168.1.1 Their Tag 38d270-1301a8c0-13c4-43747-431e71f
d-43747 Our tag: as6453f4b9
[Jan  8 19:05:08] DEBUG[4306]: chan_sip.c:15154 handle_request: **** Received ACK (6) - Command in SIP ACK
[Jan  8 19:05:08] DEBUG[4306]: chan_sip.c:2170 __sip_ack: Stopping retransmission on '36ce20-1301a8c0-13c4-43747-1b74564-43747@192.168.1.1' of Response 2: Match Not Found
[Jan  8 19:05:08] DEBUG[5325]: rtp.c:2759 ast_rtp_write: Ooh, format changed from unknown to alaw
[Jan  8 19:05:08] DEBUG[5325]: rtp.c:2776 ast_rtp_write: Created smoother: format: 8 ms: 20 len: 160
[Jan  8 19:05:11] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 69a718397444071f01870aff7b4c475e@192.168.1.1 Their Tag df3ab1ba821f69c9i0 Our tag: as578af8a4
[Jan  8 19:05:11] DEBUG[4306]: chan_sip.c:15154 handle_request: **** Received INFO (13) - Command in SIP INFO
[Jan  8 19:05:11] DEBUG[5325]: channel.c:4134 ast_generic_bridge: Got DTMF begin on channel (SIP/5512-08fd8f00)
[Jan  8 19:05:11] DEBUG[5325]: channel.c:4413 ast_channel_bridge: Bridge stops bridging channels SIP/5511-08fd76a0 and SIP/5512-08fd8f00
[Jan  8 19:05:11] DEBUG[5325]: channel.c:4134 ast_generic_bridge: Got DTMF end on channel (SIP/5512-08fd8f00)
[Jan  8 19:05:11] DEBUG[5325]: channel.c:4413 ast_channel_bridge: Bridge stops bridging channels SIP/5511-08fd76a0 and SIP/5512-08fd8f00
[Jan  8 19:05:11] DEBUG[5325]: res_features.c:1072 ast_feature_interpret: Feature interpret: chan=SIP/5511-08fd76a0, peer=SIP/5512-08fd8f00, sense=2, features=18 dynamic=automon
[Jan  8 19:05:11] DEBUG[5325]: res_features.c:1566 ast_bridge_call: Set time limit to 500
[Jan  8 19:05:11] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 69a718397444071f01870aff7b4c475e@192.168.1.1 Their Tag df3ab1ba821f69c9i0 Our tag: as578af8a4
[Jan  8 19:05:11] DEBUG[4306]: chan_sip.c:15154 handle_request: **** Received INFO (13) - Command in SIP INFO
[Jan  8 19:05:11] DEBUG[5325]: channel.c:4134 ast_generic_bridge: Got DTMF begin on channel (SIP/5512-08fd8f00)
[Jan  8 19:05:11] DEBUG[5325]: channel.c:4413 ast_channel_bridge: Bridge stops bridging channels SIP/5511-08fd76a0 and SIP/5512-08fd8f00
[Jan  8 19:05:11] DEBUG[5325]: channel.c:4134 ast_generic_bridge: Got DTMF end on channel (SIP/5512-08fd8f00)
[Jan  8 19:05:11] DEBUG[5325]: channel.c:4413 ast_channel_bridge: Bridge stops bridging channels SIP/5511-08fd76a0 and SIP/5512-08fd8f00
[Jan  8 19:05:11] DEBUG[5325]: res_features.c:1072 ast_feature_interpret: Feature interpret: chan=SIP/5511-08fd76a0, peer=SIP/5512-08fd8f00, sense=2, features=18 dynamic=automon
[Jan  8 19:05:11] DEBUG[5325]: res_features.c:771 builtin_atxfer: Executing Attended Transfer SIP/5511-08fd76a0, SIP/5512-08fd8f00 (sense=2) 
    -- Started music on hold, class 'default', on SIP/5511-08fd76a0
[Jan  8 19:05:11] DEBUG[5325]: channel.c:2098 ast_settimeout: Scheduling timer at 160 sample intervals
[Jan  8 19:05:11] DEBUG[5325]: channel.c:3069 set_format: Set channel SIP/5512-08fd8f00 to write format gsm
[Jan  8 19:05:11] DEBUG[5325]: rtp.c:2629 ast_rtp_raw_write: Difference is 960, ms is 140
[Jan  8 19:05:11] DEBUG[5325]: channel.c:2098 ast_settimeout: Scheduling timer at 160 sample intervals
    -- <SIP/5512-08fd8f00> Playing 'pbx-transfer' (language 'en')
[Jan  8 19:05:12] DEBUG[5236]: channel.c:3069 set_format: Set channel SIP/5511-08fd76a0 to write format slin
[Jan  8 19:05:12] DEBUG[5236]: res_musiconhold.c:266 ast_moh_files_next: SIP/5511-08fd76a0 Opened file 1 '/var/lib/asterisk/moh/fpm-calm-river'
[Jan  8 19:05:12] DEBUG[5236]: rtp.c:2629 ast_rtp_raw_write: Difference is 3528, ms is 461
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2187 ast_read_generator_actions: Generator got voice, switching to phase locked mode
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2098 ast_settimeout: Scheduling timer at 0 sample intervals
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5325]: channel.c:2098 ast_settimeout: Scheduling timer at 0 sample intervals
[Jan  8 19:05:12] DEBUG[5325]: channel.c:2098 ast_settimeout: Scheduling timer at 0 sample intervals
[Jan  8 19:05:12] DEBUG[5325]: channel.c:3069 set_format: Set channel SIP/5512-08fd8f00 to write format alaw
[Jan  8 19:05:12] DEBUG[5325]: channel.c:3069 set_format: Set channel SIP/5512-08fd8f00 to write format slin
[Jan  8 19:05:12] DEBUG[5325]: channel.c:2098 ast_settimeout: Scheduling timer at 160 sample intervals
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:12] DEBUG[5325]: channel.c:2187 ast_read_generator_actions: Generator got voice, switching to phase locked mode
[Jan  8 19:05:12] DEBUG[5325]: channel.c:2098 ast_settimeout: Scheduling timer at 0 sample intervals
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:12] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:12] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:12] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:12] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:13] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:13] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:14] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:14] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:14] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:14] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 69a718397444071f01870aff7b4c475e@192.168.1.1 Their Tag df3ab1ba821f69c9i0 Our tag: as578af8a4
[Jan  8 19:05:14] DEBUG[4306]: chan_sip.c:15154 handle_request: **** Received INFO (13) - Command in SIP INFO
[Jan  8 19:05:14] DEBUG[5325]: channel.c:3069 set_format: Set channel SIP/5512-08fd8f00 to write format alaw
[Jan  8 19:05:14] DEBUG[5325]: channel.c:2098 ast_settimeout: Scheduling timer at 0 sample intervals
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 69a718397444071f01870aff7b4c475e@192.168.1.1 Their Tag df3ab1ba821f69c9i0 Our tag: as578af8a4
[Jan  8 19:05:14] DEBUG[4306]: chan_sip.c:15154 handle_request: **** Received INFO (13) - Command in SIP INFO
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 69a718397444071f01870aff7b4c475e@192.168.1.1 Their Tag df3ab1ba821f69c9i0 Our tag: as578af8a4
[Jan  8 19:05:14] DEBUG[4306]: chan_sip.c:15154 handle_request: **** Received INFO (13) - Command in SIP INFO
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:14] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 69a718397444071f01870aff7b4c475e@192.168.1.1 Their Tag df3ab1ba821f69c9i0 Our tag: as578af8a4
[Jan  8 19:05:15] DEBUG[4306]: chan_sip.c:15154 handle_request: **** Received INFO (13) - Command in SIP INFO
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 69a718397444071f01870aff7b4c475e@192.168.1.1 Their Tag df3ab1ba821f69c9i0 Our tag: as578af8a4
[Jan  8 19:05:15] DEBUG[4306]: chan_sip.c:15154 handle_request: **** Received INFO (13) - Command in SIP INFO
[Jan  8 19:05:15] DEBUG[5325]: channel.c:3579 ast_channel_inherit_variables: Not copying variable BRIDGEPEER.
[Jan  8 19:05:15] DEBUG[5325]: channel.c:3579 ast_channel_inherit_variables: Not copying variable DIALEDPEERNUMBER.
[Jan  8 19:05:15] DEBUG[5325]: channel.c:3579 ast_channel_inherit_variables: Not copying variable SIPCALLID.
[Jan  8 19:05:15] DEBUG[5325]: channel.c:2633 ast_indicate_data: Driver for channel 'SIP/5512-08fd8f00' does not support indication 3, emulating it
[Jan  8 19:05:15] DEBUG[5325]: channel.c:3069 set_format: Set channel SIP/5512-08fd8f00 to write format slin
[Jan  8 19:05:15] DEBUG[5325]: channel.c:2098 ast_settimeout: Scheduling timer at 160 sample intervals
[Jan  8 19:05:15] DEBUG[5329]: pbx.c:1831 pbx_extension_helper: Launching 'AGI'
    -- Executing [5514@internal:1] AGI("Local/5514@internal-6871,2", "selintra|OutCluster|5514") in new stack
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
    -- Launched AGI Script /var/lib/asterisk/agi-bin/selintra
    -- AGI Script selintra completed, returning 0
[Jan  8 19:05:15] DEBUG[5329]: pbx.c:1831 pbx_extension_helper: Launching 'AGI'
    -- Executing [5514@default:1] AGI("Local/5514@internal-6871,2", "selintra|InCall|") in new stack
    -- Launched AGI Script /var/lib/asterisk/agi-bin/selintra
[Jan  8 19:05:15] DEBUG[5329]: db.c:198 ast_db_get: Unable to find key 'OCSTAT' in family 'STAT'
[Jan  8 19:05:15] DEBUG[5325]: rtp.c:2629 ast_rtp_raw_write: Difference is 10688, ms is 1356
[Jan  8 19:05:15] DEBUG[5329]: db.c:198 ast_db_get: Unable to find key '5514' in family 'cfimopen'
[Jan  8 19:05:15] DEBUG[5329]: db.c:198 ast_db_get: Unable to find key '5514' in family 'cfim'
[Jan  8 19:05:15] DEBUG[5329]: db.c:198 ast_db_get: Unable to find key 'OCSTAT' in family 'STAT'
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5329]: db.c:198 ast_db_get: Unable to find key '5514' in family 'cfimopen'
[Jan  8 19:05:15] DEBUG[5329]: db.c:198 ast_db_get: Unable to find key 'OCSTAT' in family 'STAT'
[Jan  8 19:05:15] DEBUG[5329]: db.c:198 ast_db_get: Unable to find key '5514' in family 'cfim'
[Jan  8 19:05:15] DEBUG[5329]: db.c:198 ast_db_get: Unable to find key '5514' in family 'ringdelay'
    -- AGI Script Executing Application: (Dial) Options: (SIP/5514|99|tTwW)
[Jan  8 19:05:15] DEBUG[5329]: chan_sip.c:15857 sip_request_call: Asked to create a SIP channel with formats: 0x8 (alaw)
[Jan  8 19:05:15] DEBUG[5329]: chan_sip.c:4509 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP)
[Jan  8 19:05:15] DEBUG[5329]: chan_sip.c:2733 do_setnat: Setting NAT on RTP to Off
[Jan  8 19:05:15] DEBUG[5329]: chan_sip.c:3993 sip_new: *** Our native formats are 0x8 (alaw) 
[Jan  8 19:05:15] DEBUG[5329]: chan_sip.c:3994 sip_new: *** Joint capabilities are 0x0 (nothing) 
[Jan  8 19:05:15] DEBUG[5329]: chan_sip.c:3995 sip_new: *** Our capabilities are 0x8 (alaw) 
[Jan  8 19:05:15] DEBUG[5329]: chan_sip.c:3996 sip_new: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) 
[Jan  8 19:05:15] DEBUG[5329]: chan_sip.c:3998 sip_new: *** Our preferred formats from the incoming channel are 0x8 (alaw) 
[Jan  8 19:05:15] DEBUG[5329]: chan_sip.c:4019 sip_new: This channel will not be able to handle video.
[Jan  8 19:05:15] DEBUG[5329]: rtp.c:1586 ast_rtp_make_compatible: Channel 'Local/5514@internal-6871,2' has no RTP, not doing anything
[Jan  8 19:05:15] DEBUG[5329]: channel.c:3579 ast_channel_inherit_variables: Not copying variable AGISTATUS.
[Jan  8 19:05:15] DEBUG[5329]: channel.c:3579 ast_channel_inherit_variables: Not copying variable TRANSFERERNAME.
[Jan  8 19:05:15] DEBUG[5329]: chan_sip.c:2991 sip_call: Outgoing Call for 5514
[Jan  8 19:05:15] DEBUG[5329]: chan_sip.c:3173 update_call_counter: Updating call counter for outgoing call
[Jan  8 19:05:15] DEBUG[5329]: chan_sip.c:3006 sip_call: Our T38 capability (0), joint T38 capability (0)
[Jan  8 19:05:15] DEBUG[5329]: chan_sip.c:6421 add_sdp: ** Our capability: 0x8 (alaw) Video flag: False
[Jan  8 19:05:15] DEBUG[5329]: chan_sip.c:6422 add_sdp: ** Our prefcodec: 0x8 (alaw) 
[Jan  8 19:05:15] DEBUG[5329]: chan_sip.c:6553 add_sdp: -- Done with adding codecs to SDP
[Jan  8 19:05:15] DEBUG[5329]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=43)
[Jan  8 19:05:15] DEBUG[5329]: chan_sip.c:6598 add_sdp: Done building SDP. Settling with this capability: 0x8 (alaw)
    -- Called 5514
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 23d88dec251ab33d559754745a9047dc@192.168.1.1 Their Tag  Our tag: as104386e7
[Jan  8 19:05:15] DEBUG[4306]: chan_sip.c:2212 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '23d88dec251ab33d559754745a9047dc@192.168.1.1' Requ
est 102: Found
[Jan  8 19:05:15] DEBUG[4306]: chan_sip.c:11974 handle_response_invite: SIP response 100 to standard invite
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 23d88dec251ab33d559754745a9047dc@192.168.1.1 Their Tag  Our tag: as104386e7
[Jan  8 19:05:15] DEBUG[4306]: chan_sip.c:2212 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '23d88dec251ab33d559754745a9047dc@192.168.1.1' Requ
est 102: Found
[Jan  8 19:05:15] DEBUG[4306]: chan_sip.c:11974 handle_response_invite: SIP response 180 to standard invite
[Jan  8 19:05:15] DEBUG[4306]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/5514-08ff3070
    -- SIP/5514-08ff3070 is ringing
[Jan  8 19:05:15] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5514
[Jan  8 19:05:15] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5514
[Jan  8 19:05:15] DEBUG[4259]: devicestate.c:287 do_state_change: Changing state for SIP/5514 - state 1 (Not in use)
[Jan  8 19:05:15] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5514
[Jan  8 19:05:15] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5514
[Jan  8 19:05:15] DEBUG[5329]: rtp.c:1496 ast_rtp_early_bridge: Channel 'Local/5514@internal-6871,2' has no RTP, not doing anything
[Jan  8 19:05:15] DEBUG[4325]: app_queue.c:589 handle_statechange: Device 'SIP/5514' changed to state '1' (Not in use) but we don't care because they're not a member of any queue
.
    -- Local/5514@internal-6871,1 is ringing
[Jan  8 19:05:15] DEBUG[5325]: channel.c:2633 ast_indicate_data: Driver for channel 'SIP/5512-08fd8f00' does not support indication 3, emulating it
[Jan  8 19:05:15] DEBUG[5325]: channel.c:3069 set_format: Set channel SIP/5512-08fd8f00 to write format alaw
[Jan  8 19:05:15] DEBUG[5325]: channel.c:3069 set_format: Set channel SIP/5512-08fd8f00 to write format slin
[Jan  8 19:05:15] DEBUG[5325]: channel.c:2098 ast_settimeout: Scheduling timer at 160 sample intervals
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:15] DEBUG[5325]: channel.c:2187 ast_read_generator_actions: Generator got voice, switching to phase locked mode
[Jan  8 19:05:15] DEBUG[5325]: channel.c:2098 ast_settimeout: Scheduling timer at 0 sample intervals
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:15] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:15] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:15] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:15] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:15] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:16] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:17] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:17] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:18] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:19] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:19] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:20] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:20] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[5236]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=35)
[Jan  8 19:05:21] DEBUG[4306]: chan_sip.c:4562 find_call: = No match Their Call ID: 23d88dec251ab33d559754745a9047dc@192.168.1.1 Their Tag 8a54d61cc6b11028i0 Our tag: as104386e7
[Jan  8 19:05:21] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 69a718397444071f01870aff7b4c475e@192.168.1.1 Their Tag df3ab1ba821f69c9i0 Our tag: as578af8a4
[Jan  8 19:05:21] DEBUG[4306]: chan_sip.c:15154 handle_request: **** Received BYE (8) - Command in SIP BYE
[Jan  8 19:05:21] DEBUG[4306]: chan_sip.c:1652 sip_alreadygone: Setting SIP_ALREADYGONE on dialog 69a718397444071f01870aff7b4c475e@192.168.1.1
[Jan  8 19:05:21] DEBUG[4306]: chan_sip.c:14706 handle_request_bye: Received bye, issuing owner hangup
[Jan  8 19:05:21] DEBUG[5325]: channel.c:3069 set_format: Set channel SIP/5512-08fd8f00 to write format alaw
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2098 ast_settimeout: Scheduling timer at 0 sample intervals
[Jan  8 19:05:21] DEBUG[5325]: channel.c:3069 set_format: Set channel SIP/5511-08fd76a0 to write format alaw
    -- Stopped music on hold on SIP/5511-08fd76a0
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2098 ast_settimeout: Scheduling timer at 0 sample intervals
[Jan  8 19:05:21] DEBUG[5325]: channel.c:3512 ast_channel_masquerade: Planning to masquerade channel SIP/5511-08fd76a0 into the structure of Transfered/SIP/5511-08fd76a0
[Jan  8 19:05:21] DEBUG[5325]: channel.c:3526 ast_channel_masquerade: Done planning to masquerade channel SIP/5511-08fd76a0 into the structure of Transfered/SIP/5511-08fd76a0
[Jan  8 19:05:21] DEBUG[5325]: channel.c:3637 ast_do_masquerade: Actually Masquerading SIP/5511-08fd76a0(6) into the structure of Transfered/SIP/5511-08fd76a0(6)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:3649 ast_do_masquerade: Got clone lock for masquerade on 'SIP/5511-08fd76a0' at 0x8fdd658
[Jan  8 19:05:21] DEBUG[5325]: channel.c:3852 ast_do_masquerade: Putting channel SIP/5511-08fd76a0 in 8/8 formats
[Jan  8 19:05:21] DEBUG[5325]: chan_sip.c:3772 sip_fixup: SIP Fixup: New owner for dialogue 36ce20-1301a8c0-13c4-43747-1b74564-43747@192.168.1.1: SIP/5511-08fd76a0 (Old parent: T
ransfered/SIP/5511-08fd76a0<ZOMBIE>)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:3892 ast_do_masquerade: Released clone lock on 'Transfered/SIP/5511-08fd76a0<ZOMBIE>'
[Jan  8 19:05:21] DEBUG[5325]: channel.c:3902 ast_do_masquerade: Done Masquerading SIP/5511-08fd76a0 (6)
[Jan  8 19:05:21] DEBUG[5325]: channel.c:3069 set_format: Set channel Local/5514@internal-6871,1 to write format gsm
[Jan  8 19:05:21] DEBUG[5325]: channel.c:2098 ast_settimeout: Scheduling timer at 160 sample intervals
    -- <Local/5514@internal-6871,1> Playing 'beep' (language 'en')
[Jan  8 19:05:22] DEBUG[5325]: channel.c:2098 ast_settimeout: Scheduling timer at 0 sample intervals
[Jan  8 19:05:22] DEBUG[5325]: channel.c:2098 ast_settimeout: Scheduling timer at 0 sample intervals
[Jan  8 19:05:22] DEBUG[5325]: channel.c:3069 set_format: Set channel Local/5514@internal-6871,1 to write format alaw
[Jan  8 19:05:22] DEBUG[5325]: channel.c:1789 ast_hangup: Hanging up channel 'SIP/5512-08fd8f00'
[Jan  8 19:05:22] DEBUG[5325]: chan_sip.c:3485 sip_hangup: Hangup call SIP/5512-08fd8f00, SIP callid 69a718397444071f01870aff7b4c475e@192.168.1.1)
[Jan  8 19:05:22] DEBUG[5325]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/5512-08fd8f00
[Jan  8 19:05:22] DEBUG[5325]: rtp.c:1496 ast_rtp_early_bridge: Channel 'Transfered/SIP/5511-08fd76a0<ZOMBIE>' has no RTP, not doing anything
[Jan  8 19:05:22] DEBUG[5325]: app_dial.c:1736 dial_exec_full: Exiting with DIALSTATUS=ANSWER.
[Jan  8 19:05:22] DEBUG[5325]: res_agi.c:1860 run_agi: Transfered/SIP/5511-08fd76a0<ZOMBIE> hungup
[Jan  8 19:05:22] DEBUG[5325]: pbx.c:2427 __ast_pbx_run: Spawn extension (default,5512,1) exited non-zero on 'Transfered/SIP/5511-08fd76a0<ZOMBIE>'
  == Spawn extension (default, 5512, 1) exited non-zero on 'Transfered/SIP/5511-08fd76a0<ZOMBIE>'
[Jan  8 19:05:22] DEBUG[5325]: channel.c:1570 ast_softhangup_nolock: Soft-Hanging up channel 'Transfered/SIP/5511-08fd76a0<ZOMBIE>'
[Jan  8 19:05:22] DEBUG[5325]: pbx.c:1831 pbx_extension_helper: Launching 'Hangup'
    -- Executing [h@default:1] Hangup("Transfered/SIP/5511-08fd76a0<ZOMBIE>", "") in new stack
[Jan  8 19:05:22] DEBUG[5325]: pbx.c:2550 __ast_pbx_run: Spawn extension (default,h,1) exited non-zero on 'Transfered/SIP/5511-08fd76a0<ZOMBIE>'
  == Spawn extension (default, h, 1) exited non-zero on 'Transfered/SIP/5511-08fd76a0<ZOMBIE>'
[Jan  8 19:05:22] DEBUG[5325]: channel.c:1794 ast_hangup: Hanging up zombie 'Transfered/SIP/5511-08fd76a0<ZOMBIE>'
[Jan  8 19:05:22] DEBUG[5325]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Transfered/SIP/5511-08fd76a0<ZOMB
IE>
[Jan  8 19:05:22] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5512
[Jan  8 19:05:22] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5512
[Jan  8 19:05:22] DEBUG[4259]: devicestate.c:287 do_state_change: Changing state for SIP/5512 - state 1 (Not in use)
[Jan  8 19:05:22] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5512
[Jan  8 19:05:22] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5512
[Jan  8 19:05:22] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Transfered - SIP/5511
[Jan  8 19:05:22] DEBUG[4259]: devicestate.c:287 do_state_change: Changing state for Transfered/SIP/5511 - state 4 (Invalid)
[Jan  8 19:05:22] DEBUG[5325]: cdr_addon_mysql.c:226 mysql_log: cdr_mysql: inserting a CDR record.
[Jan  8 19:05:22] DEBUG[5325]: cdr_addon_mysql.c:243 mysql_log: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,last
data,duration,billsec,disposition,amaflags,accountcode) VALUES ('2008-01-08 19:05:02','','','5512','default', 'Transfered/SIP/5511-08fd76a0<ZOMBIE>','SIP/5512-08fd8f00','','',20,
14,'ANSWERED',3,'')
[Jan  8 19:05:22] DEBUG[4325]: app_queue.c:589 handle_statechange: Device 'SIP/5512' changed to state '1' (Not in use) but we don't care because they're not a member of any queue
.
[Jan  8 19:05:22] DEBUG[4325]: app_queue.c:589 handle_statechange: Device 'Transfered/SIP/5511' changed to state '4' (Invalid) but we don't care because they're not a member of a
ny queue.
Really destroying SIP dialog '69a718397444071f01870aff7b4c475e@192.168.1.1' Method: BYE
[Jan  8 19:05:31] DEBUG[4318]: chan_iax2.c:7722 socket_process: Peer OnNet1: got pong, lastms 2, historicms 2, maxms 3000
[Jan  8 19:05:31] DEBUG[4306]: chan_sip.c:4509 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Jan  8 19:05:31] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 636a1a322ae405c63150e5d21aa75129@192.168.1.1 Their Tag  Our tag: as10d2af48
[Jan  8 19:05:31] DEBUG[4306]: chan_sip.c:2170 __sip_ack: Stopping retransmission on '636a1a322ae405c63150e5d21aa75129@192.168.1.1' of Request 102: Match Not Found
Really destroying SIP dialog '636a1a322ae405c63150e5d21aa75129@192.168.1.1' Method: OPTIONS
[Jan  8 19:05:31] DEBUG[4306]: chan_sip.c:4509 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Jan  8 19:05:31] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 4a37fcb6659590264ecc4e0152329379@192.168.1.1 Their Tag  Our tag: as69d847ac
[Jan  8 19:05:31] DEBUG[4306]: chan_sip.c:2170 __sip_ack: Stopping retransmission on '4a37fcb6659590264ecc4e0152329379@192.168.1.1' of Request 102: Match Not Found
Really destroying SIP dialog '4a37fcb6659590264ecc4e0152329379@192.168.1.1' Method: OPTIONS
[Jan  8 19:05:31] DEBUG[4306]: chan_sip.c:4509 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Jan  8 19:05:32] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 4c4599f023d0929424ee6fc34ee7ae72@192.168.1.1 Their Tag  Our tag: as38e13f1a
[Jan  8 19:05:32] DEBUG[4306]: chan_sip.c:2170 __sip_ack: Stopping retransmission on '4c4599f023d0929424ee6fc34ee7ae72@192.168.1.1' of Request 102: Match Not Found
Really destroying SIP dialog '4c4599f023d0929424ee6fc34ee7ae72@192.168.1.1' Method: OPTIONS
[Jan  8 19:05:32] DEBUG[4306]: chan_sip.c:4509 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Jan  8 19:05:32] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 4141db023c8e2260333a821e2e42c8c0@192.168.1.1 Their Tag  Our tag: as230c2ad6
[Jan  8 19:05:32] DEBUG[4306]: chan_sip.c:2170 __sip_ack: Stopping retransmission on '4141db023c8e2260333a821e2e42c8c0@192.168.1.1' of Request 102: Match Not Found
Really destroying SIP dialog '4141db023c8e2260333a821e2e42c8c0@192.168.1.1' Method: OPTIONS
[Jan  8 19:05:32] DEBUG[4306]: chan_sip.c:4509 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Jan  8 19:05:32] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 285bee9a1bb2c0273de46efe1aefad5b@192.168.1.1 Their Tag  Our tag: as13c5f39c
[Jan  8 19:05:32] DEBUG[4306]: chan_sip.c:2170 __sip_ack: Stopping retransmission on '285bee9a1bb2c0273de46efe1aefad5b@192.168.1.1' of Request 102: Match Not Found
Really destroying SIP dialog '285bee9a1bb2c0273de46efe1aefad5b@192.168.1.1' Method: OPTIONS
[Jan  8 19:05:35] DEBUG[4306]: chan_sip.c:4509 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Jan  8 19:05:35] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 36cc67852b5012655b9d968e6c7045d6@192.168.1.1 Their Tag  Our tag: as140fc296
[Jan  8 19:05:35] DEBUG[4306]: chan_sip.c:2170 __sip_ack: Stopping retransmission on '36cc67852b5012655b9d968e6c7045d6@192.168.1.1' of Request 102: Match Not Found
Really destroying SIP dialog '36cc67852b5012655b9d968e6c7045d6@192.168.1.1' Method: OPTIONS
[Jan  8 19:05:38] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 23d88dec251ab33d559754745a9047dc@192.168.1.1 Their Tag 8a54d61cc6b11028i0 Our tag: as104386e7
[Jan  8 19:05:38] DEBUG[4306]: chan_sip.c:2152 __sip_ack: Acked pending invite 102
[Jan  8 19:05:38] DEBUG[4306]: chan_sip.c:2170 __sip_ack: Stopping retransmission on '23d88dec251ab33d559754745a9047dc@192.168.1.1' of Request 102: Match Not Found
[Jan  8 19:05:38] DEBUG[4306]: chan_sip.c:11974 handle_response_invite: SIP response 200 to standard invite
[Jan  8 19:05:38] DEBUG[4306]: chan_sip.c:5388 process_sdp: T38 state changed to 0 on channel SIP/5514-08ff3070
[Jan  8 19:05:38] DEBUG[4306]: chan_sip.c:5468 process_sdp: We're settling with these formats: 0x8 (alaw)
[Jan  8 19:05:38] DEBUG[4306]: chan_sip.c:5475 process_sdp: We have an owner, now see if we need to change this call
[Jan  8 19:05:38] DEBUG[4306]: chan_sip.c:3173 update_call_counter: Updating call counter for outgoing call
[Jan  8 19:05:38] DEBUG[4306]: chan_sip.c:8241 build_route: build_route: Contact hop: 5514 <sip:5514@192.168.1.185:5060>
[Jan  8 19:05:38] DEBUG[5329]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/5514-08ff3070
    -- SIP/5514-08ff3070 answered Local/5514@internal-6871,2
[Jan  8 19:05:38] DEBUG[5329]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/5514@internal-6871,2
[Jan  8 19:05:38] DEBUG[5332]: channel.c:4111 ast_generic_bridge: Got a FRAME_CONTROL (-1) frame on channel Local/5514@internal-6871,1
[Jan  8 19:05:38] DEBUG[5332]: channel.c:4413 ast_channel_bridge: Bridge stops bridging channels Local/5514@internal-6871,1 and SIP/5511-08fd76a0
[Jan  8 19:05:38] DEBUG[5332]: channel.c:2357 __ast_read: Ignoring answer on an inbound call!
[Jan  8 19:05:38] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5514
[Jan  8 19:05:38] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5514
[Jan  8 19:05:38] DEBUG[4259]: devicestate.c:287 do_state_change: Changing state for SIP/5514 - state 1 (Not in use)
[Jan  8 19:05:38] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5514
[Jan  8 19:05:38] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5514
[Jan  8 19:05:38] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 5514@internal
[Jan  8 19:05:38] DEBUG[4259]: chan_local.c:145 local_devicestate: Checking if extension 5514@internal exists (devicestate)
[Jan  8 19:05:38] DEBUG[4259]: devicestate.c:287 do_state_change: Changing state for Local/5514@internal - state 2 (In use)
[Jan  8 19:05:38] DEBUG[4325]: app_queue.c:589 handle_statechange: Device 'SIP/5514' changed to state '1' (Not in use) but we don't care because they're not a member of any queue
.
[Jan  8 19:05:38] DEBUG[4325]: app_queue.c:589 handle_statechange: Device 'Local/5514@internal' changed to state '2' (In use) but we don't care because they're not a member of an
y queue.
[Jan  8 19:05:38] DEBUG[5329]: rtp.c:2759 ast_rtp_write: Ooh, format changed from unknown to alaw
[Jan  8 19:05:38] DEBUG[5329]: rtp.c:2776 ast_rtp_write: Created smoother: format: 8 ms: 20 len: 160
[Jan  8 19:05:44] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 23d88dec251ab33d559754745a9047dc@192.168.1.1 Their Tag 8a54d61cc6b11028i0 Our tag: as104386e7
[Jan  8 19:05:44] DEBUG[4306]: chan_sip.c:15154 handle_request: **** Received BYE (8) - Command in SIP BYE
[Jan  8 19:05:44] DEBUG[4306]: chan_sip.c:1652 sip_alreadygone: Setting SIP_ALREADYGONE on dialog 23d88dec251ab33d559754745a9047dc@192.168.1.1
[Jan  8 19:05:44] DEBUG[4306]: chan_sip.c:14706 handle_request_bye: Received bye, issuing owner hangup
[Jan  8 19:05:44] DEBUG[5329]: channel.c:4088 ast_generic_bridge: Didn't get a frame from channel: SIP/5514-08ff3070
[Jan  8 19:05:44] DEBUG[5329]: channel.c:4413 ast_channel_bridge: Bridge stops bridging channels Local/5514@internal-6871,2 and SIP/5514-08ff3070
[Jan  8 19:05:44] DEBUG[5329]: channel.c:1789 ast_hangup: Hanging up channel 'SIP/5514-08ff3070'
[Jan  8 19:05:44] DEBUG[5329]: chan_sip.c:3485 sip_hangup: Hangup call SIP/5514-08ff3070, SIP callid 23d88dec251ab33d559754745a9047dc@192.168.1.1)
[Jan  8 19:05:44] DEBUG[5329]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/5514-08ff3070
[Jan  8 19:05:44] DEBUG[5329]: rtp.c:1496 ast_rtp_early_bridge: Channel 'Local/5514@internal-6871,2' has no RTP, not doing anything
[Jan  8 19:05:44] DEBUG[5329]: app_dial.c:1736 dial_exec_full: Exiting with DIALSTATUS=ANSWER.
[Jan  8 19:05:44] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5514
[Jan  8 19:05:44] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5514
[Jan  8 19:05:44] DEBUG[4259]: devicestate.c:287 do_state_change: Changing state for SIP/5514 - state 1 (Not in use)
[Jan  8 19:05:44] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5514
[Jan  8 19:05:44] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5514
[Jan  8 19:05:44] DEBUG[4325]: app_queue.c:589 handle_statechange: Device 'SIP/5514' changed to state '1' (Not in use) but we don't care because they're not a member of any queue
.
    -- AGI Script selintra completed, returning 0
  == Auto fallthrough, channel 'Local/5514@internal-6871,2' status is 'ANSWER'
[Jan  8 19:05:44] DEBUG[5329]: channel.c:1570 ast_softhangup_nolock: Soft-Hanging up channel 'Local/5514@internal-6871,2'
[Jan  8 19:05:44] DEBUG[5329]: pbx.c:1831 pbx_extension_helper: Launching 'Hangup'
    -- Executing [h@default:1] Hangup("Local/5514@internal-6871,2", "") in new stack
[Jan  8 19:05:44] DEBUG[5329]: pbx.c:2550 __ast_pbx_run: Spawn extension (default,h,1) exited non-zero on 'Local/5514@internal-6871,2'
  == Spawn extension (default, h, 1) exited non-zero on 'Local/5514@internal-6871,2'
[Jan  8 19:05:44] DEBUG[5329]: channel.c:1789 ast_hangup: Hanging up channel 'Local/5514@internal-6871,2'
[Jan  8 19:05:44] DEBUG[5329]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/5514@internal-6871,2
[Jan  8 19:05:44] DEBUG[5332]: channel.c:4088 ast_generic_bridge: Didn't get a frame from channel: Local/5514@internal-6871,1
[Jan  8 19:05:44] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 5514@internal
[Jan  8 19:05:44] DEBUG[4259]: chan_local.c:145 local_devicestate: Checking if extension 5514@internal exists (devicestate)
[Jan  8 19:05:44] DEBUG[4259]: devicestate.c:287 do_state_change: Changing state for Local/5514@internal - state 2 (In use)
[Jan  8 19:05:44] DEBUG[5332]: channel.c:4413 ast_channel_bridge: Bridge stops bridging channels Local/5514@internal-6871,1 and SIP/5511-08fd76a0
[Jan  8 19:05:44] DEBUG[5332]: channel.c:1789 ast_hangup: Hanging up channel 'SIP/5511-08fd76a0'
[Jan  8 19:05:44] DEBUG[5332]: chan_sip.c:3485 sip_hangup: Hangup call SIP/5511-08fd76a0, SIP callid 36ce20-1301a8c0-13c4-43747-1b74564-43747@192.168.1.1)
[Jan  8 19:05:44] DEBUG[5332]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/5511-08fd76a0
[Jan  8 19:05:44] DEBUG[5332]: channel.c:1789 ast_hangup: Hanging up channel 'Local/5514@internal-6871,1'
[Jan  8 19:05:44] DEBUG[5332]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/5514@internal-6871,1
[Jan  8 19:05:44] DEBUG[4325]: app_queue.c:589 handle_statechange: Device 'Local/5514@internal' changed to state '2' (In use) but we don't care because they're not a member of an
y queue.
[Jan  8 19:05:44] DEBUG[5329]: cdr_addon_mysql.c:226 mysql_log: cdr_mysql: inserting a CDR record.
[Jan  8 19:05:44] DEBUG[5329]: cdr_addon_mysql.c:243 mysql_log: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,last
data,duration,billsec,disposition,amaflags,accountcode) VALUES ('2008-01-08 19:05:15','5512','5512','5514','default', 'Local/5514@internal-6871,2','SIP/5514-08ff3070','Dial','SIP
/5514|99|tTwW',29,6,'ANSWERED',3,'')
[Jan  8 19:05:44] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5511
[Jan  8 19:05:44] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5511
[Jan  8 19:05:44] DEBUG[4259]: devicestate.c:287 do_state_change: Changing state for SIP/5511 - state 1 (Not in use)
[Jan  8 19:05:44] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5511
[Jan  8 19:05:44] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5511
[Jan  8 19:05:44] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 5514@internal
[Jan  8 19:05:44] DEBUG[4259]: chan_local.c:145 local_devicestate: Checking if extension 5514@internal exists (devicestate)
[Jan  8 19:05:44] DEBUG[4259]: devicestate.c:287 do_state_change: Changing state for Local/5514@internal - state 1 (Not in use)
[Jan  8 19:05:44] DEBUG[4325]: app_queue.c:589 handle_statechange: Device 'SIP/5511' changed to state '1' (Not in use) but we don't care because they're not a member of any queue
.
[Jan  8 19:05:44] DEBUG[4325]: app_queue.c:589 handle_statechange: Device 'Local/5514@internal' changed to state '1' (Not in use) but we don't care because they're not a member o
f any queue.
[Jan  8 19:05:44] DEBUG[5332]: cdr_addon_mysql.c:226 mysql_log: cdr_mysql: inserting a CDR record.
[Jan  8 19:05:44] DEBUG[5332]: cdr_addon_mysql.c:243 mysql_log: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,last
data,duration,billsec,disposition,amaflags,accountcode) VALUES ('2008-01-08 19:05:22','5512','5512','5514','internal', 'Local/5514@internal-6871,1','SIP/5511-08fd76a0','Dial','Lo
cal/5514@internal/n',22,22,'ANSWERED',3,'')
Really destroying SIP dialog '23d88dec251ab33d559754745a9047dc@192.168.1.1' Method: BYE
[Jan  8 19:05:45] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 36ce20-1301a8c0-13c4-43747-1b74564-43747@192.168.1.1 Their Tag 38d270-1301a8c0-13c4-43747-431e71f
d-43747 Our tag: as6453f4b9
[Jan  8 19:05:45] DEBUG[4306]: chan_sip.c:2170 __sip_ack: Stopping retransmission on '36ce20-1301a8c0-13c4-43747-1b74564-43747@192.168.1.1' of Request 102: Match Not Found
Really destroying SIP dialog '36ce20-1301a8c0-13c4-43747-1b74564-43747@192.168.1.1' Method: ACK
[Jan  8 19:05:46] DEBUG[4306]: chan_sip.c:4509 sip_alloc: Allocating new SIP dialog for e9c40a46-496c3ee5@192.168.1.189 - REGISTER (No RTP)
[Jan  8 19:05:46] DEBUG[4306]: chan_sip.c:15154 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER
[Jan  8 19:05:46] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: e9c40a46-496c3ee5@192.168.1.189 Their Tag 5632003937f5d29o0 Our tag: as21de2a27
[Jan  8 19:05:46] DEBUG[4306]: chan_sip.c:15154 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER
[Jan  8 19:05:46] DEBUG[4306]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/5512
[Jan  8 19:05:46] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5512
[Jan  8 19:05:46] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5512
[Jan  8 19:05:46] DEBUG[4259]: devicestate.c:287 do_state_change: Changing state for SIP/5512 - state 1 (Not in use)
[Jan  8 19:05:46] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5512
[Jan  8 19:05:46] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5512
[Jan  8 19:05:46] DEBUG[4325]: app_queue.c:589 handle_statechange: Device 'SIP/5512' changed to state '1' (Not in use) but we don't care because they're not a member of any queue
.
[Jan  8 19:05:46] DEBUG[4306]: chan_sip.c:4562 find_call: = No match Their Call ID: e9c40a46-496c3ee5@192.168.1.189 Their Tag 5632003937f5d29o0 Our tag: as21de2a27
[Jan  8 19:05:46] DEBUG[4306]: chan_sip.c:4509 sip_alloc: Allocating new SIP dialog for 57cbb123-cabafc48@192.168.1.185 - REGISTER (No RTP)
[Jan  8 19:05:46] DEBUG[4306]: chan_sip.c:15154 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER
[Jan  8 19:05:46] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 57cbb123-cabafc48@192.168.1.185 Their Tag 27e2c30992d1a607o1 Our tag: as563cf6f4
[Jan  8 19:05:46] DEBUG[4306]: chan_sip.c:15154 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER
[Jan  8 19:05:46] DEBUG[4306]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/5515
[Jan  8 19:05:46] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5515
[Jan  8 19:05:46] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5515
[Jan  8 19:05:46] DEBUG[4259]: devicestate.c:287 do_state_change: Changing state for SIP/5515 - state 1 (Not in use)
[Jan  8 19:05:46] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5515
[Jan  8 19:05:46] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5515
[Jan  8 19:05:46] DEBUG[4325]: app_queue.c:589 handle_statechange: Device 'SIP/5515' changed to state '1' (Not in use) but we don't care because they're not a member of any queue
.
[Jan  8 19:05:47] DEBUG[4306]: chan_sip.c:4562 find_call: = No match Their Call ID: 57cbb123-cabafc48@192.168.1.185 Their Tag 27e2c30992d1a607o1 Our tag: as563cf6f4
[Jan  8 19:05:47] DEBUG[4306]: chan_sip.c:4562 find_call: = No match Their Call ID: e9c40a46-496c3ee5@192.168.1.189 Their Tag 5632003937f5d29o0 Our tag: as21de2a27
[Jan  8 19:05:47] DEBUG[4306]: chan_sip.c:4509 sip_alloc: Allocating new SIP dialog for 30693a11-9502585c@192.168.1.186 - REGISTER (No RTP)
[Jan  8 19:05:47] DEBUG[4306]: chan_sip.c:15154 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER
[Jan  8 19:05:47] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 30693a11-9502585c@192.168.1.186 Their Tag a25be95c5bdcf999o1 Our tag: as182a2e07
[Jan  8 19:05:47] DEBUG[4306]: chan_sip.c:15154 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER
[Jan  8 19:05:47] DEBUG[4306]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/5513
[Jan  8 19:05:47] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5513
[Jan  8 19:05:47] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5513
[Jan  8 19:05:47] DEBUG[4259]: devicestate.c:287 do_state_change: Changing state for SIP/5513 - state 1 (Not in use)
[Jan  8 19:05:47] DEBUG[4259]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 5513
[Jan  8 19:05:47] DEBUG[4259]: chan_sip.c:15788 sip_devicestate: Checking device state for peer 5513
[Jan  8 19:05:47] DEBUG[4325]: app_queue.c:589 handle_statechange: Device 'SIP/5513' changed to state '1' (Not in use) but we don't care because they're not a member of any queue
.
[Jan  8 19:05:52] DEBUG[4306]: chan_sip.c:4509 sip_alloc: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Jan  8 19:05:52] DEBUG[4306]: chan_sip.c:4509 sip_alloc: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Jan  8 19:05:52] DEBUG[4306]: chan_sip.c:4509 sip_alloc: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Jan  8 19:05:52] DEBUG[4306]: chan_sip.c:4562 find_call: = No match Their Call ID: 66b6e8a17a7cdc3e1de04e731314bee2@192.168.1.1 Their Tag  Our tag: as1a14a5f7
[Jan  8 19:05:52] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 3c1854786bd181634da1320e1917faf2@192.168.1.1 Their Tag  Our tag: as696549fe
[Jan  8 19:05:52] DEBUG[4306]: chan_sip.c:2170 __sip_ack: Stopping retransmission on '3c1854786bd181634da1320e1917faf2@192.168.1.1' of Request 102: Match Not Found
[Jan  8 19:05:52] DEBUG[4306]: chan_sip.c:4562 find_call: = No match Their Call ID: 66b6e8a17a7cdc3e1de04e731314bee2@192.168.1.1 Their Tag  Our tag: as1a14a5f7
[Jan  8 19:05:52] DEBUG[4306]: chan_sip.c:4562 find_call: = No match Their Call ID: 3c1854786bd181634da1320e1917faf2@192.168.1.1 Their Tag 8fd23ad86f10764di1 Our tag: as696549fe
[Jan  8 19:05:52] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 746fa80750f1476b72f63816794f1d7a@192.168.1.1 Their Tag  Our tag: as16c408e6
[Jan  8 19:05:52] DEBUG[4306]: chan_sip.c:2170 __sip_ack: Stopping retransmission on '746fa80750f1476b72f63816794f1d7a@192.168.1.1' of Request 102: Match Not Found
Really destroying SIP dialog '3c1854786bd181634da1320e1917faf2@192.168.1.1' Method: NOTIFY
Really destroying SIP dialog '746fa80750f1476b72f63816794f1d7a@192.168.1.1' Method: NOTIFY
[Jan  8 19:05:52] DEBUG[4306]: chan_sip.c:4562 find_call: = Found Their Call ID: 66b6e8a17a7cdc3e1de04e731314bee2@192.168.1.1 Their Tag  Our tag: as1a14a5f7
[Jan  8 19:05:52] DEBUG[4306]: chan_sip.c:2170 __sip_ack: Stopping retransmission on '66b6e8a17a7cdc3e1de04e731314bee2@192.168.1.1' of Request 102: Match Not Found
Really destroying SIP dialog '66b6e8a17a7cdc3e1de04e731314bee2@192.168.1.1' Method: NOTIFY
office*CLI> 
<<< Log from 192.168.1.1 ended january 08, 2008, 19:06:03 >>>