Asterisk not starting after reboot

Hello-

I have been testing Asterisk for quite some time now on Ubuntu Server 14.04 LTS. Asterisk versions I’m using have varied but I was most recently using 13.12.1 and then upgraded to 13.13.0 this morning.
Up until now I’ve not recalled any issues where if I reboot the server, the Asterisk service has any problem starting.

This morning I came in to see my test phones in a reboot loop, unable to connect, and I was unable to get into the Asterisk CLI on my Ubuntu Server. I very quickly noticed that the Asterisk service was not running. I tried to start it and then go back into the CLI but it didn’t seem to start as asterisk -rvvv was not available. I tried this multiple times.

I then just tried to reboot my server but again saw that the Asterisk service had not started and it has always started at boot in the past. I started the service manually with a service asterisk start command. Ubuntu says the service started but it actually didn’t. If I try start it manually via asterisk -cvvv I can see it fail with a “Segmentation fault (core dumped)” error. The point at which this error appears seems to be totally random.

Finally I unplugged all of my phones from the switch and rebooted my server. This time the server came up normally with the Asterisk service started. I was able to plug my phones back in and they registered without any problems.

Unfortunately, if I reboot the server with the phones on and registered, the Asterisk service fails to start, and the only way to get it back is to unplug all of the phones, reboot the server, and then plug all of the phones back in.

I updated to 13.13 hoping maybe this was a bug I hadn’t encountered yet. No joy. I actually removed everything and re-installed Asterisk as well but still nothing.

Does anyone have any ideas as to what this could be? I’m using the SIP protocol. Any help is much appreciated thanks.

EDIT: I just noticed a moment ago that when I start the service via the “service asterisk start” command, and then try to go into the CLI via asterisk -rvvv, it appears to be bombing out on:

Loading app_agent_pool.so.
== Manager registered action Agents
== Manager registered action AgentLogoff
== Registered custom function ‘AGENT’
== Registered application ‘AgentLogin’
== Registered application 'AgentRequest’
callserver*CLI>
Disconnected from Asterisk server

For the segmentation fault I’d suggest following the instructions on the wiki[1] to get a backtrace, it may show where the over all problem is.

[1] https://wiki.asterisk.org/wiki/display/AST/Getting+a+Backtrace

1 Like

Got the backtrace. Here is the contents of the .txt file.
I’m not really sure what it’s saying, but this is it. If there is more needed let me know.

