I have been using some form of Asterisk for over 10 years now and I have never had a problem with Asterisk crashing.
FreePBX 13 (10.13.66-22) - Asterisk 11 (then upgraded to Asterisk 13.19.1 with same issue) This is a FreePBX distro install.
Asterisk has crashed 8 times over the last 3 weeks. I will list date and times in case if that leads us anywhere. These times and dates are the date stamps on the core dump files.
04-09-18 06:38 pm
04-10-18 09:39 pm
04-17-18 09:50 am
04-18-18 07:51 pm
04-19-18 04:51 pm
04-26-18 11:35 pm
04-27-18 09:42 am
04-28-18 09:37 am
Dedicated server hosted at CyberLynk (FreePBXhosting.com). SuperMicro, Intel Xeon, 16gb ram, raid 1 500gb array. I worked with FreePBX support (paid incident) as well as the CyberLynk techs have also evaluated the situation.
Both support organizations are telling me that ChanSip is sending something to Asterisk that is very large and causing Asterisk to run out of memory however neither can figure out what is being sent so I am hoping someone in the forums can help.
This is the message from CyberLynk support:
I’ve been staring at these logs for over an hour. While it looks fairly clear that chan_sip is doing something that’s exceeding available memory, which looks to be causing Asterisk to crash, I can’t actually determine what it is. Looks like something massive is being transmitted to these extensions (17121 and 27201 as best as I can tell). I have changed the IP addresses below to mask the originals.
[2018-04-27 09:42:41] WARNING[13954] chan_sip.c: sip_xmit of 0x7f86f426c2f0 (len 140217595986952) to 60.184.82.13:31354 returned -2: Cannot allocate memory
(60.184.82.13:31354 was ext 17121)
[2018-04-26 23:35:18] WARNING[504] chan_sip.c: sip_xmit of 0x7f2290287b70 (len 139786421535656) to 183.151.17.217:12751 returned -2: Cannot allocate memory
(183.151.17.217:12751 was ext 27201)
**I don’t think it has anything to do with those extensions in particular or your trunk. Just those ones happened to be the recipients of (whatever) chan_sip was transmitting which looked to have an abnormally large packet length and ran Asterisk out of memory. The server is averaging < 15% RAM use, so more RAM is not the answer either. But since Asterisk 11 is EOL anyway, I would change to Asterisk 13 and see if the issue persists. Asterisk 13 has better debugging output if it crashes, so if the issue continues it should be easier to diagnose. **
This is the message from FreePBX support:
Frank, the core dumps are mostly unreadable however I was able to get some info:
Thread 296 (Thread 0x7ff9ff07f700 (LWP 27268)): #0 0x00007ffb31f15113 in poll () from /lib64/libc.so.6 #1 0x00007ffac0b2c136 in ?? () from /usr/lib64/asterisk/modules/chan_sip.so #2 0x00007ffac0b2b010 in ?? () from /usr/lib64/asterisk/modules/chan_sip.so #3 0x0000000000588cf5 in ?? () #4 0x00000000005990c8 in ?? () #5 0x00007ffb30951aa1 in start_thread () from /lib64/libpthread.so.0 #6 0x00007ffb31f1e93d in clone () from /lib64/libc.so.6
So, basically chan_sip is causing the crash and therefor my original advise is stands… you need to get away from Asterisk 11 and go to 13.
As mentioned above I have upgraded to Asterisk 13 using the Asterisk Switch Script to Asterisk 13 and still receiving the core dumps … Asterisk Crashing.
I have received another update from the CyberLynk techs:
I looked at the core dump from 09:37 and again I can tell it looks like something chan_sip is doing, but I can’t tell exactly what. However based on the frequency and quantity of FRACK errors I’m seeing in /var/log/asterisk/full I’m going to take a wild shot in the dark and speculate that maybe it’s something to do with the SIP OPTIONS request being sent out to your phones. This would make sense, given that on Thursday at 11:35PM when the system crashed, no calls had come in for 7 minutes and the system was basically idle.
You have all your extensions’ “Qualify Frequency” set to 30 seconds, meaning every 30 seconds the server is sending a message to the phones to keep their UDP connection open through whatever NAT they are behind. We don’t recommend lowering this in lieu of increasing the UDP timeout on the client side firewall, but some people do it as a last ditch when they can’t alter the client’s NAT router.
However you have 250+ active extensions, and at every 30 seconds the system is firing off a LOT of SIP OPTIONS headers, they’re going out pretty much constantly. Perhaps backing this off to 45-60 might help alleviate the problem?
I am now going through and setting each extensions qualify to 60.
Just an update. I have now updated all extensions within the system to qualify 60.
If anyone has any recommendations or suggestions all will be taken very seriously. This is our primary server and we are all stating to freak out over here.
Another update. I was able to locate this within the FULL log during one of the Asterisk Crashes, I am hoping that this will help someone help me.
[2018-04-10 21:38:59] VERBOSE[28754] chan_sip.c: == Extension Changed 31104[ext-local] new state Idle for Notify User 31102
[2018-04-10 21:38:59] VERBOSE[28754] chan_sip.c: == Extension Changed 31104[ext-local] new state Idle for Notify User 31103
[2018-04-10 21:38:59] VERBOSE[28754] chan_sip.c: == Extension Changed 31104[ext-local] new state Idle for Notify User 31101
[2018-04-10 21:38:59] VERBOSE[28754] chan_sip.c: == Extension Changed 31104[ext-local] new state Idle for Notify User 31107 [2018-04-10 21:39:00] ERROR[28952] /builddir/build/BUILD/asterisk-11.25.3/include/asterisk/utils.h: Memory Allocation Failure in function ast_str_create at line 435 of /builddir/build/BUILD/asterisk-11.25.3/include/asterisk/strings.h [2018-04-10 21:39:00] WARNING[28952] chan_sip.c: sip_xmit of 0x7f778c1698c0 (len 140151426646952) to 173.161.17.217:12521 returned -2: Cannot allocate memory
[2018-04-10 21:39:00] ERROR[28952] chan_sip.c: Serious Network Trouble; __sip_xmit returns error for pkt data
[2018-04-10 21:39:04] Asterisk 11.25.3 built by mockbuild @ jenkins2.schmoozecom.net on a x86_64 running Linux on 2017-09-19 17:44:52 UTC
[2018-04-10 21:39:04] VERBOSE[20026] config.c: == Parsing ‘/etc/asterisk/asterisk.conf’: Found
[2018-04-10 21:39:04] VERBOSE[20026] manager.c: == Manager registered action DBGet
[2018-04-10 21:39:04] VERBOSE[20026] manager.c: == Manager registered action DBPut
[2018-04-10 21:39:04] VERBOSE[20026] manager.c: == Manager registered action DBDel
Why are you still on asterisk 11. Didn’t everyone here tell you to go to asterisk 13
I would say report your full crash to Digium. But unfortunately the crash is based on asterisk 11 which is EOL.
Another use had this issue and switched everything to pjsip. You should probably do that as well because Chan sip is deprecated. Digium does not work on bugs against it.
Hi @tm1000, I didn’t mean to confuse the topic, the log I had posted was one of the crashes when I had Asterisk 11 loaded. I just changed that to Asterisk 13, using the switch script last night (4/27/18)
Here is the area of the log showing the crash with Asterisk 13 installed:
[2018-04-28 09:37:26] VERBOSE[14518][C-000000fb] app_dial.c: SIP/34102-000003a2 connected line has changed. Saving it until answer for SIP/VI-TRUNK-64.136.73.31-000003a0
[2018-04-28 09:37:26] VERBOSE[14518][C-000000fb] app_dial.c: SIP/34101-000003a1 connected line has changed. Saving it until answer for SIP/VI-TRUNK-64.136.73.31-000003a0
[2018-04-28 09:37:26] VERBOSE[21714] chan_sip.c: Extension Changed 34102[ext-local] new state Ringing for Notify User 34101
[2018-04-28 09:37:26] VERBOSE[21714] chan_sip.c: Extension Changed 34102[ext-local] new state Ringing for Notify User 34102
[2018-04-28 09:37:26] VERBOSE[14518][C-000000fb] app_dial.c: SIP/34101-000003a1 is ringing
[2018-04-28 09:37:26] VERBOSE[14518][C-000000fb] app_dial.c: SIP/34102-000003a2 is ringing
[2018-04-28 09:37:27] NOTICE[23735] chan_sip.c: Peer ‘17109’ is now Reachable. (27ms / 2000ms)
[2018-04-28 09:37:27] VERBOSE[21714] chan_sip.c: Extension Changed 17109[ext-local] new state Idle for Notify User 17114
[2018-04-28 09:37:27] VERBOSE[21714] chan_sip.c: Extension Changed 17109[ext-local] new state Idle for Notify User 17112
[2018-04-28 09:37:27] VERBOSE[21714] chan_sip.c: Extension Changed 17109[ext-local] new state Idle for Notify User 17115
[2018-04-28 09:37:27] VERBOSE[21714] chan_sip.c: Extension Changed 17109[ext-local] new state Idle for Notify User 17120
[2018-04-28 09:37:27] VERBOSE[21714] chan_sip.c: Extension Changed 17109[ext-local] new state Idle for Notify User 17119
[2018-04-28 09:37:27] VERBOSE[21714] chan_sip.c: Extension Changed 17109[ext-local] new state Idle for Notify User 17116
[2018-04-28 09:37:27] VERBOSE[21714] chan_sip.c: Extension Changed 17109[ext-local] new state Idle for Notify User 17101
[2018-04-28 09:37:27] VERBOSE[21714] chan_sip.c: Extension Changed 17109[ext-local] new state Idle for Notify User 17111
[2018-04-28 09:37:27] VERBOSE[21714] chan_sip.c: Extension Changed 17109[ext-local] new state Idle for Notify User 17121
[2018-04-28 09:37:27] VERBOSE[21714] chan_sip.c: Extension Changed 17109[ext-local] new state Idle for Notify User 17110
[2018-04-28 09:37:27] VERBOSE[21714] chan_sip.c: Extension Changed 17109[ext-local] new state Idle for Notify User 17113
[2018-04-28 09:37:27] VERBOSE[21714] chan_sip.c: Extension Changed 17109[ext-local] new state Idle for Notify User 17107
[2018-04-28 09:37:27] VERBOSE[21714] chan_sip.c: Extension Changed 17109[ext-local] new state Idle for Notify User 17108
[2018-04-28 09:37:27] VERBOSE[21714] chan_sip.c: Extension Changed 17109[ext-local] new state Idle for Notify User 17117
[2018-04-28 09:37:27] VERBOSE[21714] chan_sip.c: Extension Changed 17109[ext-local] new state Idle for Notify User 17109
[2018-04-28 09:37:27] NOTICE[22093] chan_sip.c: Received SIP subscribe for peer without mailbox: 29207
[2018-04-28 09:37:29] ERROR[22212] astobj2.c: FRACK!, Failed assertion bad magic number 0x0 for object 0x4393670 (0)
[2018-04-28 09:37:29] VERBOSE[22212] logger.c: Got 21 backtrace records
[2018-04-28 09:37:29] VERBOSE[22212] logger.c: #0: [0x60a91a] asterisk __ast_assert_failed() (0x60a892+88)
[2018-04-28 09:37:29] VERBOSE[22212] logger.c: #1: [0x45e4f2] asterisk ()
[2018-04-28 09:37:29] VERBOSE[22212] logger.c: #2: [0x45eb84] asterisk ()
[2018-04-28 09:37:29] VERBOSE[22212] logger.c: #3: [0x45eff8] asterisk __ao2_ref() (0x45efc7+31)
[2018-04-28 09:37:29] VERBOSE[22212] logger.c: #4: [0x45ff22] asterisk ()
[2018-04-28 09:37:29] VERBOSE[22212] logger.c: #5: [0x460244] asterisk __ao2_callback_data() (0x4601e0+64)
[2018-04-28 09:37:29] VERBOSE[22212] logger.c: #6: [0x7f8b70b7717e] chan_sip.so ()
[2018-04-28 09:37:29] VERBOSE[22212] logger.c: #7: [0x7f8b70b77392] chan_sip.so ()
[2018-04-28 09:37:33] Asterisk 13.19.1 built by mockbuild @ jenkins2.schmoozecom.net on a x86_64 running Linux on 2018-02-13 20:32:49 UTC
[2018-04-28 09:37:33] VERBOSE[14888] message.c: Message handler ‘dialplan’ registered.
[2018-04-28 09:37:33] VERBOSE[14888] pbx_functions.c: Registered custom function ‘MESSAGE’
[2018-04-28 09:37:33] VERBOSE[14888] pbx_functions.c: Registered custom function ‘MESSAGE_DATA’
[2018-04-28 09:37:33] VERBOSE[14888] pbx_app.c: Registered application ‘MessageSend’
[2018-04-28 09:37:33] VERBOSE[14888] manager.c: Manager registered action MessageSend
[2018-04-28 09:37:33] VERBOSE[14888] manager.c: Manager registered action DataGet
[2018-04-28 09:37:33] VERBOSE[14888] channel.c: Registered channel type ‘Surrogate’ (Surrogate channel used to pull channel from an application)
[2018-04-28 09:37:33] VERBOSE[14888] manager.c: Manager registered action BridgeTechnologyList
[2018-04-28 09:37:33] VERBOSE[14888] manager.c: Manager registered action BridgeTechnologySuspend
[2018-04-28 09:37:33] VERBOSE[14888] manager.c: Manager registered action BridgeTechnologyUnsuspend
[2018-04-28 09:37:33] VERBOSE[14888] loader.c: Asterisk Dynamic Loader Starting:
[2018-04-28 09:37:33] VERBOSE[14888] config.c: Parsing ‘/etc/asterisk/modules.conf’: Found
[2018-04-28 09:37:33] NOTICE[14888] loader.c: 7 modules will be loaded.
[2018-04-28 09:37:33] WARNING[14888] loader.c: Error loading module ‘chan_local.so’: /usr/lib64/asterisk/modules/chan_local.so: cannot open shared object file: No such file or directory
[2018-04-28 09:37:33] WARNING[14888] loader.c: Error loading module ‘res_mwi_blf.so’: /usr/lib64/asterisk/modules/res_mwi_blf.so: cannot open shared object file: No such file or directory
[2018-04-28 09:37:33] VERBOSE[14888] loader.c: Loading res_odbc.so.
[2018-04-28 09:37:33] VERBOSE[14888] config.c: Parsing ‘/etc/asterisk/res_odbc.conf’: Found
[2018-04-28 09:37:33] VERBOSE[14888] config.c: Parsing ‘/etc/asterisk/res_odbc_custom.conf’: Found
[2018-04-28 09:37:33] VERBOSE[14888] config.c: Parsing ‘/etc/asterisk/res_odbc_additional.conf’: Found
[2018-04-28 09:37:33] WARNING[14888] res_odbc.c: The ‘pooling’, ‘shared_connections’, ‘limit’, and ‘idlecheck’ options were replaced by ‘max_connections’. See res_odbc.conf.sample.
[2018-04-28 09:37:33] WARNING[14888] res_odbc.c: The ‘pooling’, ‘shared_connections’, ‘limit’, and ‘idlecheck’ options were replaced by ‘max_connections’. See res_odbc.conf.sample.
[2018-04-28 09:37:33] NOTICE[14888] res_odbc.c: Registered ODBC class ‘asteriskcdrdb’ dsn->[MySQL-asteriskcdrdb]
I know this probably won’t help you now Frank but you could have had CyberLynk clone your A11 setup and run the upgrade script on the clone then swap it in during downtime. If it was me in your shoes if I had any kind of backup or CyberLynk had any kind of backup I would immediately restore to a clone server, then revert the extensions. then poke at it in my spare time and bother the engineers about it. You should be figuring out how to revert and not trying to push ahead and fix it on the production system. My gut tells me your going to have to ditch chan_sip, though, if for no other reason than the support people are going to use it as a convenient scapegoat because they clearly don’t have a clue about what’s wrong. My gut also says it’s not chan_sip. Good luck!
Darn it Andrew I’ve got a POTS gateway that doesn’t work with pjsip, now I’ll have to go through the bother of setting up a test server and filing a proper bug report…
Remember he said he’s paying for hosting. If his hosting provider is a real virtual provider it couldn’t be ram, since at any given instant his virtual server could be running on a different physical server (or several physical servers) Of course, if his virtual hoster is a garage operation with a stack of a couple hundred 1U physical servers that could be the case but then why wouldn’t the other virtual servers on the same physical server he is on be having trouble? But in either instance that wouldn’t be his problem it would be his hoster’s problem.
But setting up a physical server would be a great next troubleshooting step, that allows for subtracting the virtualization as a potential source of trouble.
