[Feb 25 20:45:59] DEBUG[23606] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket... [Feb 25 20:45:59] DEBUG[23606] chan_sip.c: Stopping retransmission on '6ca3c787792a79da29b489f71adb742c@193.179.38.20' of Request 102: Match Found [Feb 25 20:46:01] DEBUG[23606] acl.c: Found IP address for this socket [Feb 25 20:46:01] DEBUG[23606] chan_sip.c: Allocating new SIP dialog for 4ee3c82c304502a04062ad537cc8c427@172.20.24.11 - REGISTER (No RTP) [Feb 25 20:46:01] DEBUG[23606] chan_sip.c: Trying to put 'SIP/2.0 40' onto UDP socket... [Feb 25 20:46:01] DEBUG[23606] chan_sip.c: Trying to put 'SIP/2.0 20' onto UDP socket... [Feb 25 20:46:01] DEBUG[23606] devicestate.c: Notification of state change to be queued on device/channel SIP/prec-gw [Feb 25 20:46:01] DEBUG[23606] chan_sip.c: Checking device state for peer prec-gw [Feb 25 20:46:01] DEBUG[23606] devicestate.c: Changing state for SIP/prec-gw - state 1 (Not in use) [Feb 25 20:46:01] DEBUG[23606] devicestate.c: Notification of state change to be queued on device/channel SIP/prec [Feb 25 20:46:01] DEBUG[23606] chan_sip.c: Checking device state for peer prec [Feb 25 20:46:01] DEBUG[23606] devicestate.c: Changing state for SIP/prec - state 1 (Not in use) [Feb 25 20:46:04] DEBUG[23606] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Feb 25 20:46:04] DEBUG[23606] acl.c: Found IP address for this socket [Feb 25 20:46:04] DEBUG[23606] chan_sip.c: Initializing initreq for method OPTIONS - callid 3e4412606f40e6fa4a92c29c762703be@193.179.38.20 [Feb 25 20:46:04] DEBUG[23606] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 25 20:46:04] DEBUG[23606] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 25 20:46:04] DEBUG[23606] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 25 20:46:04] DEBUG[23606] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 25 20:46:04] DEBUG[23606] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 25 20:46:04] DEBUG[23606] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 25 20:46:04] DEBUG[23606] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 25 20:46:04] DEBUG[23606] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 25 20:46:04] DEBUG[23606] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 25 20:46:04] DEBUG[23606] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 25 20:46:04] DEBUG[23606] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 25 20:46:04] DEBUG[23606] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket... [Feb 25 20:46:04] DEBUG[23606] chan_sip.c: Stopping retransmission on '3e4412606f40e6fa4a92c29c762703be@193.179.38.20' of Request 102: Match Found [Feb 25 20:46:04] DEBUG[23606] chan_sip.c: Auto destroying SIP dialog '6146f0311e26c6314bb36cdf5f0492ad@85.216.201.137' [Feb 25 20:46:04] DEBUG[23606] chan_sip.c: Destroying SIP dialog 6146f0311e26c6314bb36cdf5f0492ad@85.216.201.137 [Feb 25 20:46:04] DEBUG[23606] chan_sip.c: Auto destroying SIP dialog '2033866f37479d3059ce7fe94a55aa3a@85.216.201.137' [Feb 25 20:46:04] DEBUG[23606] chan_sip.c: Destroying SIP dialog 2033866f37479d3059ce7fe94a55aa3a@85.216.201.137 [Feb 25 20:46:04] DEBUG[23606] chan_sip.c: Auto destroying SIP dialog '52daea680b326a44209004fd62dfeff7@85.216.201.137' [Feb 25 20:46:04] DEBUG[23606] chan_sip.c: Destroying SIP dialog 52daea680b326a44209004fd62dfeff7@85.216.201.137 [Feb 25 20:46:04] DEBUG[23606] chan_sip.c: Auto destroying SIP dialog '110ab9b933b634954a067dc6706ce39b@85.216.201.137' [Feb 25 20:46:04] DEBUG[23606] chan_sip.c: Destroying SIP dialog 110ab9b933b634954a067dc6706ce39b@85.216.201.137 [Feb 25 20:46:04] DEBUG[23606] chan_sip.c: Auto destroying SIP dialog '5edbfdf442003bca38cba0104cd90afd@85.216.201.137' [Feb 25 20:46:04] DEBUG[23606] chan_sip.c: Destroying SIP dialog 5edbfdf442003bca38cba0104cd90afd@85.216.201.137 [Feb 25 20:46:04] DEBUG[23606] chan_sip.c: Auto destroying SIP dialog '28ba313260eb843c6d4ab6922839285f@85.216.201.137' [Feb 25 20:46:04] DEBUG[23606] chan_sip.c: Destroying SIP dialog 28ba313260eb843c6d4ab6922839285f@85.216.201.137 [Feb 25 20:46:04] DEBUG[23606] chan_sip.c: Auto destroying SIP dialog '502824037f36bf41621e35593fd6ff1e@85.216.201.137' [Feb 25 20:46:04] DEBUG[23606] chan_sip.c: Destroying SIP dialog 502824037f36bf41621e35593fd6ff1e@85.216.201.137 [Feb 25 20:46:04] DEBUG[23606] chan_sip.c: Auto destroying SIP dialog '6b2112032aff812f2ca0a46805f662ee@10.0.0.2' [Feb 25 20:46:04] DEBUG[23606] chan_sip.c: Destroying SIP dialog 6b2112032aff812f2ca0a46805f662ee@10.0.0.2 [Feb 25 20:46:04] ERROR[23606] /root/src/asterisk-r104085/include/asterisk/lock.h: chan_sip.c line 4319 (__sip_destroy): Error: attempt to destroy locked mutex '&p->pvt_lock'. [Feb 25 20:46:04] ERROR[23606] /root/src/asterisk-r104085/include/asterisk/lock.h: chan_sip.c line 5853 (find_call): Error: '&p->pvt_lock' was locked here. [Feb 25 20:46:04] ERROR[23606] /root/src/asterisk-r104085/include/asterisk/lock.h: chan_sip.c line 4319 (__sip_destroy): Error destroying mutex &p->pvt_lock: Device or resource busy [Feb 25 20:46:04] DEBUG[23606] chan_sip.c: Auto destroying SIP dialog '5e525abb4cd1f26c0d24494c314a615a@85.216.201.137' [Feb 25 20:46:04] DEBUG[23606] chan_sip.c: Destroying SIP dialog 5e525abb4cd1f26c0d24494c314a615a@85.216.201.137 [Feb 25 20:46:08] DEBUG[23606] chan_sip.c: Auto destroying SIP dialog '2834cc5a0a4d493b122556db37c4b9c0@192.168.40.4' [Feb 25 20:46:08] DEBUG[23606] chan_sip.c: Destroying SIP dialog 2834cc5a0a4d493b122556db37c4b9c0@192.168.40.4 [Feb 25 20:46:14] DEBUG[23606] chan_sip.c: Auto destroying SIP dialog '0e60d29a6591566b78c7b4d555cb3e0f@192.168.40.4' [Feb 25 20:46:14] DEBUG[23606] chan_sip.c: Destroying SIP dialog 0e60d29a6591566b78c7b4d555cb3e0f@192.168.40.4 [Feb 25 20:46:18] DEBUG[23606] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Feb 25 21:01:27] DEBUG[23606] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 25 21:01:27] DEBUG[23606] sched.c: Attempted to delete nonexistent schedule entry 0! [Feb 25 21:01:27] DEBUG[23606] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket... [Feb 25 21:01:27] DEBUG[23606] chan_sip.c: Stopping retransmission on '11a2ccdf4fc541860b294ba00d3ba123@193.179.38.20' of Request 102: Match Found [Feb 25 21:01:28] DEBUG[23606] rtp.c: Got RTCP report of 64 bytes [Feb 25 21:01:31] DEBUG[23606] chan_sip.c: Auto destroying SIP dialog '7418a8b1766f3f95365c430b01cf9546@172.20.24.11' [Feb 25 21:01:31] DEBUG[23606] chan_sip.c: Destroying SIP dialog 7418a8b1766f3f95365c430b01cf9546@172.20.24.11 [Feb 25 21:01:32] ERROR[23606] /root/src/asterisk-r104085/include/asterisk/lock.h: chan_sip.c line 18040 (handle_request_do): mutex '&p->owner->lock_dont_use' freed more times than we've locked! [Feb 25 21:01:32] ERROR[23606] /root/src/asterisk-r104085/include/asterisk/lock.h: chan_sip.c line 18040 (handle_request_do): Error releasing mutex: Operation not permitted [Feb 25 21:01:32] ERROR[23606] /root/src/asterisk-r104085/include/asterisk/lock.h: chan_sip.c line 18041 (handle_request_do): mutex '&p->pvt_lock' freed more times than we've locked! [Feb 25 21:01:32] ERROR[23606] /root/src/asterisk-r104085/include/asterisk/lock.h: chan_sip.c line 18041 (handle_request_do): Error releasing mutex: Operation not permitted [Feb 25 21:01:32] DEBUG[23606] acl.c: Found IP address for this socket [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Allocating new SIP dialog for 488419d32c99d4b026a0efa42b7b96aa@85.216.201.137 - OPTIONS (No RTP) [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Trying to put 'SIP/2.0 20' onto TLS socket... [Feb 25 21:01:32] DEBUG[23606] acl.c: Found IP address for this socket [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Allocating new SIP dialog for 658695a0427e7c910300e8fd51a81c00@85.216.201.137 - OPTIONS (No RTP) [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Trying to put 'SIP/2.0 20' onto TLS socket... [Feb 25 21:01:32] DEBUG[23606] acl.c: Found IP address for this socket [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Allocating new SIP dialog for 6b2112032aff812f2ca0a46805f662ee@10.0.0.2 - REGISTER (No RTP) [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Trying to put 'SIP/2.0 40' onto TLS socket... [Feb 25 21:01:32] DEBUG[23606] acl.c: Found IP address for this socket [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Allocating new SIP dialog for 34e0da7062b0d4ca378d90d72e8d1a3c@85.216.201.137 - OPTIONS (No RTP) [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Trying to put 'SIP/2.0 20' onto TLS socket... [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Trying to put 'SIP/2.0 40' onto TLS socket... [Feb 25 21:01:32] DEBUG[23606] acl.c: Found IP address for this socket [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Allocating new SIP dialog for 42c7a3557b93b38c29e9407c0f4ec6f3@85.216.201.137 - OPTIONS (No RTP) [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Trying to put 'SIP/2.0 20' onto TLS socket... [Feb 25 21:01:32] DEBUG[23606] acl.c: Found IP address for this socket [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Allocating new SIP dialog for 570d017e7600f68927d1691655e89a7f@85.216.201.137 - OPTIONS (No RTP) [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Trying to put 'SIP/2.0 20' onto TLS socket... [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Trying to put 'SIP/2.0 40' onto TLS socket... [Feb 25 21:01:32] DEBUG[23606] acl.c: Found IP address for this socket [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Allocating new SIP dialog for 7544850b20bd89d349471ee82d32d4a0@85.216.201.137 - OPTIONS (No RTP) [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Trying to put 'SIP/2.0 20' onto TLS socket... [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Trying to put 'SIP/2.0 40' onto TLS socket... [Feb 25 21:01:32] DEBUG[23606] acl.c: Found IP address for this socket [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Allocating new SIP dialog for 67157a100b73cae346d003c77f0a4ad5@85.216.201.137 - OPTIONS (No RTP) [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Trying to put 'SIP/2.0 20' onto TLS socket... [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Trying to put 'SIP/2.0 40' onto TLS socket... [Feb 25 21:01:32] DEBUG[23606] acl.c: Found IP address for this socket [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Allocating new SIP dialog for 57c0370f03e0c40a7a4a559d561e199f@85.216.201.137 - OPTIONS (No RTP) [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Trying to put 'SIP/2.0 20' onto TLS socket... [Feb 25 21:01:32] DEBUG[23606] acl.c: Found IP address for this socket [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Allocating new SIP dialog for 5e07b501289af1f307fcbfe7250edada@85.216.201.137 - OPTIONS (No RTP) [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Trying to put 'SIP/2.0 20' onto TLS socket... [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Trying to put 'SIP/2.0 40' onto TLS socket... [Feb 25 21:01:32] DEBUG[23606] acl.c: Found IP address for this socket [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Allocating new SIP dialog for 06c96a6a55beb427248edecf5d946b3d@85.216.201.137 - OPTIONS (No RTP) [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Trying to put 'SIP/2.0 20' onto TLS socket... [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Trying to put 'SIP/2.0 40' onto TLS socket... [Feb 25 21:01:32] DEBUG[23606] acl.c: Found IP address for this socket [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Allocating new SIP dialog for 39d1c67e0df1ff6a7e6a23da1c74c4f1@85.216.201.137 - OPTIONS (No RTP) [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Trying to put 'SIP/2.0 20' onto TLS socket... [Feb 25 21:01:32] DEBUG[23606] acl.c: Found IP address for this socket [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Allocating new SIP dialog for 45e41f16732125105d92f3663beae769@85.216.201.137 - OPTIONS (No RTP) [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Trying to put 'SIP/2.0 20' onto TLS socket... [Feb 25 21:01:32] DEBUG[23606] chan_sip.c: Trying to put 'SIP/2.0 40' onto TLS socket... [Feb 25 21:01:33] DEBUG[23606] rtp.c: Got RTCP report of 124 bytes [Feb 25 21:01:33] DEBUG[23606] chan_sip.c: Auto destroying SIP dialog '2834cc5a0a4d493b122556db37c4b9c0@192.168.40.4' [Feb 25 21:01:33] DEBUG[23606] chan_sip.c: Destroying SIP dialog 2834cc5a0a4d493b122556db37c4b9c0@192.168.40.4