[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2b78dd36 Our tag: as60c40b6a
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3204f887538fb6576aff82994c4e6d88@66.49.255.61 Their Tag as755cac8c Our tag: as4d531303
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7e1d02ca8dc4f41483eedc4d85a79c9d@192.168.192.194 Their Tag 01c18ff2e06534a Our tag: as32e36ce9
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0d59ff5c5d7da93c40fcb25cdbeb58a7@192.168.192.193 Their Tag 6ab4515851df784 Our tag: as01251cbd
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1bee3216-93306860-fb20c5d9@192.168.192.191 Their Tag 664A6EBA-5D17EA5B Our tag: as1b49dc59
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 445fafbb-3f36520d-2950089a@192.168.192.191 Their Tag 256D0FAF-6D161884 Our tag: as12e1b29f
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 9bc65609-d3d27e0b-7ec854d0@192.168.192.191 Their Tag 6B4700DD-971C18AA Our tag: as7ea11f27
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 958a807e-bb07d908-e3592421@192.168.192.191 Their Tag 3202BA2-88C03DE3 Our tag: as7a128639
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 4891da07-ac8f8739-f79accf6@192.168.192.191 Their Tag 50571ABB-91D94E40 Our tag: as57f441f2
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 6a8e83f4-e3aa426e-f220365f@192.168.192.191 Their Tag EF679478-F5E3DF51 Our tag: as16a462c8
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: ff51f8d5-43fc9fb7-e2e27ac@192.168.192.191 Their Tag 15E48C69-7BB4C0E6 Our tag: as6967dce3
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c26701520c0-duvkdwbwjm32 Their Tag 08j0pr3ogj Our tag: as102b506d
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2670151ddc-bnz4m8sg5zgw Their Tag 0wm7jm1qjq Our tag: as6e1f2643
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:2783 do_setnat: Setting NAT on RTP to Off
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:2788 do_setnat: Setting NAT on VRTP to Off
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:2793 do_setnat: Setting NAT on UDPTL to Off
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4621 sip_alloc: Allocating new SIP dialog for 1805017497@192.168.192.157 - INVITE (With RTP)
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:15870 handle_request: **** Received INVITE (5) - Command in SIP INVITE
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:2783 do_setnat: Setting NAT on RTP to Off
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:2788 do_setnat: Setting NAT on VRTP to Off
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:2793 do_setnat: Setting NAT on UDPTL to Off
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 1805017497@192.168.192.157 Their Tag 56902390 Our tag: as35df1f0e
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:15870 handle_request: **** Received ACK (6) - Command in SIP ACK
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '1805017497@192.168.192.157' of Response 20: Match Found
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 1805017497@192.168.192.157 Their Tag 56902390 Our tag: as35df1f0e
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:15870 handle_request: **** Received INVITE (5) - Command in SIP INVITE
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:2783 do_setnat: Setting NAT on RTP to Off
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:2788 do_setnat: Setting NAT on VRTP to Off
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:2793 do_setnat: Setting NAT on UDPTL to Off
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:5568 process_sdp: T38 state changed to 0 on channel <none>
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:5648 process_sdp: We're settling with these formats: 0x104 (ulaw|g729)
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:14506 handle_request_invite: Checking SIP call limits for device 222
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:3252 update_call_counter: Updating call counter for incoming call
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:3329 update_call_counter: Call from peer '222' is 1 out of 8
[Mar  9 20:00:33] DEBUG[2295]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/222
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4095 sip_new: *** Our native formats are 0x4 (ulaw) 
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4096 sip_new: *** Joint capabilities are 0x104 (ulaw|g729) 
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4097 sip_new: *** Our capabilities are 0x104 (ulaw|g729) 
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4098 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) 
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4121 sip_new: This channel will not be able to handle video.
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:8503 build_route: build_route: Contact hop: <sip:222@192.168.192.157>
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:14589 handle_request_invite: SIP/222-08566178: New call is still down.... Trying... 
[Mar  9 20:00:33] DEBUG[2295]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/222
[Mar  9 20:00:33] DEBUG[20497]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '222'
[Mar  9 20:00:33] DEBUG[20497]: pbx.c:1843 pbx_extension_helper: Launching 'Set'
    -- Executing [*850@commzilla-super:1] Set("SIP/222-08566178", "GROUP(OUTGOING)=222") in new stack
[Mar  9 20:00:33] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222
[Mar  9 20:00:33] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222
[Mar  9 20:00:33] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/222 - state 2 (In use)
[Mar  9 20:00:33] DEBUG[2292]: app_queue.c:676 handle_statechange: Device 'SIP/222' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Mar  9 20:00:33] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222
[Mar  9 20:00:33] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222
[Mar  9 20:00:33] DEBUG[20497]: pbx.c:1843 pbx_extension_helper: Launching 'Answer'
    -- Executing [*850@commzilla-super:2] Answer("SIP/222-08566178", "") in new stack
[Mar  9 20:00:33] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:33] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'ChanSpy' in family 'commzilla/222'
[Mar  9 20:00:33] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:33] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'DoNotDisturb' in family 'commzilla/222'
[Mar  9 20:00:33] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222
[Mar  9 20:00:33] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:33] DEBUG[20497]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/222
[Mar  9 20:00:33] DEBUG[20497]: chan_sip.c:3730 sip_answer: SIP answering channel: SIP/222-08566178
[Mar  9 20:00:33] DEBUG[20497]: chan_sip.c:6856 transmit_response_with_sdp: Setting framing from config on incoming call
[Mar  9 20:00:33] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'DoNotDisturb_Reason' in family 'commzilla/222'
[Mar  9 20:00:33] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222
 Extension Changed 222[commzilla-local] new state InUse for Notify User 220 
[Mar  9 20:00:33] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222
[Mar  9 20:00:33] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222
 Extension Changed 222[commzilla-local] new state InUse for Notify User 300 
[Mar  9 20:00:33] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:33] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:33] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:33] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:33] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'CallWaiting' in family 'commzilla/222'
[Mar  9 20:00:33] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:33] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'Login' in family 'commzilla/222/Agent'
[Mar  9 20:00:33] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:33] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'Paused' in family 'commzilla/222/Agent'
[Mar  9 20:00:33] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:33] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'HotDesk' in family 'commzilla/222'
[Mar  9 20:00:33] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222
[Mar  9 20:00:33] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222
[Mar  9 20:00:33] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/222 - state 2 (In use)
[Mar  9 20:00:33] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222
[Mar  9 20:00:33] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222
[Mar  9 20:00:33] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222
[Mar  9 20:00:33] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222
[Mar  9 20:00:33] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/222 - state 2 (In use)
[Mar  9 20:00:33] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222
[Mar  9 20:00:33] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222
[Mar  9 20:00:33] DEBUG[20497]: chan_sip.c:6620 add_sdp: ** Our capability: 0x104 (ulaw|g729) Video flag: True
[Mar  9 20:00:33] DEBUG[2292]: app_queue.c:676 handle_statechange: Device 'SIP/222' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Mar  9 20:00:33] DEBUG[2292]: app_queue.c:676 handle_statechange: Device 'SIP/222' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Mar  9 20:00:33] DEBUG[20497]: chan_sip.c:6621 add_sdp: ** Our prefcodec: 0x0 (nothing) 
[Mar  9 20:00:33] DEBUG[20497]: chan_sip.c:6752 add_sdp: -- Done with adding codecs to SDP
[Mar  9 20:00:33] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:33] DEBUG[20497]: chan_sip.c:6797 add_sdp: Done building SDP. Settling with this capability: 0x104 (ulaw|g729)
[Mar  9 20:00:33] DEBUG[20497]: pbx.c:1843 pbx_extension_helper: Launching 'Set'
    -- Executing [*850@commzilla-super:3] Set("SIP/222-08566178", "QUEUE_PRIO=0") in new stack
[Mar  9 20:00:33] DEBUG[20497]: pbx.c:1843 pbx_extension_helper: Launching 'Goto'
    -- Executing [*850@commzilla-super:4] Goto("SIP/222-08566178", "commzilla-application-acd-sales|s|1") in new stack
    -- Goto (commzilla-application-acd-sales,s,1)
[Mar  9 20:00:33] DEBUG[20497]: pbx.c:1843 pbx_extension_helper: Launching 'NoOp'
    -- Executing [s@commzilla-application-acd-sales:1] NoOp("SIP/222-08566178", ""=== START QUEUE (commzilla-sales) ==="") in new stack
[Mar  9 20:00:33] DEBUG[20497]: pbx.c:1843 pbx_extension_helper: Launching 'Set'
    -- Executing [s@commzilla-application-acd-sales:2] Set("SIP/222-08566178", "__QUEUENAME=commzilla-sales") in new stack
