[2011-01-20 11:21:35] DEBUG[2089]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.107 with 192.168.0.0
[2011-01-20 11:21:35] DEBUG[2089]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.107 with 10.0.0.0
[2011-01-20 11:21:35] DEBUG[2089]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.107 with 172.16.0.0
[2011-01-20 11:21:35] DEBUG[2089]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.107 with 169.254.0.0
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:3030 do_setnat: Setting NAT on RTP to Off
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:3035 do_setnat: Setting NAT on VRTP to Off
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:3040 do_setnat: Setting NAT on UDPTL to Off
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:4947 sip_alloc: Allocating new SIP dialog for 5145e211-b1fd99f8-f1f5c703@192.168.30.107 - INVITE (With RTP)
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:3030 do_setnat: Setting NAT on RTP to Off
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:3035 do_setnat: Setting NAT on VRTP to Off
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:3040 do_setnat: Setting NAT on UDPTL to Off
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:2325 __sip_ack: Stopping retransmission on '5145e211-b1fd99f8-f1f5c703@192.168.30.107' of Response 1: Match Found
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:3030 do_setnat: Setting NAT on RTP to Off
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:3035 do_setnat: Setting NAT on VRTP to Off
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:3040 do_setnat: Setting NAT on UDPTL to Off
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:5585 process_sdp: Processing session-level SDP v=0... UNSUPPORTED.
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:5585 process_sdp: Processing session-level SDP o=- 1295540456 1295540456 IN IP4 192.168.30.107... UNSUPPORTED.
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:5585 process_sdp: Processing session-level SDP s=Polycom IP Phone... UNSUPPORTED.
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:5585 process_sdp: Processing session-level SDP c=IN IP4 192.168.30.107... OK.
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:5585 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED.
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:5585 process_sdp: Processing session-level SDP a=sendrecv... OK.
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:5733 process_sdp: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK.
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:5733 process_sdp: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK.
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:5733 process_sdp: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK.
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:5733 process_sdp: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK.
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:5733 process_sdp: Processing media-level (audio) SDP a=fmtp:18 annexb=no... UNSUPPORTED.
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:5733 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK.
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:5758 process_sdp: T38 state changed to 0 on channel <none>
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:5891 process_sdp: We're settling with these formats: 0x1004 (ulaw|g722)
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:15538 handle_request_invite: Checking SIP call limits for device 6002
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:3534 update_call_counter: Updating call counter for incoming call
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:3611 update_call_counter: Call from peer '6002' is 1 out of 8
[2011-01-20 11:21:35] DEBUG[2089]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/6002
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:4389 sip_new: *** Our native formats are 0x4 (ulaw)
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:4390 sip_new: *** Joint capabilities are 0x1004 (ulaw|g722)
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:4391 sip_new: *** Our capabilities are 0x1004 (ulaw|g722)
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:4392 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw)
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:4415 sip_new: This channel will not be able to handle video.
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:9112 build_route: build_route: Contact hop: <sip:6002@192.168.30.107:5060>
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:15642 handle_request_invite: SIP/6002-00000020: New call is still down.... Trying...
[2011-01-20 11:21:35] DEBUG[2089]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/6002
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1866 pbx_extension_helper: Launching 'Set'
[2011-01-20 11:21:35]     -- Executing [6010@default-super:1] Set("SIP/6002-00000020", "LOCAL_EXTEN=6010") in new stack
[2011-01-20 11:21:35] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6002
[2011-01-20 11:21:35] DEBUG[1933]: devicestate.c:287 do_state_change: Changing state for SIP/6002 - state 2 (In use)
[2011-01-20 11:21:35] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6002
[2011-01-20 11:21:35] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6002
[2011-01-20 11:21:35] DEBUG[1933]: devicestate.c:287 do_state_change: Changing state for SIP/6002 - state 2 (In use)
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6002
[2011-01-20 11:21:35]  Extension Changed 6002[default-local] new state InUse for Notify User 6010
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6002
[2011-01-20 11:21:35]  Extension Changed 6002[default-local] new state InUse for Notify User 6002
[2011-01-20 11:21:35] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6002
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1866 pbx_extension_helper: Launching 'Set'
[2011-01-20 11:21:35]     -- Executing [6010@default-super:2] Set("SIP/6002-00000020", "LOCAL_LIMIT=1") in new stack
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1866 pbx_extension_helper: Launching 'Gosub'
[2011-01-20 11:21:35]     -- Executing [6010@default-super:3] Gosub("SIP/6002-00000020", "all-local-extension|s|1") in new stack
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:2293 __sip_ack: Acked pending invite 121
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:2325 __sip_ack: Stopping retransmission on '148e2ad7-60780ab8-743ba645@192.168.30.194' of Request 121: Match Found
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1866 pbx_extension_helper: Launching 'Set'
[2011-01-20 11:21:35]     -- Executing [s@all-local-extension:1] Set("SIP/6002-00000020", "__PICKUPMARK=6010") in new stack
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1782 pbx_substitute_variables_helper_full: Expression result is '0'
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1782 pbx_substitute_variables_helper_full: Expression result is '4'
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1866 pbx_extension_helper: Launching 'GotoIf'
[2011-01-20 11:21:35]     -- Executing [s@all-local-extension:2] GotoIf("SIP/6002-00000020", "0?4") in new stack
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:6181 pbx_builtin_gotoif: Not taking any branch
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is '6002'
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1866 pbx_extension_helper: Launching 'Set'
[2011-01-20 11:21:35]     -- Executing [s@all-local-extension:3] Set("SIP/6002-00000020", "GROUP(OUTGOING)=6002") in new stack
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1866 pbx_extension_helper: Launching 'Set'
[2011-01-20 11:21:35]     -- Executing [s@all-local-extension:4] Set("SIP/6002-00000020", "OUTBOUND_GROUP_ONCE=6010@INCOMING") in new stack
[2011-01-20 11:21:35] DEBUG[2184]: app_queue.c:711 handle_statechange: Device 'SIP/6002' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[2011-01-20 11:21:35] DEBUG[2184]: app_queue.c:711 handle_statechange: Device 'SIP/6002' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1782 pbx_substitute_variables_helper_full: Expression result is '0'
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1782 pbx_substitute_variables_helper_full: Expression result is '8'
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:2293 __sip_ack: Acked pending invite 121
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:2325 __sip_ack: Stopping retransmission on '7f494750-646c8cfb-6c51f5ba@192.168.30.107' of Request 121: Match Found
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1866 pbx_extension_helper: Launching 'GotoIf'
[2011-01-20 11:21:35]     -- Executing [s@all-local-extension:5] GotoIf("SIP/6002-00000020", "0?8") in new stack
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:6181 pbx_builtin_gotoif: Not taking any branch
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is '0'
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1866 pbx_extension_helper: Launching 'Set'
[2011-01-20 11:21:35]     -- Executing [s@all-local-extension:6] Set("SIP/6002-00000020", "GROUPCOUNT=0") in new stack
[2011-01-20 11:21:35] DEBUG[2038]: manager.c:2277 process_message: Manager received command 'GetVar'
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is '0'
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1866 pbx_extension_helper: Launching 'Set'
[2011-01-20 11:21:35]     -- Executing [s@all-local-extension:7] Set("SIP/6002-00000020", "GROUPCOUNT2=0") in new stack
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1866 pbx_extension_helper: Launching 'Return'
[2011-01-20 11:21:35]     -- Executing [s@all-local-extension:8] Return("SIP/6002-00000020", "") in new stack
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1866 pbx_extension_helper: Launching 'Set'
[2011-01-20 11:21:35]     -- Executing [6010@default-super:4] Set("SIP/6002-00000020", "SCOPSERV_DBPUT(default/wrapup/6010/lastcall)=1295540495.71") in new stack
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is '1295540495.71'
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is 'default/wrapup/6010/lastcall'
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1866 pbx_extension_helper: Launching 'Macro'
[2011-01-20 11:21:35]     -- Executing [6010@default-super:5] Macro("SIP/6002-00000020", "default-dial|SIP/6010|6010|default|20|en|b6010@default|tkK||default||Local/s@default-aa-operator-6010|disa") in new stack
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is '6002'
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is 'Reception 6002'
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1866 pbx_extension_helper: Launching 'NoOp'
[2011-01-20 11:21:35]     -- Executing [s@macro-default-dial:1] NoOp("SIP/6002-00000020", ""CALL TO LOCAL EXTENSION FROM 6002(Reception 6002)"") in new stack
[2011-01-20 11:21:35] DEBUG[6463]: app_macro.c:379 _macro_exec: Executed application: NoOp
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1866 pbx_extension_helper: Launching 'Set'
[2011-01-20 11:21:35]     -- Executing [s@macro-default-dial:2] Set("SIP/6002-00000020", "__PICKUPMARK=6010") in new stack
[2011-01-20 11:21:35] DEBUG[6463]: app_macro.c:379 _macro_exec: Executed application: Set
[2011-01-20 11:21:35] DEBUG[6463]: pbx.c:1866 pbx_extension_helper: Launching 'AGI'
[2011-01-20 11:21:35]     -- Executing [s@macro-default-dial:3] AGI("SIP/6002-00000020", "agi://127.0.0.1:4573/dial") in new stack
[2011-01-20 11:21:35] DEBUG[6467]: manager.c:2277 process_message: Manager received command 'login'
[2011-01-20 11:21:35]   == Parsing '/etc/asterisk/manager.conf': [2011-01-20 11:21:35] DEBUG[6467]: config.c:895 config_text_file_load: Parsing /etc/asterisk/manager.conf
[2011-01-20 11:21:35] Found
[2011-01-20 11:21:35] DEBUG[6467]: acl.c:355 ast_append_ha: 127.0.0.1/255.255.255.255 appended to acl for peer
[2011-01-20 11:21:35] DEBUG[6467]: acl.c:370 ast_apply_ha: ##### Testing 127.0.0.1 with 127.0.0.1
[2011-01-20 11:21:35]   agi://127.0.0.1:4573/dial: Variable 'ARG1' result is SIP/6010
[2011-01-20 11:21:35]   agi://127.0.0.1:4573/dial: Variable 'ARG2' result is 6010
[2011-01-20 11:21:35]   agi://127.0.0.1:4573/dial: Variable 'ARG3' result is default
[2011-01-20 11:21:35]   agi://127.0.0.1:4573/dial: Variable 'ARG4' result is 20
[2011-01-20 11:21:35]   agi://127.0.0.1:4573/dial: Variable 'ARG5' result is en
[2011-01-20 11:21:35]   agi://127.0.0.1:4573/dial: Variable 'ARG6' result is b6010@default
[2011-01-20 11:21:35]   agi://127.0.0.1:4573/dial: Variable 'ARG7' result is tkK
[2011-01-20 11:21:35]   agi://127.0.0.1:4573/dial: Variable 'ARG8' result is
[2011-01-20 11:21:35]   agi://127.0.0.1:4573/dial: Variable 'ARG9' result is default
[2011-01-20 11:21:35]   agi://127.0.0.1:4573/dial: Variable 'ARG10' result is
[2011-01-20 11:21:35]   agi://127.0.0.1:4573/dial: Variable 'ARG11' result is Local/s@default-aa-operator-6010
[2011-01-20 11:21:35]   agi://127.0.0.1:4573/dial: Variable 'ARG12' result is disa
[2011-01-20 11:21:35]   agi://127.0.0.1:4573/dial: Variable 'EXT_ACCODE' result is not defined!!!
[2011-01-20 11:21:35]   agi://127.0.0.1:4573/dial: Variable 'MACRO_PRIORITY' result is 5
[2011-01-20 11:21:35]   agi://127.0.0.1:4573/dial: Variable 'CALLBACK_ON_HANGUP' result is not defined!!!
[2011-01-20 11:21:35]   agi://127.0.0.1:4573/dial: Variable 'CLID_BLOCK' result is not defined!!!
[2011-01-20 11:21:35] DEBUG[6463]: db.c:196 ast_db_get: Unable to find key 'SIP/6010' in family 'DND'
[2011-01-20 11:21:35] DEBUG[6463]: db.c:196 ast_db_get: Unable to find key '6010' in family 'DND'
[2011-01-20 11:21:35]   agi://127.0.0.1:4573/dial: Variable 'INCOMINGLINE' result is not defined!!!
[2011-01-20 11:21:35]   agi://127.0.0.1:4573/dial: Variable 'MONITOR_OPTION' result is wW
[2011-01-20 11:21:35]   agi://127.0.0.1:4573/dial: Variable 'AUTO_RECORDING' result is 6002
[2011-01-20 11:21:35]   agi://127.0.0.1:4573/dial: Variable 'FORCE_RECORDING' result is not defined!!!
[2011-01-20 11:21:35]     -- AGI Script Executing Application: (MixMonitor) Options: (default-super_1295540495.71.WAV|b)
[2011-01-20 11:21:35]   == Begin MixMonitor Recording SIP/6002-00000020
[2011-01-20 11:21:35] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:35] DEBUG[6463]: func_audiohookinherit.c:146 setup_inheritable_audiohook: Set audiohook MixMonitor to be inheritable
[2011-01-20 11:21:35]   agi://127.0.0.1:4573/dial: Variable 'LIMIT_IN_DEFAULT_6010' result is 8
[2011-01-20 11:21:35]   agi://127.0.0.1:4573/dial: Variable 'GROUPCOUNT' result is 0
[2011-01-20 11:21:35]   agi://127.0.0.1:4573/dial: Variable 'GROUPCOUNT2' result is 0
[2011-01-20 11:21:35] DEBUG[6467]: manager.c:2277 process_message: Manager received command 'ExtensionState'
[2011-01-20 11:21:35] DEBUG[6467]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:35]     -- AGI Script Executing Application: (NoOp) Options: (STATUS:)
[2011-01-20 11:21:35]     -- AGI Script Executing Application: (Dial) Options: (SIP/6010|20|tkKTwW|)
[2011-01-20 11:21:35] DEBUG[6463]: chan_sip.c:17865 sip_request_call: Asked to create a SIP channel with formats: 0x4 (ulaw)
[2011-01-20 11:21:35] DEBUG[6463]: chan_sip.c:4947 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP)
[2011-01-20 11:21:35] DEBUG[6463]: chan_sip.c:3030 do_setnat: Setting NAT on RTP to Off
[2011-01-20 11:21:35] DEBUG[6463]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.194 with 192.168.0.0
[2011-01-20 11:21:35] DEBUG[6463]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.194 with 10.0.0.0
[2011-01-20 11:21:35] DEBUG[6463]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.194 with 172.16.0.0
[2011-01-20 11:21:35] DEBUG[6463]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.194 with 169.254.0.0
[2011-01-20 11:21:35] DEBUG[6463]: chan_sip.c:4389 sip_new: *** Our native formats are 0x4 (ulaw)
[2011-01-20 11:21:35] DEBUG[6463]: chan_sip.c:4390 sip_new: *** Joint capabilities are 0x0 (nothing)
[2011-01-20 11:21:35] DEBUG[2038]: manager.c:2277 process_message: Manager received command 'GetVar'
[2011-01-20 11:21:35] DEBUG[6463]: chan_sip.c:4391 sip_new: *** Our capabilities are 0x4 (ulaw)
[2011-01-20 11:21:35] DEBUG[6463]: chan_sip.c:4392 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw)
[2011-01-20 11:21:35] DEBUG[6463]: chan_sip.c:4394 sip_new: *** Our preferred formats from the incoming channel are 0x4 (ulaw)
[2011-01-20 11:21:35] DEBUG[6463]: chan_sip.c:4415 sip_new: This channel will not be able to handle video.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable DIALEDTIME.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable ANSWEREDTIME.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable DIALEDPEERNAME.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable DIALEDPEERNUMBER.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable DIALSTATUS.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable MIXMONITOR_FILENAME.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable TOUCH_MIXMONITOR.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable TOUCH_MONITOR.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable MACRO_DEPTH.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4077 ast_channel_inherit_variables: Copying hard-transferable variable PICKUPMARK.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable ARG12.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable ARG11.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable ARG10.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable ARG9.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable ARG8.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable ARG7.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable ARG6.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable ARG5.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable ARG4.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable ARG3.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable ARG2.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable ARG1.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable MACRO_PRIORITY.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable MACRO_CONTEXT.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable MACRO_EXTEN.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable ODBCROWS.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable GROUPCOUNT2.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable GROUPCOUNT.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable LOCAL_LIMIT.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable LOCAL_EXTEN.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable SPYGROUP.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable INBOUND_GROUP.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable MONITOR_OPTION.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable AUTO_RECORDING.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable EXTCONTEXT.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable SIPCALLID.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable SIPDOMAIN.
[2011-01-20 11:21:35] DEBUG[6463]: channel.c:4082 ast_channel_inherit_variables: Not copying variable SIPURI.
[2011-01-20 11:21:35] DEBUG[6463]: chan_sip.c:3315 sip_call: Outgoing Call for 6010
[2011-01-20 11:21:35] DEBUG[6463]: chan_sip.c:3534 update_call_counter: Updating call counter for outgoing call
[2011-01-20 11:21:35] DEBUG[6463]: chan_sip.c:3611 update_call_counter: Call to peer '6010' is 1 out of 8
[2011-01-20 11:21:35] DEBUG[6463]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/6010
[2011-01-20 11:21:35] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:35] DEBUG[1933]: devicestate.c:287 do_state_change: Changing state for SIP/6010 - state 6 (Ringing)
[2011-01-20 11:21:35] DEBUG[2184]: app_queue.c:716 handle_statechange: Device 'SIP/6010' changed to state '6' (Ringing)
[2011-01-20 11:21:35] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:35] DEBUG[6463]: chan_sip.c:3330 sip_call: Our T38 capability (16144), joint T38 capability (16144)
[2011-01-20 11:21:35] DEBUG[6463]: chan_sip.c:7118 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: False
[2011-01-20 11:21:35] DEBUG[6463]: chan_sip.c:7119 add_sdp: ** Our prefcodec: 0x4 (ulaw)
[2011-01-20 11:21:35] DEBUG[6463]: chan_sip.c:7243 add_sdp: -- Done with adding codecs to SDP
[2011-01-20 11:21:35] DEBUG[6463]: chan_sip.c:7342 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw)
[2011-01-20 11:21:35]     -- Called 6010
[2011-01-20 11:21:35] DEBUG[2038]: manager.c:2277 process_message: Manager received command 'GetVar'
[2011-01-20 11:21:35] DEBUG[2038]: manager.c:2277 process_message: Manager received command 'GetVar'
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:2367 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '0d6e84f91fc954445547a8ae791d8738@192.168.30.254' Request 102: Found
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:35]  Extension Changed 6010[default-local] new state Ringing for Notify User 6002
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:35]  Extension Changed 6010[default-local] new state Ringing for Notify User 6010
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:2293 __sip_ack: Acked pending invite 125
[2011-01-20 11:21:35] DEBUG[2089]: chan_sip.c:2325 __sip_ack: Stopping retransmission on 'fe520271-262a30d8-91531a63@192.168.30.107' of Request 125: Match Found
[2011-01-20 11:21:35] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:36] DEBUG[2089]: chan_sip.c:2293 __sip_ack: Acked pending invite 125
[2011-01-20 11:21:36] DEBUG[2089]: chan_sip.c:2325 __sip_ack: Stopping retransmission on 'f8d2c1b9-14b83272-449e1bf7@192.168.30.194' of Request 125: Match Found
[2011-01-20 11:21:36] DEBUG[2089]: chan_sip.c:2367 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '0d6e84f91fc954445547a8ae791d8738@192.168.30.254' Request 102: Found
[2011-01-20 11:21:36] DEBUG[2089]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/6010
[2011-01-20 11:21:36]     -- SIP/6010-00000021 is ringing
[2011-01-20 11:21:36] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:36] DEBUG[1933]: devicestate.c:287 do_state_change: Changing state for SIP/6010 - state 6 (Ringing)
[2011-01-20 11:21:36] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:36] DEBUG[2184]: app_queue.c:716 handle_statechange: Device 'SIP/6010' changed to state '6' (Ringing)
[2011-01-20 11:21:36] DEBUG[2016]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:36] DEBUG[1959]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:36] DEBUG[1959]: manager.c:2277 process_message: Manager received command 'GetVar'
[2011-01-20 11:21:36] DEBUG[1951]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:36] DEBUG[1946]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:36] DEBUG[1953]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:2293 __sip_ack: Acked pending invite 102
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:2325 __sip_ack: Stopping retransmission on '0d6e84f91fc954445547a8ae791d8738@192.168.30.254' of Request 102: Match Found
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:5585 process_sdp: Processing session-level SDP v=0... UNSUPPORTED.
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:5585 process_sdp: Processing session-level SDP o=- 1295540455 1295540455 IN IP4 192.168.30.194... UNSUPPORTED.
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:5585 process_sdp: Processing session-level SDP s=Polycom IP Phone... UNSUPPORTED.
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:5585 process_sdp: Processing session-level SDP c=IN IP4 192.168.30.194... OK.
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:5585 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED.
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:5733 process_sdp: Processing media-level (audio) SDP a=sendrecv... OK.
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:5733 process_sdp: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK.
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:5733 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK.
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:5758 process_sdp: T38 state changed to 0 on channel SIP/6010-00000021
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:5891 process_sdp: We're settling with these formats: 0x4 (ulaw)
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:3534 update_call_counter: Updating call counter for outgoing call
[2011-01-20 11:21:37] DEBUG[2089]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/6010
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:9112 build_route: build_route: Contact hop: <sip:6010@192.168.30.194:5060>
[2011-01-20 11:21:37] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:37] DEBUG[1933]: devicestate.c:287 do_state_change: Changing state for SIP/6010 - state 2 (In use)
[2011-01-20 11:21:37] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:37] DEBUG[6463]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/6010
[2011-01-20 11:21:37]     -- SIP/6010-00000021 answered SIP/6002-00000020
[2011-01-20 11:21:37] DEBUG[6463]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/6002
[2011-01-20 11:21:37] DEBUG[6463]: chan_sip.c:4014 sip_answer: SIP answering channel: SIP/6002-00000020
[2011-01-20 11:21:37] DEBUG[6463]: rtp.c:2119 ast_rtp_new_source: Setting the marker bit due to a source update
[2011-01-20 11:21:37] DEBUG[6463]: chan_sip.c:7400 transmit_response_with_sdp: Setting framing from config on incoming call
[2011-01-20 11:21:37] DEBUG[6463]: chan_sip.c:7118 add_sdp: ** Our capability: 0x1004 (ulaw|g722) Video flag: True
[2011-01-20 11:21:37] DEBUG[6463]: chan_sip.c:7119 add_sdp: ** Our prefcodec: 0x0 (nothing)
[2011-01-20 11:21:37] DEBUG[6463]: chan_sip.c:7243 add_sdp: -- Done with adding codecs to SDP
[2011-01-20 11:21:37] DEBUG[6463]: chan_sip.c:7342 add_sdp: Done building SDP. Settling with this capability: 0x1004 (ulaw|g722)
[2011-01-20 11:21:37] DEBUG[2184]: app_queue.c:716 handle_statechange: Device 'SIP/6010' changed to state '2' (In use)
[2011-01-20 11:21:37] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:37] DEBUG[1933]: devicestate.c:287 do_state_change: Changing state for SIP/6010 - state 2 (In use)
[2011-01-20 11:21:37] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:37] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6002
[2011-01-20 11:21:37] DEBUG[1933]: devicestate.c:287 do_state_change: Changing state for SIP/6002 - state 2 (In use)
[2011-01-20 11:21:37] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6002
[2011-01-20 11:21:37] DEBUG[6463]: rtp.c:2119 ast_rtp_new_source: Setting the marker bit due to a source update
[2011-01-20 11:21:37] DEBUG[6463]: rtp.c:2119 ast_rtp_new_source: Setting the marker bit due to a source update
[2011-01-20 11:21:37] DEBUG[2184]: app_queue.c:716 handle_statechange: Device 'SIP/6010' changed to state '2' (In use)
[2011-01-20 11:21:37] DEBUG[2184]: app_queue.c:711 handle_statechange: Device 'SIP/6002' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:2325 __sip_ack: Stopping retransmission on '5145e211-b1fd99f8-f1f5c703@192.168.30.107' of Response 2: Match Found
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:37]  Extension Changed 6010[default-local] new state InUse for Notify User 6002
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:37]  Extension Changed 6010[default-local] new state InUse for Notify User 6010
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:2293 __sip_ack: Acked pending invite 126
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:2325 __sip_ack: Stopping retransmission on 'f8d2c1b9-14b83272-449e1bf7@192.168.30.194' of Request 126: Match Found
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:259 audiohook_read_frame_both: Failed to get 160 samples from read factory 0xa2475a8
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6463]: rtp.c:2970 ast_rtp_write: Ooh, format changed from unknown to ulaw
[2011-01-20 11:21:37] DEBUG[6463]: rtp.c:2987 ast_rtp_write: Created smoother: format: 4 ms: 20 len: 160
[2011-01-20 11:21:37] DEBUG[6463]: rtp.c:2970 ast_rtp_write: Ooh, format changed from unknown to ulaw
[2011-01-20 11:21:37] DEBUG[6463]: rtp.c:2987 ast_rtp_write: Created smoother: format: 4 ms: 20 len: 160
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:2293 __sip_ack: Acked pending invite 126
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:2325 __sip_ack: Stopping retransmission on 'fe520271-262a30d8-91531a63@192.168.30.107' of Request 126: Match Found
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[2089]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.86 with 192.168.0.0
[2011-01-20 11:21:37] DEBUG[2089]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.86 with 10.0.0.0
[2011-01-20 11:21:37] DEBUG[2089]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.86 with 172.16.0.0
[2011-01-20 11:21:37] DEBUG[2089]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.86 with 169.254.0.0
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:4947 sip_alloc: Allocating new SIP dialog for 6363118a-1cf24945-d916a5a4@192.168.30.86 - SUBSCRIBE (No RTP)
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:9112 build_route: build_route: Contact hop: <sip:6057@192.168.30.86:5060>
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:9050 build_route: build_route: Retaining previous route: <sip:6057@192.168.30.86:5060>
[2011-01-20 11:21:37] DEBUG[2089]: chan_sip.c:16754 handle_request_subscribe: Received SIP subscribe for unknown event package: missed-call-summary
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:37] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:38] DEBUG[1947]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:224 audiohook_read_frame_both: Read factory 0xa2475a8 and write factory 0xa247fc4 both fail to provide 160 samples
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:5585 process_sdp: Processing session-level SDP v=0... UNSUPPORTED.
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:5585 process_sdp: Processing session-level SDP o=- 1295540455 1295540456 IN IP4 192.168.30.194... UNSUPPORTED.
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:5585 process_sdp: Processing session-level SDP s=Polycom IP Phone... UNSUPPORTED.
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:5585 process_sdp: Processing session-level SDP c=IN IP4 192.168.30.194... OK.
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:5585 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED.
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:5585 process_sdp: Processing session-level SDP a=sendonly... OK.
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:5733 process_sdp: Processing media-level (audio) SDP a=sendonly... OK.
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:5733 process_sdp: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK.
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:5733 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK.
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:5758 process_sdp: T38 state changed to 0 on channel SIP/6010-00000021
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:5891 process_sdp: We're settling with these formats: 0x4 (ulaw)
[2011-01-20 11:21:38] DEBUG[2089]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/6010
[2011-01-20 11:21:38] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:38] DEBUG[1933]: devicestate.c:287 do_state_change: Changing state for SIP/6010 - state 8 (On Hold)
[2011-01-20 11:21:38] DEBUG[2184]: app_queue.c:716 handle_statechange: Device 'SIP/6010' changed to state '8' (On Hold)
[2011-01-20 11:21:38] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:15716 handle_request_invite: SIP/6010-00000021: This call is UP....
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:7400 transmit_response_with_sdp: Setting framing from config on incoming call
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:7118 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: True
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:7119 add_sdp: ** Our prefcodec: 0x4 (ulaw)
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:7243 add_sdp: -- Done with adding codecs to SDP
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:7342 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw)
[2011-01-20 11:21:38] DEBUG[6463]: rtp.c:2119 ast_rtp_new_source: Setting the marker bit due to a source update
[2011-01-20 11:21:38] DEBUG[6463]: channel.c:3444 set_format: Set channel SIP/6002-00000020 to write format slin
[2011-01-20 11:21:38]     -- Started music on hold, class 'default', on channel 'SIP/6002-00000020'
[2011-01-20 11:21:38] DEBUG[6463]: channel.c:2013 ast_settimeout: Scheduling timer at 160 sample intervals
[2011-01-20 11:21:38] DEBUG[6463]: channel.c:2110 ast_read_generator_actions: Generator got voice, switching to phase locked mode
[2011-01-20 11:21:38] DEBUG[6463]: channel.c:2013 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-01-20 11:21:38] DEBUG[6463]: rtp.c:2119 ast_rtp_new_source: Setting the marker bit due to a source update
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:38]  Extension Changed 6010[default-local] new state Hold for Notify User 6002
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:38]  Extension Changed 6010[default-local] new state Hold for Notify User 6010
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:2293 __sip_ack: Acked pending invite 127
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:2325 __sip_ack: Stopping retransmission on 'fe520271-262a30d8-91531a63@192.168.30.107' of Request 127: Match Found
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:2325 __sip_ack: Stopping retransmission on '0d6e84f91fc954445547a8ae791d8738@192.168.30.254' of Response 1: Match Found
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:2293 __sip_ack: Acked pending invite 127
[2011-01-20 11:21:38] DEBUG[2089]: chan_sip.c:2325 __sip_ack: Stopping retransmission on 'f8d2c1b9-14b83272-449e1bf7@192.168.30.194' of Request 127: Match Found
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[2086]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:38] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[1945]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[1949]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[2089]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.194 with 192.168.0.0
[2011-01-20 11:21:39] DEBUG[2089]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.194 with 10.0.0.0
[2011-01-20 11:21:39] DEBUG[2089]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.194 with 172.16.0.0
[2011-01-20 11:21:39] DEBUG[2089]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.194 with 169.254.0.0
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:3030 do_setnat: Setting NAT on RTP to Off
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:3035 do_setnat: Setting NAT on VRTP to Off
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:3040 do_setnat: Setting NAT on UDPTL to Off
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:4947 sip_alloc: Allocating new SIP dialog for 57597d08-4c1d0e55-92e2c5de@192.168.30.194 - INVITE (With RTP)
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:3030 do_setnat: Setting NAT on RTP to Off
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:3035 do_setnat: Setting NAT on VRTP to Off
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:3040 do_setnat: Setting NAT on UDPTL to Off
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:2325 __sip_ack: Stopping retransmission on '57597d08-4c1d0e55-92e2c5de@192.168.30.194' of Response 1: Match Found
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:3030 do_setnat: Setting NAT on RTP to Off
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:3035 do_setnat: Setting NAT on VRTP to Off
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:3040 do_setnat: Setting NAT on UDPTL to Off
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:5585 process_sdp: Processing session-level SDP v=0... UNSUPPORTED.
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:5585 process_sdp: Processing session-level SDP o=- 1295540458 1295540458 IN IP4 192.168.30.194... UNSUPPORTED.
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:5585 process_sdp: Processing session-level SDP s=Polycom IP Phone... UNSUPPORTED.
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:5585 process_sdp: Processing session-level SDP c=IN IP4 192.168.30.194... OK.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:5585 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED.
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:5585 process_sdp: Processing session-level SDP a=sendrecv... OK.
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:5733 process_sdp: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK.
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:5733 process_sdp: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK.
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:5733 process_sdp: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK.
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:5733 process_sdp: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK.
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:5733 process_sdp: Processing media-level (audio) SDP a=fmtp:18 annexb=no... UNSUPPORTED.
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:5733 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK.
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:5758 process_sdp: T38 state changed to 0 on channel <none>
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:5891 process_sdp: We're settling with these formats: 0x4 (ulaw)
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:15538 handle_request_invite: Checking SIP call limits for device 6010
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:3534 update_call_counter: Updating call counter for incoming call
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:3611 update_call_counter: Call from peer '6010' is 2 out of 8
[2011-01-20 11:21:39] DEBUG[2089]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/6010
[2011-01-20 11:21:39] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:39] DEBUG[1933]: devicestate.c:287 do_state_change: Changing state for SIP/6010 - state 8 (On Hold)
[2011-01-20 11:21:39] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:39] DEBUG[2184]: app_queue.c:716 handle_statechange: Device 'SIP/6010' changed to state '8' (On Hold)
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:4389 sip_new: *** Our native formats are 0x4 (ulaw)
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:4390 sip_new: *** Joint capabilities are 0x4 (ulaw)
[2011-01-20 11:21:39] DEBUG[2038]: manager.c:2277 process_message: Manager received command 'GetVar'
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:4391 sip_new: *** Our capabilities are 0x4 (ulaw)
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:4392 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw)
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:4415 sip_new: This channel will not be able to handle video.
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:9112 build_route: build_route: Contact hop: <sip:6010@192.168.30.194:5060>
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:15642 handle_request_invite: SIP/6010-00000022: New call is still down.... Trying...
[2011-01-20 11:21:39] DEBUG[2089]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/6010
[2011-01-20 11:21:39] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:39] DEBUG[1933]: devicestate.c:287 do_state_change: Changing state for SIP/6010 - state 8 (On Hold)
[2011-01-20 11:21:39] DEBUG[2184]: app_queue.c:716 handle_statechange: Device 'SIP/6010' changed to state '8' (On Hold)
[2011-01-20 11:21:39] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6505]: pbx.c:1866 pbx_extension_helper: Launching 'Park'
[2011-01-20 11:21:39]     -- Executing [7000@default-super:1] Park("SIP/6010-00000022", "") in new stack
[2011-01-20 11:21:39] DEBUG[6505]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/6010
[2011-01-20 11:21:39] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:39] DEBUG[1933]: devicestate.c:287 do_state_change: Changing state for SIP/6010 - state 8 (On Hold)
[2011-01-20 11:21:39] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:39] DEBUG[2184]: app_queue.c:716 handle_statechange: Device 'SIP/6010' changed to state '8' (On Hold)
[2011-01-20 11:21:39] DEBUG[6505]: chan_sip.c:4014 sip_answer: SIP answering channel: SIP/6010-00000022
[2011-01-20 11:21:39] DEBUG[6505]: rtp.c:2119 ast_rtp_new_source: Setting the marker bit due to a source update
[2011-01-20 11:21:39] DEBUG[6505]: chan_sip.c:7400 transmit_response_with_sdp: Setting framing from config on incoming call
[2011-01-20 11:21:39] DEBUG[6505]: chan_sip.c:7118 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: True
[2011-01-20 11:21:39] DEBUG[6505]: chan_sip.c:7119 add_sdp: ** Our prefcodec: 0x0 (nothing)
[2011-01-20 11:21:39] DEBUG[6505]: chan_sip.c:7243 add_sdp: -- Done with adding codecs to SDP
[2011-01-20 11:21:39] DEBUG[6505]: chan_sip.c:7342 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw)
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:2325 __sip_ack: Stopping retransmission on '57597d08-4c1d0e55-92e2c5de@192.168.30.194' of Response 2: Match Found
[2011-01-20 11:21:39] DEBUG[1950]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[2089]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.150 with 192.168.0.0
[2011-01-20 11:21:39] DEBUG[2089]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.150 with 10.0.0.0
[2011-01-20 11:21:39] DEBUG[2089]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.150 with 172.16.0.0
[2011-01-20 11:21:39] DEBUG[2089]: acl.c:370 ast_apply_ha: ##### Testing 192.168.30.150 with 169.254.0.0
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:4947 sip_alloc: Allocating new SIP dialog for b8bd70a4-54284773-8a408c1a@192.168.30.150 - SUBSCRIBE (No RTP)
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:9112 build_route: build_route: Contact hop: <sip:6003@192.168.30.150:5060>
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:9050 build_route: build_route: Retaining previous route: <sip:6003@192.168.30.150:5060>
[2011-01-20 11:21:39] DEBUG[2089]: chan_sip.c:16754 handle_request_subscribe: Received SIP subscribe for unknown event package: missed-call-summary
[2011-01-20 11:21:39] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:39] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[2016]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[1959]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[1951]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6505]: channel.c:4006 ast_channel_masquerade: Planning to masquerade channel SIP/6010-00000022 into the structure of Parked/SIP/6010-00000022
[2011-01-20 11:21:40] DEBUG[6505]: channel.c:4015 ast_channel_masquerade: Done planning to masquerade channel SIP/6010-00000022 into the structure of Parked/SIP/6010-00000022
[2011-01-20 11:21:40] DEBUG[6505]: channel.c:4171 ast_do_masquerade: Got clone lock for masquerade on 'SIP/6010-00000022' at 0xb7b7ca48
[2011-01-20 11:21:40] DEBUG[2038]: manager.c:2277 process_message: Manager received command 'GetVar'
[2011-01-20 11:21:40] DEBUG[6505]: channel.c:4357 ast_do_masquerade: Putting channel SIP/6010-00000022 in 4/4 formats
[2011-01-20 11:21:40] DEBUG[6505]: chan_sip.c:4159 sip_fixup: SIP Fixup: New owner for dialogue 57597d08-4c1d0e55-92e2c5de@192.168.30.194: SIP/6010-00000022 (Old parent: Parked/SIP/6010-00000022<ZOMBIE>)
[2011-01-20 11:21:40] DEBUG[6505]: channel.c:4405 ast_do_masquerade: Released clone lock on 'Parked/SIP/6010-00000022<ZOMBIE>'
[2011-01-20 11:21:40] DEBUG[6505]: channel.c:4415 ast_do_masquerade: Done Masquerading SIP/6010-00000022 (6)
[2011-01-20 11:21:40] DEBUG[6505]: rtp.c:2131 ast_rtp_change_source: Changing ssrc from 281865581 to 540992709 due to a source change
[2011-01-20 11:21:40]   == Parked SIP/6010-00000022 on 7001@parkedcalls. Will timeout back to extension [default-super] s, 1 in 45 seconds
[2011-01-20 11:21:40] DEBUG[6505]: pbx.c:4989 ast_add_extension2: Added extension '7001' priority 1 to parkedcalls
[2011-01-20 11:21:40]     -- Added extension '7001' priority 1 to parkedcalls
[2011-01-20 11:21:40] DEBUG[6505]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel park:7001@parkedcalls
[2011-01-20 11:21:40] DEBUG[6505]: rtp.c:2970 ast_rtp_write: Ooh, format changed from unknown to ulaw
[2011-01-20 11:21:40] DEBUG[6505]: rtp.c:2987 ast_rtp_write: Created smoother: format: 4 ms: 20 len: 160
[2011-01-20 11:21:40] DEBUG[6505]: channel.c:2013 ast_settimeout: Scheduling timer at 160 sample intervals
[2011-01-20 11:21:40]     -- <SIP/6010-00000022> Playing 'digits/7' (language 'en')
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[1933]: devicestate.c:157 ast_device_state: Checking if I can find provider for "park" - number: 7001@parkedcalls
[2011-01-20 11:21:40] DEBUG[1933]: devicestate.c:287 do_state_change: Changing state for park:7001@parkedcalls - state 2 (In use)
[2011-01-20 11:21:40] DEBUG[1933]: devicestate.c:157 ast_device_state: Checking if I can find provider for "park" - number: 7001@parkedcalls
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[2089]: devicestate.c:157 ast_device_state: Checking if I can find provider for "park" - number: 7001@parkedcalls
[2011-01-20 11:21:40]  Extension Changed 7001[default-local] new state InUse for Notify User 6006
[2011-01-20 11:21:40] DEBUG[2089]: devicestate.c:157 ast_device_state: Checking if I can find provider for "park" - number: 7001@parkedcalls
[2011-01-20 11:21:40]  Extension Changed 7001[default-local] new state InUse for Notify User 6002
[2011-01-20 11:21:40] DEBUG[2089]: chan_sip.c:2293 __sip_ack: Acked pending invite 105
[2011-01-20 11:21:40] DEBUG[2089]: chan_sip.c:2325 __sip_ack: Stopping retransmission on '261e2f5af85172b7' of Request 105: Match Found
[2011-01-20 11:21:40] DEBUG[2089]: chan_sip.c:2293 __sip_ack: Acked pending invite 111
[2011-01-20 11:21:40] DEBUG[2089]: chan_sip.c:2325 __sip_ack: Stopping retransmission on 'e39c6d42-69ca1a5-36eb443c@192.168.30.107' of Request 111: Match Found
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[1946]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:40] DEBUG[1953]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:40] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[3961]: res_musiconhold.c:602 monmp3thread: Read 384 bytes of audio while expecting 640
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6505]: channel.c:2013 ast_settimeout: Scheduling timer at 154 sample intervals
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6505]: channel.c:2013 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-01-20 11:21:41] DEBUG[6505]: channel.c:2013 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-01-20 11:21:41] DEBUG[6505]: channel.c:2013 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-01-20 11:21:41] DEBUG[6505]: channel.c:2013 ast_settimeout: Scheduling timer at 160 sample intervals
[2011-01-20 11:21:41]     -- <SIP/6010-00000022> Playing 'digits/0' (language 'en')
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6463]: rtp.c:941 ast_rtcp_read: Got RTCP report of 104 bytes
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:41] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:41] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:41] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:41] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6463]: rtp.c:941 ast_rtcp_read: Got RTCP report of 104 bytes
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[6505]: channel.c:2013 ast_settimeout: Scheduling timer at 144 sample intervals
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[6505]: channel.c:2013 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-01-20 11:21:42] DEBUG[6505]: channel.c:2013 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-01-20 11:21:42] DEBUG[6505]: channel.c:2013 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-01-20 11:21:42] DEBUG[6505]: channel.c:2013 ast_settimeout: Scheduling timer at 160 sample intervals
[2011-01-20 11:21:42]     -- <SIP/6010-00000022> Playing 'digits/0' (language 'en')
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[2036]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[1947]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxCount'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2473]: manager.c:2277 process_message: Manager received command 'MailboxStatus'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[2086]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6505]: channel.c:2013 ast_settimeout: Scheduling timer at 144 sample intervals
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6505]: channel.c:2013 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-01-20 11:21:42] DEBUG[6505]: channel.c:2013 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-01-20 11:21:42] DEBUG[6505]: channel.c:2013 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-01-20 11:21:42] DEBUG[6505]: channel.c:2013 ast_settimeout: Scheduling timer at 160 sample intervals
[2011-01-20 11:21:42]     -- <SIP/6010-00000022> Playing 'digits/1' (language 'en')
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:42] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[1945]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[1949]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6505]: channel.c:2013 ast_settimeout: Scheduling timer at 36 sample intervals
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6505]: channel.c:2013 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-01-20 11:21:43] DEBUG[6505]: channel.c:2013 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-01-20 11:21:43] DEBUG[6505]: channel.c:2013 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-01-20 11:21:43] DEBUG[6505]: rtp.c:2119 ast_rtp_new_source: Setting the marker bit due to a source update
[2011-01-20 11:21:43] DEBUG[6505]: channel.c:3444 set_format: Set channel SIP/6010-00000022 to write format slin
[2011-01-20 11:21:43]     -- Started music on hold, class 'default', on channel 'SIP/6010-00000022'
[2011-01-20 11:21:43] DEBUG[6505]: channel.c:2013 ast_settimeout: Scheduling timer at 160 sample intervals
[2011-01-20 11:21:43] DEBUG[6505]: pbx.c:2473 __ast_pbx_run: Spawn extension (default-super,s,1) exited non-zero on 'Parked/SIP/6010-00000022<ZOMBIE>'
[2011-01-20 11:21:43]   == Spawn extension (default-super, s, 1) exited non-zero on 'Parked/SIP/6010-00000022<ZOMBIE>'
[2011-01-20 11:21:43] DEBUG[6505]: channel.c:1578 ast_softhangup_nolock: Soft-Hanging up channel 'Parked/SIP/6010-00000022<ZOMBIE>'
[2011-01-20 11:21:43] DEBUG[6505]: channel.c:1686 ast_hangup: Hanging up zombie 'Parked/SIP/6010-00000022<ZOMBIE>'
[2011-01-20 11:21:43] DEBUG[6505]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel Parked/SIP/6010
[2011-01-20 11:21:43] DEBUG[1933]: devicestate.c:287 do_state_change: Changing state for Parked/SIP/6010 - state 4 (Invalid)
[2011-01-20 11:21:43] DEBUG[2184]: app_queue.c:711 handle_statechange: Device 'Parked/SIP/6010' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[2011-01-20 11:21:43] DEBUG[1937]: channel.c:2110 ast_read_generator_actions: Generator got voice, switching to phase locked mode
[2011-01-20 11:21:43] DEBUG[1937]: channel.c:2013 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:43] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[2016]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[1959]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[1951]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:44] DEBUG[2089]: chan_sip.c:10198 get_refer_info: Attended transfer: Will use Replace-Call-ID : 57597d08-4c1d0e55-92e2c5de@192.168.30.194 (No check of from/to tags)
[2011-01-20 11:21:44] DEBUG[2089]: chan_sip.c:14546 attempt_transfer: SIP transfer: Four channels to handle
[2011-01-20 11:21:44] DEBUG[2089]: channel.c:3444 set_format: Set channel SIP/6010-00000022 to write format ulaw
[2011-01-20 11:21:44]     -- Stopped music on hold on SIP/6010-00000022
[2011-01-20 11:21:44] DEBUG[2089]: channel.c:2013 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-01-20 11:21:44] DEBUG[2089]: channel.c:3444 set_format: Set channel SIP/6002-00000020 to write format ulaw
[2011-01-20 11:21:44]     -- Stopped music on hold on SIP/6002-00000020
[2011-01-20 11:21:44] DEBUG[2089]: channel.c:2013 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-01-20 11:21:44] DEBUG[2089]: channel.c:4006 ast_channel_masquerade: Planning to masquerade channel SIP/6002-00000020 into the structure of SIP/6010-00000022
[2011-01-20 11:21:44] DEBUG[2089]: channel.c:4015 ast_channel_masquerade: Done planning to masquerade channel SIP/6002-00000020 into the structure of SIP/6010-00000022
[2011-01-20 11:21:44] DEBUG[2089]: chan_sip.c:14569 attempt_transfer: SIP transfer: Succeeded to masquerade channels.
[2011-01-20 11:21:44] DEBUG[2089]: chan_sip.c:15918 local_attended_transfer: SIP attended transfer: Unlocking channel SIP/6010-00000022
[2011-01-20 11:21:44] DEBUG[6463]: rtp.c:2119 ast_rtp_new_source: Setting the marker bit due to a source update
[2011-01-20 11:21:44] DEBUG[1937]: channel.c:4171 ast_do_masquerade: Got clone lock for masquerade on 'SIP/6002-00000020' at 0xb79558d8
[2011-01-20 11:21:44] DEBUG[1937]: chan_sip.c:4159 sip_fixup: SIP Fixup: New owner for dialogue 57597d08-4c1d0e55-92e2c5de@192.168.30.194: SIP/6002-00000020<MASQ> (Old parent: SIP/6002-00000020)
[2011-01-20 11:21:44] DEBUG[1937]: chan_sip.c:3852 sip_hangup: Hangup call SIP/6002-00000020<MASQ>, SIP callid 57597d08-4c1d0e55-92e2c5de@192.168.30.194)
[2011-01-20 11:21:44] DEBUG[1937]: chan_sip.c:3534 update_call_counter: Updating call counter for incoming call
[2011-01-20 11:21:44] DEBUG[1937]: chan_sip.c:3585 update_call_counter: Call from peer '6010' removed from call limit 8
[2011-01-20 11:21:44] DEBUG[1937]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/6010
[2011-01-20 11:21:44] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:44] DEBUG[1933]: devicestate.c:287 do_state_change: Changing state for SIP/6010 - state 8 (On Hold)
[2011-01-20 11:21:44] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:44] DEBUG[2184]: app_queue.c:716 handle_statechange: Device 'SIP/6010' changed to state '8' (On Hold)
[2011-01-20 11:21:44] DEBUG[1937]: func_audiohookinherit.c:70 audiohook_inheritance_fixup: inheritance fixup occurring for channels SIP/6010-00000022<ZOMBIE>(0xb7955860) and SIP/6002-00000020(0xa1b9028)[2011-01-20 11:21:44] DEBUG[1937]: func_audiohookinherit.c:76 audiohook_inheritance_fixup: Moved audiohook MixMonitor from SIP/6010-00000022<ZOMBIE>(0xb7955860) to SIP/6002-00000020(0xa1b9028)
[2011-01-20 11:21:44] DEBUG[1937]: channel.c:4357 ast_do_masquerade: Putting channel SIP/6002-00000020 in 4/4 formats
[2011-01-20 11:21:44] DEBUG[1937]: chan_sip.c:4159 sip_fixup: SIP Fixup: New owner for dialogue 5145e211-b1fd99f8-f1f5c703@192.168.30.107: SIP/6002-00000020 (Old parent: SIP/6010-00000022<ZOMBIE>)
[2011-01-20 11:21:44] DEBUG[1937]: rtp.c:2119 ast_rtp_new_source: Setting the marker bit due to a source update
[2011-01-20 11:21:44] DEBUG[1937]: channel.c:3444 set_format: Set channel SIP/6002-00000020 to write format slin
[2011-01-20 11:21:44]     -- Started music on hold, class 'default', on channel 'SIP/6002-00000020'
[2011-01-20 11:21:44] DEBUG[1937]: channel.c:2013 ast_settimeout: Scheduling timer at 160 sample intervals
[2011-01-20 11:21:44] DEBUG[1937]: channel.c:4405 ast_do_masquerade: Released clone lock on 'SIP/6010-00000022<ZOMBIE>'
[2011-01-20 11:21:44] DEBUG[1937]: channel.c:4415 ast_do_masquerade: Done Masquerading SIP/6002-00000020 (6)
[2011-01-20 11:21:44] DEBUG[1937]: rtp.c:2131 ast_rtp_change_source: Changing ssrc from 1149999970 to 1567266640 due to a source change
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6463]: channel.c:4882 ast_channel_bridge: Bridge stops because we're zombie or need a soft hangup: c0=SIP/6010-00000022<ZOMBIE>, c1=SIP/6010-00000021, flags: Yes,Yes,No,No
[2011-01-20 11:21:44] DEBUG[6463]: rtp.c:2119 ast_rtp_new_source: Setting the marker bit due to a source update
[2011-01-20 11:21:44] DEBUG[1937]: channel.c:2110 ast_read_generator_actions: Generator got voice, switching to phase locked mode
[2011-01-20 11:21:44] DEBUG[1937]: channel.c:2013 ast_settimeout: Scheduling timer at 0 sample intervals
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[2089]: chan_sip.c:2325 __sip_ack: Stopping retransmission on '0d6e84f91fc954445547a8ae791d8738@192.168.30.254' of Request 103: Match Found
[2011-01-20 11:21:44] DEBUG[2089]: chan_sip.c:14223 handle_response: Got 200 OK on NOTIFY for transfer
[2011-01-20 11:21:44] DEBUG[6463]: channel.c:4999 ast_channel_bridge: Bridge stops bridging channels SIP/6010-00000022<ZOMBIE> and SIP/6010-00000021
[2011-01-20 11:21:44] DEBUG[6463]: pbx.c:1866 pbx_extension_helper: Launching 'ResetCDR'
[2011-01-20 11:21:44] DEBUG[2089]: chan_sip.c:1761 sip_alreadygone: Setting SIP_ALREADYGONE on dialog 0d6e84f91fc954445547a8ae791d8738@192.168.30.254
[2011-01-20 11:21:44] DEBUG[2089]: chan_sip.c:16474 handle_request_bye: Received bye, issuing owner hangup
[2011-01-20 11:21:44]     -- Executing [h@macro-default-dial:1] ResetCDR("SIP/6010-00000022<ZOMBIE>", "w") in new stack
[2011-01-20 11:21:44] DEBUG[6463]: cdr_radius.c:221 radius_log: Unable to create RADIUS record. CDR not recorded!
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is '"Reception 6002" <6002>'
[2011-01-20 11:21:44] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is '6002'
[2011-01-20 11:21:44] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is '6010'
[2011-01-20 11:21:44] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is 'default-super'
[2011-01-20 11:21:44] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is 'SIP/6002-00000020'
[2011-01-20 11:21:44] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is 'SIP/6010-00000021'
[2011-01-20 11:21:44] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is 'Dial'
[2011-01-20 11:21:44] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is 'SIP/6010|20|tkKTwW|'
[2011-01-20 11:21:44] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is '2011-01-20 11:21:35'
[2011-01-20 11:21:44] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is '2011-01-20 11:21:37'
[2011-01-20 11:21:44] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is '2011-01-20 11:21:44'
[2011-01-20 11:21:44] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is '9'
[2011-01-20 11:21:44] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is '7'
[2011-01-20 11:21:44] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is 'ANSWERED'
[2011-01-20 11:21:44] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION'
[2011-01-20 11:21:44] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is '6002'
[2011-01-20 11:21:44] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is '1295540495.71'
[2011-01-20 11:21:44] DEBUG[6463]: pbx.c:1714 pbx_substitute_variables_helper_full: Function result is '(null)'
[2011-01-20 11:21:44] DEBUG[6463]: pbx.c:1866 pbx_extension_helper: Launching 'NoCDR'
[2011-01-20 11:21:44]     -- Executing [h@macro-default-dial:2] NoCDR("SIP/6010-00000022<ZOMBIE>", "") in new stack
[2011-01-20 11:21:44] DEBUG[2089]: chan_sip.c:2325 __sip_ack: Stopping retransmission on '57597d08-4c1d0e55-92e2c5de@192.168.30.194' of Request 102: Match Found
[2011-01-20 11:21:44] DEBUG[6463]: channel.c:1681 ast_hangup: Hanging up channel 'SIP/6010-00000021'
[2011-01-20 11:21:44] DEBUG[6463]: chan_sip.c:3534 update_call_counter: Updating call counter for outgoing call
[2011-01-20 11:21:44] DEBUG[6463]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/6010
[2011-01-20 11:21:44] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:44] DEBUG[1933]: devicestate.c:287 do_state_change: Changing state for SIP/6010 - state 1 (Not in use)
[2011-01-20 11:21:44] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:44] DEBUG[2184]: app_queue.c:716 handle_statechange: Device 'SIP/6010' changed to state '1' (Not in use)
[2011-01-20 11:21:44] DEBUG[6463]: chan_sip.c:3585 update_call_counter: Call to peer '6010' removed from call limit 8
[2011-01-20 11:21:44] DEBUG[6463]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/6010
[2011-01-20 11:21:44] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:44] DEBUG[1933]: devicestate.c:287 do_state_change: Changing state for SIP/6010 - state 1 (Not in use)
[2011-01-20 11:21:44] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:44] DEBUG[2184]: app_queue.c:716 handle_statechange: Device 'SIP/6010' changed to state '1' (Not in use)
[2011-01-20 11:21:44] DEBUG[6463]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/6010
[2011-01-20 11:21:44] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:44] DEBUG[1933]: devicestate.c:287 do_state_change: Changing state for SIP/6010 - state 1 (Not in use)
[2011-01-20 11:21:44] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:44] DEBUG[2184]: app_queue.c:716 handle_statechange: Device 'SIP/6010' changed to state '1' (Not in use)
[2011-01-20 11:21:44] DEBUG[6463]: rtp.c:1623 ast_rtp_early_bridge: Channel '<unspecified>' has no RTP, not doing anything
[2011-01-20 11:21:44] DEBUG[6463]: app_dial.c:1938 dial_exec_full: Exiting with DIALSTATUS=ANSWER.
[2011-01-20 11:21:44] DEBUG[6463]: res_agi.c:1925 run_agi: SIP/6010-00000022<ZOMBIE> hungup
[2011-01-20 11:21:44] DEBUG[6463]: app_macro.c:372 _macro_exec: Spawn extension (macro-default-dial,s,3) exited non-zero on 'SIP/6010-00000022<ZOMBIE>' in macro 'default-dial'
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6463]: pbx.c:2473 __ast_pbx_run: Spawn extension (default-super,6010,5) exited non-zero on 'SIP/6010-00000022<ZOMBIE>'
[2011-01-20 11:21:44]   == Spawn extension (default-super, 6010, 5) exited non-zero on 'SIP/6010-00000022<ZOMBIE>'
[2011-01-20 11:21:44] DEBUG[6463]: channel.c:1578 ast_softhangup_nolock: Soft-Hanging up channel 'SIP/6010-00000022<ZOMBIE>'
[2011-01-20 11:21:44] DEBUG[6463]: channel.c:1686 ast_hangup: Hanging up zombie 'SIP/6010-00000022<ZOMBIE>'
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6463]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/6010
[2011-01-20 11:21:44] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:44] DEBUG[1933]: devicestate.c:287 do_state_change: Changing state for SIP/6010 - state 1 (Not in use)
[2011-01-20 11:21:44] DEBUG[1933]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:44] DEBUG[2184]: app_queue.c:716 handle_statechange: Device 'SIP/6010' changed to state '1' (Not in use)
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[2089]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:44]  Extension Changed 6010[default-local] new state Idle for Notify User 6002
[2011-01-20 11:21:44] DEBUG[2089]: chan_sip.c:17789 sip_devicestate: Checking device state for peer 6010
[2011-01-20 11:21:44]  Extension Changed 6010[default-local] new state Idle for Notify User 6010
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[2089]: chan_sip.c:2293 __sip_ack: Acked pending invite 128
[2011-01-20 11:21:44] DEBUG[2089]: chan_sip.c:2325 __sip_ack: Stopping retransmission on 'f8d2c1b9-14b83272-449e1bf7@192.168.30.194' of Request 128: Match Found
[2011-01-20 11:21:44] DEBUG[2089]: chan_sip.c:2293 __sip_ack: Acked pending invite 128
[2011-01-20 11:21:44] DEBUG[2089]: chan_sip.c:2325 __sip_ack: Stopping retransmission on 'fe520271-262a30d8-91531a63@192.168.30.107' of Request 128: Match Found
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[2510]: manager.c:2277 process_message: Manager received command 'Ping'
[2011-01-20 11:21:44] DEBUG[2510]: manager.c:2277 process_message: Manager received command 'Command'
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.
[2011-01-20 11:21:44] DEBUG[6470]: audiohook.c:231 audiohook_read_frame_both: Write factory 0xa247fc4 was pretty quick last time, waiting for them.