> GNU gdb (Ubuntu 7.7.1-0ubuntu5~14.04.2) 7.7.1
> Copyright (C) 2014 Free Software Foundation, Inc.
> License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
> This is free software: you are free to change and redistribute it.
> There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
> and "show warranty" for details.
> This GDB was configured as "i686-linux-gnu".
> Type "show configuration" for configuration details.
> For bug reporting instructions, please see:
> <http://www.gnu.org/software/gdb/bugs/>.
> Find the GDB manual and other documentation resources online at:
> <http://www.gnu.org/software/gdb/documentation/>.
> For help, type "help".
> Type "apropos word" to search for commands related to "word"...
> Reading symbols from asterisk...done.
> [New LWP 23871]
> [New LWP 23845]
> [New LWP 23856]
> [New LWP 23850]
> [New LWP 23843]
> [New LWP 23872]
> [New LWP 23844]
> [New LWP 23873]
> [New LWP 23846]
> [New LWP 23847]
> [New LWP 23842]
> [New LWP 23848]
> [New LWP 23849]
> [New LWP 23851]
> [New LWP 23852]
> [New LWP 23862]
> [New LWP 23853]
> [New LWP 23854]
> [New LWP 23855]
> [New LWP 23857]
> [New LWP 23858]
> [New LWP 23859]
> [New LWP 23860]
> [New LWP 23861]
> [New LWP 23863]
> [New LWP 23864]
> [New LWP 23865]
> [New LWP 23866]
> [New LWP 23867]
> [New LWP 23868]
> [New LWP 23869]
> [New LWP 23870]
> [Thread debugging using libthread_db enabled]
> Using host libthread_db library "/lib/i386-linux-gnu/libthread_db.so.1".
> Core was generated by `asterisk -vvvvvg -c'.
> Program terminated with signal SIGSEGV, Segmentation fault.
> #0  0xb6284c69 in handle_response_peerpoke (p=0xb6d05578, resp=200, req=0xb5565c34) at chan_sip.c:25678
> 25678				alias->peer->lastms = pingtime;
> (gdb) bt
> #0  0xb6284c69 in handle_response_peerpoke (p=0xb6d05578, resp=200, req=0xb5565c34) at chan_sip.c:25678
> #1  0xb6286069 in handle_response (p=0xb6d05578, resp=200, rest=0xb6d096d0 "OK", req=0xb5565c34, seqno=101) at chan_sip.c:25954
> #2  0xb62a6994 in handle_incoming (p=0xb6d05578, req=0xb5565c34, addr=0xb5566178, recount=0xb5565bc8, nounlock=0xb5565bcc) at chan_sip.c:32515
> #3  0xb62a8118 in handle_request_do (req=0xb5565c34, addr=0xb5566178) at chan_sip.c:32825
> #4  0xb62a7cd8 in sipsock_read (id=0xb6d00698, fd=8, events=1, ignore=0x0) at chan_sip.c:32756
> #5  0x08161088 in ast_io_wait (ioc=0x9942658, howlong=0) at io.c:295
> #6  0xb62acb3b in do_monitor (data=0x0) at chan_sip.c:33721
> #7  0x0822464f in dummy_start (data=0x9a05be8) at utils.c:1235
> #8  0xb72e3f72 in start_thread (arg=0xb5566b40) at pthread_create.c:312
> #9  0xb7198f8e in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:129
> (gdb) bt full
> #0  0xb6284c69 in handle_response_peerpoke (p=0xb6d05578, resp=200, req=0xb5565c34) at chan_sip.c:25678
>     alias = 0x9a18eb0
>     peer = 0x9a17dc0
>     statechanged = 1
>     is_reachable = 1
>     was_reachable = 0
>     pingtime = 70
>     status = 0xb62e5214 "Reachable"
>     lastms = "70\000\000\000\000\000\000\340rжPeжj\006\000"
>     __PRETTY_FUNCTION__ = "handle_response_peerpoke"
> #1  0xb6286069 in handle_response (p=0xb6d05578, resp=200, rest=0xb6d096d0 "OK", req=0xb5565c34, seqno=101) at chan_sip.c:25954
>     owner = 0x0
>     sipmethod = 3
>     c = 0xb6d097f9 "101 OPTIONS"
>     c_copy = 0xb5565780 "101 OPTIONS"
>     msg = 0xb5565784 "OPTIONS"
>     ack_res = 1
>     __PRETTY_FUNCTION__ = "handle_response"
> #2  0xb62a6994 in handle_incoming (p=0xb6d05578, req=0xb5565c34, addr=0xb5566178, recount=0xb5565bc8, nounlock=0xb5565bcc) at chan_sip.c:32515
>     cmd = 0xb6d096c4 "SIP/2.0"
>     cseq = 0xb6d097f9 "101 OPTIONS"
>     useragent = 0xb62d5c50 ""
>     via = 0xb6d096d8 "SIP/2.0/UDP 192.168.4.53:5060;branch=z9hG4bK65fa0991"
>     callid = 0xb6d0979c "11ce894c6ca95aee2af49651393d4d63@192.168.4.53:5060"
>     via_pos = 2
>     seqno = 101
>     len = 4
>     respid = 200
>     res = 0
>     e = 0xb6d096cc "200 OK"
>     error = 0
>     oldmethod = 3
>     acked = 0
>     __PRETTY_FUNCTION__ = "handle_incoming"
> #3  0xb62a8118 in handle_request_do (req=0xb5565c34, addr=0xb5566178) at chan_sip.c:32825
>     p = 0xb6d05578
>     owner_chan_ref = 0x0
>     recount = 0
>     nounlock = 0
>     __PRETTY_FUNCTION__ = "handle_request_do"
> #4  0xb62a7cd8 in sipsock_read (id=0xb6d00698, fd=8, events=1, ignore=0x0) at chan_sip.c:32756
>     req = {rlpart1 = 0, rlpart2 = 8, headers = 17, method = 1, lines = 13, sdp_start = 0, sdp_count = 0, debug = 0 '\000', has_to_tag = 1 '\001', ignore = 0 '\000', authenticated = 0 '\000', header = {
>         0, 15, 73, 122, 207, 267, 303, 321, 349, 415, 447, 509, 535, 555, 783, 803, 833, 880, 0 <repeats 46 times>}, line = {881, 885, 928, 939, 945, 980, 1001, 1022, 1044, 1064, 1087, 1108, 1142, 
>         0 <repeats 243 times>}, data = 0xb6d096b8, content = 0x0, socket = {type = AST_TRANSPORT_UDP, fd = -1, port = 50195, tcptls_session = 0x0, ws_session = 0x0}, next = {next = 0x0}, 
>       reqsipoptions = 0}
>     addr = {ss = {ss_family = 2, __ss_align = 3691292864, 
>         __ss_padding = "\000\000\000\000\000\000\000\000\250aV\265 \254\t\b\000\000\000\000\240U\237\t\200U\237\t0`.\267\266u$\b@kV\265\030bV\265\f\303\t\b\260U\237\t\001\000\000\000\063v$\b0`.\267P\001\000\000Gv$\b\000\000\000\000\300p.\267P^\237\t\000\000\000\000\000\340/\266\030bV\265\000\340/\266@kV\265\000\000\000\000\062\215\026\bP^\237\tXbV\265"}, len = 16}
>     res = 1189
>     readbuf = "SIP/2.0 200 OK\r\nVia: SIP/2.0/UDP 192.168.4.53:5060;branch=z9hG4bK65fa0991\r\nFrom: <sip:asterisk@192.168.4.53>;tag=as043def4d\r\nTo: <sip:101@192.168.4.220:5060;transport=udp>;tag=00131a59225500211dcffd4b"...
>     __PRETTY_FUNCTION__ = "sipsock_read"
> #5  0x08161088 in ast_io_wait (ioc=0x9942658, howlong=0) at io.c:295
>     res = 1
>     x = 0
>     origcnt = 1
> #6  0xb62acb3b in do_monitor (data=0x0) at chan_sip.c:33721
>     res = 0
>     t = 1480949494
>     reloading = 0
>     __PRETTY_FUNCTION__ = "do_monitor"
> #7  0x0822464f in dummy_start (data=0x9a05be8) at utils.c:1235
>     __cancel_buf = {__cancel_jmp_buf = {{__cancel_jmp_buf = {-1221632000, -1252627648, 0, -1252629736, 1817678870, -2078356628}, __mask_was_saved = 0}}, __pad = {0xb5566350, 0x0, 0x0, 0x0}}
>     __cancel_routine = 0x808eeb7 <ast_unregister_thread>
>     __cancel_arg = 0xb5566b40
>     __not_first_call = 0
>     ret = 0x0
>     a = {start_routine = 0xb62ac8b1 <do_monitor>, data = 0x0, name = 0x9a05bf8 "do_monitor", ' ' <repeats 11 times>, "started at [33754] chan_sip.c restart_monitor()"}
> #8  0xb72e3f72 in start_thread (arg=0xb5566b40) at pthread_create.c:312
>     __res = <optimized out>
>     pd = 0xb5566b40
>     now = <optimized out>
>     unwind_buf = {cancel_jmp_buf = {{jmp_buf = {-1221632000, -1252627648, 4001536, -1252629528, 1817482262, -1662219758}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, 
>           cleanup = 0x0, canceltype = 0}}}
>     not_first_call = <optimized out>
>     pagesize_m1 = <optimized out>
>     sp = <optimized out>
>     freesize = <optimized out>
>     __PRETTY_FUNCTION__ = "start_thread"
> #9  0xb7198f8e in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:129
> No locals.
> (gdb) thread apply all bt

> Thread 32 (Thread 0xb55c0b40 (LWP 23870)):
> #0  0xb7773cf9 in ?? ()
> #1  0x0820f9fa in default_tps_processing_function (data=0x9a07578) at taskprocessor.c:178
> #2  0x0822464f in dummy_start (data=0x99d4a38) at utils.c:1235
> #3  0xb72e3f72 in start_thread (arg=0xb55c0b40) at pthread_create.c:312
> #4  0xb7198f8e in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:129

> Thread 31 (Thread 0xb55fcb40 (LWP 23869)):
> #0  0xb7773cf9 in ?? ()
> #1  0xb5ff04de in do_monitor (data=0x0) at chan_mgcp.c:3928
> #2  0x0822464f in dummy_start (data=0x994ab00) at utils.c:1235
> #3  0xb72e3f72 in start_thread (arg=0xb55fcb40) at pthread_create.c:312
> #4  0xb7198f8e in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:129

> Thread 30 (Thread 0xb5638b40 (LWP 23868)):
> #0  0xb7773cf9 in ?? ()
> (gdb) quit

That code does not appear to exist in Asterisk mainline. Are you using a patch which adds or changes code? If so then the problem seems to be in the patch.

1 Like

I am indeed. Cisco patch.
I had actually considered that since I recently upgraded from 13.11.2 with the Cisco 13.10 patch(there was no 13.11 patch) and then upgraded to the 13.12.1 Asterisk and Cisco patch.

I was just struggling to remember if I had seen this problem at all with 13.11.2, but I don’t think I did. Apparently I installed 13.12.1 over a month ago and don’t remember this happening until recently. Strange.

Anyway, I’m going to go back to 13.11.2, see what I get, and I’ll post what happens either way, but I’ll try and notify the person who makes the patch of the problem. Thanks for your help.

I wanted to update those who may be searching for info on this issue.

This has to do with the Cisco patch, however it was that I was using it incorrectly.

In order for everything to function well using the usecallmanager patch, you have to switch to TCP transport in sip.conf instead of UDP. I did that and everything is good now.

Also note Cisco phones will need to told what transport protocol to use as well.

In the phone’s SEPMAC.cnf.xml file, set transportLayerProtocol to 1.

<transportLayerProtocol>1</transportLayerProtocol>