[Mar  9 20:00:33] DEBUG[20497]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '0'
[Mar  9 20:00:33] DEBUG[20497]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '6'
[Mar  9 20:00:33] DEBUG[20497]: pbx.c:1843 pbx_extension_helper: Launching 'GotoIf'
    -- Executing [s@commzilla-application-acd-sales:3] GotoIf("SIP/222-08566178", "0?6") in new stack
[Mar  9 20:00:33] DEBUG[20497]: pbx.c:6042 pbx_builtin_gotoif: Not taking any branch
[Mar  9 20:00:33] DEBUG[20497]: pbx.c:1843 pbx_extension_helper: Launching 'Set'
    -- Executing [s@commzilla-application-acd-sales:4] Set("SIP/222-08566178", "MONITOR_FILENAME=1236643233.254") in new stack
[Mar  9 20:00:33] DEBUG[20497]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '7'
[Mar  9 20:00:33] DEBUG[20497]: pbx.c:1843 pbx_extension_helper: Launching 'Goto'
    -- Executing [s@commzilla-application-acd-sales:5] Goto("SIP/222-08566178", "7") in new stack
    -- Goto (commzilla-application-acd-sales,s,7)
[Mar  9 20:00:33] DEBUG[20497]: pbx.c:1843 pbx_extension_helper: Launching 'Set'
    -- Executing [s@commzilla-application-acd-sales:7] Set("SIP/222-08566178", "TIMEOUT(digit)=1") in new stack
    -- Digit timeout set to 1
[Mar  9 20:00:33] DEBUG[20497]: pbx.c:1843 pbx_extension_helper: Launching 'Set'
    -- Executing [s@commzilla-application-acd-sales:8] Set("SIP/222-08566178", "TIMEOUT(response)=1") in new stack
    -- Response timeout set to 1
[Mar  9 20:00:33] DEBUG[20497]: pbx.c:1843 pbx_extension_helper: Launching 'BackGround'
    -- Executing [s@commzilla-application-acd-sales:9] BackGround("SIP/222-08566178", "custom/0001") in new stack
[Mar  9 20:00:33] DEBUG[20497]: rtp.c:2781 ast_rtp_write: Ooh, format changed from unknown to ulaw
[Mar  9 20:00:33] DEBUG[20497]: rtp.c:2798 ast_rtp_write: Created smoother: format: 4 ms: 20 len: 160
    -- <SIP/222-08566178> Playing 'custom/0001' (language 'en')
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1805017497@192.168.192.157 Their Tag 56902390 Our tag: as46025d57
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2b78dd36 Our tag: as60c40b6a
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3204f887538fb6576aff82994c4e6d88@66.49.255.61 Their Tag as755cac8c Our tag: as4d531303
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7e1d02ca8dc4f41483eedc4d85a79c9d@192.168.192.194 Their Tag 01c18ff2e06534a Our tag: as32e36ce9
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0d59ff5c5d7da93c40fcb25cdbeb58a7@192.168.192.193 Their Tag 6ab4515851df784 Our tag: as01251cbd
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1bee3216-93306860-fb20c5d9@192.168.192.191 Their Tag 664A6EBA-5D17EA5B Our tag: as1b49dc59
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 445fafbb-3f36520d-2950089a@192.168.192.191 Their Tag 256D0FAF-6D161884 Our tag: as12e1b29f
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 9bc65609-d3d27e0b-7ec854d0@192.168.192.191 Their Tag 6B4700DD-971C18AA Our tag: as7ea11f27
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 958a807e-bb07d908-e3592421@192.168.192.191 Their Tag 3202BA2-88C03DE3 Our tag: as7a128639
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 4891da07-ac8f8739-f79accf6@192.168.192.191 Their Tag 50571ABB-91D94E40 Our tag: as57f441f2
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 6a8e83f4-e3aa426e-f220365f@192.168.192.191 Their Tag EF679478-F5E3DF51 Our tag: as16a462c8
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: ff51f8d5-43fc9fb7-e2e27ac@192.168.192.191 Their Tag 15E48C69-7BB4C0E6 Our tag: as6967dce3
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 919
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on 'ff51f8d5-43fc9fb7-e2e27ac@192.168.192.191' of Request 919: Match Found
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1805017497@192.168.192.157 Their Tag 56902390 Our tag: as46025d57
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2b78dd36 Our tag: as60c40b6a
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3204f887538fb6576aff82994c4e6d88@66.49.255.61 Their Tag as755cac8c Our tag: as4d531303
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7e1d02ca8dc4f41483eedc4d85a79c9d@192.168.192.194 Their Tag 01c18ff2e06534a Our tag: as32e36ce9
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 759
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on 'a5283085413b819d' of Request 759: Match Found
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 1805017497@192.168.192.157 Their Tag 56902390 Our tag: as46025d57
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:15870 handle_request: **** Received ACK (6) - Command in SIP ACK
[Mar  9 20:00:33] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '1805017497@192.168.192.157' of Response 21: Match Found
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4621 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:3361 sip_destroy: Destroying SIP dialog 69470e591600ce6219c75f240fa467ad@99.229.93.248
Really destroying SIP dialog '69470e591600ce6219c75f240fa467ad@99.229.93.248' Method: OPTIONS
[Mar  9 20:00:36] DEBUG[2295]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/230
[Mar  9 20:00:36] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 230
[Mar  9 20:00:36] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 230
[Mar  9 20:00:36] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/230 - state 5 (Unavailable)
[Mar  9 20:00:36] DEBUG[2292]: app_queue.c:676 handle_statechange: Device 'SIP/230' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue.
[Mar  9 20:00:36] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 230
[Mar  9 20:00:36] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 230
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1805017497@192.168.192.157 Their Tag 56902390 Our tag: as46025d57
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2b78dd36 Our tag: as60c40b6a
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3204f887538fb6576aff82994c4e6d88@66.49.255.61 Their Tag as755cac8c Our tag: as4d531303
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7e1d02ca8dc4f41483eedc4d85a79c9d@192.168.192.194 Their Tag 01c18ff2e06534a Our tag: as32e36ce9
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0d59ff5c5d7da93c40fcb25cdbeb58a7@192.168.192.193 Their Tag 6ab4515851df784 Our tag: as01251cbd
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1bee3216-93306860-fb20c5d9@192.168.192.191 Their Tag 664A6EBA-5D17EA5B Our tag: as1b49dc59
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 445fafbb-3f36520d-2950089a@192.168.192.191 Their Tag 256D0FAF-6D161884 Our tag: as12e1b29f
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 9bc65609-d3d27e0b-7ec854d0@192.168.192.191 Their Tag 6B4700DD-971C18AA Our tag: as7ea11f27
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 958a807e-bb07d908-e3592421@192.168.192.191 Their Tag 3202BA2-88C03DE3 Our tag: as7a128639
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 4891da07-ac8f8739-f79accf6@192.168.192.191 Their Tag 50571ABB-91D94E40 Our tag: as57f441f2
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 6a8e83f4-e3aa426e-f220365f@192.168.192.191 Their Tag EF679478-F5E3DF51 Our tag: as16a462c8
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: ff51f8d5-43fc9fb7-e2e27ac@192.168.192.191 Their Tag 15E48C69-7BB4C0E6 Our tag: as6967dce3
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c26701520c0-duvkdwbwjm32 Their Tag 08j0pr3ogj Our tag: as102b506d
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2670151ddc-bnz4m8sg5zgw Their Tag 0wm7jm1qjq Our tag: as6e1f2643
[Mar  9 20:00:36] DEBUG[2295]: chan_sip.c:16142 sipsock_read: Invalid SIP message - rejected , no callid, len 579
[Mar  9 20:00:36] DEBUG[4987]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:36] DEBUG[4987]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:36] DEBUG[4987]: manager.c:2184 process_message: Manager received command 'MailboxStatus'
[Mar  9 20:00:36] DEBUG[4987]: manager.c:2184 process_message: Manager received command 'MailboxCount'
[Mar  9 20:00:36] DEBUG[4987]: manager.c:2184 process_message: Manager received command 'MailboxStatus'
[Mar  9 20:00:36] DEBUG[4987]: manager.c:2184 process_message: Manager received command 'MailboxCount'
[Mar  9 20:00:38] DEBUG[20497]: pbx.c:1843 pbx_extension_helper: Launching 'Set'
    -- Executing [s@commzilla-application-acd-sales:10] Set("SIP/222-08566178", "__ACD_TO_OUTGOING=1") in new stack
