[Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4 [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77 [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc [Mar 9 19:55:01] 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 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264 [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744 [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9 [Mar 9 19:55:01] 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 19:55:01] 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 19:55:01] 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 19:55:01] 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 19:55:01] 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 19:55:01] 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 19:55:01] 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 19:55:01] 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 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c26701520c0-duvkdwbwjm32 Their Tag 08j0pr3ogj Our tag: as102b506d [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2670151ddc-bnz4m8sg5zgw Their Tag 0wm7jm1qjq Our tag: as6e1f2643 [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:2783 do_setnat: Setting NAT on RTP to Off [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:2788 do_setnat: Setting NAT on VRTP to Off [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:2793 do_setnat: Setting NAT on UDPTL to Off [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4621 sip_alloc: Allocating new SIP dialog for 8702016@192.168.192.157 - INVITE (With RTP) [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:15870 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:2783 do_setnat: Setting NAT on RTP to Off [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:2788 do_setnat: Setting NAT on VRTP to Off [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:2793 do_setnat: Setting NAT on UDPTL to Off [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 8702016@192.168.192.157 Their Tag 419718679 Our tag: as03511d4f [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:15870 handle_request: **** Received ACK (6) - Command in SIP ACK [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '8702016@192.168.192.157' of Response 20: Match Found [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 8702016@192.168.192.157 Their Tag 419718679 Our tag: as03511d4f [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:15870 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:2783 do_setnat: Setting NAT on RTP to Off [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:2788 do_setnat: Setting NAT on VRTP to Off [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:2793 do_setnat: Setting NAT on UDPTL to Off [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:5568 process_sdp: T38 state changed to 0 on channel [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:5648 process_sdp: We're settling with these formats: 0x104 (ulaw|g729) [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:14506 handle_request_invite: Checking SIP call limits for device 222 [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:3252 update_call_counter: Updating call counter for incoming call [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:3329 update_call_counter: Call from peer '222' is 1 out of 8 [Mar 9 19:55:01] DEBUG[2295]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/222 [Mar 9 19:55:01] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222 [Mar 9 19:55:01] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222 [Mar 9 19:55:01] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/222 - state 2 (In use) [Mar 9 19:55:01] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222 [Mar 9 19:55:01] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222 [Mar 9 19:55:01] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222 [Mar 9 19:55:01] 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 19:55:01] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222 [Mar 9 19:55:01] 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 19:55:01] 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 19:55:01] DEBUG[2295]: chan_sip.c:4095 sip_new: *** Our native formats are 0x4 (ulaw) [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4096 sip_new: *** Joint capabilities are 0x104 (ulaw|g729) [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4097 sip_new: *** Our capabilities are 0x104 (ulaw|g729) [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4098 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4121 sip_new: This channel will not be able to handle video. [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:8503 build_route: build_route: Contact hop: [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:14589 handle_request_invite: SIP/222-b736faa8: New call is still down.... Trying... [Mar 9 19:55:01] DEBUG[2295]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/222 [Mar 9 19:55:01] DEBUG[1269]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '222' [Mar 9 19:55:01] DEBUG[1269]: pbx.c:1843 pbx_extension_helper: Launching 'Set' -- Executing [*850@commzilla-super:1] Set("SIP/222-b736faa8", "GROUP(OUTGOING)=222") in new stack [Mar 9 19:55:01] DEBUG[1269]: pbx.c:1843 pbx_extension_helper: Launching 'Answer' -- Executing [*850@commzilla-super:2] Answer("SIP/222-b736faa8", "") in new stack [Mar 9 19:55:01] DEBUG[1269]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/222 [Mar 9 19:55:01] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222 [Mar 9 19:55:01] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222 [Mar 9 19:55:01] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/222 - state 2 (In use) [Mar 9 19:55:01] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222 [Mar 9 19:55:01] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222 [Mar 9 19:55:01] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222 [Mar 9 19:55:01] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222 [Mar 9 19:55:01] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/222 - state 2 (In use) [Mar 9 19:55:01] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222 [Mar 9 19:55:01] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222 [Mar 9 19:55:01] 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 19:55:01] DEBUG[1269]: chan_sip.c:3730 sip_answer: SIP answering channel: SIP/222-b736faa8 [Mar 9 19:55:01] DEBUG[1269]: chan_sip.c:6856 transmit_response_with_sdp: Setting framing from config on incoming call [Mar 9 19:55:01] DEBUG[1269]: chan_sip.c:6620 add_sdp: ** Our capability: 0x104 (ulaw|g729) Video flag: True [Mar 9 19:55:01] DEBUG[1269]: chan_sip.c:6621 add_sdp: ** Our prefcodec: 0x0 (nothing) [Mar 9 19:55:01] DEBUG[1269]: chan_sip.c:6752 add_sdp: -- Done with adding codecs to SDP [Mar 9 19:55:01] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:01] DEBUG[1269]: chan_sip.c:6797 add_sdp: Done building SDP. Settling with this capability: 0x104 (ulaw|g729) [Mar 9 19:55:01] 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 19:55:01] DEBUG[1269]: pbx.c:1843 pbx_extension_helper: Launching 'Set' -- Executing [*850@commzilla-super:3] Set("SIP/222-b736faa8", "QUEUE_PRIO=0") in new stack [Mar 9 19:55:01] DEBUG[1269]: pbx.c:1843 pbx_extension_helper: Launching 'Goto' -- Executing [*850@commzilla-super:4] Goto("SIP/222-b736faa8", "commzilla-application-acd-sales|s|1") in new stack -- Goto (commzilla-application-acd-sales,s,1) [Mar 9 19:55:01] DEBUG[1269]: pbx.c:1843 pbx_extension_helper: Launching 'NoOp' -- Executing [s@commzilla-application-acd-sales:1] NoOp("SIP/222-b736faa8", ""=== START QUEUE (commzilla-sales) ==="") in new stack [Mar 9 19:55:01] DEBUG[1269]: pbx.c:1843 pbx_extension_helper: Launching 'Set' -- Executing [s@commzilla-application-acd-sales:2] Set("SIP/222-b736faa8", "__QUEUENAME=commzilla-sales") in new stack [Mar 9 19:55:01] DEBUG[1269]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '0' [Mar 9 19:55:01] DEBUG[1269]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '6' [Mar 9 19:55:01] DEBUG[1269]: pbx.c:1843 pbx_extension_helper: Launching 'GotoIf' -- Executing [s@commzilla-application-acd-sales:3] GotoIf("SIP/222-b736faa8", "0?6") in new stack [Mar 9 19:55:01] DEBUG[1269]: pbx.c:6042 pbx_builtin_gotoif: Not taking any branch [Mar 9 19:55:01] DEBUG[1269]: pbx.c:1843 pbx_extension_helper: Launching 'Set' -- Executing [s@commzilla-application-acd-sales:4] Set("SIP/222-b736faa8", "MONITOR_FILENAME=1236642901.245") in new stack [Mar 9 19:55:01] DEBUG[1269]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '7' [Mar 9 19:55:01] DEBUG[1269]: pbx.c:1843 pbx_extension_helper: Launching 'Goto' -- Executing [s@commzilla-application-acd-sales:5] Goto("SIP/222-b736faa8", "7") in new stack -- Goto (commzilla-application-acd-sales,s,7) [Mar 9 19:55:01] DEBUG[1269]: pbx.c:1843 pbx_extension_helper: Launching 'Set' -- Executing [s@commzilla-application-acd-sales:7] Set("SIP/222-b736faa8", "TIMEOUT(digit)=1") in new stack -- Digit timeout set to 1 [Mar 9 19:55:01] DEBUG[1269]: pbx.c:1843 pbx_extension_helper: Launching 'Set' -- Executing [s@commzilla-application-acd-sales:8] Set("SIP/222-b736faa8", "TIMEOUT(response)=1") in new stack -- Response timeout set to 1 [Mar 9 19:55:01] DEBUG[1269]: pbx.c:1843 pbx_extension_helper: Launching 'BackGround' -- Executing [s@commzilla-application-acd-sales:9] BackGround("SIP/222-b736faa8", "custom/0001") in new stack [Mar 9 19:55:01] DEBUG[1269]: rtp.c:2781 ast_rtp_write: Ooh, format changed from unknown to ulaw [Mar 9 19:55:01] DEBUG[1269]: rtp.c:2798 ast_rtp_write: Created smoother: format: 4 ms: 20 len: 160 -- Playing 'custom/0001' (language 'en') [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 8702016@192.168.192.157 Their Tag 419718679 Our tag: as7cc7b295 [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4 [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77 [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc [Mar 9 19:55:01] 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 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264 [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744 [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9 [Mar 9 19:55:01] 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 19:55:01] 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 19:55:01] 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 19:55:01] 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 19:55:01] 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 19:55:01] 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 19:55:01] 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 19:55:01] 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 19:55:01] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 913 [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on 'ff51f8d5-43fc9fb7-e2e27ac@192.168.192.191' of Request 913: Match Found [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 8702016@192.168.192.157 Their Tag 419718679 Our tag: as7cc7b295 [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4 [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77 [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc [Mar 9 19:55:01] 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 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264 [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744 [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 753 [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on 'a5283085413b819d' of Request 753: Match Found [Mar 9 19:55:01] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:01] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'ChanSpy' in family 'commzilla/222' [Mar 9 19:55:01] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:01] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'DoNotDisturb' in family 'commzilla/222' [Mar 9 19:55:01] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:01] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'DoNotDisturb_Reason' in family 'commzilla/222' [Mar 9 19:55:01] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:01] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:01] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:01] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:01] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'CallWaiting' in family 'commzilla/222' [Mar 9 19:55:01] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:01] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'Login' in family 'commzilla/222/Agent' [Mar 9 19:55:01] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:01] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'Paused' in family 'commzilla/222/Agent' [Mar 9 19:55:01] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:01] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'HotDesk' in family 'commzilla/222' [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 8702016@192.168.192.157 Their Tag 419718679 Our tag: as7cc7b295 [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:15870 handle_request: **** Received ACK (6) - Command in SIP ACK [Mar 9 19:55:01] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '8702016@192.168.192.157' of Response 21: Match Found [Mar 9 19:55:04] DEBUG[2295]: chan_sip.c:4621 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Mar 9 19:55:04] DEBUG[2295]: chan_sip.c:3361 sip_destroy: Destroying SIP dialog 59f90cc74a63a9ff598362ed3c02bd6d@99.229.93.248 Really destroying SIP dialog '59f90cc74a63a9ff598362ed3c02bd6d@99.229.93.248' Method: OPTIONS [Mar 9 19:55:04] DEBUG[2295]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/230 [Mar 9 19:55:04] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 230 [Mar 9 19:55:04] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 230 [Mar 9 19:55:04] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/230 - state 5 (Unavailable) [Mar 9 19:55:04] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 230 [Mar 9 19:55:04] 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 19:55:04] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 230 [Mar 9 19:55:04] DEBUG[1970]: manager.c:2184 process_message: Manager received command 'login' == Parsing '/etc/asterisk/manager.conf': [Mar 9 19:55:04] DEBUG[1970]: config.c:893 config_text_file_load: Parsing /etc/asterisk/manager.conf Found [Mar 9 19:55:04] DEBUG[1970]: acl.c:363 ast_append_ha: 127.0.0.1/255.255.255.255 appended to acl for peer [Mar 9 19:55:04] DEBUG[1970]: acl.c:378 ast_apply_ha: ##### Testing 127.0.0.1 with 127.0.0.1 [Mar 9 19:55:04] DEBUG[1970]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:04] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 8702016@192.168.192.157 Their Tag 419718679 Our tag: as7cc7b295 [Mar 9 19:55:04] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4 [Mar 9 19:55:04] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77 [Mar 9 19:55:04] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe [Mar 9 19:55:04] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc [Mar 9 19:55:04] 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 19:55:04] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c [Mar 9 19:55:04] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b [Mar 9 19:55:04] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b [Mar 9 19:55:04] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264 [Mar 9 19:55:04] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b [Mar 9 19:55:04] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744 [Mar 9 19:55:04] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb [Mar 9 19:55:04] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac [Mar 9 19:55:04] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9 [Mar 9 19:55:04] 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 19:55:04] 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 19:55:04] 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 19:55:04] 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 19:55:04] 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 19:55:04] 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 19:55:04] 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 19:55:04] 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 19:55:04] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c26701520c0-duvkdwbwjm32 Their Tag 08j0pr3ogj Our tag: as102b506d [Mar 9 19:55:04] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2670151ddc-bnz4m8sg5zgw Their Tag 0wm7jm1qjq Our tag: as6e1f2643 [Mar 9 19:55:04] DEBUG[2295]: chan_sip.c:16142 sipsock_read: Invalid SIP message - rejected , no callid, len 579 [Mar 9 19:55:04] DEBUG[2048]: manager.c:2184 process_message: Manager received command 'login' == Parsing '/etc/asterisk/manager.conf': [Mar 9 19:55:04] DEBUG[2048]: config.c:893 config_text_file_load: Parsing /etc/asterisk/manager.conf FoundLI> [Mar 9 19:55:04] DEBUG[2048]: acl.c:363 ast_append_ha: 127.0.0.1/255.255.255.255 appended to acl for peer [Mar 9 19:55:04] DEBUG[2048]: acl.c:378 ast_apply_ha: ##### Testing 127.0.0.1 with 127.0.0.1 [Mar 9 19:55:04] DEBUG[2076]: manager.c:2184 process_message: Manager received command 'login' == Parsing '/etc/asterisk/manager.conf': [Mar 9 19:55:04] DEBUG[2076]: config.c:893 config_text_file_load: Parsing /etc/asterisk/manager.conf FoundLI> [Mar 9 19:55:04] DEBUG[2076]: acl.c:363 ast_append_ha: 127.0.0.1/255.255.255.255 appended to acl for peer [Mar 9 19:55:04] DEBUG[2076]: acl.c:378 ast_apply_ha: ##### Testing 127.0.0.1 with 127.0.0.1 [Mar 9 19:55:04] DEBUG[2076]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:05] DEBUG[2295]: chan_sip.c:4621 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Mar 9 19:55:05] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 68ed6a133dd71a0401b992a248c23894@192.168.192.1 Their Tag Our tag: as1ec95a57 [Mar 9 19:55:05] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '68ed6a133dd71a0401b992a248c23894@192.168.192.1' of Request 102: Match Found Really destroying SIP dialog '68ed6a133dd71a0401b992a248c23894@192.168.192.1' Method: OPTIONS [Mar 9 19:55:06] DEBUG[1269]: pbx.c:1843 pbx_extension_helper: Launching 'Set' -- Executing [s@commzilla-application-acd-sales:10] Set("SIP/222-b736faa8", "__ACD_TO_OUTGOING=1") in new stack [Mar 9 19:55:06] DEBUG[1269]: pbx.c:1843 pbx_extension_helper: Launching 'Set' -- Executing [s@commzilla-application-acd-sales:11] Set("SIP/222-b736faa8", "CHANNEL(musicclass)=default") in new stack [Mar 9 19:55:06] DEBUG[1269]: pbx.c:1843 pbx_extension_helper: Launching 'Set' -- Executing [s@commzilla-application-acd-sales:12] Set("SIP/222-b736faa8", "__ALLOW_TRANSFER=twk") in new stack [Mar 9 19:55:06] DEBUG[1269]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is 'WiFi' [Mar 9 19:55:06] DEBUG[1269]: pbx.c:1843 pbx_extension_helper: Launching 'Set' -- Executing [s@commzilla-application-acd-sales:13] Set("SIP/222-b736faa8", "CALLERID(name)=SALES:WiFi") in new stack [Mar 9 19:55:06] DEBUG[1269]: pbx.c:1843 pbx_extension_helper: Launching 'Queue' -- Executing [s@commzilla-application-acd-sales:14] Queue("SIP/222-b736faa8", "commzilla-sales|tH|||300|") in new stack [Mar 9 19:55:06] DEBUG[1269]: app_queue.c:3927 queue_exec: SIP/222-b736faa8: Got priority 0 from ${QUEUE_PRIO}. [Mar 9 19:55:06] DEBUG[1269]: app_queue.c:3959 queue_exec: queue: commzilla-sales, options: tH, url: , announce: , expires: 1236643206, priority: 0 [Mar 9 19:55:06] DEBUG[1269]: app_queue.c:1355 update_realtime_members: Queue commzilla-sales has no realtime members defined. No need for update [Mar 9 19:55:06] DEBUG[1269]: app_queue.c:1500 join_queue: Queue 'commzilla-sales' Join, Channel 'SIP/222-b736faa8', Position '1' [Mar 9 19:55:06] DEBUG[1269]: channel.c:2961 set_format: Set channel SIP/222-b736faa8 to write format slin -- Started music on hold, class 'default', on channel 'SIP/222-b736faa8' [Mar 9 19:55:06] DEBUG[1269]: app_queue.c:2419 is_our_turn: There are 1 available members. [Mar 9 19:55:06] DEBUG[1269]: app_queue.c:2430 is_our_turn: It's our turn (SIP/222-b736faa8). [Mar 9 19:55:06] DEBUG[1269]: app_queue.c:2816 try_calling: SIP/222-b736faa8 is trying to call a queue member. [Mar 9 19:55:06] DEBUG[1269]: app_queue.c:2005 ring_one: Trying 'Local/233@commzilla-agent/n' with metric 1000 [Mar 9 19:55:06] DEBUG[1269]: channel.c:3464 ast_channel_inherit_variables: Copying hard-transferable variable ALLOW_TRANSFER. [Mar 9 19:55:06] DEBUG[1269]: channel.c:3464 ast_channel_inherit_variables: Copying hard-transferable variable ACD_TO_OUTGOING. [Mar 9 19:55:06] DEBUG[1269]: channel.c:3469 ast_channel_inherit_variables: Not copying variable MONITOR_FILENAME. [Mar 9 19:55:06] DEBUG[1269]: channel.c:3464 ast_channel_inherit_variables: Copying hard-transferable variable QUEUENAME. [Mar 9 19:55:06] DEBUG[1269]: channel.c:3469 ast_channel_inherit_variables: Not copying variable QUEUE_PRIO. [Mar 9 19:55:06] DEBUG[1269]: channel.c:3469 ast_channel_inherit_variables: Not copying variable SPYGROUP. [Mar 9 19:55:06] DEBUG[1269]: channel.c:3469 ast_channel_inherit_variables: Not copying variable INBOUND_GROUP. [Mar 9 19:55:06] DEBUG[1269]: channel.c:3469 ast_channel_inherit_variables: Not copying variable AUTO_RECORDING. [Mar 9 19:55:06] DEBUG[1269]: channel.c:3469 ast_channel_inherit_variables: Not copying variable FORCE_RECORDING. [Mar 9 19:55:06] DEBUG[1269]: channel.c:3469 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Mar 9 19:55:06] DEBUG[1269]: channel.c:3469 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [Mar 9 19:55:06] DEBUG[1269]: channel.c:3469 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Mar 9 19:55:06] DEBUG[1269]: channel.c:3469 ast_channel_inherit_variables: Not copying variable SIPURI. -- Called Local/233@commzilla-agent/n [Mar 9 19:55:06] DEBUG[1269]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 233@commzilla-agent/n [Mar 9 19:55:06] DEBUG[1269]: chan_local.c:145 local_devicestate: Checking if extension 233@commzilla-agent exists (devicestate) [Mar 9 19:55:06] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1843 pbx_extension_helper: Launching 'NoCDR' -- Executing [233@commzilla-agent:1] NoCDR("Local/233@commzilla-agent-0a55,2", "") in new stack [Mar 9 19:55:06] DEBUG[2469]: db.c:198 ast_db_get: Unable to find key '233/DoNotDisturb' in family 'commzilla' [Mar 9 19:55:06] DEBUG[2469]: func_db.c:70 function_db_read: DB: commzilla/233/DoNotDisturb not found in database. [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '' [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1843 pbx_extension_helper: Launching 'Set' -- Executing [233@commzilla-agent:2] Set("Local/233@commzilla-agent-0a55,2", "DND=") in new stack [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '0' [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1843 pbx_extension_helper: Launching 'GotoIf' -- Executing [233@commzilla-agent:3] GotoIf("Local/233@commzilla-agent-0a55,2", "0?20") in new stack [Mar 9 19:55:06] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:06] DEBUG[2469]: pbx.c:6042 pbx_builtin_gotoif: Not taking any branch [Mar 9 19:55:06] DEBUG[2469]: db.c:198 ast_db_get: Unable to find key '233/OutOffice' in family 'commzilla' [Mar 9 19:55:06] DEBUG[2469]: func_db.c:70 function_db_read: DB: commzilla/233/OutOffice not found in database. [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '' [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1843 pbx_extension_helper: Launching 'Set' -- Executing [233@commzilla-agent:4] Set("Local/233@commzilla-agent-0a55,2", "OutOffice=") in new stack [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '0' [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1843 pbx_extension_helper: Launching 'GotoIf' -- Executing [233@commzilla-agent:5] GotoIf("Local/233@commzilla-agent-0a55,2", "0?20") in new stack [Mar 9 19:55:06] DEBUG[2469]: pbx.c:6042 pbx_builtin_gotoif: Not taking any branch [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '0' [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '0' [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '0' [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1843 pbx_extension_helper: Launching 'Set' -- Executing [233@commzilla-agent:6] Set("Local/233@commzilla-agent-0a55,2", "GROUPCOUNT=0") in new stack [Mar 9 19:55:06] DEBUG[2469]: db.c:198 ast_db_get: Unable to find key 'agent/1/maxcalls' in family 'commzilla' [Mar 9 19:55:06] DEBUG[2469]: func_db.c:70 function_db_read: DB: commzilla/agent/1/maxcalls not found in database. [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '' [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1843 pbx_extension_helper: Launching 'Set' -- Executing [233@commzilla-agent:7] Set("Local/233@commzilla-agent-0a55,2", "AGENTMAXCALL=") in new stack [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '1' [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '9' [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '10' [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1843 pbx_extension_helper: Launching 'GotoIf' -- Executing [233@commzilla-agent:8] GotoIf("Local/233@commzilla-agent-0a55,2", "1?9:10") in new stack -- Goto (commzilla-agent,233,9) [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1843 pbx_extension_helper: Launching 'Set' -- Executing [233@commzilla-agent:9] Set("Local/233@commzilla-agent-0a55,2", "AGENTMAXCALL=1") in new stack [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '0' [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1843 pbx_extension_helper: Launching 'GotoIf' -- Executing [233@commzilla-agent:10] GotoIf("Local/233@commzilla-agent-0a55,2", "0?20") in new stack [Mar 9 19:55:06] DEBUG[2469]: pbx.c:6042 pbx_builtin_gotoif: Not taking any branch [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '1' [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '14' [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1843 pbx_extension_helper: Launching 'GotoIf' -- Executing [233@commzilla-agent:11] GotoIf("Local/233@commzilla-agent-0a55,2", "1?14") in new stack -- Goto (commzilla-agent,233,14) [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1843 pbx_extension_helper: Launching 'Set' -- Executing [233@commzilla-agent:14] Set("Local/233@commzilla-agent-0a55,2", "OUTBOUND_GROUP_ONCE=233@INCOMING") in new stack [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1843 pbx_extension_helper: Launching 'Set' -- Executing [233@commzilla-agent:15] Set("Local/233@commzilla-agent-0a55,2", "DB(commzilla/wrapup/233/lastcall)=1236642906.247") in new stack [Mar 9 19:55:06] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1843 pbx_extension_helper: Launching 'Goto' -- Executing [233@commzilla-agent:16] Goto("Local/233@commzilla-agent-0a55,2", "commzilla-local-devices|233|1") in new stack -- Goto (commzilla-local-devices,233,1) [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1843 pbx_extension_helper: Launching 'Set' -- Executing [233@commzilla-local-devices:1] Set("Local/233@commzilla-agent-0a55,2", "DB(commzilla/wrapup/233/lastcall)=1236642906.247") in new stack [Mar 9 19:55:06] DEBUG[2469]: pbx.c:1843 pbx_extension_helper: Launching 'Dial' -- Executing [233@commzilla-local-devices:2] Dial("Local/233@commzilla-agent-0a55,2", "SIP/233||twk") in new stack [Mar 9 19:55:06] DEBUG[2469]: chan_sip.c:16713 sip_request_call: Asked to create a SIP channel with formats: 0x4 (ulaw) [Mar 9 19:55:06] DEBUG[2469]: chan_sip.c:4621 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Mar 9 19:55:06] DEBUG[2469]: chan_sip.c:2783 do_setnat: Setting NAT on RTP to Off [Mar 9 19:55:06] DEBUG[2469]: chan_sip.c:4095 sip_new: *** Our native formats are 0x4 (ulaw) [Mar 9 19:55:06] DEBUG[2469]: chan_sip.c:4096 sip_new: *** Joint capabilities are 0x0 (nothing) [Mar 9 19:55:06] DEBUG[2469]: chan_sip.c:4097 sip_new: *** Our capabilities are 0x4 (ulaw) [Mar 9 19:55:06] DEBUG[2469]: chan_sip.c:4098 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Mar 9 19:55:06] DEBUG[2469]: chan_sip.c:4100 sip_new: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Mar 9 19:55:06] DEBUG[2469]: chan_sip.c:4121 sip_new: This channel will not be able to handle video. [Mar 9 19:55:06] DEBUG[2469]: rtp.c:1592 ast_rtp_make_compatible: Channel 'Local/233@commzilla-agent-0a55,2' has no RTP, not doing anything [Mar 9 19:55:06] DEBUG[2469]: channel.c:3469 ast_channel_inherit_variables: Not copying variable DIALEDTIME. [Mar 9 19:55:06] DEBUG[2469]: channel.c:3469 ast_channel_inherit_variables: Not copying variable ANSWEREDTIME. [Mar 9 19:55:06] DEBUG[2469]: channel.c:3469 ast_channel_inherit_variables: Not copying variable DIALEDPEERNAME. [Mar 9 19:55:06] DEBUG[2469]: channel.c:3469 ast_channel_inherit_variables: Not copying variable DIALEDPEERNUMBER. [Mar 9 19:55:06] DEBUG[2469]: channel.c:3469 ast_channel_inherit_variables: Not copying variable DIALSTATUS. [Mar 9 19:55:06] DEBUG[2469]: channel.c:3469 ast_channel_inherit_variables: Not copying variable AGENTMAXCALL. [Mar 9 19:55:06] DEBUG[2469]: channel.c:3469 ast_channel_inherit_variables: Not copying variable GROUPCOUNT. [Mar 9 19:55:06] DEBUG[2469]: channel.c:3469 ast_channel_inherit_variables: Not copying variable OutOffice. [Mar 9 19:55:06] DEBUG[2469]: channel.c:3469 ast_channel_inherit_variables: Not copying variable DND. [Mar 9 19:55:06] DEBUG[2469]: channel.c:3464 ast_channel_inherit_variables: Copying hard-transferable variable ALLOW_TRANSFER. [Mar 9 19:55:06] DEBUG[2469]: channel.c:3464 ast_channel_inherit_variables: Copying hard-transferable variable ACD_TO_OUTGOING. [Mar 9 19:55:06] DEBUG[2469]: channel.c:3464 ast_channel_inherit_variables: Copying hard-transferable variable QUEUENAME. [Mar 9 19:55:06] DEBUG[2469]: chan_sip.c:3046 sip_call: Outgoing Call for 233 [Mar 9 19:55:06] DEBUG[2469]: chan_sip.c:3252 update_call_counter: Updating call counter for outgoing call [Mar 9 19:55:06] DEBUG[2469]: chan_sip.c:3329 update_call_counter: Call to peer '233' is 1 out of 4 [Mar 9 19:55:06] DEBUG[2469]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/233 [Mar 9 19:55:06] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:06] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233 [Mar 9 19:55:06] DEBUG[2469]: chan_sip.c:3061 sip_call: Our T38 capability (3856), joint T38 capability (3856) [Mar 9 19:55:06] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233 [Mar 9 19:55:06] DEBUG[2469]: chan_sip.c:6620 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: False [Mar 9 19:55:06] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/233 - state 6 (Ringing) [Mar 9 19:55:06] DEBUG[2469]: chan_sip.c:6621 add_sdp: ** Our prefcodec: 0x4 (ulaw) [Mar 9 19:55:06] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233 [Mar 9 19:55:06] DEBUG[2469]: chan_sip.c:6752 add_sdp: -- Done with adding codecs to SDP [Mar 9 19:55:06] DEBUG[2292]: app_queue.c:681 handle_statechange: Device 'SIP/233' changed to state '6' (Ringing) [Mar 9 19:55:06] DEBUG[2469]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:06] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233 [Mar 9 19:55:06] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233 [Mar 9 19:55:06] 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 19:55:06] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233 [Mar 9 19:55:06] 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 19:55:06] DEBUG[2469]: chan_sip.c:6797 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw) -- Called 233 [Mar 9 19:55:06] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:06] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'ChanSpy' in family 'commzilla/233' [Mar 9 19:55:06] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:06] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'DoNotDisturb' in family 'commzilla/233' [Mar 9 19:55:06] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:06] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'DoNotDisturb_Reason' in family 'commzilla/233' [Mar 9 19:55:06] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:06] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:06] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:06] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:06] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'CallWaiting' in family 'commzilla/233' [Mar 9 19:55:06] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:06] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:06] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:06] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'Paused' in family 'commzilla/233/Agent' [Mar 9 19:55:06] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:06] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'HotDesk' in family 'commzilla/233' [Mar 9 19:55:06] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 4126976f0b9f6fa524d8ff4b2bf8c482@192.168.192.1 Their Tag Our tag: as5353a587 [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 8702016@192.168.192.157 Their Tag 419718679 Our tag: as7cc7b295 [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4 [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77 [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc [Mar 9 19:55:06] 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 19:55:06] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264 [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744 [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9 [Mar 9 19:55:06] 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 19:55:06] 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 19:55:06] 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 19:55:06] 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 19:55:06] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 445 [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '9bc65609-d3d27e0b-7ec854d0@192.168.192.191' of Request 445: Match Found [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 4126976f0b9f6fa524d8ff4b2bf8c482@192.168.192.1 Their Tag Our tag: as5353a587 [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 8702016@192.168.192.157 Their Tag 419718679 Our tag: as7cc7b295 [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4 [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77 [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 285 [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '511c90173aab58af' of Request 285: Match Found [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 4126976f0b9f6fa524d8ff4b2bf8c482@192.168.192.1 Their Tag Our tag: as5353a587 [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:2259 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '4126976f0b9f6fa524d8ff4b2bf8c482@192.168.192.1' Request 102: Found [Mar 9 19:55:06] DEBUG[2295]: chan_sip.c:12324 handle_response_invite: SIP response 180 to standard invite [Mar 9 19:55:06] DEBUG[2295]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/233 [Mar 9 19:55:06] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233 [Mar 9 19:55:06] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233 [Mar 9 19:55:06] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/233 - state 6 (Ringing) [Mar 9 19:55:06] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233 [Mar 9 19:55:06] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233 [Mar 9 19:55:06] DEBUG[2292]: app_queue.c:681 handle_statechange: Device 'SIP/233' changed to state '6' (Ringing) -- SIP/233-084bb0c8 is ringing [Mar 9 19:55:06] DEBUG[2469]: rtp.c:1503 ast_rtp_early_bridge: Channel 'Local/233@commzilla-agent-0a55,2' has no RTP, not doing anything -- Local/233@commzilla-agent-0a55,1 is ringing [Mar 9 19:55:06] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 4126976f0b9f6fa524d8ff4b2bf8c482@192.168.192.1 Their Tag i5mgjbkt7o Our tag: as5353a587 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:2259 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '4126976f0b9f6fa524d8ff4b2bf8c482@192.168.192.1' Request 102: Found [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:12324 handle_response_invite: SIP response 180 to standard invite -- SIP/233-084bb0c8 is ringing [Mar 9 19:55:07] DEBUG[2469]: rtp.c:1503 ast_rtp_early_bridge: Channel 'Local/233@commzilla-agent-0a55,2' has no RTP, not doing anything [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[2469]: rtp.c:879 ast_rtcp_read: Got RTCP report of 68 bytes [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4621 sip_alloc: Allocating new SIP dialog for 41e472780329e01d1562617572cfb440@67.55.31.179 - REGISTER (No RTP) [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:7757 transmit_register: Scheduled a registration timeout for voip5-3.acanac.com id #528017 REGISTER attempt 1 to 9057564513@voip5-3.acanac.com [Mar 9 19:55:07] DEBUG[1269]: channel.c:2429 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag Our tag: as26a4d1a1 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:2259 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '41e472780329e01d1562617572cfb440@67.55.31.179' Request 514: Found [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag Our tag: as26a4d1a1 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '41e472780329e01d1562617572cfb440@67.55.31.179' of Request 514: Match Found [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:1663 initialize_initreq: Initializing already initialized SIP dialog 41e472780329e01d1562617572cfb440@67.55.31.179 (presumably reinvite) REGISTER attempt 2 to 9057564513@voip5-3.acanac.com [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag Our tag: as337443e0 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 4126976f0b9f6fa524d8ff4b2bf8c482@192.168.192.1 Their Tag i5mgjbkt7o Our tag: as5353a587 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 102 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '4126976f0b9f6fa524d8ff4b2bf8c482@192.168.192.1' of Request 102: Match Found [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:12324 handle_response_invite: SIP response 200 to standard invite [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:5568 process_sdp: T38 state changed to 0 on channel SIP/233-084bb0c8 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:5648 process_sdp: We're settling with these formats: 0x4 (ulaw) [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:5655 process_sdp: We have an owner, now see if we need to change this call [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:3252 update_call_counter: Updating call counter for outgoing call [Mar 9 19:55:07] DEBUG[2295]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/233 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:8503 build_route: build_route: Contact hop: ;reg-id=1 [Mar 9 19:55:07] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233 [Mar 9 19:55:07] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233 [Mar 9 19:55:07] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/233 - state 2 (In use) [Mar 9 19:55:07] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233 [Mar 9 19:55:07] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233 [Mar 9 19:55:07] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233 [Mar 9 19:55:07] 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 19:55:07] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233 [Mar 9 19:55:07] 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 19:55:07] DEBUG[2469]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/233 -- SIP/233-084bb0c8 answered Local/233@commzilla-agent-0a55,2 [Mar 9 19:55:07] DEBUG[2469]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/233@commzilla-agent [Mar 9 19:55:07] DEBUG[2292]: app_queue.c:681 handle_statechange: Device 'SIP/233' changed to state '2' (In use) [Mar 9 19:55:07] DEBUG[1269]: app_queue.c:2309 wait_for_answer: Dunno what to do with control type -1 [Mar 9 19:55:07] DEBUG[1269]: 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-0a55,1 answered SIP/222-b736faa8 [Mar 9 19:55:07] DEBUG[1269]: channel.c:2961 set_format: Set channel SIP/222-b736faa8 to write format ulaw -- Stopped music on hold on SIP/222-b736faa8 [Mar 9 19:55:07] DEBUG[1269]: app_queue.c:3079 try_calling: Starting MixMonitor as requested. [Mar 9 19:55:07] DEBUG[1269]: app_queue.c:3137 try_calling: Arguments being passed to MixMonitor: 1236642901.245.wav49|b [Mar 9 19:55:07] DEBUG[1269]: app_queue.c:1699 leave_queue: Queue 'commzilla-sales' Leave, Channel 'SIP/222-b736faa8' [Mar 9 19:55:07] DEBUG[1269]: channel.c:3995 ast_generic_bridge: Got a FRAME_CONTROL (-1) frame on channel Local/233@commzilla-agent-0a55,1 [Mar 9 19:55:07] DEBUG[1269]: channel.c:4311 ast_channel_bridge: Bridge stops bridging channels SIP/222-b736faa8 and Local/233@commzilla-agent-0a55,1 [Mar 9 19:55:07] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233 [Mar 9 19:55:07] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233 [Mar 9 19:55:07] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/233 - state 2 (In use) [Mar 9 19:55:07] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233 [Mar 9 19:55:07] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233 [Mar 9 19:55:07] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 233@commzilla-agent [Mar 9 19:55:07] DEBUG[2243]: chan_local.c:145 local_devicestate: Checking if extension 233@commzilla-agent exists (devicestate) [Mar 9 19:55:07] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for Local/233@commzilla-agent - state 2 (In use) [Mar 9 19:55:07] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 233@commzilla-agent [Mar 9 19:55:07] DEBUG[2243]: chan_local.c:145 local_devicestate: Checking if extension 233@commzilla-agent exists (devicestate) [Mar 9 19:55:07] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for Local/233@commzilla-agent - state 2 (In use) [Mar 9 19:55:07] DEBUG[2292]: app_queue.c:681 handle_statechange: Device 'SIP/233' changed to state '2' (In use) [Mar 9 19:55:07] 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 19:55:07] 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 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag Our tag: as337443e0 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:2259 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '41e472780329e01d1562617572cfb440@67.55.31.179' Request 515: Found == Begin MixMonitor Recording SIP/222-b736faa8 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag Our tag: as337443e0 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '41e472780329e01d1562617572cfb440@67.55.31.179' of Request 515: Match Found [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:12768 handle_response_register: Registration successful [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:12771 handle_response_register: Cancelling timeout 528017 [Mar 9 19:55:07] DEBUG[2469]: rtp.c:2781 ast_rtp_write: Ooh, format changed from unknown to ulaw [Mar 9 19:55:07] DEBUG[2469]: rtp.c:2798 ast_rtp_write: Created smoother: format: 4 ms: 20 len: 160 [Mar 9 19:55:07] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:07] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:07] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'ChanSpy' in family 'commzilla/233' [Mar 9 19:55:07] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:07] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'DoNotDisturb' in family 'commzilla/233' [Mar 9 19:55:07] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:07] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'DoNotDisturb_Reason' in family 'commzilla/233' [Mar 9 19:55:07] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:07] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:07] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:07] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:07] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'CallWaiting' in family 'commzilla/233' [Mar 9 19:55:07] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:07] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:07] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:07] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'Paused' in family 'commzilla/233/Agent' [Mar 9 19:55:07] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:07] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'HotDesk' in family 'commzilla/233' [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2269f2c1 Our tag: as337443e0 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 4126976f0b9f6fa524d8ff4b2bf8c482@192.168.192.1 Their Tag i5mgjbkt7o Our tag: as5353a587 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 8702016@192.168.192.157 Their Tag 419718679 Our tag: as7cc7b295 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc [Mar 9 19:55:07] 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 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9 [Mar 9 19:55:07] 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 19:55:07] 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 19:55:07] 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 19:55:07] 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 19:55:07] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 446 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '9bc65609-d3d27e0b-7ec854d0@192.168.192.191' of Request 446: Match Found [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2269f2c1 Our tag: as337443e0 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 4126976f0b9f6fa524d8ff4b2bf8c482@192.168.192.1 Their Tag i5mgjbkt7o Our tag: as5353a587 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 8702016@192.168.192.157 Their Tag 419718679 Our tag: as7cc7b295 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 286 [Mar 9 19:55:07] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '511c90173aab58af' of Request 286: Match Found [Mar 9 19:55:07] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:07] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:07] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:07] DEBUG[2877]: audiohook.c:221 audiohook_read_frame_both: Write factory 0x85c488c was pretty quick last time, waiting for them. [Mar 9 19:55:07] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:07] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:07] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:07] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:07] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:08] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:09] DEBUG[23214]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:09] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:228 audiohook_read_frame_both: Read factory 0x85c3e70 was pretty quick last time, waiting for them. [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:10] DEBUG[23214]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2269f2c1 Our tag: as337443e0 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 4126976f0b9f6fa524d8ff4b2bf8c482@192.168.192.1 Their Tag i5mgjbkt7o Our tag: as5353a587 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:15870 handle_request: **** Received BYE (8) - Command in SIP BYE [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:1675 sip_alreadygone: Setting SIP_ALREADYGONE on dialog 4126976f0b9f6fa524d8ff4b2bf8c482@192.168.192.1 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:15408 handle_request_bye: Received bye, issuing owner hangup [Mar 9 19:55:10] DEBUG[2469]: channel.c:3968 ast_generic_bridge: Didn't get a frame from channel: SIP/233-084bb0c8 [Mar 9 19:55:10] DEBUG[2469]: channel.c:4311 ast_channel_bridge: Bridge stops bridging channels Local/233@commzilla-agent-0a55,2 and SIP/233-084bb0c8 [Mar 9 19:55:10] DEBUG[2469]: channel.c:1520 ast_hangup: Hanging up channel 'SIP/233-084bb0c8' [Mar 9 19:55:10] DEBUG[2469]: chan_sip.c:3569 sip_hangup: Hangup call SIP/233-084bb0c8, SIP callid 4126976f0b9f6fa524d8ff4b2bf8c482@192.168.192.1) [Mar 9 19:55:10] DEBUG[2469]: chan_sip.c:3252 update_call_counter: Updating call counter for outgoing call [Mar 9 19:55:10] DEBUG[2469]: chan_sip.c:3303 update_call_counter: Call to peer '233' removed from call limit 4 [Mar 9 19:55:10] DEBUG[2469]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/233 [Mar 9 19:55:10] DEBUG[2469]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/233 [Mar 9 19:55:10] DEBUG[2469]: rtp.c:1503 ast_rtp_early_bridge: Channel 'Local/233@commzilla-agent-0a55,2' has no RTP, not doing anything [Mar 9 19:55:10] DEBUG[2469]: app_dial.c:1786 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Mar 9 19:55:10] DEBUG[2469]: pbx.c:2428 __ast_pbx_run: Spawn extension (commzilla-local-devices,233,2) exited non-zero on 'Local/233@commzilla-agent-0a55,2' == Spawn extension (commzilla-local-devices, 233, 2) exited non-zero on 'Local/233@commzilla-agent-0a55,2' [Mar 9 19:55:10] DEBUG[2469]: channel.c:1427 ast_softhangup_nolock: Soft-Hanging up channel 'Local/233@commzilla-agent-0a55,2' [Mar 9 19:55:10] DEBUG[2469]: channel.c:1520 ast_hangup: Hanging up channel 'Local/233@commzilla-agent-0a55,2' [Mar 9 19:55:10] DEBUG[2469]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/233@commzilla-agent [Mar 9 19:55:10] DEBUG[1269]: channel.c:3968 ast_generic_bridge: Didn't get a frame from channel: Local/233@commzilla-agent-0a55,1 [Mar 9 19:55:10] DEBUG[1269]: channel.c:4311 ast_channel_bridge: Bridge stops bridging channels SIP/222-b736faa8 and Local/233@commzilla-agent-0a55,1 [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1843 pbx_extension_helper: Launching 'Goto' -- Executing [h@commzilla-application-acd-sales:1] Goto("SIP/222-b736faa8", "all-hangup|s|1") in new stack -- Goto (all-hangup,s,1) [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '0' [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1760 pbx_substitute_variables_helper_full: Expression result is '2' [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1843 pbx_extension_helper: Launching 'GotoIf' -- Executing [s@all-hangup:1] GotoIf("SIP/222-b736faa8", "0?all-faxnotify|s|1:2") in new stack -- Goto (all-hangup,s,2) [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1843 pbx_extension_helper: Launching 'ResetCDR' -- Executing [s@all-hangup:2] ResetCDR("SIP/222-b736faa8", "w") in new stack [Mar 9 19:55:10] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233 [Mar 9 19:55:10] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233 [Mar 9 19:55:10] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/233 - state 1 (Not in use) [Mar 9 19:55:10] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233 [Mar 9 19:55:10] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233 [Mar 9 19:55:10] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233 [Mar 9 19:55:10] 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 19:55:10] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233 [Mar 9 19:55:10] 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 19:55:10] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233 [Mar 9 19:55:10] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233 [Mar 9 19:55:10] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/233 - state 1 (Not in use) [Mar 9 19:55:10] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 233 [Mar 9 19:55:10] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 233 [Mar 9 19:55:10] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 233@commzilla-agent [Mar 9 19:55:10] DEBUG[2243]: chan_local.c:145 local_devicestate: Checking if extension 233@commzilla-agent exists (devicestate) [Mar 9 19:55:10] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for Local/233@commzilla-agent - state 2 (In use) [Mar 9 19:55:10] DEBUG[2292]: app_queue.c:681 handle_statechange: Device 'SIP/233' changed to state '1' (Not in use) [Mar 9 19:55:10] DEBUG[2292]: app_queue.c:681 handle_statechange: Device 'SIP/233' changed to state '1' (Not in use) [Mar 9 19:55:10] 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 19:55:10] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:10] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'ChanSpy' in family 'commzilla/233' [Mar 9 19:55:10] DEBUG[22443]: manager.c:2184 process_message: Really destroying SIP dialog '4126976f0b9f6fa524d8ff4b2bf8c482@192.168.192.1' Method: BYE Manager received command 'Command' [Mar 9 19:55:10] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'DoNotDisturb' in family 'commzilla/233' [Mar 9 19:55:10] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:10] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'DoNotDisturb_Reason' in family 'commzilla/233' [Mar 9 19:55:10] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:10] DEBUG[1269]: cdr_addon_mysql.c:228 mysql_log: cdr_mysql: inserting a CDR record. [Mar 9 19:55:10] DEBUG[1269]: 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 19:55:01','\"SALES:WiFi\" <222>','222','s','commzilla-application-acd-sales', 'SIP/222-b736faa8','Local/233@commzilla-agent-0a55,1','ResetCDR','w',9,9,'ANSWERED',3,'222','1236642901.245','') [Mar 9 19:55:10] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:10] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:10] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:10] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'CallWaiting' in family 'commzilla/233' [Mar 9 19:55:10] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:10] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:10] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'Paused' in family 'commzilla/233/Agent' [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '"SALES:WiFi" <222>' [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '222' [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is 's' [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is 'commzilla-application-acd-sales' [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is 'SIP/222-b736faa8' [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is 'Local/233@commzilla-agent-0a55,1' [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is 'ResetCDR' [Mar 9 19:55:10] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is 'w' [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '2009-03-09 19:55:01' [Mar 9 19:55:10] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'HotDesk' in family 'commzilla/233' [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '2009-03-09 19:55:01' [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '2009-03-09 19:55:10' [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '9' [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '9' [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '222' [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '1236642901.245' [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1692 pbx_substitute_variables_helper_full: Function result is '(null)' [Mar 9 19:55:10] DEBUG[1269]: cdr_radius.c:221 radius_log: Unable to create RADIUS record. CDR not recorded! [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1843 pbx_extension_helper: Launching 'NoCDR' -- Executing [s@all-hangup:3] NoCDR("SIP/222-b736faa8", "") in new stack [Mar 9 19:55:10] DEBUG[1269]: pbx.c:1843 pbx_extension_helper: Launching 'System' -- Executing [s@all-hangup:4] System("SIP/222-b736faa8", "/var/www/scopserv/telephony/scripts/billing/cdr.sh 1236642901.245") in new stack [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2269f2c1 Our tag: as337443e0 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 8702016@192.168.192.157 Their Tag 419718679 Our tag: as7cc7b295 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc [Mar 9 19:55:10] 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 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9 [Mar 9 19:55:10] 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 19:55:10] 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 19:55:10] 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 19:55:10] 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 19:55:10] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 447 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '9bc65609-d3d27e0b-7ec854d0@192.168.192.191' of Request 447: Match Found [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2269f2c1 Our tag: as337443e0 [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 8702016@192.168.192.157 Their Tag 419718679 Our tag: as7cc7b295 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 287 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '511c90173aab58af' of Request 287: Match Found [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:10] DEBUG[23214]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:10] DEBUG[2877]: audiohook.c:268 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x85c488c [Mar 9 19:55:10] DEBUG[1269]: channel.c:1520 ast_hangup: Hanging up channel 'Local/233@commzilla-agent-0a55,1' [Mar 9 19:55:10] DEBUG[1269]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/233@commzilla-agent [Mar 9 19:55:10] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 233@commzilla-agent [Mar 9 19:55:10] DEBUG[2243]: chan_local.c:145 local_devicestate: Checking if extension 233@commzilla-agent exists (devicestate) [Mar 9 19:55:10] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for Local/233@commzilla-agent - state 1 (Not in use) [Mar 9 19:55:10] 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 19:55:10] DEBUG[1269]: pbx.c:2428 __ast_pbx_run: Spawn extension (all-hangup,s,14) exited non-zero on 'SIP/222-b736faa8' == Spawn extension (all-hangup, s, 14) exited non-zero on 'SIP/222-b736faa8' [Mar 9 19:55:10] DEBUG[1269]: channel.c:1427 ast_softhangup_nolock: Soft-Hanging up channel 'SIP/222-b736faa8' [Mar 9 19:55:10] DEBUG[1269]: channel.c:1520 ast_hangup: Hanging up channel 'SIP/222-b736faa8' [Mar 9 19:55:10] DEBUG[1269]: chan_sip.c:3569 sip_hangup: Hangup call SIP/222-b736faa8, SIP callid 8702016@192.168.192.157) [Mar 9 19:55:10] DEBUG[1269]: chan_sip.c:3252 update_call_counter: Updating call counter for incoming call [Mar 9 19:55:10] DEBUG[1269]: chan_sip.c:3303 update_call_counter: Call from peer '222' removed from call limit 8 [Mar 9 19:55:10] DEBUG[1269]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/222 [Mar 9 19:55:10] DEBUG[1269]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/222 == End MixMonitor Recording SIP/222-b736faa8 [Mar 9 19:55:10] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222 [Mar 9 19:55:10] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222 [Mar 9 19:55:10] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/222 - state 1 (Not in use) [Mar 9 19:55:10] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222 [Mar 9 19:55:10] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222 [Mar 9 19:55:10] 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 19:55:10] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222 [Mar 9 19:55:10] 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 19:55:10] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222 [Mar 9 19:55:10] 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 19:55:10] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222 [Mar 9 19:55:10] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222 [Mar 9 19:55:10] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/222 - state 1 (Not in use) [Mar 9 19:55:10] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 222 [Mar 9 19:55:10] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 222 [Mar 9 19:55:10] 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 19:55:10] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:10] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'ChanSpy' in family 'commzilla/222' [Mar 9 19:55:10] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:10] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'DoNotDisturb' in family 'commzilla/222' [Mar 9 19:55:10] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:10] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'DoNotDisturb_Reason' in family 'commzilla/222' [Mar 9 19:55:10] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:10] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:10] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:10] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:10] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'CallWaiting' in family 'commzilla/222' [Mar 9 19:55:10] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:10] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'Login' in family 'commzilla/222/Agent' [Mar 9 19:55:10] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:10] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'Paused' in family 'commzilla/222/Agent' [Mar 9 19:55:10] DEBUG[22443]: manager.c:2184 process_message: Manager received command 'Command' [Mar 9 19:55:10] DEBUG[22443]: db.c:198 ast_db_get: Unable to find key 'HotDesk' in family 'commzilla/222' [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2269f2c1 Our tag: as337443e0 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 8702016@192.168.192.157 Their Tag 419718679 Our tag: as7cc7b295 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc [Mar 9 19:55:10] 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 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 754 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on 'a5283085413b819d' of Request 754: Match Found [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2269f2c1 Our tag: as337443e0 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 8702016@192.168.192.157 Their Tag 419718679 Our tag: as7cc7b295 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc [Mar 9 19:55:10] 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 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9 [Mar 9 19:55:10] 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 19:55:10] 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 19:55:10] 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 19:55:10] 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 19:55:10] 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 19:55:10] 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 19:55:10] 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 19:55:10] 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 19:55:10] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 914 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on 'ff51f8d5-43fc9fb7-e2e27ac@192.168.192.191' of Request 914: Match Found [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2269f2c1 Our tag: as337443e0 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 8702016@192.168.192.157 Their Tag 419718679 Our tag: as7cc7b295 [Mar 9 19:55:10] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '8702016@192.168.192.157' of Request 102: Match Found Really destroying SIP dialog '8702016@192.168.192.157' Method: ACK [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2269f2c1 Our tag: as337443e0 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc [Mar 9 19:55:11] 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 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9 [Mar 9 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 3c26701520c0-duvkdwbwjm32 Their Tag 08j0pr3ogj Our tag: as102b506d [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:15870 handle_request: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2269f2c1 Our tag: as337443e0 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc [Mar 9 19:55:11] 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 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9 [Mar 9 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 3c26701520c0-duvkdwbwjm32 Their Tag 08j0pr3ogj Our tag: as102b506d [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:15870 handle_request: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:15665 handle_request_subscribe: Adding subscription for extension 220 context commzilla-local for peer 233 [Mar 9 19:55:11] DEBUG[2295]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 220 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 220 [Mar 9 19:55:11] DEBUG[2295]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 220 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 220 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2269f2c1 Our tag: as337443e0 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc [Mar 9 19:55:11] 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 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9 [Mar 9 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c26701520c0-duvkdwbwjm32 Their Tag 08j0pr3ogj Our tag: as102b506d [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 3c2670151ddc-bnz4m8sg5zgw Their Tag 0wm7jm1qjq Our tag: as6e1f2643 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:15870 handle_request: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2269f2c1 Our tag: as337443e0 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc [Mar 9 19:55:11] 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 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9 [Mar 9 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 3c26701520c0-duvkdwbwjm32 Their Tag 08j0pr3ogj Our tag: as102b506d [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 3053 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '3c26701520c0-duvkdwbwjm32' of Request 3053: Match Found [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2269f2c1 Our tag: as337443e0 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc [Mar 9 19:55:11] 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 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9 [Mar 9 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c26701520c0-duvkdwbwjm32 Their Tag 08j0pr3ogj Our tag: as102b506d [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 3c2670151ddc-bnz4m8sg5zgw Their Tag 0wm7jm1qjq Our tag: as6e1f2643 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:15870 handle_request: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:15665 handle_request_subscribe: Adding subscription for extension 701 context commzilla-local for peer 233 [Mar 9 19:55:11] DEBUG[2295]: devicestate.c:157 ast_device_state: Checking if I can find provider for "park" - number: 701@parkedcalls [Mar 9 19:55:11] DEBUG[2295]: devicestate.c:230 getproviderstate: Checking provider SLA with park [Mar 9 19:55:11] DEBUG[2295]: devicestate.c:230 getproviderstate: Checking provider Meetme with park [Mar 9 19:55:11] DEBUG[2295]: devicestate.c:230 getproviderstate: Checking provider Custom with park [Mar 9 19:55:11] DEBUG[2295]: devicestate.c:230 getproviderstate: Checking provider Park with park [Mar 9 19:55:11] DEBUG[2295]: res_features.c:339 metermaidstate: Checking state of exten 701 in context parkedcalls [Mar 9 19:55:11] DEBUG[2295]: devicestate.c:157 ast_device_state: Checking if I can find provider for "park" - number: 701@parkedcalls [Mar 9 19:55:11] DEBUG[2295]: devicestate.c:230 getproviderstate: Checking provider SLA with park [Mar 9 19:55:11] DEBUG[2295]: devicestate.c:230 getproviderstate: Checking provider Meetme with park [Mar 9 19:55:11] DEBUG[2295]: devicestate.c:230 getproviderstate: Checking provider Custom with park [Mar 9 19:55:11] DEBUG[2295]: devicestate.c:230 getproviderstate: Checking provider Park with park [Mar 9 19:55:11] DEBUG[2295]: res_features.c:339 metermaidstate: Checking state of exten 701 in context parkedcalls [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2269f2c1 Our tag: as337443e0 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc [Mar 9 19:55:11] 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 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9 [Mar 9 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] 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 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c26701520c0-duvkdwbwjm32 Their Tag 08j0pr3ogj Our tag: as102b506d [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 3c2670151ddc-bnz4m8sg5zgw Their Tag 0wm7jm1qjq Our tag: as6e1f2643 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:2184 __sip_ack: Acked pending invite 3006 [Mar 9 19:55:11] DEBUG[2295]: chan_sip.c:2218 __sip_ack: Stopping retransmission on '3c2670151ddc-bnz4m8sg5zgw' of Request 3006: Match Found [Mar 9 19:55:13] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2269f2c1 Our tag: as337443e0 [Mar 9 19:55:13] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4 [Mar 9 19:55:13] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77 [Mar 9 19:55:13] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe [Mar 9 19:55:13] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc [Mar 9 19:55:13] 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 19:55:13] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c [Mar 9 19:55:13] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b [Mar 9 19:55:13] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b [Mar 9 19:55:13] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264 [Mar 9 19:55:13] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b [Mar 9 19:55:13] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744 [Mar 9 19:55:13] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb [Mar 9 19:55:13] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac [Mar 9 19:55:13] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9 [Mar 9 19:55:13] 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 19:55:13] 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 19:55:13] 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 19:55:13] 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 19:55:13] 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 19:55:13] 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 19:55:13] 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 19:55:13] 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 19:55:13] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c26701520c0-duvkdwbwjm32 Their Tag 08j0pr3ogj Our tag: as102b506d [Mar 9 19:55:13] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2670151ddc-bnz4m8sg5zgw Their Tag 0wm7jm1qjq Our tag: as6e1f2643 [Mar 9 19:55:13] DEBUG[2295]: chan_sip.c:4621 sip_alloc: Allocating new SIP dialog for 7f11da0d-3c5fd7af-f3bb0084@192.168.192.191 - SUBSCRIBE (No RTP) [Mar 9 19:55:13] DEBUG[2295]: chan_sip.c:15870 handle_request: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE [Mar 9 19:55:13] DEBUG[2295]: chan_sip.c:4677 find_call: = Found Their Call ID: 7f11da0d-3c5fd7af-f3bb0084@192.168.192.191 Their Tag 4EAE1921-88BCA97E Our tag: as43507a94 [Mar 9 19:55:13] DEBUG[2295]: chan_sip.c:15870 handle_request: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE [Mar 9 19:55:13] DEBUG[2295]: chan_sip.c:15637 handle_request_subscribe: Received SIP subscribe for unknown event package: missed-call-summary Really destroying SIP dialog '7f11da0d-3c5fd7af-f3bb0084@192.168.192.191' Method: SUBSCRIBE [Mar 9 19:55:14] DEBUG[2295]: chan_sip.c:4621 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Mar 9 19:55:14] DEBUG[2295]: chan_sip.c:3361 sip_destroy: Destroying SIP dialog 7d78989f5cffde9368beabdf411e19db@99.229.93.248 Really destroying SIP dialog '7d78989f5cffde9368beabdf411e19db@99.229.93.248' Method: OPTIONS [Mar 9 19:55:14] DEBUG[2295]: devicestate.c:302 ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/230 [Mar 9 19:55:14] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 230 [Mar 9 19:55:14] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 230 [Mar 9 19:55:14] DEBUG[2243]: devicestate.c:287 do_state_change: Changing state for SIP/230 - state 5 (Unavailable) [Mar 9 19:55:14] DEBUG[2243]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 230 [Mar 9 19:55:14] DEBUG[2243]: chan_sip.c:16637 sip_devicestate: Checking device state for peer 230 [Mar 9 19:55:14] 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 19:55:14] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2269f2c1 Our tag: as337443e0 [Mar 9 19:55:14] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4 [Mar 9 19:55:14] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77 [Mar 9 19:55:14] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe [Mar 9 19:55:14] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc [Mar 9 19:55:14] 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 19:55:14] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c [Mar 9 19:55:14] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b [Mar 9 19:55:14] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b [Mar 9 19:55:14] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264 [Mar 9 19:55:14] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b [Mar 9 19:55:14] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744 [Mar 9 19:55:14] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb [Mar 9 19:55:14] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac [Mar 9 19:55:14] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9 [Mar 9 19:55:14] 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 19:55:14] 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 19:55:14] 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 19:55:14] 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 19:55:14] 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 19:55:14] 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 19:55:14] 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 19:55:14] 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 19:55:14] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c26701520c0-duvkdwbwjm32 Their Tag 08j0pr3ogj Our tag: as102b506d [Mar 9 19:55:14] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2670151ddc-bnz4m8sg5zgw Their Tag 0wm7jm1qjq Our tag: as6e1f2643 [Mar 9 19:55:14] DEBUG[2295]: chan_sip.c:16142 sipsock_read: Invalid SIP message - rejected , no callid, len 579 [Mar 9 19:55:17] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 41e472780329e01d1562617572cfb440@67.55.31.179 Their Tag as2269f2c1 Our tag: as337443e0 [Mar 9 19:55:17] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584247e2-rppyd3embsq7 Their Tag qj5fmxfq90 Our tag: as40ab73a4 [Mar 9 19:55:17] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2c584259c7-jw1urfm8cthy Their Tag zveng89eys Our tag: as49542a77 [Mar 9 19:55:17] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 511c90173aab58af Their Tag 794f98b7c6 Our tag: as125f6cbe [Mar 9 19:55:17] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 1d1af257c5f96a16 Their Tag dc6226dcba Our tag: as2be765dc [Mar 9 19:55:17] 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 19:55:17] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 23d73632342fd41f Their Tag 5cf47049c7 Our tag: as7f68699c [Mar 9 19:55:17] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 674a51b1c6a6f486 Their Tag afcbd4ffe9 Our tag: as08f50f3b [Mar 9 19:55:17] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 14f44547feca0a31 Their Tag 3d71c2ce02 Our tag: as0493d76b [Mar 9 19:55:17] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 54c926546783f18d Their Tag ef04ca8193 Our tag: as719b9264 [Mar 9 19:55:17] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 7461789fbc6735ef Their Tag fc141e8297 Our tag: as0918286b [Mar 9 19:55:17] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: a5283085413b819d Their Tag f026e0d22e Our tag: as0f435744 [Mar 9 19:55:17] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 33f9e6b364725d42 Their Tag e620f33393 Our tag: as0bc68cbb [Mar 9 19:55:17] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 89b28dde40946e30 Their Tag fdc64f6397 Our tag: as490402ac [Mar 9 19:55:17] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 0fc3423de88b079d Their Tag 0feecb83ca Our tag: as20fa22d9 [Mar 9 19:55:17] 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 19:55:17] 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 19:55:17] 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 19:55:17] 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 19:55:17] 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 19:55:17] 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 19:55:17] 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 19:55:17] 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 19:55:17] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c26701520c0-duvkdwbwjm32 Their Tag 08j0pr3ogj Our tag: as102b506d [Mar 9 19:55:17] DEBUG[2295]: chan_sip.c:4677 find_call: = No match Their Call ID: 3c2670151ddc-bnz4m8sg5zgw Their Tag 0wm7jm1qjq Our tag: as6e1f2643 [Mar 9 19:55:17] DEBUG[2295]: chan_sip.c:16142 sipsock_read: Invalid SIP message - rejected , no callid, len 551