1.8.32.3 – No Timing Indicated, Tens Of Thousands Of __sip_autodestruct Error Messages
Home » Asterisk Users » 1.8.32.3 – No Timing Indicated, Tens Of Thousands Of __sip_autodestruct Error Messages
Hi all
I’m running a 1.8.32.3 instance of Asterisk on CentOS 7.
About 80 SIP phones connected.
I’m getting tens of thousands of error messages in the CLI, and callers are having extreme difficulty dialing, they can dial once and then if they try to dial again their extension is shown as busy.
The server has been running for a year and a half, until this Wedenesday. When I encountered this problem I then replaced the server with a new physical machine with the same version of Asterisk that has been working for the past year.
E. g. the hardware on the server is completely new, still having the exact same problem as with the older server.
This is what is appearing in the CLI:
[Oct 30 11:02:16] WARNING[16831]: chan_sip.c:4057 __sip_autodestruct:
Autodestruct on dialog ‘702825cb5d9de4fc6a29675f158f000f@192.168.1.2:5060′
with owner SIP/centra-out-00000140 in place (Method: BYE). Rescheduling destruction for 10000 ms
[Oct 30 11:02:24] WARNING[16831]: chan_sip.c:4057 __sip_autodestruct:
Autodestruct on dialog ’18eea85e1c27f2fd533586452b41f9a7@172.7.1.3:5060’
with owner SIP/3088-000001b0 in place (Method: BYE). Rescheduling destruction for 10000 ms
[Oct 30 11:02:37] WARNING[16831]: chan_sip.c:4057 __sip_autodestruct:
Autodestruct on dialog ‘4004649c0c903ee1676f5b5c2d47e0eb@172.7.1.3:5060’
with owner SIP/3055-00000137 in place (Method: BYE). Rescheduling destruction for 10000 ms
[Oct 30 11:02:39] WARNING[16831]: chan_sip.c:4057 __sip_autodestruct:
Autodestruct on dialog ‘3dbbe75d30e0c7bd72ddf69716be8806@192.168.1.2:5060’
with owner SIP/centra-out-000001b1 in place (Method: BYE). Rescheduling destruction for 10000 ms
[Oct 30 11:02:40] WARNING[16831]: chan_sip.c:4057 __sip_autodestruct:
Autodestruct on dialog ‘2ff26c957b75c41f11b6523c7c53a134@192.168.1.2:5060’
with owner SIP/centra-out-000000cb in place (Method: BYE). Rescheduling destruction for 10000 ms
[Oct 30 11:02:40] WARNING[16831]: chan_sip.c:4057 __sip_autodestruct:
Autodestruct on dialog ‘1627933358aec1323968a60564e76d1a@172.7.1.3:5060′
with owner SIP/3065-000000ca in place (Method: BYE). Rescheduling destruction for 10000 ms
[Oct 30 11:02:43] WARNING[16831]: chan_sip.c:4057 __sip_autodestruct:
Autodestruct on dialog ’41a753fb01f16d5f0d366a314495685b@192.168.1.2:5060’
with owner SIP/centra-out-00000138 in place (Method: BYE). Rescheduling destruction for 10000 ms
[Oct 30 11:02:46] WARNING[16831]: chan_sip.c:4057 __sip_autodestruct:
Autodestruct on dialog ‘1d90ffab7a7241d9236bd3816a9889fd@172.7.1.3:5060’
with owner SIP/3054-0000013f in place (Method: BYE). Rescheduling destruction for 10000 ms
[Oct 30 11:02:48] WARNING[16831]: chan_sip.c:4057 __sip_autodestruct:
Autodestruct on dialog ‘702825cb5d9de4fc6a29675f158f000f@192.168.1.2:5060′
with owner SIP/centra-out-00000140 in place (Method: BYE). Rescheduling destruction for 10000 ms
[Oct 30 11:02:56] WARNING[16831]: chan_sip.c:4057 __sip_autodestruct:
Autodestruct on dialog ’18eea85e1c27f2fd533586452b41f9a7@172.7.1.3:5060′
with owner SIP/3088-000001b0 in place (Method: BYE). Rescheduling destruction for 10000 ms
[Oct 30 11:02:59] WARNING[16831]: chan_sip.c:4057 __sip_autodestruct:
Autodestruct on dialog ’47c4a97d2d1a85e95c85a5b42ba9c27f@172.7.1.3:5060′
with owner SIP/3008-000001d2 in place (Method: BYE). Rescheduling destruction for 10000 ms
[Oct 30 11:03:00] WARNING[16831]: chan_sip.c:4057 __sip_autodestruct:
Autodestruct on dialog ’32fe9add31a3305674bca7e108ff9746@172.7.1.3:5060′
with owner SIP/3014-000001d7 in place (Method: BYE). Rescheduling destruction for 10000 ms
[Oct 30 11:03:03] WARNING[16831]: chan_sip.c:4057 __sip_autodestruct:
Autodestruct on dialog ’72e37d2a700418d12c9e5a2e645f5993@172.7.1.3:5060’
with owner SIP/3061-000001d5 in place (Method: BYE). Rescheduling destruction for 10000 ms
[Oct 30 11:03:09] WARNING[16831]: chan_sip.c:4057 __sip_autodestruct:
Autodestruct on dialog ‘4004649c0c903ee1676f5b5c2d47e0eb@172.7.1.3:5060’
with owner SIP/3055-00000137 in place (Method: BYE). Rescheduling destruction for 10000 ms
[Oct 30 11:03:11] WARNING[16831]: chan_sip.c:4057 __sip_autodestruct:
Autodestruct on dialog ‘3dbbe75d30e0c7bd72ddf69716be8806@192.168.1.2:5060’
with owner SIP/centra-out-000001b1 in place (Method: BYE). Rescheduling destruction for 10000 ms
[Oct 30 11:03:12] WARNING[16831]: chan_sip.c:4057 __sip_autodestruct:
Autodestruct on dialog ‘2ff26c957b75c41f11b6523c7c53a134@192.168.1.2:5060’
with owner SIP/centra-out-000000cb in place (Method: BYE). Rescheduling destruction for 10000 ms
If I do
asterisk*CLI>module show like timing
I get
module show like timing Module Description Use Count res_timing_dahdi.so DAHDI Timing Interface 0
asterisk*CLI>
My modules.conf specifies that only dahdi timing.
I have never seen any of my other 17 Asterisk servers at other sites showing NO use of ANY timing interface…
What does these __sip_autodestruct messages mean? How can I fix this problem?
Calls in progress are also randomly cut-off with no other CLI indications.
As I said, the server has been running completely stable for more than a year before this started, and replacing the server physically has not helped, same version of Asterisk loaded.
Any ideas?
Thanks!
Stefan
One thought on - 1.8.32.3 – No Timing Indicated, Tens Of Thousands Of __sip_autodestruct Error Messages
Hi list
Just to let everybody know I think I’ve got to the bottom of the above problem / error.
Turns out that the issues described in my previous post were caused by problems in an MSSQL database that the Asterisk 1.8.32.3 instance was writing to…!
Once I dropped the FreeTDS driver (while trying to diagnose what was going on) the Asterisk instance immediately started performing normally and the
__sip_autodestruct error messages disappeared.
Channels linked to calls that were hung up closed normally once again and everything was golden.
The problem on MSSQL turned out to be that some of the indices on the table to which the Asterisk instance was writing required rebuilding as the table had grown immensely since the Asterisk instance was created. The issue was that an insert that would have normally taken about 500 milliseconds was now taking up to 30 seconds to a minute. Therefore as a call is finished Asterisk attempted to write the call into the CDR database but was extremely delayed due to slow database performance. The __sip_autodestruct error messages apparently is a watchdog thread / process that then detects that channels that should be closed and gone have not been closed / disposed – it then posts a warning and then later tries to close the channels involved, which are still hanging around after the call they are linked to has finished.
This had the effect that users could only make one call, then had to wait until the channels disappeared (sometimes up to a minute later as the DB
managed to finish inserting that call’s details in to the table with the index problems) before they could make a second call, while the above watchdog process complained loudly about channels that were hanging around that should not be as Asterisk waited for MSSQL.
So the fix was simply to rebuild the indexes on the relevant tabe in MSSQL –
this definitively solved the problem and tens of thousands of calls have now been made after the reindex in MSSQL and everything is fine.
This is interesting as it seems that Asterisk does NOT use FreeTDS
asynchronously, but synchronously as calls progress…
Anyway, hope this helps someone who runs into something similar – the databases you touch from the CDR subsystem in Asterisk must be -FAST- and able to be inserted into in milliseconds. Apparently anything taking a second or more in a FreeTDS accessed DB linked to Asterisk can start causing problems in Asterisk itself.
Regards
Stefan