[Mar  9 20:00:38] DEBUG[20497]: pbx.c:1843 pbx_extension_helper: Launching 'Set'
    -- Executing [s@commzilla-application-acd-sales:11] Set("SIP/222-08566178", "CHANNEL(musicclass)=default") in new stack
[Mar  9 20:00:38] DEBUG[20497]: pbx.c:1843 pbx_extension_helper: Launching 'Set'
    -- Executing [s@commzilla-application-acd-sales:12] Set("SIP/222-08566178", "__ALLOW_TRANSFER=twk") in new stack
[Mar  9 20:00:38] DEBUG[20497]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is 'WiFi'
[Mar  9 20:00:38] DEBUG[20497]: pbx.c:1843 pbx_extension_helper: Launching 'Set'
    -- Executing [s@commzilla-application-acd-sales:13] Set("SIP/222-08566178", "CALLERID(name)=SALES:WiFi") in new stack
[Mar  9 20:00:38] DEBUG[20497]: pbx.c:1843 pbx_extension_helper: Launching 'Queue'
    -- Executing [s@commzilla-application-acd-sales:14] Queue("SIP/222-08566178", "commzilla-sales|tH|||300|") in new stack
[Mar  9 20:00:38] DEBUG[20497]: app_queue.c:3927 queue_exec: SIP/222-08566178: Got priority 0 from ${QUEUE_PRIO}.
[Mar  9 20:00:38] DEBUG[20497]: app_queue.c:3959 queue_exec: queue: commzilla-sales, options: tH, url: , announce: , expires: 1236643538, priority: 0
[Mar  9 20:00:38] DEBUG[20497]: app_queue.c:1355 update_realtime_members: Queue commzilla-sales has no realtime members defined. No need for update
[Mar  9 20:00:38] DEBUG[20497]: app_queue.c:1500 join_queue: Queue 'commzilla-sales' Join, Channel 'SIP/222-08566178', Position '1'
[Mar  9 20:00:38] DEBUG[20497]: channel.c:2961 set_format: Set channel SIP/222-08566178 to write format slin
    -- Started music on hold, class 'default', on channel 'SIP/222-08566178'
[Mar  9 20:00:38] DEBUG[20497]: app_queue.c:2419 is_our_turn: There are 1 available members.
[Mar  9 20:00:38] DEBUG[20497]: app_queue.c:2430 is_our_turn: It's our turn (SIP/222-08566178).
[Mar  9 20:00:38] DEBUG[20497]: app_queue.c:2816 try_calling: SIP/222-08566178 is trying to call a queue member.
[Mar  9 20:00:38] DEBUG[20497]: app_queue.c:2005 ring_one: Trying 'Local/233@commzilla-agent/n' with metric 1000
[Mar  9 20:00:38] DEBUG[20497]: channel.c:3464 ast_channel_inherit_variables: Copying hard-transferable variable ALLOW_TRANSFER.
[Mar  9 20:00:38] DEBUG[20497]: channel.c:3464 ast_channel_inherit_variables: Copying hard-transferable variable ACD_TO_OUTGOING.
[Mar  9 20:00:38] DEBUG[20497]: channel.c:3469 ast_channel_inherit_variables: Not copying variable MONITOR_FILENAME.
[Mar  9 20:00:38] DEBUG[20497]: channel.c:3464 ast_channel_inherit_variables: Copying hard-transferable variable QUEUENAME.
[Mar  9 20:00:38] DEBUG[20497]: channel.c:3469 ast_channel_inherit_variables: Not copying variable QUEUE_PRIO.
[Mar  9 20:00:38] DEBUG[20497]: channel.c:3469 ast_channel_inherit_variables: Not copying variable SPYGROUP.
[Mar  9 20:00:38] DEBUG[20497]: channel.c:3469 ast_channel_inherit_variables: Not copying variable INBOUND_GROUP.
[Mar  9 20:00:38] DEBUG[20497]: channel.c:3469 ast_channel_inherit_variables: Not copying variable AUTO_RECORDING.
[Mar  9 20:00:38] DEBUG[20497]: channel.c:3469 ast_channel_inherit_variables: Not copying variable FORCE_RECORDING.
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4621 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Mar  9 20:00:38] DEBUG[20497]: channel.c:3469 ast_channel_inherit_variables: Not copying variable SIPCALLID.
[Mar  9 20:00:38] DEBUG[20497]: channel.c:3469 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT.
[Mar  9 20:00:38] DEBUG[20497]: channel.c:3469 ast_channel_inherit_variables: Not copying variable SIPDOMAIN.
[Mar  9 20:00:38] DEBUG[20497]: channel.c:3469 ast_channel_inherit_variables: Not copying variable SIPURI.
    -- Called Local/233@commzilla-agent/n
[Mar  9 20:00:38] DEBUG[20497]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 233@commzilla-agent/n
[Mar  9 20:00:38] DEBUG[20497]: chan_local.c:145 local_devicestate: Checking if extension 233@commzilla-agent exists (devicestate)
[Mar  9 20:00:38] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1843 pbx_extension_helper: Launching 'NoCDR'
    -- Executing [233@commzilla-agent:1] NoCDR("Local/233@commzilla-agent-ce09,2", "") in new stack
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 337fce021b43cdba1528e7fb477d4753@99.229.93.248 Their Tag  Our tag: as7f29aae8
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '337fce021b43cdba1528e7fb477d4753@99.229.93.248' of Request 102: Match Found
[Mar  9 20:00:38] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:38] DEBUG[21258]: db.c:198 ast_db_get: Unable to find key '233/DoNotDisturb' in family 'commzilla'
[Mar  9 20:00:38] DEBUG[21258]: func_db.c:70 function_db_read: DB: commzilla/233/DoNotDisturb not found in database.
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is ''
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1843 pbx_extension_helper: Launching 'Set'
    -- Executing [233@commzilla-agent:2] Set("Local/233@commzilla-agent-ce09,2", "DND=") in new stack
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '0'
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1843 pbx_extension_helper: Launching 'GotoIf'
Really destroying SIP dialog '337fce021b43cdba1528e7fb477d4753@99.229.93.248' Method: OPTIONS
    -- Executing [233@commzilla-agent:3] GotoIf("Local/233@commzilla-agent-ce09,2", "0?20") in new stack
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:6042 pbx_builtin_gotoif: Not taking any branch
[Mar  9 20:00:38] DEBUG[21258]: db.c:198 ast_db_get: Unable to find key '233/OutOffice' in family 'commzilla'
[Mar  9 20:00:38] DEBUG[21258]: func_db.c:70 function_db_read: DB: commzilla/233/OutOffice not found in database.
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is ''
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1843 pbx_extension_helper: Launching 'Set'
    -- Executing [233@commzilla-agent:4] Set("Local/233@commzilla-agent-ce09,2", "OutOffice=") in new stack
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '0'
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1843 pbx_extension_helper: Launching 'GotoIf'
    -- Executing [233@commzilla-agent:5] GotoIf("Local/233@commzilla-agent-ce09,2", "0?20") in new stack
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:6042 pbx_builtin_gotoif: Not taking any branch
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '0'
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '0'
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '0'
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1843 pbx_extension_helper: Launching 'Set'
    -- Executing [233@commzilla-agent:6] Set("Local/233@commzilla-agent-ce09,2", "GROUPCOUNT=0") in new stack
[Mar  9 20:00:38] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:38] DEBUG[21258]: db.c:198 ast_db_get: Unable to find key 'agent/1/maxcalls' in family 'commzilla'
[Mar  9 20:00:38] DEBUG[21258]: func_db.c:70 function_db_read: DB: commzilla/agent/1/maxcalls not found in database.
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is ''
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1843 pbx_extension_helper: Launching 'Set'
    -- Executing [233@commzilla-agent:7] Set("Local/233@commzilla-agent-ce09,2", "AGENTMAXCALL=") in new stack
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '1'
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '9'
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '10'
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1843 pbx_extension_helper: Launching 'GotoIf'
    -- Executing [233@commzilla-agent:8] GotoIf("Local/233@commzilla-agent-ce09,2", "1?9:10") in new stack
    -- Goto (commzilla-agent,233,9)
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1843 pbx_extension_helper: Launching 'Set'
    -- Executing [233@commzilla-agent:9] Set("Local/233@commzilla-agent-ce09,2", "AGENTMAXCALL=1") in new stack
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '0'
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1843 pbx_extension_helper: Launching 'GotoIf'
    -- Executing [233@commzilla-agent:10] GotoIf("Local/233@commzilla-agent-ce09,2", "0?20") in new stack
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:6042 pbx_builtin_gotoif: Not taking any branch
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '1'
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '14'
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1843 pbx_extension_helper: Launching 'GotoIf'
    -- Executing [233@commzilla-agent:11] GotoIf("Local/233@commzilla-agent-ce09,2", "1?14") in new stack
