Hi guys, I have a problem with my asterisk installation, it suddenly uses 100% CPU that causes all our phones (Analog and IP Phone) stop responding. I’ve already tried running asterisk on a dedicated appliance, Hyper V with 2 and 4 Cores, Asterisk version 16.19 and 16.20 still I get the same result. I have realtime enabled, I also tried hosting the database on a separate server, still the same problem. Currently, the only way to solve the issue is to reboot the asterisk host machine. When I run debug I get the same error message each time this issue happens.
[Sep 2 08:35:58] DEBUG[1845] res_odbc.c: Reusing ODBC handle 0x7fb2f0005e10 from class ‘asterisk’
[Sep 2 08:35:58] DEBUG[1845] res_config_odbc.c: Skip: 0; SQL: UPDATE sippeers SET ipaddr=?, fullcontact=?, lastms=?, useragent=?, defaultuser=?, regseconds=?, port=? WHERE name=?
[Sep 2 08:35:58] DEBUG[1845] res_config_odbc.c: Parameter 1 (‘ipaddr’) = ‘192.168.3.5’
[Sep 2 08:35:58] DEBUG[1845] res_config_odbc.c: Parameter 2 (‘fullcontact’) = ‘sip:201@192.168.3.5:5060’
[Sep 2 08:35:58] DEBUG[1845] res_config_odbc.c: Parameter 3 (‘lastms’) = ‘-1’
[Sep 2 08:35:58] DEBUG[1845] res_config_odbc.c: Parameter 4 (‘useragent’) = ‘Grandstream GXP1615 1.0.4.67’
[Sep 2 08:35:58] DEBUG[1845] res_config_odbc.c: Parameter 5 (‘defaultuser’) = ‘201’
[Sep 2 08:35:58] DEBUG[1845] res_config_odbc.c: Parameter 6 (‘regseconds’) = ‘1630546558’
[Sep 2 08:35:58] DEBUG[1845] res_config_odbc.c: Parameter 7 (‘port’) = ‘5060’
[Sep 2 08:35:58] DEBUG[1845] res_config_odbc.c: Parameter 8 = ‘201’
[Sep 2 08:35:58] DEBUG[1845] res_odbc.c: Releasing ODBC handle 0x7fb2f0005e10 into pool
[Sep 2 08:35:58] DEBUG[1845] chan_sip.c: Trying to put ‘SIP/2.0 200’ onto UDP socket destined for 192.168.3.5:5060
[Sep 2 08:35:58] DEBUG[1845] res_odbc.c: Reusing ODBC handle 0x7fb2f0005e10 from class ‘asterisk’
[Sep 2 08:35:58] DEBUG[1845] res_odbc.c: Releasing ODBC handle 0x7fb2f0005e10 into pool
[Sep 2 08:35:58] DEBUG[1845] chan_sip.c: Allocating new SIP dialog for 588d468f79c44888287eb89e30c79f52@127.0.1.1:5060 - NOTIFY (No RTP)
[Sep 2 08:35:58] DEBUG[1040] devicestate.c: No provider found, checking channel drivers for SIP - 201
[Sep 2 08:35:58] DEBUG[1040] chan_sip.c: Checking device state for peer 201
[Sep 2 08:35:58] DEBUG[1845] chan_sip.c: Destroying SIP dialog 588d468f79c44888287eb89e30c79f52@127.0.1.1:5060
[Sep 2 08:35:58] DEBUG[1040] devicestate.c: Changing state for SIP/201 - state 5 (Unavailable)
[Sep 2 08:35:58] DEBUG[1040] stasis.c: Creating topic. name: devicestate:all/SIP/201, detail:
[Sep 2 08:35:58] DEBUG[1040] stasis.c: Topic ‘devicestate:all/SIP/201’: 0x7fb2ec023580 created
[Sep 2 08:35:58] DEBUG[1845] chan_sip.c: = Looking for Call ID: 51b69ee70602925a6a325eca46a08d3d@192.168.1.10:5060 (Checking To) --From tag as639f9c1c --To-tag 60794257
[Sep 2 08:35:58] DEBUG[1845] chan_sip.c: Stopping retransmission on ‘51b69ee70602925a6a325eca46a08d3d@192.168.1.10:5060’ of Request 102: Match Found
[Sep 2 08:35:58] DEBUG[1878] app_queue.c: Device ‘SIP/201’ changed to state ‘5’ (Unavailable) but we don’t care because they’re not a member of any queue.
[Sep 2 08:35:58] DEBUG[1040] devicestate.c: No provider found, checking channel drivers for SIP - 201
[Sep 2 08:35:58] DEBUG[1040] chan_sip.c: Checking device state for peer 201
[Sep 2 08:35:58] DEBUG[1040] devicestate.c: Changing state for SIP/201 - state 1 (Not in use)
[Sep 2 08:35:58] DEBUG[1878] app_queue.c: Device ‘SIP/201’ changed to state ‘1’ (Not in use) but we don’t care because they’re not a member of any queue.
[Sep 2 08:35:58] DEBUG[1043] chan_sip.c: Trying to put ‘NOTIFY sip:’ onto UDP socket destined for 192.168.3.8:5060
[Sep 2 08:35:58] DEBUG[1043] chan_sip.c: Trying to put ‘NOTIFY sip:’ onto UDP socket destined for 192.168.3.10:5060
[Sep 2 08:36:09] DEBUG[1837] res_pjsip_registrar.c: Woke up at 1630542969 Interval: 30
[Sep 2 08:36:09] DEBUG[1837] res_pjsip_registrar.c: Expiring 0 contacts
[Sep 2 08:36:17] DEBUG[2588] threadpool.c: Worker thread idle timeout reached. Dying.
[Sep 2 08:36:17] DEBUG[961] threadpool.c: Destroying worker thread 104
[Sep 2 08:36:39] DEBUG[1837] res_pjsip_registrar.c: Woke up at 1630542999 Interval: 30
[Sep 2 08:36:39] DEBUG[1837] res_pjsip_registrar.c: Expiring 0 contacts
[Sep 2 08:37:09] DEBUG[1837] res_pjsip_registrar.c: Woke up at 1630543029 Interval: 30
[Sep 2 08:37:09] DEBUG[1837] res_pjsip_registrar.c: Expiring 0 contacts
[Sep 2 08:37:39] DEBUG[1837] res_pjsip_registrar.c: Woke up at 1630543059 Interval: 30
[Sep 2 08:37:39] DEBUG[1837] res_pjsip_registrar.c: Expiring 0 contacts
[Sep 2 08:37:44] DEBUG[844] cdr.c: CDR Engine termination request received; waiting on messages…
[Sep 2 08:37:44] DEBUG[844] res_musiconhold.c: Destroying MOH class ‘default’
[Sep 2 08:37:44] DEBUG[844] res_musiconhold.c: Destroying MOH class ‘conference’
[Sep 2 08:37:44] DEBUG[844] asterisk.c: Asterisk ending (0).
[Sep 2 08:38:12] Asterisk 16.20.0 built by root @ asteriskubuntu20 on a x86_64 running Linux on 2021-08-27 12:01:11 UTC
Note: I’m not using pjsip
Hope someone else encountered this problem and was able to solve it or someone who can point me in the right direction on how to find the issue.
Hi @BlazeStudios I can now confirm that this issue happens when a SIP Account tries to register with the asterisk server. I was able to re-create this over and over. The weird thing is we’ve been using this asterisk server for about2 years now and this is the first time I have encountered this. Heres the a screenshot of htop
I actually don’t see an issue here outside of the fact your system doesn’t seem to spread the load over all four CPUs. So what you have is a single CPU doing all the work and getting up to 100% of its usage. You still have three full CPU’s that haven’t been touched that can still be used to do stuff with.
Look at your load averages, 0.20, 0.11, 0.11. I can’t see how this system is “overloaded”. Unless for some reason you have 4 CPU cores and the system never touches the other three. In that case it’s not an Asterisk problem.
Hi @BlazeStudios, thats another issue that I wan to look into. But for now I can almost certainly confirm that this is an issue I encounter on version 16.19 and 16.20, I installed another asterisk server with v16.14 with all the same configuration as the other 2 versions and never encountered the issue.
Update:
I badly wanted to find out what causing this problem on my asterisk v16.20 Server I tried using it again then recreating the cause of the problem by registering a sip account. and here’s what I got by typing ‘core show locks’
