[Feb 29 16:02:03] DEBUG[8183] acl.c: ##### Testing 192.168.10.105 with 192.168.10.0
[Feb 29 16:02:03] DEBUG[8183] chan_sip.c: Allocating new SIP dialog for 39e175a5-c1139f88-ac72f8f@192.168.10.105 - REGISTER (No RTP)
[Feb 29 16:02:03] DEBUG[8183] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER
[Feb 29 16:02:03] DEBUG[8183] chan_sip.c: = Found Their Call ID: 39e175a5-c1139f88-ac72f8f@192.168.10.105 Their Tag 8508E96A-84CF7509 Our tag: as7f473efd
[Feb 29 16:02:03] DEBUG[8183] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER
[Feb 29 16:02:03] DEBUG[8183] devicestate.c: Notification of state change to be queued on device/channel SIP/220
[Feb 29 16:02:03] DEBUG[8167] devicestate.c: No provider found, checking channel drivers for SIP - 220
[Feb 29 16:02:03] DEBUG[8167] chan_sip.c: Checking device state for peer 220
[Feb 29 16:02:03] DEBUG[8167] devicestate.c: Changing state for SIP/220 - state 1 (Not in use)
[Feb 29 16:02:03] DEBUG[8167] devicestate.c: No provider found, checking channel drivers for SIP - 220
[Feb 29 16:02:03] DEBUG[8167] chan_sip.c: Checking device state for peer 220
[Feb 29 16:02:03] DEBUG[8195] app_queue.c: Device 'SIP/220' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Feb 29 16:02:05] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7ae0abab311a00b72969b93a39ed5e0c@212.150.88.20
[Feb 29 16:02:07] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 50a782dc70f5390e5d79883e28fc8469@212.150.88.20
[Feb 29 16:02:10] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 5b1e5da360f038fd433550e60cf0cfec@212.150.88.20
[Feb 29 16:02:11] DEBUG[8183] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Feb 29 16:02:11] DEBUG[8183] acl.c: ##### Testing 192.168.10.105 with 192.168.10.0
[Feb 29 16:02:11] DEBUG[8183] chan_sip.c: = Found Their Call ID: 7b0e5e3619eb53d547a347aa7946bf48@192.168.10.210 Their Tag Our tag: as345fbdd9
[Feb 29 16:02:11] DEBUG[8183] chan_sip.c: Stopping retransmission on '7b0e5e3619eb53d547a347aa7946bf48@192.168.10.210' of Request 102: Match Not Found
[Feb 29 16:02:11] VERBOSE[8183] logger.c: Really destroying SIP dialog '7b0e5e3619eb53d547a347aa7946bf48@192.168.10.210' Method: NOTIFY
[Feb 29 16:02:12] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 4e285aed751f76f658fc1b0021778c69@212.150.88.20
[Feb 29 16:02:20] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 29e3f42835a81659589d72f6741ae21e@212.150.88.20
[Feb 29 16:02:20] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 42a4279830cfb18e5dbd06ca3fefe116@212.150.88.20
[Feb 29 16:02:20] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 25c2645e119453753be8389827704a1f@212.150.88.20
[Feb 29 16:02:22] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 3de08a4d3d27ea787c4a3287202aa1a5@212.150.88.20
[Feb 29 16:02:24] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7c4f19471f4890a12eaaefea616d3ec8@212.150.88.20
[Feb 29 16:02:35] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 70f8ff7b46c5c84a73828a2c2110cfc0@212.150.88.20
[Feb 29 16:02:35] DEBUG[8183] chan_sip.c: Auto destroying SIP dialog '39e175a5-c1139f88-ac72f8f@192.168.10.105'
[Feb 29 16:02:35] DEBUG[8183] chan_sip.c: Destroying SIP dialog 39e175a5-c1139f88-ac72f8f@192.168.10.105
[Feb 29 16:02:35] VERBOSE[8183] logger.c: Really destroying SIP dialog '39e175a5-c1139f88-ac72f8f@192.168.10.105' Method: REGISTER
[Feb 29 16:02:37] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7ae0abab311a00b72969b93a39ed5e0c@212.150.88.20
[Feb 29 16:02:39] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 50a782dc70f5390e5d79883e28fc8469@212.150.88.20
[Feb 29 16:02:42] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 5b1e5da360f038fd433550e60cf0cfec@212.150.88.20
[Feb 29 16:02:43] DEBUG[8183] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Feb 29 16:02:43] DEBUG[8183] acl.c: ##### Testing 192.168.10.105 with 192.168.10.0
[Feb 29 16:02:43] DEBUG[8183] chan_sip.c: = Found Their Call ID: 613492826b22fbd47350d3a96a590c0f@192.168.10.210 Their Tag Our tag: as4a98d42b
[Feb 29 16:02:43] DEBUG[8183] chan_sip.c: Stopping retransmission on '613492826b22fbd47350d3a96a590c0f@192.168.10.210' of Request 102: Match Not Found
[Feb 29 16:02:43] VERBOSE[8183] logger.c: Really destroying SIP dialog '613492826b22fbd47350d3a96a590c0f@192.168.10.210' Method: OPTIONS
[Feb 29 16:02:44] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 4e285aed751f76f658fc1b0021778c69@212.150.88.20
[Feb 29 16:02:52] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 29e3f42835a81659589d72f6741ae21e@212.150.88.20
[Feb 29 16:02:52] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 42a4279830cfb18e5dbd06ca3fefe116@212.150.88.20
[Feb 29 16:02:52] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 25c2645e119453753be8389827704a1f@212.150.88.20
[Feb 29 16:02:54] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 3de08a4d3d27ea787c4a3287202aa1a5@212.150.88.20
[Feb 29 16:02:56] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7c4f19471f4890a12eaaefea616d3ec8@212.150.88.20
[Feb 29 16:03:07] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 70f8ff7b46c5c84a73828a2c2110cfc0@212.150.88.20
[Feb 29 16:03:09] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7ae0abab311a00b72969b93a39ed5e0c@212.150.88.20
[Feb 29 16:03:11] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 50a782dc70f5390e5d79883e28fc8469@212.150.88.20
[Feb 29 16:03:14] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 5b1e5da360f038fd433550e60cf0cfec@212.150.88.20
[Feb 29 16:03:16] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 4e285aed751f76f658fc1b0021778c69@212.150.88.20
[Feb 29 16:03:24] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 29e3f42835a81659589d72f6741ae21e@212.150.88.20
[Feb 29 16:03:24] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 42a4279830cfb18e5dbd06ca3fefe116@212.150.88.20
[Feb 29 16:03:24] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 25c2645e119453753be8389827704a1f@212.150.88.20
[Feb 29 16:03:26] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 3de08a4d3d27ea787c4a3287202aa1a5@212.150.88.20
[Feb 29 16:03:28] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7c4f19471f4890a12eaaefea616d3ec8@212.150.88.20
[Feb 29 16:03:39] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 70f8ff7b46c5c84a73828a2c2110cfc0@212.150.88.20
[Feb 29 16:03:41] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7ae0abab311a00b72969b93a39ed5e0c@212.150.88.20
[Feb 29 16:03:43] DEBUG[8183] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Feb 29 16:03:43] DEBUG[8183] acl.c: ##### Testing 192.168.10.105 with 192.168.10.0
[Feb 29 16:03:43] DEBUG[8183] chan_sip.c: = Found Their Call ID: 0fbf39ae4dbc9021141488d229e5bff3@192.168.10.210 Their Tag Our tag: as3098a239
[Feb 29 16:03:43] DEBUG[8183] chan_sip.c: Stopping retransmission on '0fbf39ae4dbc9021141488d229e5bff3@192.168.10.210' of Request 102: Match Not Found
[Feb 29 16:03:43] VERBOSE[8183] logger.c: Really destroying SIP dialog '0fbf39ae4dbc9021141488d229e5bff3@192.168.10.210' Method: OPTIONS
[Feb 29 16:03:43] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 50a782dc70f5390e5d79883e28fc8469@212.150.88.20
[Feb 29 16:03:46] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 5b1e5da360f038fd433550e60cf0cfec@212.150.88.20
[Feb 29 16:03:48] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 4e285aed751f76f658fc1b0021778c69@212.150.88.20
[Feb 29 16:03:56] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 29e3f42835a81659589d72f6741ae21e@212.150.88.20
[Feb 29 16:03:56] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 42a4279830cfb18e5dbd06ca3fefe116@212.150.88.20
[Feb 29 16:03:56] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 25c2645e119453753be8389827704a1f@212.150.88.20
[Feb 29 16:03:58] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 3de08a4d3d27ea787c4a3287202aa1a5@212.150.88.20
[Feb 29 16:04:00] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7c4f19471f4890a12eaaefea616d3ec8@212.150.88.20
[Feb 29 16:04:11] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 70f8ff7b46c5c84a73828a2c2110cfc0@212.150.88.20
[Feb 29 16:04:13] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7ae0abab311a00b72969b93a39ed5e0c@212.150.88.20
[Feb 29 16:04:15] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 50a782dc70f5390e5d79883e28fc8469@212.150.88.20
[Feb 29 16:04:18] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 5b1e5da360f038fd433550e60cf0cfec@212.150.88.20
[Feb 29 16:04:20] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 4e285aed751f76f658fc1b0021778c69@212.150.88.20
[Feb 29 16:04:28] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 29e3f42835a81659589d72f6741ae21e@212.150.88.20
[Feb 29 16:04:28] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 42a4279830cfb18e5dbd06ca3fefe116@212.150.88.20
[Feb 29 16:04:28] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 25c2645e119453753be8389827704a1f@212.150.88.20
[Feb 29 16:04:30] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 3de08a4d3d27ea787c4a3287202aa1a5@212.150.88.20
[Feb 29 16:04:32] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7c4f19471f4890a12eaaefea616d3ec8@212.150.88.20
[Feb 29 16:04:43] DEBUG[8183] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Feb 29 16:04:43] DEBUG[8183] acl.c: ##### Testing 192.168.10.105 with 192.168.10.0
[Feb 29 16:04:43] DEBUG[8183] chan_sip.c: = Found Their Call ID: 75666b801e4160d37e6af3a576a0bc8e@192.168.10.210 Their Tag Our tag: as324f63ef
[Feb 29 16:04:43] DEBUG[8183] chan_sip.c: Stopping retransmission on '75666b801e4160d37e6af3a576a0bc8e@192.168.10.210' of Request 102: Match Not Found
[Feb 29 16:04:43] VERBOSE[8183] logger.c: Really destroying SIP dialog '75666b801e4160d37e6af3a576a0bc8e@192.168.10.210' Method: OPTIONS
[Feb 29 16:04:43] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 70f8ff7b46c5c84a73828a2c2110cfc0@212.150.88.20
[Feb 29 16:04:45] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7ae0abab311a00b72969b93a39ed5e0c@212.150.88.20
[Feb 29 16:04:47] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 50a782dc70f5390e5d79883e28fc8469@212.150.88.20
[Feb 29 16:04:50] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 5b1e5da360f038fd433550e60cf0cfec@212.150.88.20
[Feb 29 16:04:52] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 4e285aed751f76f658fc1b0021778c69@212.150.88.20
[Feb 29 16:05:00] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 29e3f42835a81659589d72f6741ae21e@212.150.88.20
[Feb 29 16:05:00] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 42a4279830cfb18e5dbd06ca3fefe116@212.150.88.20
[Feb 29 16:05:00] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 25c2645e119453753be8389827704a1f@212.150.88.20
[Feb 29 16:05:02] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 3de08a4d3d27ea787c4a3287202aa1a5@212.150.88.20
[Feb 29 16:05:04] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7c4f19471f4890a12eaaefea616d3ec8@212.150.88.20
[Feb 29 16:05:15] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 70f8ff7b46c5c84a73828a2c2110cfc0@212.150.88.20
[Feb 29 16:05:17] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7ae0abab311a00b72969b93a39ed5e0c@212.150.88.20
[Feb 29 16:05:19] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 50a782dc70f5390e5d79883e28fc8469@212.150.88.20
[Feb 29 16:05:22] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 5b1e5da360f038fd433550e60cf0cfec@212.150.88.20
[Feb 29 16:05:24] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 4e285aed751f76f658fc1b0021778c69@212.150.88.20
[Feb 29 16:05:32] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 29e3f42835a81659589d72f6741ae21e@212.150.88.20
[Feb 29 16:05:32] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 42a4279830cfb18e5dbd06ca3fefe116@212.150.88.20
[Feb 29 16:05:32] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 25c2645e119453753be8389827704a1f@212.150.88.20
[Feb 29 16:05:34] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 3de08a4d3d27ea787c4a3287202aa1a5@212.150.88.20
[Feb 29 16:05:36] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7c4f19471f4890a12eaaefea616d3ec8@212.150.88.20
[Feb 29 16:05:43] DEBUG[8183] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Feb 29 16:05:43] DEBUG[8183] acl.c: ##### Testing 192.168.10.105 with 192.168.10.0
[Feb 29 16:05:43] DEBUG[8183] chan_sip.c: = Found Their Call ID: 7a704f6402a3c06e12be38fe34010392@192.168.10.210 Their Tag Our tag: as59d4a9d7
[Feb 29 16:05:43] DEBUG[8183] chan_sip.c: Stopping retransmission on '7a704f6402a3c06e12be38fe34010392@192.168.10.210' of Request 102: Match Not Found
[Feb 29 16:05:43] VERBOSE[8183] logger.c: Really destroying SIP dialog '7a704f6402a3c06e12be38fe34010392@192.168.10.210' Method: OPTIONS
[Feb 29 16:05:47] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 70f8ff7b46c5c84a73828a2c2110cfc0@212.150.88.20
[Feb 29 16:05:49] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7ae0abab311a00b72969b93a39ed5e0c@212.150.88.20
[Feb 29 16:05:51] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 50a782dc70f5390e5d79883e28fc8469@212.150.88.20
[Feb 29 16:05:54] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 5b1e5da360f038fd433550e60cf0cfec@212.150.88.20
[Feb 29 16:05:56] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 4e285aed751f76f658fc1b0021778c69@212.150.88.20
[Feb 29 16:06:04] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 29e3f42835a81659589d72f6741ae21e@212.150.88.20
[Feb 29 16:06:04] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 42a4279830cfb18e5dbd06ca3fefe116@212.150.88.20
[Feb 29 16:06:04] DEBUG[8183] chan_sip.c: = No match Their Call ID: 42a4279830cfb18e5dbd06ca3fefe116@212.150.88.20 Their Tag as0ddef762 Our tag: as5f90a085
[Feb 29 16:06:04] DEBUG[8183] chan_sip.c: = No match Their Call ID: 3de08a4d3d27ea787c4a3287202aa1a5@212.150.88.20 Their Tag as52729247 Our tag: as753fa433
[Feb 29 16:06:04] DEBUG[8183] chan_sip.c: = No match Their Call ID: 7c4f19471f4890a12eaaefea616d3ec8@212.150.88.20 Their Tag as34583d2a Our tag: as22ab5c67
[Feb 29 16:06:04] DEBUG[8183] chan_sip.c: = No match Their Call ID: 4e285aed751f76f658fc1b0021778c69@212.150.88.20 Their Tag as017943c0 Our tag: as37ede7fc
[Feb 29 16:06:04] DEBUG[8183] chan_sip.c: = No match Their Call ID: 5b1e5da360f038fd433550e60cf0cfec@212.150.88.20 Their Tag as1a5bf437 Our tag: as330e1e2a
[Feb 29 16:06:04] DEBUG[8183] chan_sip.c: = No match Their Call ID: 29e3f42835a81659589d72f6741ae21e@212.150.88.20 Their Tag as561536f3 Our tag: as7902a4f9
[Feb 29 16:06:04] DEBUG[8183] chan_sip.c: = No match Their Call ID: 50a782dc70f5390e5d79883e28fc8469@212.150.88.20 Their Tag as4abe9a5f Our tag: as44e2984a
[Feb 29 16:06:04] DEBUG[8183] chan_sip.c: = No match Their Call ID: 66a85fe557bb3a347168db411f4f6ec9@212.150.88.20 Their Tag as2a035300 Our tag: as375b194d
[Feb 29 16:06:04] DEBUG[8183] chan_sip.c: = No match Their Call ID: 61455d2a3230fe7263e72100521774f7@212.150.88.20 Their Tag as5efeeff1 Our tag: as18ed26dd
[Feb 29 16:06:04] DEBUG[8183] chan_sip.c: = No match Their Call ID: 70f8ff7b46c5c84a73828a2c2110cfc0@212.150.88.20 Their Tag as00741db3 Our tag: as264299ea
[Feb 29 16:06:04] DEBUG[8183] chan_sip.c: = Found Their Call ID: 1d242d5b-60212ac6-5b7d8cb5@192.168.10.105 Their Tag FC50F358-C39A791F Our tag: as4f3016ac
[Feb 29 16:06:04] DEBUG[8183] chan_sip.c: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE
[Feb 29 16:06:04] DEBUG[8183] chan_sip.c: Adding subscription for mailbox notification - peer 220 Mailbox 220@default
[Feb 29 16:06:04] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 25c2645e119453753be8389827704a1f@212.150.88.20
[Feb 29 16:06:06] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 3de08a4d3d27ea787c4a3287202aa1a5@212.150.88.20
[Feb 29 16:06:08] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7c4f19471f4890a12eaaefea616d3ec8@212.150.88.20
[Feb 29 16:06:19] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 70f8ff7b46c5c84a73828a2c2110cfc0@212.150.88.20
[Feb 29 16:06:21] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7ae0abab311a00b72969b93a39ed5e0c@212.150.88.20
[Feb 29 16:06:23] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 50a782dc70f5390e5d79883e28fc8469@212.150.88.20
[Feb 29 16:06:26] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 5b1e5da360f038fd433550e60cf0cfec@212.150.88.20
[Feb 29 16:06:28] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 4e285aed751f76f658fc1b0021778c69@212.150.88.20
[Feb 29 16:06:36] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 29e3f42835a81659589d72f6741ae21e@212.150.88.20
[Feb 29 16:06:36] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 42a4279830cfb18e5dbd06ca3fefe116@212.150.88.20
[Feb 29 16:06:36] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 25c2645e119453753be8389827704a1f@212.150.88.20
[Feb 29 16:06:38] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 3de08a4d3d27ea787c4a3287202aa1a5@212.150.88.20
[Feb 29 16:06:40] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7c4f19471f4890a12eaaefea616d3ec8@212.150.88.20
[Feb 29 16:06:43] DEBUG[8183] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Feb 29 16:06:43] DEBUG[8183] acl.c: ##### Testing 192.168.10.105 with 192.168.10.0
[Feb 29 16:06:43] DEBUG[8183] chan_sip.c: = Found Their Call ID: 1b36cbdc1a7e0ad93f84dac623c4d7c3@192.168.10.210 Their Tag Our tag: as31350a0b
[Feb 29 16:06:43] DEBUG[8183] chan_sip.c: Stopping retransmission on '1b36cbdc1a7e0ad93f84dac623c4d7c3@192.168.10.210' of Request 102: Match Not Found
[Feb 29 16:06:43] VERBOSE[8183] logger.c: Really destroying SIP dialog '1b36cbdc1a7e0ad93f84dac623c4d7c3@192.168.10.210' Method: OPTIONS
[Feb 29 16:06:51] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 70f8ff7b46c5c84a73828a2c2110cfc0@212.150.88.20
[Feb 29 16:06:53] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7ae0abab311a00b72969b93a39ed5e0c@212.150.88.20
[Feb 29 16:06:55] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 50a782dc70f5390e5d79883e28fc8469@212.150.88.20
[Feb 29 16:06:58] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 5b1e5da360f038fd433550e60cf0cfec@212.150.88.20
[Feb 29 16:07:00] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 4e285aed751f76f658fc1b0021778c69@212.150.88.20
[Feb 29 16:07:08] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 29e3f42835a81659589d72f6741ae21e@212.150.88.20
[Feb 29 16:07:08] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 42a4279830cfb18e5dbd06ca3fefe116@212.150.88.20
[Feb 29 16:07:08] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 25c2645e119453753be8389827704a1f@212.150.88.20
[Feb 29 16:07:10] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 3de08a4d3d27ea787c4a3287202aa1a5@212.150.88.20
[Feb 29 16:07:12] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7c4f19471f4890a12eaaefea616d3ec8@212.150.88.20
[Feb 29 16:07:23] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 70f8ff7b46c5c84a73828a2c2110cfc0@212.150.88.20
[Feb 29 16:07:25] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7ae0abab311a00b72969b93a39ed5e0c@212.150.88.20
[Feb 29 16:07:27] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 50a782dc70f5390e5d79883e28fc8469@212.150.88.20
[Feb 29 16:07:30] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 5b1e5da360f038fd433550e60cf0cfec@212.150.88.20
[Feb 29 16:07:32] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 4e285aed751f76f658fc1b0021778c69@212.150.88.20
[Feb 29 16:07:40] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 29e3f42835a81659589d72f6741ae21e@212.150.88.20
[Feb 29 16:07:40] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 42a4279830cfb18e5dbd06ca3fefe116@212.150.88.20
[Feb 29 16:07:40] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 25c2645e119453753be8389827704a1f@212.150.88.20
[Feb 29 16:07:42] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 3de08a4d3d27ea787c4a3287202aa1a5@212.150.88.20
[Feb 29 16:07:43] DEBUG[8183] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Feb 29 16:07:43] DEBUG[8183] acl.c: ##### Testing 192.168.10.105 with 192.168.10.0
[Feb 29 16:07:43] DEBUG[8183] chan_sip.c: = Found Their Call ID: 0495b4907ddc73d8768c8c3e41256069@192.168.10.210 Their Tag Our tag: as0541a153
[Feb 29 16:07:43] DEBUG[8183] chan_sip.c: Stopping retransmission on '0495b4907ddc73d8768c8c3e41256069@192.168.10.210' of Request 102: Match Not Found
[Feb 29 16:07:43] VERBOSE[8183] logger.c: Really destroying SIP dialog '0495b4907ddc73d8768c8c3e41256069@192.168.10.210' Method: OPTIONS
[Feb 29 16:07:44] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7c4f19471f4890a12eaaefea616d3ec8@212.150.88.20
[Feb 29 16:07:55] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 70f8ff7b46c5c84a73828a2c2110cfc0@212.150.88.20
[Feb 29 16:07:57] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7ae0abab311a00b72969b93a39ed5e0c@212.150.88.20
[Feb 29 16:07:59] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 50a782dc70f5390e5d79883e28fc8469@212.150.88.20
[Feb 29 16:08:02] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 5b1e5da360f038fd433550e60cf0cfec@212.150.88.20
[Feb 29 16:08:04] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 4e285aed751f76f658fc1b0021778c69@212.150.88.20
[Feb 29 16:08:12] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 29e3f42835a81659589d72f6741ae21e@212.150.88.20
[Feb 29 16:08:12] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 42a4279830cfb18e5dbd06ca3fefe116@212.150.88.20
[Feb 29 16:08:12] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 25c2645e119453753be8389827704a1f@212.150.88.20
[Feb 29 16:08:14] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 3de08a4d3d27ea787c4a3287202aa1a5@212.150.88.20
[Feb 29 16:08:16] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7c4f19471f4890a12eaaefea616d3ec8@212.150.88.20
[Feb 29 16:08:27] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 70f8ff7b46c5c84a73828a2c2110cfc0@212.150.88.20
[Feb 29 16:08:29] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7ae0abab311a00b72969b93a39ed5e0c@212.150.88.20
[Feb 29 16:08:31] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 50a782dc70f5390e5d79883e28fc8469@212.150.88.20
[Feb 29 16:08:34] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 5b1e5da360f038fd433550e60cf0cfec@212.150.88.20
[Feb 29 16:08:36] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 4e285aed751f76f658fc1b0021778c69@212.150.88.20
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: = No match Their Call ID: 42a4279830cfb18e5dbd06ca3fefe116@212.150.88.20 Their Tag as0ddef762 Our tag: as5f90a085
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: = No match Their Call ID: 3de08a4d3d27ea787c4a3287202aa1a5@212.150.88.20 Their Tag as52729247 Our tag: as753fa433
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: = No match Their Call ID: 7c4f19471f4890a12eaaefea616d3ec8@212.150.88.20 Their Tag as34583d2a Our tag: as22ab5c67
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: = No match Their Call ID: 4e285aed751f76f658fc1b0021778c69@212.150.88.20 Their Tag as017943c0 Our tag: as37ede7fc
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: = No match Their Call ID: 5b1e5da360f038fd433550e60cf0cfec@212.150.88.20 Their Tag as1a5bf437 Our tag: as330e1e2a
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: = No match Their Call ID: 29e3f42835a81659589d72f6741ae21e@212.150.88.20 Their Tag as561536f3 Our tag: as7902a4f9
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: = No match Their Call ID: 50a782dc70f5390e5d79883e28fc8469@212.150.88.20 Their Tag as4abe9a5f Our tag: as44e2984a
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: = No match Their Call ID: 66a85fe557bb3a347168db411f4f6ec9@212.150.88.20 Their Tag as2a035300 Our tag: as375b194d
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: = No match Their Call ID: 61455d2a3230fe7263e72100521774f7@212.150.88.20 Their Tag as5efeeff1 Our tag: as18ed26dd
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: = No match Their Call ID: 70f8ff7b46c5c84a73828a2c2110cfc0@212.150.88.20 Their Tag as00741db3 Our tag: as264299ea
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: = No match Their Call ID: 1d242d5b-60212ac6-5b7d8cb5@192.168.10.105 Their Tag FC50F358-C39A791F Our tag: as4f3016ac
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: = No match Their Call ID: 25c2645e119453753be8389827704a1f@212.150.88.20 Their Tag as48641ed7 Our tag: as0e128327
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: = No match Their Call ID: 7ae0abab311a00b72969b93a39ed5e0c@212.150.88.20 Their Tag as37495c29 Our tag: as13666574
[Feb 29 16:08:38] WARNING[8183] acl.c: Cannot connect
[Feb 29 16:08:38] DEBUG[8183] acl.c: ##### Testing 212.150.88.20 with 192.168.10.0
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: Target address 212.150.88.20 is not local, substituting externip
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: Setting NAT on RTP to Off
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: Allocating new SIP dialog for 31f8f981582e4cec4bf953bc70764d0b@212.150.88.20 - INVITE (With RTP)
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: T38 state changed to 0 on channel
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: We're settling with these formats: 0xc (ulaw|alaw)
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: Checking SIP call limits for device
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: Updating call counter for incoming call
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: *** Our native formats are 0x4 (ulaw)
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: *** Joint capabilities are 0xc (ulaw|alaw)
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: *** Our capabilities are 0xc (ulaw|alaw)
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw)
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: This channel will not be able to handle video.
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: build_route: Contact hop:
[Feb 29 16:08:38] DEBUG[8183] chan_sip.c: SIP/212.150.88.20-0953b9e0: New call is still down.... Trying...
[Feb 29 16:08:38] WARNING[8183] chan_sip.c: sip_xmit of 0xa9d194 (len 466) to 212.150.88.20:5060 returned -2: Network is unreachable
[Feb 29 16:08:38] DEBUG[8183] devicestate.c: Notification of state change to be queued on device/channel SIP/212.150.88.20-0953b9e0
[Feb 29 16:08:38] DEBUG[8183] devicestate.c: Notification of state change to be queued on device/channel SIP/212.150.88.20
[Feb 29 16:08:38] DEBUG[8167] devicestate.c: No provider found, checking channel drivers for SIP - 212.150.88.20-0953b9e0
[Feb 29 16:08:38] DEBUG[8167] chan_sip.c: Checking device state for peer 212.150.88.20-0953b9e0
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Launching 'NoOp'
[Feb 29 16:08:38] VERBOSE[9003] logger.c: -- Executing [97225695295@from-sip-external:1] NoOp("SIP/212.150.88.20-0953b9e0", "Received incoming SIP connection from unknown peer to 97225695295") in new stack
[Feb 29 16:08:38] DEBUG[8167] devicestate.c: Changing state for SIP/212.150.88.20-0953b9e0 - state 4 (Invalid)
[Feb 29 16:08:38] DEBUG[8167] devicestate.c: No provider found, checking channel drivers for SIP - 212.150.88.20
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Expression result is '0'
[Feb 29 16:08:38] DEBUG[8167] chan_sip.c: Checking device state for peer 212.150.88.20
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Function result is '97225695295'
[Feb 29 16:08:38] DEBUG[8195] app_queue.c: Device 'SIP/212.150.88.20-0953b9e0' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Launching 'Set'
[Feb 29 16:08:38] DEBUG[8167] devicestate.c: Changing state for SIP/212.150.88.20 - state 2 (In use)
[Feb 29 16:08:38] DEBUG[8195] app_queue.c: Device 'SIP/212.150.88.20' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Feb 29 16:08:38] VERBOSE[9003] logger.c: -- Executing [97225695295@from-sip-external:2] Set("SIP/212.150.88.20-0953b9e0", "DID=97225695295") in new stack
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Launching 'Goto'
[Feb 29 16:08:38] VERBOSE[9003] logger.c: -- Executing [97225695295@from-sip-external:3] Goto("SIP/212.150.88.20-0953b9e0", "s|1") in new stack
[Feb 29 16:08:38] VERBOSE[9003] logger.c: -- Goto (from-sip-external,s,1)
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Expression result is '1'
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Launching 'GotoIf'
[Feb 29 16:08:38] VERBOSE[9003] logger.c: -- Executing [s@from-sip-external:1] GotoIf("SIP/212.150.88.20-0953b9e0", "1?from-trunk|97225695295|1") in new stack
[Feb 29 16:08:38] VERBOSE[9003] logger.c: -- Goto (from-trunk,97225695295,1)
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Launching 'Set'
[Feb 29 16:08:38] VERBOSE[9003] logger.c: -- Executing [97225695295@from-trunk:1] Set("SIP/212.150.88.20-0953b9e0", "__FROM_DID=97225695295") in new stack
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Function result is '6561116'
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Expression result is '1'
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Launching 'GotoIf'
[Feb 29 16:08:38] VERBOSE[9003] logger.c: -- Executing [97225695295@from-trunk:2] GotoIf("SIP/212.150.88.20-0953b9e0", "1 ?cidok") in new stack
[Feb 29 16:08:38] VERBOSE[9003] logger.c: -- Goto (from-trunk,97225695295,4)
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Function result is '"6561116" <6561116>'
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Launching 'NoOp'
[Feb 29 16:08:38] VERBOSE[9003] logger.c: -- Executing [97225695295@from-trunk:4] NoOp("SIP/212.150.88.20-0953b9e0", "CallerID is "6561116" <6561116>") in new stack
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Launching 'Goto'
[Feb 29 16:08:38] VERBOSE[9003] logger.c: -- Executing [97225695295@from-trunk:5] Goto("SIP/212.150.88.20-0953b9e0", "app-languages|1|1") in new stack
[Feb 29 16:08:38] VERBOSE[9003] logger.c: -- Goto (app-languages,1,1)
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Launching 'NoOp'
[Feb 29 16:08:38] VERBOSE[9003] logger.c: -- Executing [1@app-languages:1] NoOp("SIP/212.150.88.20-0953b9e0", "Changing Channel to language: he (he->ivr-landing)") in new stack
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Launching 'Set'
[Feb 29 16:08:38] VERBOSE[9003] logger.c: -- Executing [1@app-languages:2] Set("SIP/212.150.88.20-0953b9e0", "CHANNEL(language)=he") in new stack
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Launching 'Goto'
[Feb 29 16:08:38] VERBOSE[9003] logger.c: -- Executing [1@app-languages:3] Goto("SIP/212.150.88.20-0953b9e0", "ivr-3|s|1") in new stack
[Feb 29 16:08:38] VERBOSE[9003] logger.c: -- Goto (ivr-3,s,1)
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Launching 'Set'
[Feb 29 16:08:38] VERBOSE[9003] logger.c: -- Executing [s@ivr-3:1] Set("SIP/212.150.88.20-0953b9e0", "LOOPCOUNT=0") in new stack
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Launching 'Set'
[Feb 29 16:08:38] VERBOSE[9003] logger.c: -- Executing [s@ivr-3:2] Set("SIP/212.150.88.20-0953b9e0", "__DIR-CONTEXT=default") in new stack
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Launching 'Set'
[Feb 29 16:08:38] VERBOSE[9003] logger.c: -- Executing [s@ivr-3:3] Set("SIP/212.150.88.20-0953b9e0", "_IVR_CONTEXT_ivr-3=") in new stack
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Launching 'Set'
[Feb 29 16:08:38] VERBOSE[9003] logger.c: -- Executing [s@ivr-3:4] Set("SIP/212.150.88.20-0953b9e0", "_IVR_CONTEXT=ivr-3") in new stack
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Function result is 'NO ANSWER'
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Expression result is '0'
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Launching 'GotoIf'
[Feb 29 16:08:38] VERBOSE[9003] logger.c: -- Executing [s@ivr-3:5] GotoIf("SIP/212.150.88.20-0953b9e0", "0?begin") in new stack
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Not taking any branch
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Launching 'Answer'
[Feb 29 16:08:38] VERBOSE[9003] logger.c: -- Executing [s@ivr-3:6] Answer("SIP/212.150.88.20-0953b9e0", "") in new stack
[Feb 29 16:08:38] DEBUG[9003] devicestate.c: Notification of state change to be queued on device/channel SIP/212.150.88.20-0953b9e0
[Feb 29 16:08:38] DEBUG[8167] devicestate.c: No provider found, checking channel drivers for SIP - 212.150.88.20-0953b9e0
[Feb 29 16:08:38] DEBUG[9003] devicestate.c: Notification of state change to be queued on device/channel SIP/212.150.88.20
[Feb 29 16:08:38] DEBUG[8167] chan_sip.c: Checking device state for peer 212.150.88.20-0953b9e0
[Feb 29 16:08:38] DEBUG[9003] chan_sip.c: SIP answering channel: SIP/212.150.88.20-0953b9e0
[Feb 29 16:08:38] DEBUG[9003] chan_sip.c: Setting framing from config on incoming call
[Feb 29 16:08:38] DEBUG[9003] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: True
[Feb 29 16:08:38] DEBUG[8167] devicestate.c: Changing state for SIP/212.150.88.20-0953b9e0 - state 4 (Invalid)
[Feb 29 16:08:38] DEBUG[9003] chan_sip.c: ** Our prefcodec: 0x0 (nothing)
[Feb 29 16:08:38] DEBUG[8167] devicestate.c: No provider found, checking channel drivers for SIP - 212.150.88.20
[Feb 29 16:08:38] DEBUG[8195] app_queue.c: Device 'SIP/212.150.88.20-0953b9e0' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[Feb 29 16:08:38] DEBUG[9003] chan_sip.c: -- Done with adding codecs to SDP
[Feb 29 16:08:38] DEBUG[8167] chan_sip.c: Checking device state for peer 212.150.88.20
[Feb 29 16:08:38] DEBUG[9003] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[Feb 29 16:08:38] DEBUG[8167] channel.c: Avoiding initial deadlock for channel '0x95985c8'
[Feb 29 16:08:38] DEBUG[9003] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw)
[Feb 29 16:08:38] WARNING[9003] chan_sip.c: sip_xmit of 0x959e118 (len 776) to 212.150.88.20:5060 returned -2: Network is unreachable
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Spawn extension (ivr-3,s,6) exited non-zero on 'SIP/212.150.88.20-0953b9e0'
[Feb 29 16:08:38] VERBOSE[9003] logger.c: == Spawn extension (ivr-3, s, 6) exited non-zero on 'SIP/212.150.88.20-0953b9e0'
[Feb 29 16:08:38] DEBUG[9003] channel.c: Soft-Hanging up channel 'SIP/212.150.88.20-0953b9e0'
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Launching 'Hangup'
[Feb 29 16:08:38] VERBOSE[9003] logger.c: -- Executing [h@ivr-3:1] Hangup("SIP/212.150.88.20-0953b9e0", "") in new stack
[Feb 29 16:08:38] DEBUG[9003] pbx.c: Spawn extension (ivr-3,h,1) exited non-zero on 'SIP/212.150.88.20-0953b9e0'
[Feb 29 16:08:38] VERBOSE[9003] logger.c: == Spawn extension (ivr-3, h, 1) exited non-zero on 'SIP/212.150.88.20-0953b9e0'
[Feb 29 16:08:38] DEBUG[9003] channel.c: Hanging up channel 'SIP/212.150.88.20-0953b9e0'
[Feb 29 16:08:38] DEBUG[9003] chan_sip.c: Hangup call SIP/212.150.88.20-0953b9e0, SIP callid 31f8f981582e4cec4bf953bc70764d0b@212.150.88.20)
[Feb 29 16:08:38] DEBUG[9003] sched.c: Attempted to delete nonexistent schedule entry 0!
[Feb 29 16:08:38] DEBUG[9003] sched.c: Attempted to delete nonexistent schedule entry 0!
[Feb 29 16:08:38] DEBUG[8167] channel.c: Avoiding initial deadlock for channel '0x95985c8'
[Feb 29 16:08:38] DEBUG[8167] channel.c: Avoiding initial deadlock for channel '0x95985c8'
[Feb 29 16:08:38] DEBUG[9003] sched.c: Attempted to delete nonexistent schedule entry 0!
[Feb 29 16:08:38] DEBUG[8167] channel.c: Avoiding initial deadlock for channel '0x95985c8'
[Feb 29 16:08:38] DEBUG[9003] sched.c: Attempted to delete nonexistent schedule entry 0!
[Feb 29 16:08:38] DEBUG[8167] channel.c: Avoiding initial deadlock for channel '0x95985c8'
[Feb 29 16:08:38] DEBUG[9003] sched.c: Attempted to delete nonexistent schedule entry 0!
[Feb 29 16:08:38] DEBUG[8167] channel.c: Avoiding initial deadlock for channel '0x95985c8'
[Feb 29 16:08:38] DEBUG[9003] sched.c: Attempted to delete nonexistent schedule entry 0!
[Feb 29 16:08:38] DEBUG[9003] sched.c: Attempted to delete nonexistent schedule entry 0!
[Feb 29 16:08:38] DEBUG[8167] channel.c: Avoiding initial deadlock for channel '0x95985c8'
[Feb 29 16:08:38] DEBUG[8167] channel.c: Avoiding initial deadlock for channel '0x95985c8'
[Feb 29 16:08:38] DEBUG[9003] sched.c: Attempted to delete nonexistent schedule entry 0!
[Feb 29 16:08:38] DEBUG[9003] sched.c: Attempted to delete nonexistent schedule entry 0!
[Feb 29 16:08:38] DEBUG[8167] channel.c: Avoiding initial deadlock for channel '0x95985c8'
[Feb 29 16:08:38] DEBUG[9003] sched.c: Attempted to delete nonexistent schedule entry 0!
[Feb 29 16:08:38] DEBUG[8167] channel.c: Avoiding initial deadlock for channel '0x95985c8'
[Feb 29 16:08:38] DEBUG[8167] channel.c: Failure, could not lock '0x95985c8' after 9 retries!
[Feb 29 16:08:38] DEBUG[9003] sched.c: Attempted to delete nonexistent schedule entry 0!
[Feb 29 16:08:38] DEBUG[9003] devicestate.c: Notification of state change to be queued on device/channel SIP/212.150.88.20-0953b9e0
[Feb 29 16:08:38] DEBUG[9003] devicestate.c: Notification of state change to be queued on device/channel SIP/212.150.88.20
[Feb 29 16:08:38] DEBUG[9003] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
[Feb 29 16:08:38] DEBUG[9003] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,userfield) VALUES ('2008-02-29 16:08:38','\"6561116\" <6561116>','6561116','s','ivr-3', 'SIP/212.150.88.20-0953b9e0','','Answer','',0,0,'ANSWERED',3,'','')
[Feb 29 16:08:38] DEBUG[8167] devicestate.c: Changing state for SIP/212.150.88.20 - state 1 (Not in use)
[Feb 29 16:08:38] DEBUG[8167] devicestate.c: No provider found, checking channel drivers for SIP - 212.150.88.20-0953b9e0
[Feb 29 16:08:38] DEBUG[8167] chan_sip.c: Checking device state for peer 212.150.88.20-0953b9e0
[Feb 29 16:08:38] DEBUG[8167] devicestate.c: Changing state for SIP/212.150.88.20-0953b9e0 - state 4 (Invalid)
[Feb 29 16:08:38] DEBUG[8167] devicestate.c: No provider found, checking channel drivers for SIP - 212.150.88.20
[Feb 29 16:08:38] DEBUG[8167] chan_sip.c: Checking device state for peer 212.150.88.20
[Feb 29 16:08:38] DEBUG[8167] devicestate.c: Changing state for SIP/212.150.88.20 - state 1 (Not in use)
[Feb 29 16:08:38] DEBUG[8195] app_queue.c: Device 'SIP/212.150.88.20' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Feb 29 16:08:38] DEBUG[8195] app_queue.c: Device 'SIP/212.150.88.20-0953b9e0' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[Feb 29 16:08:38] DEBUG[8195] app_queue.c: Device 'SIP/212.150.88.20' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Feb 29 16:08:39] DEBUG[8183] chan_sip.c: = Found Their Call ID: 31f8f981582e4cec4bf953bc70764d0b@212.150.88.20 Their Tag as4441c47c Our tag: as1e07b654
[Feb 29 16:08:39] DEBUG[8183] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[Feb 29 16:08:39] DEBUG[8183] chan_sip.c: Ignoring SIP message because of retransmit (INVITE Seqno 102, ours 102)
[Feb 29 16:08:39] NOTICE[8183] chan_sip.c: Unable to create/find SIP channel for this INVITE
[Feb 29 16:08:39] WARNING[8183] chan_sip.c: sip_xmit of 0xa9d194 (len 486) to 212.150.88.20:5060 returned -2: Network is unreachable
[Feb 29 16:08:40] DEBUG[8183] chan_sip.c: = Found Their Call ID: 31f8f981582e4cec4bf953bc70764d0b@212.150.88.20 Their Tag as4441c47c Our tag: as1e07b654
[Feb 29 16:08:40] DEBUG[8183] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[Feb 29 16:08:40] DEBUG[8183] chan_sip.c: Ignoring SIP message because of retransmit (INVITE Seqno 102, ours 102)
[Feb 29 16:08:42] DEBUG[8183] chan_sip.c: = Found Their Call ID: 31f8f981582e4cec4bf953bc70764d0b@212.150.88.20 Their Tag as4441c47c Our tag: as1e07b654
[Feb 29 16:08:42] DEBUG[8183] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[Feb 29 16:08:42] DEBUG[8183] chan_sip.c: Ignoring SIP message because of retransmit (INVITE Seqno 102, ours 102)
[Feb 29 16:08:43] DEBUG[8183] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Feb 29 16:08:43] DEBUG[8183] acl.c: ##### Testing 192.168.10.105 with 192.168.10.0
[Feb 29 16:08:43] DEBUG[8183] chan_sip.c: = Found Their Call ID: 5af14d0804d70cfc189f4037738522ad@192.168.10.210 Their Tag Our tag: as3f4e5cf1
[Feb 29 16:08:43] DEBUG[8183] chan_sip.c: Stopping retransmission on '5af14d0804d70cfc189f4037738522ad@192.168.10.210' of Request 102: Match Not Found
[Feb 29 16:08:43] VERBOSE[8183] logger.c: Really destroying SIP dialog '5af14d0804d70cfc189f4037738522ad@192.168.10.210' Method: OPTIONS
[Feb 29 16:08:44] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 29e3f42835a81659589d72f6741ae21e@212.150.88.20
[Feb 29 16:08:44] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 42a4279830cfb18e5dbd06ca3fefe116@212.150.88.20
[Feb 29 16:08:44] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 25c2645e119453753be8389827704a1f@212.150.88.20
[Feb 29 16:08:46] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 3de08a4d3d27ea787c4a3287202aa1a5@212.150.88.20
[Feb 29 16:08:46] DEBUG[8183] chan_sip.c: = Found Their Call ID: 31f8f981582e4cec4bf953bc70764d0b@212.150.88.20 Their Tag as4441c47c Our tag: as1e07b654
[Feb 29 16:08:46] DEBUG[8183] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[Feb 29 16:08:46] DEBUG[8183] chan_sip.c: Ignoring SIP message because of retransmit (INVITE Seqno 102, ours 102)
[Feb 29 16:08:48] DEBUG[8183] chan_sip.c: Re-scheduled destruction of SIP call 7c4f19471f4890a12eaaefea616d3ec8@212.150.88.20