[Mar  9 20:00:38] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
    -- Goto (commzilla-agent,233,14)
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1843 pbx_extension_helper: Launching 'Set'
    -- Executing [233@commzilla-agent:14] Set("Local/233@commzilla-agent-ce09,2", "OUTBOUND_GROUP_ONCE=233@INCOMING") in new stack
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1843 pbx_extension_helper: Launching 'Set'
    -- Executing [233@commzilla-agent:15] Set("Local/233@commzilla-agent-ce09,2", "DB(commzilla/wrapup/233/lastcall)=1236643238.256") in new stack
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1843 pbx_extension_helper: Launching 'Goto'
    -- Executing [233@commzilla-agent:16] Goto("Local/233@commzilla-agent-ce09,2", "commzilla-local-devices|233|1") in new stack
    -- Goto (commzilla-local-devices,233,1)
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1843 pbx_extension_helper: Launching 'Set'
    -- Executing [233@commzilla-local-devices:1] Set("Local/233@commzilla-agent-ce09,2", "DB(commzilla/wrapup/233/lastcall)=1236643238.256") in new stack
[Mar  9 20:00:38] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:38] DEBUG[21258]: pbx.c:1843 pbx_extension_helper: Launching 'Dial'
    -- Executing [233@commzilla-local-devices:2] Dial("Local/233@commzilla-agent-ce09,2", "SIP/233||twk") in new stack
[Mar  9 20:00:38] DEBUG[21258]: chan_sip.c:16713 sip_request_call: Asked to create a SIP channel with formats: 0x4 (ulaw)
[Mar  9 20:00:38] DEBUG[21258]: chan_sip.c:4621 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP)
[Mar  9 20:00:38] DEBUG[21258]: chan_sip.c:2783 do_setnat: Setting NAT on RTP to Off
[Mar  9 20:00:38] DEBUG[21258]: chan_sip.c:4095 sip_new: *** Our native formats are 0x4 (ulaw) 
[Mar  9 20:00:38] DEBUG[21258]: chan_sip.c:4096 sip_new: *** Joint capabilities are 0x0 (nothing) 
[Mar  9 20:00:38] DEBUG[21258]: chan_sip.c:4097 sip_new: *** Our capabilities are 0x4 (ulaw) 
[Mar  9 20:00:38] DEBUG[21258]: chan_sip.c:4098 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) 
[Mar  9 20:00:38] DEBUG[21258]: chan_sip.c:4100 sip_new: *** Our preferred formats from the incoming channel are 0x4 (ulaw) 
[Mar  9 20:00:38] DEBUG[21258]: chan_sip.c:4121 sip_new: This channel will not be able to handle video.
[Mar  9 20:00:38] DEBUG[21258]: rtp.c:1592 ast_rtp_make_compatible: Channel 'Local/233@commzilla-agent-ce09,2' has no RTP, not doing anything
[Mar  9 20:00:38] DEBUG[21258]: channel.c:3469 ast_channel_inherit_variables: Not copying variable DIALEDTIME.
[Mar  9 20:00:38] DEBUG[21258]: channel.c:3469 ast_channel_inherit_variables: Not copying variable ANSWEREDTIME.
[Mar  9 20:00:38] DEBUG[21258]: channel.c:3469 ast_channel_inherit_variables: Not copying variable DIALEDPEERNAME.
[Mar  9 20:00:38] DEBUG[21258]: channel.c:3469 ast_channel_inherit_variables: Not copying variable DIALEDPEERNUMBER.
[Mar  9 20:00:38] DEBUG[21258]: channel.c:3469 ast_channel_inherit_variables: Not copying variable DIALSTATUS.
[Mar  9 20:00:38] DEBUG[21258]: channel.c:3469 ast_channel_inherit_variables: Not copying variable AGENTMAXCALL.
[Mar  9 20:00:38] DEBUG[21258]: channel.c:3469 ast_channel_inherit_variables: Not copying variable GROUPCOUNT.
[Mar  9 20:00:38] DEBUG[21258]: channel.c:3469 ast_channel_inherit_variables: Not copying variable OutOffice.
[Mar  9 20:00:38] DEBUG[21258]: channel.c:3469 ast_channel_inherit_variables: Not copying variable DND.
[Mar  9 20:00:38] DEBUG[21258]: channel.c:3464 ast_channel_inherit_variables: Copying hard-transferable variable ALLOW_TRANSFER.
[Mar  9 20:00:38] DEBUG[21258]: channel.c:3464 ast_channel_inherit_variables: Copying hard-transferable variable ACD_TO_OUTGOING.
[Mar  9 20:00:38] DEBUG[21258]: channel.c:3464 ast_channel_inherit_variables: Copying hard-transferable variable QUEUENAME.
[Mar  9 20:00:38] DEBUG[21258]: chan_sip.c:3046 sip_call: Outgoing Call for 233
[Mar  9 20:00:38] DEBUG[21258]: chan_sip.c:3252 update_call_counter: Updating call counter for outgoing call
[Mar  9 20:00:38] DEBUG[21258]: chan_sip.c:3329 update_call_counter: Call to peer '233' is 1 out of 4
[Mar  9 20:00:38] DEBUG[21258]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/233
[Mar  9 20:00:38] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233
[Mar  9 20:00:38] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233
[Mar  9 20:00:38] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/233 - state 6 (Ringing)
[Mar  9 20:00:38] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233
[Mar  9 20:00:38] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233
[Mar  9 20:00:38] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233
[Mar  9 20:00:38] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233
 Extension Changed 233[commzilla-local] new state Ringing for Notify User 220 
[Mar  9 20:00:38] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233
[Mar  9 20:00:38] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233
 Extension Changed 233[commzilla-local] new state Ringing for Notify User 300 
[Mar  9 20:00:38] DEBUG[2292]: app_queue.c:681 handle_statechange: Device 'SIP/233' changed to state '6' (Ringing)
[Mar  9 20:00:38] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:38] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'ChanSpy' in family 'commzilla/233'
[Mar  9 20:00:38] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:38] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:38] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'DoNotDisturb' in family 'commzilla/233'
[Mar  9 20:00:38] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:38] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'DoNotDisturb_Reason' in family 'commzilla/233'
[Mar  9 20:00:38] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:38] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:38] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:38] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:38] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'CallWaiting' in family 'commzilla/233'
[Mar  9 20:00:38] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:38] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:38] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'Paused' in family 'commzilla/233/Agent'
[Mar  9 20:00:38] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:38] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'HotDesk' in family 'commzilla/233'
[Mar  9 20:00:38] DEBUG[21258]: chan_sip.c:3061 sip_call: Our T38 capability (3856), joint T38 capability (3856)
[Mar  9 20:00:38] DEBUG[21258]: chan_sip.c:6620 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: False
[Mar  9 20:00:38] DEBUG[21258]: chan_sip.c:6621 add_sdp: ** Our prefcodec: 0x4 (ulaw) 
[Mar  9 20:00:38] DEBUG[21258]: chan_sip.c:6752 add_sdp: -- Done with adding codecs to SDP
[Mar  9 20:00:38] DEBUG[21258]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:38] DEBUG[21258]: chan_sip.c:6797 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw)
    -- Called 233
[Mar  9 20:00:38] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 158ca4b731bdfc67700f46c7644d5271@192.168.192.1 Their Tag  Our tag: as0b6e98b1
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1805017497@192.168.192.157 Their Tag 56902390 Our tag: as46025d57
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2b78dd36 Our tag: as60c40b6a
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3204f887538fb6576aff82994c4e6d88@66.49.255.61 Their Tag as755cac8c Our tag: as4d531303
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7e1d02ca8dc4f41483eedc4d85a79c9d@192.168.192.194 Their Tag 01c18ff2e06534a Our tag: as32e36ce9
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0d59ff5c5d7da93c40fcb25cdbeb58a7@192.168.192.193 Their Tag 6ab4515851df784 Our tag: as01251cbd
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1bee3216-93306860-fb20c5d9@192.168.192.191 Their Tag 664A6EBA-5D17EA5B Our tag: as1b49dc59
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 445fafbb-3f36520d-2950089a@192.168.192.191 Their Tag 256D0FAF-6D161884 Our tag: as12e1b29f
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 9bc65609-d3d27e0b-7ec854d0@192.168.192.191 Their Tag 6B4700DD-971C18AA Our tag: as7ea11f27
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 451
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '9bc65609-d3d27e0b-7ec854d0@192.168.192.191' of Request 451: Match Found
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 158ca4b731bdfc67700f46c7644d5271@192.168.192.1 Their Tag  Our tag: as0b6e98b1
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1805017497@192.168.192.157 Their Tag 56902390 Our tag: as46025d57
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2b78dd36 Our tag: as60c40b6a
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3204f887538fb6576aff82994c4e6d88@66.49.255.61 Their Tag as755cac8c Our tag: as4d531303
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4
[Mar  9 20:00:38] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 291
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '511c90173aab58af' of Request 291: Match Found
[Mar  9 20:00:38] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 158ca4b731bdfc67700f46c7644d5271@192.168.192.1 Their Tag  Our tag: as0b6e98b1
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:2259 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '158ca4b731bdfc67700f46c7644d5271@192.168.192.1' Request 102: Found
[Mar  9 20:00:38] DEBUG[2295]: chan_sip.c:12324 handle_response_invite: SIP response 180 to standard invite
[Mar  9 20:00:38] DEBUG[2295]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/233
[Mar  9 20:00:38] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233
[Mar  9 20:00:38] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233
[Mar  9 20:00:38] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/233 - state 6 (Ringing)
[Mar  9 20:00:38] DEBUG[2292]: app_queue.c:681 handle_statechange: Device 'SIP/233' changed to state '6' (Ringing)
[Mar  9 20:00:38] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233
[Mar  9 20:00:38] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233
    -- SIP/233-b736faa8 is ringing
[Mar  9 20:00:38] DEBUG[21258]: rtp.c:1503 ast_rtp_early_bridge: Channel 'Local/233@commzilla-agent-ce09,2' has no RTP, not doing anything
    -- Local/233@commzilla-agent-ce09,1 is ringing
[Mar  9 20:00:38] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:38] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:38] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:38] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:38] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:38] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:38] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 158ca4b731bdfc67700f46c7644d5271@192.168.192.1 Their Tag 0td3jpcl2s Our tag: as0b6e98b1
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:2259 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '158ca4b731bdfc67700f46c7644d5271@192.168.192.1' Request 102: Found
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:12324 handle_response_invite: SIP response 180 to standard invite
    -- SIP/233-b736faa8 is ringing
[Mar  9 20:00:39] DEBUG[21258]: rtp.c:1503 ast_rtp_early_bridge: Channel 'Local/233@commzilla-agent-ce09,2' has no RTP, not doing anything
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[21258]: rtp.c:879 ast_rtcp_read: Got RTCP report of 68 bytes
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 158ca4b731bdfc67700f46c7644d5271@192.168.192.1 Their Tag 0td3jpcl2s Our tag: as0b6e98b1
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 102
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '158ca4b731bdfc67700f46c7644d5271@192.168.192.1' of Request 102: Match Found
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:12324 handle_response_invite: SIP response 200 to standard invite
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:5568 process_sdp: T38 state changed to 0 on channel SIP/233-b736faa8
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:5648 process_sdp: We're settling with these formats: 0x4 (ulaw)
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:5655 process_sdp: We have an owner, now see if we need to change this call
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:3252 update_call_counter: Updating call counter for outgoing call
[Mar  9 20:00:39] DEBUG[2295]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/233
[Mar  9 20:00:39] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:8503 build_route: build_route: Contact hop: <sip:233@192.168.192.189:5060;line=6et1aw7d>;reg-id=1
[Mar  9 20:00:39] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233
[Mar  9 20:00:39] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/233 - state 2 (In use)
[Mar  9 20:00:39] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233
[Mar  9 20:00:39] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233
[Mar  9 20:00:39] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233
[Mar  9 20:00:39] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233
 Extension Changed 233[commzilla-local] new state InUse for Notify User 220 
[Mar  9 20:00:39] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233
[Mar  9 20:00:39] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233
 Extension Changed 233[commzilla-local] new state InUse for Notify User 300 
[Mar  9 20:00:39] DEBUG[21258]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/233
    -- SIP/233-b736faa8 answered Local/233@commzilla-agent-ce09,2
[Mar  9 20:00:39] DEBUG[20497]: app_queue.c:2309 wait_for_answer: Dunno what to do with control type -1
[Mar  9 20:00:39] DEBUG[20497]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/233@commzilla-agent
    -- Local/233@commzilla-agent-ce09,1 answered SIP/222-08566178
[Mar  9 20:00:39] DEBUG[20497]: channel.c:2961 set_format: Set channel SIP/222-08566178 to write format ulaw
    -- Stopped music on hold on SIP/222-08566178
[Mar  9 20:00:39] DEBUG[20497]: app_queue.c:3079 try_calling: Starting MixMonitor as requested.
[Mar  9 20:00:39] DEBUG[20497]: app_queue.c:3137 try_calling: Arguments being passed to MixMonitor: 1236643233.254.wav49|b
[Mar  9 20:00:39] DEBUG[2292]: app_queue.c:681 handle_statechange: Device 'SIP/233' changed to state '2' (In use)
[Mar  9 20:00:39] DEBUG[21258]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/233@commzilla-agent
  == Begin MixMonitor Recording SIP/222-08566178
[Mar  9 20:00:39] DEBUG[20497]: app_queue.c:1699 leave_queue: Queue 'commzilla-sales' Leave, Channel 'SIP/222-08566178'
[Mar  9 20:00:39] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:39] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'ChanSpy' in family 'commzilla/233'
[Mar  9 20:00:39] DEBUG[20497]: channel.c:3995 ast_generic_bridge: Got a FRAME_CONTROL (-1) frame on channel Local/233@commzilla-agent-ce09,1
[Mar  9 20:00:39] DEBUG[20497]: channel.c:4311 ast_channel_bridge: Bridge stops bridging channels SIP/222-08566178 and Local/233@commzilla-agent-ce09,1
[Mar  9 20:00:39] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:39] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'DoNotDisturb' in family 'commzilla/233'
[Mar  9 20:00:39] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:39] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'DoNotDisturb_Reason' in family 'commzilla/233'
[Mar  9 20:00:39] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:39] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:39] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:39] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:39] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'CallWaiting' in family 'commzilla/233'
[Mar  9 20:00:39] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:39] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:39] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'Paused' in family 'commzilla/233/Agent'
[Mar  9 20:00:39] DEBUG[21258]: rtp.c:2781 ast_rtp_write: Ooh, format changed from unknown to ulaw
[Mar  9 20:00:39] DEBUG[21258]: rtp.c:2798 ast_rtp_write: Created smoother: format: 4 ms: 20 len: 160
[Mar  9 20:00:39] DEBUG[21735]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x841b97c
[Mar  9 20:00:39] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:39] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'HotDesk' in family 'commzilla/233'
[Mar  9 20:00:39] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233
[Mar  9 20:00:39] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233
[Mar  9 20:00:39] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/233 - state 2 (In use)
[Mar  9 20:00:39] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233
[Mar  9 20:00:39] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233
[Mar  9 20:00:39] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 233@commzilla-agent
[Mar  9 20:00:39] DEBUG[2243]: chan_local.c:145 local_devicestate: Checking if extension 233@commzilla-agent exists (devicestate)
[Mar  9 20:00:39] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for Local/233@commzilla-agent - state 2 (In use)
[Mar  9 20:00:39] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 233@commzilla-agent
[Mar  9 20:00:39] DEBUG[2243]: chan_local.c:145 local_devicestate: Checking if extension 233@commzilla-agent exists (devicestate)
[Mar  9 20:00:39] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for Local/233@commzilla-agent - state 2 (In use)
[Mar  9 20:00:39] DEBUG[2292]: app_queue.c:681 handle_statechange: Device 'SIP/233' changed to state '2' (In use)
[Mar  9 20:00:39] DEBUG[2292]: app_queue.c:676 handle_statechange: Device 'Local/233@commzilla-agent' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Mar  9 20:00:39] DEBUG[2292]: app_queue.c:676 handle_statechange: Device 'Local/233@commzilla-agent' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Mar  9 20:00:39] DEBUG[21735]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x841b97c
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 158ca4b731bdfc67700f46c7644d5271@192.168.192.1 Their Tag 0td3jpcl2s Our tag: as0b6e98b1
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1805017497@192.168.192.157 Their Tag 56902390 Our tag: as46025d57
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2b78dd36 Our tag: as60c40b6a
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3204f887538fb6576aff82994c4e6d88@66.49.255.61 Their Tag as755cac8c Our tag: as4d531303
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 292
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '511c90173aab58af' of Request 292: Match Found
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 158ca4b731bdfc67700f46c7644d5271@192.168.192.1 Their Tag 0td3jpcl2s Our tag: as0b6e98b1
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1805017497@192.168.192.157 Their Tag 56902390 Our tag: as46025d57
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2b78dd36 Our tag: as60c40b6a
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3204f887538fb6576aff82994c4e6d88@66.49.255.61 Their Tag as755cac8c Our tag: as4d531303
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7e1d02ca8dc4f41483eedc4d85a79c9d@192.168.192.194 Their Tag 01c18ff2e06534a Our tag: as32e36ce9
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0d59ff5c5d7da93c40fcb25cdbeb58a7@192.168.192.193 Their Tag 6ab4515851df784 Our tag: as01251cbd
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1bee3216-93306860-fb20c5d9@192.168.192.191 Their Tag 664A6EBA-5D17EA5B Our tag: as1b49dc59
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 445fafbb-3f36520d-2950089a@192.168.192.191 Their Tag 256D0FAF-6D161884 Our tag: as12e1b29f
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 9bc65609-d3d27e0b-7ec854d0@192.168.192.191 Their Tag 6B4700DD-971C18AA Our tag: as7ea11f27
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 452
[Mar  9 20:00:39] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '9bc65609-d3d27e0b-7ec854d0@192.168.192.191' of Request 452: Match Found
[Mar  9 20:00:39] DEBUG[21735]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x841b97c
[Mar  9 20:00:39] DEBUG[21735]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x841b97c
[Mar  9 20:00:39] DEBUG[21735]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x841b97c
[Mar  9 20:00:39] DEBUG[21735]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x841b97c
[Mar  9 20:00:39] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:39] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:39] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:39] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:39] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:39] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:39] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:39] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:40] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[2295]: chan_sip.c:4621 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 0ae9236f3060e4ad7b7ae6d42d9b5cc3@192.168.192.1 Their Tag  Our tag: as4a0b823e
[Mar  9 20:00:41] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '0ae9236f3060e4ad7b7ae6d42d9b5cc3@192.168.192.1' of Request 102: Match Found
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
Really destroying SIP dialog '0ae9236f3060e4ad7b7ae6d42d9b5cc3@192.168.192.1' Method: OPTIONS
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:41] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[23214]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[23214]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4621 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x841af60 was pretty quick last time, waiting for them.
[Mar  9 20:00:42] DEBUG[5063]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 50c891f226d3a77a101ab5d3261b8436@192.168.192.1 Their Tag  Our tag: as616a1c71
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '50c891f226d3a77a101ab5d3261b8436@192.168.192.1' of Request 102: Match Found
Really destroying SIP dialog '50c891f226d3a77a101ab5d3261b8436@192.168.192.1' Method: OPTIONS
[Mar  9 20:00:42] DEBUG[5063]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x841b97c
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x841b97c
[Mar  9 20:00:42] DEBUG[21735]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x841b97c
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 158ca4b731bdfc67700f46c7644d5271@192.168.192.1 Their Tag 0td3jpcl2s Our tag: as0b6e98b1
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:15870 handle_request: **** Received BYE (8) - Command in SIP BYE
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:1675 sip_alreadygone: Setting SIP_ALREADYGONE on dialog 158ca4b731bdfc67700f46c7644d5271@192.168.192.1
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:15408 handle_request_bye: Received bye, issuing owner hangup
[Mar  9 20:00:42] DEBUG[21258]: channel.c:3968 ast_generic_bridge: Didn't get a frame from channel: SIP/233-b736faa8
[Mar  9 20:00:42] DEBUG[21258]: channel.c:4311 ast_channel_bridge: Bridge stops bridging channels Local/233@commzilla-agent-ce09,2 and SIP/233-b736faa8
[Mar  9 20:00:42] DEBUG[21258]: channel.c:1520 ast_hangup: Hanging up channel 'SIP/233-b736faa8'
[Mar  9 20:00:42] DEBUG[21258]: chan_sip.c:3569 sip_hangup: Hangup call SIP/233-b736faa8, SIP callid 158ca4b731bdfc67700f46c7644d5271@192.168.192.1)
[Mar  9 20:00:42] DEBUG[21258]: chan_sip.c:3252 update_call_counter: Updating call counter for outgoing call
[Mar  9 20:00:42] DEBUG[21258]: chan_sip.c:3303 update_call_counter: Call to peer '233' removed from call limit 4
[Mar  9 20:00:42] DEBUG[21258]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/233
[Mar  9 20:00:42] DEBUG[21258]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/233
[Mar  9 20:00:42] DEBUG[21258]: rtp.c:1503 ast_rtp_early_bridge: Channel 'Local/233@commzilla-agent-ce09,2' has no RTP, not doing anything
[Mar  9 20:00:42] DEBUG[21258]: app_dial.c:1786 dial_exec_full: Exiting with DIALSTATUS=ANSWER.
[Mar  9 20:00:42] DEBUG[21258]: pbx.c:2428 __ast_pbx_run: Spawn extension (commzilla-local-devices,233,2) exited non-zero on 'Local/233@commzilla-agent-ce09,2'
  == Spawn extension (commzilla-local-devices, 233, 2) exited non-zero on 'Local/233@commzilla-agent-ce09,2'
[Mar  9 20:00:42] DEBUG[21258]: channel.c:1427 ast_softhangup_nolock: Soft-Hanging up channel 'Local/233@commzilla-agent-ce09,2'
[Mar  9 20:00:42] DEBUG[21258]: channel.c:1520 ast_hangup: Hanging up channel 'Local/233@commzilla-agent-ce09,2'
[Mar  9 20:00:42] DEBUG[21258]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/233@commzilla-agent
[Mar  9 20:00:42] DEBUG[20497]: channel.c:3968 ast_generic_bridge: Didn't get a frame from channel: Local/233@commzilla-agent-ce09,1
[Mar  9 20:00:42] DEBUG[20497]: channel.c:4311 ast_channel_bridge: Bridge stops bridging channels SIP/222-08566178 and Local/233@commzilla-agent-ce09,1
[Mar  9 20:00:42] DEBUG[20497]: cdr_addon_mysql.c:228 mysql_log: cdr_mysql: inserting a CDR record.
[Mar  9 20:00:42] DEBUG[20497]: cdr_addon_mysql.c:245 mysql_log: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2009-03-09 20:00:33','\"SALES:WiFi\" <222>','222','s','commzilla-application-acd-sales', 'SIP/222-08566178','Local/233@commzilla-agent-ce09,1','Queue','commzilla-sales|tH|||300|',9,9,'ANSWERED',3,'222','1236643233.254','')
[Mar  9 20:00:42] DEBUG[20497]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '"SALES:WiFi" <222>'
[Mar  9 20:00:42] DEBUG[20497]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '222'
[Mar  9 20:00:42] DEBUG[20497]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is 's'
[Mar  9 20:00:42] DEBUG[20497]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is 'commzilla-application-acd-sales'
[Mar  9 20:00:42] DEBUG[20497]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is 'SIP/222-08566178'
[Mar  9 20:00:42] DEBUG[20497]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is 'Local/233@commzilla-agent-ce09,1'
[Mar  9 20:00:42] DEBUG[20497]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is 'Queue'
[Mar  9 20:00:42] DEBUG[20497]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is 'commzilla-sales|tH|||300|'
[Mar  9 20:00:42] DEBUG[20497]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '2009-03-09 20:00:33'
[Mar  9 20:00:42] DEBUG[20497]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '2009-03-09 20:00:33'
[Mar  9 20:00:42] DEBUG[20497]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '2009-03-09 20:00:42'
[Mar  9 20:00:42] DEBUG[20497]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '9'
[Mar  9 20:00:42] DEBUG[20497]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '9'
[Mar  9 20:00:42] DEBUG[20497]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is 'ANSWERED'
[Mar  9 20:00:42] DEBUG[20497]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION'
[Mar  9 20:00:42] DEBUG[20497]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '222'
[Mar  9 20:00:42] DEBUG[20497]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '1236643233.254'
[Mar  9 20:00:42] DEBUG[20497]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '(null)'
[Mar  9 20:00:42] DEBUG[20497]: cdr_radius.c:221 radius_log: Unable to create RADIUS record. CDR not recorded!
[Mar  9 20:00:42] DEBUG[20497]: channel.c:1520 ast_hangup: Hanging up channel 'Local/233@commzilla-agent-ce09,1'
[Mar  9 20:00:42] DEBUG[20497]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/233@commzilla-agent
[Mar  9 20:00:42] DEBUG[20497]: pbx.c:2428 __ast_pbx_run: Spawn extension (commzilla-application-acd-sales,s,14) exited non-zero on 'SIP/222-08566178'
  == Spawn extension (commzilla-application-acd-sales, s, 14) exited non-zero on 'SIP/222-08566178'
[Mar  9 20:00:42] DEBUG[20497]: channel.c:1427 ast_softhangup_nolock: Soft-Hanging up channel 'SIP/222-08566178'
[Mar  9 20:00:42] DEBUG[20497]: channel.c:1520 ast_hangup: Hanging up channel 'SIP/222-08566178'
[Mar  9 20:00:42] DEBUG[20497]: chan_sip.c:3569 sip_hangup: Hangup call SIP/222-08566178, SIP callid 1805017497@192.168.192.157)
[Mar  9 20:00:42] DEBUG[20497]: chan_sip.c:3252 update_call_counter: Updating call counter for incoming call
[Mar  9 20:00:42] DEBUG[20497]: chan_sip.c:3303 update_call_counter: Call from peer '222' removed from call limit 8
[Mar  9 20:00:42] DEBUG[20497]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/222
[Mar  9 20:00:42] DEBUG[20497]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/222
[Mar  9 20:00:42] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233
[Mar  9 20:00:42] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233
[Mar  9 20:00:42] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/233 - state 1 (Not in use)
[Mar  9 20:00:42] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233
[Mar  9 20:00:42] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233
[Mar  9 20:00:42] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233
[Mar  9 20:00:42] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233
 Extension Changed 233[commzilla-local] new state Idle for Notify User 220 
[Mar  9 20:00:42] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233
[Mar  9 20:00:42] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233
 Extension Changed 233[commzilla-local] new state Idle for Notify User 300 
[Mar  9 20:00:42] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233
[Mar  9 20:00:42] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233
[Mar  9 20:00:42] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/233 - state 1 (Not in use)
[Mar  9 20:00:42] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233
[Mar  9 20:00:42] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233
[Mar  9 20:00:42] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 233@commzilla-agent
[Mar  9 20:00:42] DEBUG[2243]: chan_local.c:145 local_devicestate: Checking if extension 233@commzilla-agent exists (devicestate)
[Mar  9 20:00:42] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for Local/233@commzilla-agent - state 1 (Not in use)
[Mar  9 20:00:42] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 233@commzilla-agent
[Mar  9 20:00:42] DEBUG[2243]: chan_local.c:145 local_devicestate: Checking if extension 233@commzilla-agent exists (devicestate)
[Mar  9 20:00:42] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for Local/233@commzilla-agent - state 1 (Not in use)
[Mar  9 20:00:42] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222
[Mar  9 20:00:42] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222
[Mar  9 20:00:42] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/222 - state 1 (Not in use)
[Mar  9 20:00:42] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222
[Mar  9 20:00:42] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222
[Mar  9 20:00:42] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222
[Mar  9 20:00:42] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222
 Extension Changed 222[commzilla-local] new state Idle for Notify User 220 
[Mar  9 20:00:42] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222
[Mar  9 20:00:42] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222
 Extension Changed 222[commzilla-local] new state Idle for Notify User 300 
[Mar  9 20:00:42] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222
[Mar  9 20:00:42] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222
[Mar  9 20:00:42] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/222 - state 1 (Not in use)
[Mar  9 20:00:42] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222
[Mar  9 20:00:42] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222
  == End MixMonitor Recording SIP/222-08566178
[Mar  9 20:00:42] DEBUG[2292]: app_queue.c:681 handle_statechange: Device 'SIP/233' changed to state '1' (Not in use)
[Mar  9 20:00:42] DEBUG[2292]: app_queue.c:681 handle_statechange: Device 'SIP/233' changed to state '1' (Not in use)
[Mar  9 20:00:42] DEBUG[2292]: app_queue.c:676 handle_statechange: Device 'Local/233@commzilla-agent' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Mar  9 20:00:42] DEBUG[2292]: app_queue.c:676 handle_statechange: Device 'Local/233@commzilla-agent' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Mar  9 20:00:42] DEBUG[2292]: app_queue.c:676 handle_statechange: Device 'SIP/222' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Mar  9 20:00:42] DEBUG[2292]: app_queue.c:676 handle_statechange: Device 'SIP/222' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
Really destroying SIP dialog '158ca4b731bdfc67700f46c7644d5271@192.168.192.1' Method: BYE
[Mar  9 20:00:42] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'ChanSpy' in family 'commzilla/233'
[Mar  9 20:00:42] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'ChanSpy' in family 'commzilla/222'
[Mar  9 20:00:42] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'DoNotDisturb' in family 'commzilla/222'
[Mar  9 20:00:42] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'DoNotDisturb_Reason' in family 'commzilla/222'
[Mar  9 20:00:42] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'CallWaiting' in family 'commzilla/222'
[Mar  9 20:00:42] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'Login' in family 'commzilla/222/Agent'
[Mar  9 20:00:42] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'Paused' in family 'commzilla/222/Agent'
[Mar  9 20:00:42] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'HotDesk' in family 'commzilla/222'
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1805017497@192.168.192.157 Their Tag 56902390 Our tag: as46025d57
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2b78dd36 Our tag: as60c40b6a
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3204f887538fb6576aff82994c4e6d88@66.49.255.61 Their Tag as755cac8c Our tag: as4d531303
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7e1d02ca8dc4f41483eedc4d85a79c9d@192.168.192.194 Their Tag 01c18ff2e06534a Our tag: as32e36ce9
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0d59ff5c5d7da93c40fcb25cdbeb58a7@192.168.192.193 Their Tag 6ab4515851df784 Our tag: as01251cbd
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1bee3216-93306860-fb20c5d9@192.168.192.191 Their Tag 664A6EBA-5D17EA5B Our tag: as1b49dc59
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 445fafbb-3f36520d-2950089a@192.168.192.191 Their Tag 256D0FAF-6D161884 Our tag: as12e1b29f
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 9bc65609-d3d27e0b-7ec854d0@192.168.192.191 Their Tag 6B4700DD-971C18AA Our tag: as7ea11f27
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 453
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '9bc65609-d3d27e0b-7ec854d0@192.168.192.191' of Request 453: Match Found
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1805017497@192.168.192.157 Their Tag 56902390 Our tag: as46025d57
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2b78dd36 Our tag: as60c40b6a
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3204f887538fb6576aff82994c4e6d88@66.49.255.61 Their Tag as755cac8c Our tag: as4d531303
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 293
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '511c90173aab58af' of Request 293: Match Found
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1805017497@192.168.192.157 Their Tag 56902390 Our tag: as46025d57
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2b78dd36 Our tag: as60c40b6a
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3204f887538fb6576aff82994c4e6d88@66.49.255.61 Their Tag as755cac8c Our tag: as4d531303
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7e1d02ca8dc4f41483eedc4d85a79c9d@192.168.192.194 Their Tag 01c18ff2e06534a Our tag: as32e36ce9
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 760
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on 'a5283085413b819d' of Request 760: Match Found
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1805017497@192.168.192.157 Their Tag 56902390 Our tag: as46025d57
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2b78dd36 Our tag: as60c40b6a
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3204f887538fb6576aff82994c4e6d88@66.49.255.61 Their Tag as755cac8c Our tag: as4d531303
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7e1d02ca8dc4f41483eedc4d85a79c9d@192.168.192.194 Their Tag 01c18ff2e06534a Our tag: as32e36ce9
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0d59ff5c5d7da93c40fcb25cdbeb58a7@192.168.192.193 Their Tag 6ab4515851df784 Our tag: as01251cbd
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1bee3216-93306860-fb20c5d9@192.168.192.191 Their Tag 664A6EBA-5D17EA5B Our tag: as1b49dc59
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 445fafbb-3f36520d-2950089a@192.168.192.191 Their Tag 256D0FAF-6D161884 Our tag: as12e1b29f
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 9bc65609-d3d27e0b-7ec854d0@192.168.192.191 Their Tag 6B4700DD-971C18AA Our tag: as7ea11f27
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 958a807e-bb07d908-e3592421@192.168.192.191 Their Tag 3202BA2-88C03DE3 Our tag: as7a128639
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 4891da07-ac8f8739-f79accf6@192.168.192.191 Their Tag 50571ABB-91D94E40 Our tag: as57f441f2
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 6a8e83f4-e3aa426e-f220365f@192.168.192.191 Their Tag EF679478-F5E3DF51 Our tag: as16a462c8
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: ff51f8d5-43fc9fb7-e2e27ac@192.168.192.191 Their Tag 15E48C69-7BB4C0E6 Our tag: as6967dce3
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 920
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on 'ff51f8d5-43fc9fb7-e2e27ac@192.168.192.191' of Request 920: Match Found
[Mar  9 20:00:42] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'DoNotDisturb' in family 'commzilla/233'
[Mar  9 20:00:42] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'DoNotDisturb_Reason' in family 'commzilla/233'
[Mar  9 20:00:42] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[23214]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'CallWaiting' in family 'commzilla/233'
[Mar  9 20:00:42] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'Paused' in family 'commzilla/233/Agent'
[Mar  9 20:00:42] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command'
[Mar  9 20:00:42] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'HotDesk' in family 'commzilla/233'
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 1805017497@192.168.192.157 Their Tag 56902390 Our tag: as46025d57
[Mar  9 20:00:42] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '1805017497@192.168.192.157' of Request 102: Match Found
Really destroying SIP dialog '1805017497@192.168.192.157' Method: ACK
[Mar  9 20:00:42] DEBUG[3855]: manager.c:2184 process_message: Manager received command 'QueueStatus'
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4621 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:3361 sip_destroy: Destroying SIP dialog 426d737d09eabad01169a1e77083115b@99.229.93.248
Really destroying SIP dialog '426d737d09eabad01169a1e77083115b@99.229.93.248' Method: OPTIONS
[Mar  9 20:00:46] DEBUG[2295]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/230
[Mar  9 20:00:46] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 230
[Mar  9 20:00:46] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 230
[Mar  9 20:00:46] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/230 - state 5 (Unavailable)
[Mar  9 20:00:46] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 230
[Mar  9 20:00:46] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 230
[Mar  9 20:00:46] DEBUG[2292]: app_queue.c:676 handle_statechange: Device 'SIP/230' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue.
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2b78dd36 Our tag: as60c40b6a
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3204f887538fb6576aff82994c4e6d88@66.49.255.61 Their Tag as755cac8c Our tag: as4d531303
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7e1d02ca8dc4f41483eedc4d85a79c9d@192.168.192.194 Their Tag 01c18ff2e06534a Our tag: as32e36ce9
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0d59ff5c5d7da93c40fcb25cdbeb58a7@192.168.192.193 Their Tag 6ab4515851df784 Our tag: as01251cbd
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1bee3216-93306860-fb20c5d9@192.168.192.191 Their Tag 664A6EBA-5D17EA5B Our tag: as1b49dc59
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 445fafbb-3f36520d-2950089a@192.168.192.191 Their Tag 256D0FAF-6D161884 Our tag: as12e1b29f
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 9bc65609-d3d27e0b-7ec854d0@192.168.192.191 Their Tag 6B4700DD-971C18AA Our tag: as7ea11f27
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 958a807e-bb07d908-e3592421@192.168.192.191 Their Tag 3202BA2-88C03DE3 Our tag: as7a128639
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 4891da07-ac8f8739-f79accf6@192.168.192.191 Their Tag 50571ABB-91D94E40 Our tag: as57f441f2
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 6a8e83f4-e3aa426e-f220365f@192.168.192.191 Their Tag EF679478-F5E3DF51 Our tag: as16a462c8
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: ff51f8d5-43fc9fb7-e2e27ac@192.168.192.191 Their Tag 15E48C69-7BB4C0E6 Our tag: as6967dce3
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c26701520c0-duvkdwbwjm32 Their Tag 08j0pr3ogj Our tag: as102b506d
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2670151ddc-bnz4m8sg5zgw Their Tag 0wm7jm1qjq Our tag: as6e1f2643
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:16142 sipsock_read: Invalid SIP message - rejected , no callid, len 579
[Mar  9 20:00:46] DEBUG[2295]: chan_sip.c:4621 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Mar  9 20:00:47] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 113a1140246ef11f6b09c66558e56021@192.168.192.1 Their Tag  Our tag: as07a5900f
[Mar  9 20:00:47] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '113a1140246ef11f6b09c66558e56021@192.168.192.1' of Request 102: Match Found
Really destroying SIP dialog '113a1140246ef11f6b09c66558e56021@192.168.192.1' Method: OPTIONS
[Mar  9 20:00:49] DEBUG[2295]: chan_sip.c:4621 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Mar  9 20:00:50] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 2f4542721c0367136197e74772a9f35c@192.168.192.1 Their Tag  Our tag: as6de2f0da
[Mar  9 20:00:50] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '2f4542721c0367136197e74772a9f35c@192.168.192.1' of Request 102: Match Found
Really destroying SIP dialog '2f4542721c0367136197e74772a9f35c@192.168.192.1' Method: OPTIONS
[Mar  9 20:00:50] DEBUG[2256]: chan_iax2.c:8138 socket_process: Peer iaxmodem0: got pong, lastms 1, historicms 1, maxms 2000
[Mar  9 20:00:50] DEBUG[2263]: chan_iax2.c:5465 raw_hangup: Raw Hangup 127.0.0.1:4570, src=12573, dst=25815
[Mar  9 20:00:52] DEBUG[2295]: chan_sip.c:2121 __sip_autodestruct: Auto destroying SIP dialog '3204f887538fb6576aff82994c4e6d88@66.49.255.61'
[Mar  9 20:00:52] DEBUG[2295]: chan_sip.c:3361 sip_destroy: Destroying SIP dialog 3204f887538fb6576aff82994c4e6d88@66.49.255.61
Really destroying SIP dialog '3204f887538fb6576aff82994c4e6d88@66.49.255.61' Method: OPTIONS
[Mar  9 20:00:53] DEBUG[2295]: chan_sip.c:4621 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Mar  9 20:00:53] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 1f0007bd28710e42335a31b163bb165e@192.168.192.1 Their Tag  Our tag: as09eee9e6
[Mar  9 20:00:53] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '1f0007bd28710e42335a31b163bb165e@192.168.192.1' of Request 102: Match Found
Really destroying SIP dialog '1f0007bd28710e42335a31b163bb165e@192.168.192.1' Method: OPTIONS
[Mar  9 20:00:54] DEBUG[2295]: chan_sip.c:2121 __sip_autodestruct: Auto destroying SIP dialog '41e472780329e01d1562617572cfb440@67.55.31.179'
[Mar  9 20:00:54] DEBUG[2295]: chan_sip.c:3361 sip_destroy: Destroying SIP dialog 41e472780329e01d1562617572cfb440@67.55.31.179
Really destroying SIP dialog '41e472780329e01d1562617572cfb440@67.55.31.179' Method: REGISTER
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4621 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:3361 sip_destroy: Destroying SIP dialog 3bcf8b9f36d39d9f079c2f912e6fd70b@99.229.93.248
Really destroying SIP dialog '3bcf8b9f36d39d9f079c2f912e6fd70b@99.229.93.248' Method: OPTIONS
[Mar  9 20:00:56] DEBUG[2295]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/230
[Mar  9 20:00:56] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 230
[Mar  9 20:00:56] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 230
[Mar  9 20:00:56] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/230 - state 5 (Unavailable)
[Mar  9 20:00:56] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 230
[Mar  9 20:00:56] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 230
[Mar  9 20:00:56] DEBUG[2292]: app_queue.c:676 handle_statechange: Device 'SIP/230' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue.
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7e1d02ca8dc4f41483eedc4d85a79c9d@192.168.192.194 Their Tag 01c18ff2e06534a Our tag: as32e36ce9
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0d59ff5c5d7da93c40fcb25cdbeb58a7@192.168.192.193 Their Tag 6ab4515851df784 Our tag: as01251cbd
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1bee3216-93306860-fb20c5d9@192.168.192.191 Their Tag 664A6EBA-5D17EA5B Our tag: as1b49dc59
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 445fafbb-3f36520d-2950089a@192.168.192.191 Their Tag 256D0FAF-6D161884 Our tag: as12e1b29f
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 9bc65609-d3d27e0b-7ec854d0@192.168.192.191 Their Tag 6B4700DD-971C18AA Our tag: as7ea11f27
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 958a807e-bb07d908-e3592421@192.168.192.191 Their Tag 3202BA2-88C03DE3 Our tag: as7a128639
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 4891da07-ac8f8739-f79accf6@192.168.192.191 Their Tag 50571ABB-91D94E40 Our tag: as57f441f2
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 6a8e83f4-e3aa426e-f220365f@192.168.192.191 Their Tag EF679478-F5E3DF51 Our tag: as16a462c8
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: ff51f8d5-43fc9fb7-e2e27ac@192.168.192.191 Their Tag 15E48C69-7BB4C0E6 Our tag: as6967dce3
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c26701520c0-duvkdwbwjm32 Their Tag 08j0pr3ogj Our tag: as102b506d
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2670151ddc-bnz4m8sg5zgw Their Tag 0wm7jm1qjq Our tag: as6e1f2643
[Mar  9 20:00:56] DEBUG[2295]: chan_sip.c:16142 sipsock_read: Invalid SIP message - rejected , no callid, len 579