Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

opensips 2.3 crash #1174

Closed
soulofmischief87 opened this issue Aug 15, 2017 · 11 comments
Closed

opensips 2.3 crash #1174

soulofmischief87 opened this issue Aug 15, 2017 · 11 comments
Assignees
Labels

Comments

@soulofmischief87
Copy link

soulofmischief87 commented Aug 15, 2017

opensips 2.3 is crashing consistently here is a back trace

 gdb /usr/sbin/opensips core.3414
GNU gdb (GDB) Red Hat Enterprise Linux 7.6.1-94.el7
Copyright (C) 2013 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 "x86_64-redhat-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/sbin/opensips...done.
[New LWP 3414]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/sbin/opensips -P /var/run/opensips.pid -f /etc/opensips/opensips.cfg -w /etc/o'.
Program terminated with signal 6, Aborted.
#0  0x00007effa3cf11d7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
56	  return INLINE_SYSCALL (tgkill, 3, pid, selftid, sig);
(gdb) bt full
#0  0x00007effa3cf11d7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
        resultvar = 0
        pid = 3414
        selftid = 3414
#1  0x00007effa3cf28c8 in __GI_abort () at abort.c:90
        save_stage = 2
        act = {__sigaction_handler = {sa_handler = 0x7eff9ac76d81 <__FUNCTION__.8131>, sa_sigaction = 0x7eff9ac76d81 <__FUNCTION__.8131>}, sa_mask = {__val = {3472120737606682963, 139636398014132, 56, 
              0, 14572702027416160256, 140733360057200, 139636428201560, 1, 0, 0, 4728072, 4945624, 5444827, 0, 0, 140733360057280}}, sa_flags = -1577425568, sa_restorer = 0x89ecb0 <mem_lock>}
        sigs = {__val = {32, 0 <repeats 15 times>}}
#2  0x00007eff9ac6763c in shm_free (_p=<optimized out>) at ../tm/../../mem/shm_mem.h:570
No locals.
#3  free_extra_array (tags=<optimized out>, array=<optimized out>, tags_len=<optimized out>) at acc_logic.c:198
        i = <optimized out>
#4  free_acc_ctx (ctx=0x7effa1fa99a8) at acc_logic.c:220
        i = <optimized out>
#5  tm_free_acc_ctx (param=0x7effa1fa99a8) at acc_logic.c:260
        param = 0x7effa1fa99a8
        ctx = 0x7effa1fa99a8
#6  0x00007eff9f575693 in empty_tmcb_list (head=head@entry=0x7effa1fcc150) at t_hooks.c:53
        cbp = 0x0
        cbp_tmp = 0x7effa1e834a0
#7  0x00007eff9f5439bf in free_cell (dead_cell=0x7effa1fcc0e0) at h_table.c:127
        b = <optimized out>
        i = <optimized out>
        rpl = <optimized out>
        tt = <optimized out>
        foo = <optimized out>
        p = <optimized out>
#8  0x00007eff9f546087 in free_hash_table () at h_table.c:383
        p_cell = <optimized out>
        tmp_cell = 0x0
        i = 26198
#9  0x00007eff9f542f75 in tm_shutdown () at t_funcs.c:89
        __FUNCTION__ = "tm_shutdown"
#10 0x00000000004b58fd in destroy_modules () at sr_module.c:527
        t = 0x7effa3ac6900
        foo = 0x7effa3ac6820
        __FUNCTION__ = "destroy_modules"
#11 0x00000000005075f3 in cleanup (show_status=show_status@entry=1) at main.c:319
        __FUNCTION__ = "cleanup"
#12 0x00000000005081d7 in handle_sigs () at main.c:522
        chld = 0
        chld_status = 134
        overall_status = 134
        i = <optimized out>
        do_exit = <optimized out>
        __FUNCTION__ = "handle_sigs"
#13 0x000000000041c990 in main_loop () at main.c:722
        startup_done = <optimized out>
        chd_rank = 25
#14 main (argc=<optimized out>, argv=<optimized out>) at main.c:1283
        cfg_stream = <optimized out>
        c = <optimized out>
        r = <optimized out>
        tmp = 0x1 <Address 0x1 out of bounds>
        tmp_len = <optimized out>
        port = <optimized out>
        proto = <optimized out>
        protos_no = <optimized out>
        options = 0x6327f8 "f:cCm:M:b:l:n:N:rRvdDFETSVhw:t:u:g:P:G:W:o:"
        ret = -1
---Type <return> to continue, or q <return> to quit---
        seed = 297171572
        rfd = <optimized out>
        __FUNCTION__ = "main"
(gdb) 

I am using centos 7 can anyone please advise as to why this is happening?

@razvancrainea razvancrainea self-assigned this Aug 16, 2017
@razvancrainea
Copy link
Member

Looks like a crash during OpenSIPS shutdown. Do you have another core dump for the runtime crash, or there is none?

Can you be more specific about the OpenSIPS version? The output of opensips -V would be more helpful.

@soulofmischief87
Copy link
Author

soulofmischief87 commented Aug 16, 2017

Hey Razvan,

I didn't trigger a shutdown then but I found this crash happen on it's own

GNU gdb (GDB) Red Hat Enterprise Linux 7.6.1-94.el7
Copyright (C) 2013 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 "x86_64-redhat-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/sbin/opensips...done.
[New LWP 5227]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/sbin/opensips -P /var/run/opensips.pid -f /etc/opensips/opensips.cfg -w /etc/o'.
Program terminated with signal 11, Segmentation fault.
#0  0x0000000000530d92 in fm_remove_free (n=0x7fe3b48efb88, qm=0x7fe3b4474000) at mem/f_malloc.c:200
200		*pf=n->u.nxt_free;
(gdb) bt full
#0  0x0000000000530d92 in fm_remove_free (n=0x7fe3b48efb88, qm=0x7fe3b4474000) at mem/f_malloc.c:200
        pf = 0x0
        hash = 19
#1  fm_malloc (qm=0x7fe3b4474000, size=size@entry=152) at mem/f_malloc.c:428
        frag = 0x7fe3b48efb88
        n = <optimized out>
        hash = 19
        __FUNCTION__ = "fm_malloc"
#2  0x00007fe3b40530d9 in shm_malloc (size=152) at ../../mem/shm_mem.h:437
        p = <optimized out>
#3  os_malloc (size=152) at tls.h:85
No locals.
#4  0x00007fe3b3a45593 in CRYPTO_malloc (num=152, file=file@entry=0x7fe3b3b48710 "bn_lib.c", line=line@entry=317) at mem.c:308
        ret = 0x0
#5  0x00007fe3b3a81287 in bn_expand_internal (b=0x7fe3b4905608, words=<optimized out>) at bn_lib.c:317
        A = <optimized out>
        a = 0x0
        B = <optimized out>
        i = <optimized out>
#6  0x00007fe3b3a81775 in bn_expand2 (b=b@entry=0x7fe3b4905608, words=words@entry=19) at bn_lib.c:432
        a = <optimized out>
#7  0x00007fe3b3a7ea2e in BN_div (dv=dv@entry=0x0, rm=rm@entry=0x7fe3b4905578, num=num@entry=0x7ffe77777240, divisor=0x7fe3b47b4368, ctx=ctx@entry=0x7fe3b48e1dc0) at bn_div.c:286
        norm_shift = 128
        i = <optimized out>
        loop = 18
        tmp = 0x7fe3b49055c0
        wnum = {d = 0x7fe3b48b4d90, top = 17, dmax = 17, neg = 0, flags = 32739}
        snum = 0x7fe3b49055d8
        sdiv = <optimized out>
        res = 0x7fe3b4905608
        resp = <optimized out>
        wnump = 0x7fe3b48b4e10
        d0 = 17764259548584316659
        d1 = 7026051210492083692
        num_n = 35
        div_n = 17
        no_branch = <optimized out>
#8  0x00007fe3b3a9d84a in RSA_eay_mod_exp (r0=0x7fe3b4905548, I=0x7fe3b4905530, rsa=0x7fe3b47b2470, ctx=0x7fe3b48e1dc0) at rsa_eay.c:870
        r1 = 0x7fe3b4905578
        m1 = 0x7fe3b4905590
        vrfy = 0x7fe3b49055a8
        local_dmp1 = {d = 0x7fe3b4853de0, top = -1265609424, dmax = 32739, neg = -1266336336, flags = 32739}
        local_dmq1 = {d = 0x7fe3b4853de0, top = -1265754688, dmax = 32739, neg = 0, flags = 0}
        local_c = {d = 0x7fe3b4854818, top = 32, dmax = 32, neg = 0, flags = 7}
        local_r1 = {d = 0x7fe3b47b42c8, top = 16, dmax = 17, neg = 0, flags = 6}
        dmp1 = <optimized out>
        dmq1 = <optimized out>
        c = 0x7ffe77777240
        pr1 = <optimized out>
        ret = 0
#9  0x00007fe3b3a9e8ce in RSA_eay_private_decrypt (flen=<optimized out>, from=<optimized out>, 
    to=0x7fe3b490c446 "\261\255ϜV\002\266\064\214\344\200ڑ\207\313_\005\026\334-\335Ѝ\240s\224\212\323i\356\356M\315\"\204y\351\271\326\304Ϻ\346\f\004\344\267z\244\364\ve(\340\236\300\376V\335\021\336ʚ\b)A\f\267\030\265\066؀kXx\342\307\331{\204\067\301N\215\064\346\264\365\006/\241\215K}EJ\"\236\266\227\327\r\003*\325ʜ\032\243\037\002\215j0\271\242\357\262XA*q\257\201\361\243\201\331\366!\344\267\066\360\250x2\244X\\b\234\347\234\004\204L\364j\200\276\036\244\234\250\230\\3mX\366P}*\324[\273L\326͞9\225\360\313\352n\336\061\006\"\342\034n\206\027\033*\345\313\004\271\214\201\320\065\347b\223"..., 
    rsa=0x7fe3b47b2470, padding=1) at rsa_eay.c:623
        f = 0x7fe3b4905530
        ret = <optimized out>
        j = <optimized out>
        num = 256
        r = -1
        p = <optimized out>
---Type <return> to continue, or q <return> to quit---
        buf = 0x7fe3b48b4e58 ""
        ctx = 0x7fe3b48e1dc0
        local_blinding = 0
        unblind = 0x7fe3b4905560
        blinding = <optimized out>
#10 0x00007fe3b3debac5 in ssl3_get_client_key_exchange (s=s@entry=0x7fe3b48a7c98) at s3_srvr.c:2255
        i = <optimized out>
        al = <optimized out>
        ok = 1
        n = 256
        alg_k = 1
        p = 0x7fe3b490c446 "\261\255ϜV\002\266\064\214\344\200ڑ\207\313_\005\026\334-\335Ѝ\240s\224\212\323i\356\356M\315\"\204y\351\271\326\304Ϻ\346\f\004\344\267z\244\364\ve(\340\236\300\376V\335\021\336ʚ\b)A\f\267\030\265\066؀kXx\342\307\331{\204\067\301N\215\064\346\264\365\006/\241\215K}EJ\"\236\266\227\327\r\003*\325ʜ\032\243\037\002\215j0\271\242\357\262XA*q\257\201\361\243\201\331\366!\344\267\066\360\250x2\244X\\b\234\347\234\004\204L\364j\200\276\036\244\234\250\230\\3mX\366P}*\324[\273L\326͞9\225\360\313\352n\336\061\006\"\342\034n\206\027\033*\345\313\004\271\214\201\320\065\347b\223"...
        rsa = <optimized out>
        pkey = <optimized out>
        pub = 0x0
        dh_srvr = <optimized out>
        kssl_err = {reason = 2004317360, 
          text = "\376\177\000\000\260<\254\263\343\177\000\000@Đ\264\343\177\000\000\004", '\000' <repeats 15 times>, "k\024", '\000' <repeats 14 times>, "k\024\000\000\000\000\000\000puww\376\177\000\000\240uww\376\177\000\000\006\003\000\000\000\000\000\000\223$\254\263\343\177\000\000\006\003\000\000\000\000\000\000\a\003\000\000\000\000\000\000\b\000\000\000\000\000\000\000\255W\244\263\343\177\000\000puww\376\177\000\000i/\254\263\343\177\000\000\001\000\000\000\000\000\000\000\234\376\264\263\343\177\000\000\200Dܳ\343\177\000\000vP\244\263\343\177\000\000\320uww\376\177\000\000\020\000\000\000\325\001\000\000\000\000\000\000\000\000\000\000\220uww\376\177"...}
        srvr_ecdh = 0x0
        clnt_pub_pkey = 0x0
        clnt_ecpoint = 0x0
        bn_ctx = 0x0
#11 0x00007fe3b3dee08b in ssl3_accept (s=0x7fe3b48a7c98) at s3_srvr.c:590
        buf = <optimized out>
        alg_k = <optimized out>
        Time = 1502862668
        cb = 0x0
        ret = <optimized out>
        new_state = <optimized out>
        state = 8592
        skip = 0
#12 0x00007fe3ac4e59d7 in tls_accept (c=c@entry=0x7fe3b4905390, poll_events=poll_events@entry=0x0) at ../tls_mgm/tls_conn_server.h:242
        ret = <optimized out>
        err = <optimized out>
        ssl = 0x7fe3b48a7c98
        cert = <optimized out>
        tls_err_s = {s = 0xb <Address 0xb out of bounds>, len = 8}
#13 0x00007fe3ac4f1c69 in tls_accept (poll_events=0x0, c=0x7fe3b4905390) at ../proto_ws/ws_common.h:414
No locals.
#14 tls_fix_read_conn (c=0x7fe3b4905390) at ../tls_mgm/tls_conn_server.h:476
        ret = <optimized out>
#15 wss_read_req (con=0x7fe3b4905390, bytes_read=<optimized out>) at proto_wss.c:544
        size = <optimized out>
        d = <optimized out>
        __FUNCTION__ = "wss_read_req"
#16 0x00000000005e3067 in handle_io (event_type=1, idx=1, fm=<optimized out>) at net/net_tcp_proc.c:231
        con = 0x7fe3b4905390
        ret = 0
        n = <optimized out>
        rw = <optimized out>
        response = {140615963661200, 1}
        s = 11
        resp = <optimized out>
#17 io_wait_loop_epoll (repeat=<optimized out>, t=<optimized out>, h=<optimized out>) at net/../io_wait_loop.h:280
        ret = 1
---Type <return> to continue, or q <return> to quit---
        n = 1
        r = 1
        i = <optimized out>
        e = <optimized out>
        ep_event = {events = 3058710432, data = {ptr = 0xb6502e6800007fe3, fd = 32739, u32 = 32739, u64 = 13137051137251246051}}
        fd = <optimized out>
#18 0x00000000005e4b1b in tcp_worker_proc_loop () at net/net_tcp_proc.c:359
        __FUNCTION__ = "tcp_worker_proc_loop"
#19 0x00000000005f166d in tcp_start_processes (chd_rank=chd_rank@entry=0x89c4f0 <chd_rank.11324>, startup_done=startup_done@entry=0x7fe3b483f500) at net/net_tcp.c:1837
        r = 4
        reader_fd = {99, 103}
        pid = <optimized out>
        load_p = 0x7fe3b4840290
        __FUNCTION__ = "tcp_start_processes"
#20 0x000000000041c6a4 in main_loop () at main.c:683
        startup_done = 0x7fe3b483f500
        chd_rank = 21
#21 main (argc=<optimized out>, argv=<optimized out>) at main.c:1283
        cfg_stream = <optimized out>
        c = <optimized out>
        r = <optimized out>
        tmp = 0x1 <Address 0x1 out of bounds>
        tmp_len = <optimized out>
        port = <optimized out>
        proto = <optimized out>
        protos_no = <optimized out>
        options = 0x6327f8 "f:cCm:M:b:l:n:N:rRvdDFETSVhw:t:u:g:P:G:W:o:"
        ret = -1
        seed = 2371559815
        rfd = <optimized out>
        __FUNCTION__ = "main"

Here is the output of opensips -V

 opensips 2.3.1 (x86_64/linux)
flags: STATS: On, DISABLE_NAGLE, USE_MCAST, SHM_MMAP, PKG_MALLOC, F_MALLOC, FAST_LOCK-ADAPTIVE_WAIT
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
git revision: c33f23f
main.c compiled on 01:08:22 Aug 12 2017 with gcc 4.8.5

with

 ulimit -c unlimited

@razvancrainea
Copy link
Member

right, this looks more appropriate. Can you also send us the libssl version you are using?

@soulofmischief87
Copy link
Author

Razvan,
I am using OpenSSL 1.0.2l 25 May 2017.

@razvancrainea
Copy link
Member

Can you try to use the QM memory allocator? It will provide us with more information in case of a crash.

@soulofmischief87
Copy link
Author

Are referring to compiling with QM_MALLOC in the compile flags?

@razvancrainea
Copy link
Member

Yes, that's right.

@soulofmischief87
Copy link
Author

soulofmischief87 commented Aug 22, 2017

Razvan,

I got two core files from one crash here is the first

bt full
#0  qm_free (qm=0x7f15d2444000, p=p@entry=0x1) at mem/q_malloc.c:498
        f = 0xfffffffffffffff1
        prev = <optimized out>
        next = <optimized out>
        size = <optimized out>
        __FUNCTION__ = "qm_free"
#1  0x00007f15cdbe5ceb in shm_free (_p=0x1) at ../tm/../../mem/shm_mem.h:588
No locals.
#2  free_acc_ctx (ctx=0x7f15d285f840) at acc_logic.c:225
        i = <optimized out>
#3  tm_free_acc_ctx (param=0x7f15d285f840) at acc_logic.c:260
        param = 0x7f15d285f840
        ctx = 0x7f15d285f840
#4  0x00007f15cff03f5f in empty_tmcb_list (head=head@entry=0x7f15d29e5150) at t_hooks.c:53
        cbp = 0x0
        cbp_tmp = 0x7f15d29f0d10
#5  0x00007f15cfed00ea in free_cell (dead_cell=0x7f15d29e50e0) at h_table.c:127
        b = <optimized out>
        i = <optimized out>
        rpl = <optimized out>
        tt = <optimized out>
        foo = <optimized out>
        p = <optimized out>
#6  0x00007f15cfed23f1 in free_hash_table () at h_table.c:383
        p_cell = <optimized out>
        tmp_cell = 0x0
        i = 36113
#7  0x00007f15cfecf7e8 in tm_shutdown () at t_funcs.c:89
        __FUNCTION__ = "tm_shutdown"
#8  0x00000000004f27a4 in destroy_modules () at sr_module.c:527
        t = 0x7f15d4459220
        foo = 0x7f15d4459130
#9  0x00000000004ed4f3 in cleanup (show_status=show_status@entry=1) at main.c:319
        __FUNCTION__ = "cleanup"
#10 0x00000000004ee043 in handle_sigs () at main.c:522
        chld = 0
        chld_status = 139
        overall_status = 139
        i = <optimized out>
        do_exit = <optimized out>
        __FUNCTION__ = "handle_sigs"
#11 0x000000000041bd3a in main_loop () at main.c:722
        startup_done = <optimized out>
        chd_rank = 25
#12 main (argc=<optimized out>, argv=<optimized out>) at main.c:1283
        cfg_stream = <optimized out>
        c = <optimized out>
        r = <optimized out>
        tmp = 0x1 <Address 0x1 out of bounds>
        tmp_len = <optimized out>
        port = <optimized out>
        proto = <optimized out>
        protos_no = <optimized out>
        options = 0x61f5d8 "f:cCm:M:b:l:n:N:rRvdDFETSVhw:t:u:g:P:G:W:o:"
        ret = -1
        seed = 1735222095
        rfd = <optimized out>
        __FUNCTION__ = "main"

Here is the 2nd

GNU gdb (GDB) Red Hat Enterprise Linux 7.6.1-94.el7
Copyright (C) 2013 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 "x86_64-redhat-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/sbin/opensips...done.
[New LWP 15182]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/sbin/opensips -P /var/run/opensips.pid -f /etc/opensips/opensips.cfg -w /etc/o'.
Program terminated with signal 11, Segmentation fault.
#0  qm_free (qm=0x7f15d2444000, p=p@entry=0x1) at mem/q_malloc.c:498
498		size=f->size;
(gdb) bt full
#0  qm_free (qm=0x7f15d2444000, p=p@entry=0x1) at mem/q_malloc.c:498
        f = 0xfffffffffffffff1
        prev = <optimized out>
        next = <optimized out>
        size = <optimized out>
        __FUNCTION__ = "qm_free"
#1  0x00007f15cdbe88e9 in shm_free (_p=0x1) at ../tm/../../mem/shm_mem.h:588
No locals.
#2  free_acc_ctx (ctx=0x7f15d285f840) at acc_logic.c:225
        i = <optimized out>
#3  free_processing_acc_ctx (param=0x7f15d285f840) at acc_logic.c:279
        ctx = 0x7f15d285f840
#4  0x00000000004254dd in context_destroy (ctxtype=ctxtype@entry=CONTEXT_GLOBAL, ctx=0x7f15d44e0410) at context.c:118
        f = <optimized out>
        n = 2
        i = -733088384
#5  0x000000000045f937 in receive_msg (
    buf=0x89d180 <buf.8315> "SIP/2.0 494 Unknown Status\r\nTo: <sip:eenglish.medocity@nurseliveconnect.org>;tag=44046910_f9ca4c74_d8260efb_38a03274\r\nVia: SIP/2.0/UDP 192.237.248.108:5060;branch=z9hG4bK11d8.8cc601d1.1;i=ed5dd417\r\nVi"..., len=<optimized out>, rcv_info=rcv_info@entry=0x7ffda7760ea0, existing_context=existing_context@entry=0x0) at receive.c:273
        ctx = 0x7f15d44e0410
        msg = 0x7f15d44df580
        start = {tv_sec = 4, tv_usec = 53249700000}
        rc = <optimized out>
        in_buff = {
          s = 0x89d180 <buf.8315> "SIP/2.0 494 Unknown Status\r\nTo: <sip:eenglish.medocity@nurseliveconnect.org>;tag=44046910_f9ca4c74_d8260efb_38a03274\r\nVia: SIP/2.0/UDP 192.237.248.108:5060;branch=z9hG4bK11d8.8cc601d1.1;i=ed5dd417\r\nVi"..., len = 556}
        __FUNCTION__ = "receive_msg"
#6  0x00000000005e7276 in udp_read_req (si=<optimized out>, bytes_read=<optimized out>) at net/proto_udp/proto_udp.c:192
        ri = {src_ip = {af = 2, len = 4, u = {addrl = {3937004992, 0}, addr32 = {3937004992, 0, 0, 0}, addr16 = {60864, 60073, 0, 0, 0, 0, 0, 0}, addr = "\300\355\251\352", '\000' <repeats 11 times>}}, 
          dst_ip = {af = 2, len = 4, u = {addrl = {1828253120, 0}, addr32 = {1828253120, 0, 0, 0}, addr16 = {60864, 27896, 0, 0, 0, 0, 0, 0}, addr = "\300\355\370l", '\000' <repeats 11 times>}}, 
          src_port = 5080, dst_port = 5060, proto = 1, proto_reserved1 = 0, proto_reserved2 = 0, src_su = {s = {sa_family = 2, sa_data = "\023\330\300\355\251\352\000\000\000\000\000\000\000"}, sin = {
              sin_family = 2, sin_port = 55315, sin_addr = {s_addr = 3937004992}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 55315, sin6_flowinfo = 3937004992, 
              sin6_addr = {__in6_u = {__u6_addr8 = "\000\000\000\000\000\000\000\000\001\000\000\000\000\000\000", __u6_addr16 = {0, 0, 0, 0, 1, 0, 0, 0}, __u6_addr32 = {0, 0, 1, 0}}}, 
              sin6_scope_id = 4909503}}, bind_address = 0x7f15d44bbdb0}
        len = <optimized out>
        buf = "SIP/2.0 494 Unknown Status\r\nTo: <sip:eenglish.medocity@nurseliveconnect.org>;tag=44046910_f9ca4c74_d8260efb_38a03274\r\nVia: SIP/2.0/UDP 192.237.248.108:5060;branch=z9hG4bK11d8.8cc601d1.1;i=ed5dd417\r\nVi"...
        fromlen = 16
        p = <optimized out>
        msg = {
          s = 0x89d180 <buf.8315> "SIP/2.0 494 Unknown Status\r\nTo: <sip:eenglish.medocity@nurseliveconnect.org>;tag=44046910_f9ca4c74_d8260efb_38a03274\r\nVia: SIP/2.0/UDP 192.237.248.108:5060;branch=z9hG4bK11d8.8cc601d1.1;i=ed5dd417\r\nVi"..., len = 556}
        __FUNCTION__ = "udp_read_req"
#7  0x00000000005cb7ff in handle_io (idx=<optimized out>, event_type=<optimized out>, fm=<optimized out>) at net/net_udp.c:259
        read = 0
        fm = <optimized out>
#8  io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>) at net/../io_wait_loop.h:284
        ep_event = {events = 7, data = {ptr = 0xd244e85000000000, fd = 0, u32 = 0, u64 = 15151490476676218880}}
        ret = <optimized out>
        n = 1
        r = 0
        e = <optimized out>
        fd = <optimized out>
        i = <optimized out>
#9  udp_start_processes (chd_rank=chd_rank@entry=0x889440 <chd_rank.11324>, startup_done=startup_done@entry=0x7f15d28271c0) at net/net_udp.c:389
        si = <optimized out>
        load_p = 0x7f15d28271f0
        pid = <optimized out>
        i = <optimized out>
        __FUNCTION__ = "udp_start_processes"
#10 0x000000000041ba65 in main_loop () at main.c:677

@razvancrainea
Copy link
Member

I have just pushed a commit that should address this issue. Please update to the latest sources and let us know if you are still experiencing this crash.

@soulofmischief87
Copy link
Author

Razvan,
Seems like the crash is still happening here is the last message seen before dying
Sep 6 08:57:52 sip1 /sbin/opensips[20534]: CRITICAL:core:sig_alarm_abort: BUG - shutdown timeout triggered, dying...
gdb opensips core.20582
GNU gdb (GDB) Red Hat Enterprise Linux 7.6.1-94.el7
Copyright (C) 2013 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 "x86_64-redhat-linux-gnu".
For bug reporting instructions, please see:
http://www.gnu.org/software/gdb/bugs/...
Reading symbols from /usr/sbin/opensips...done.
[New LWP 20582]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/sbin/opensips -P /var/run/opensips.pid -f /etc/opensips/opensips.cfg -w /etc/o'.
Program terminated with signal 11, Segmentation fault.
#0 qm_detach_free (qm=0x7fcc07e62000, qm=0x7fcc07e62000, frag=0x7fcc0828bc20) at mem/q_malloc.c:294
294 prev->u.nxt_free=next;
(gdb) bt full
#0 qm_detach_free (qm=0x7fcc07e62000, qm=0x7fcc07e62000, frag=0x7fcc0828bc20) at mem/q_malloc.c:294
prev = 0x0
next = 0x7fcc08259fb0
#1 qm_free (qm=0x7fcc07e62000, p=p@entry=0x7fcc0828bc50) at mem/q_malloc.c:524
f = 0x7fcc0828bc40
prev = 0x7fcc0828bc20
next =
size = 0
FUNCTION = "qm_free"
#2 0x00007fcc07a40f14 in shm_free (_p=0x7fcc0828bc50) at ../../mem/shm_mem.h:588
No locals.
#3 os_free (ptr=0x7fcc0828bc50) at tls.h:112
No locals.
#4 0x00007fcc074337ad in CRYPTO_free (str=0x7fcc0828bc50) at mem.c:397
No locals.
#5 0x00007fcc074b3c57 in EVP_MD_CTX_destroy (ctx=) at digest.c:413
No locals.
#6 0x00007fcc077ffcd1 in ssl_clear_hash_ctx (hash=hash@entry=0x7fcc0829d1a0) at ssl_lib.c:3290
No locals.
#7 0x00007fcc078003dd in SSL_free (s=0x7fcc0829d0b0) at ssl_lib.c:560
i =
#8 0x00007fcc0033876f in tls_conn_clean (c=0x7fcc082b20f0) at ../tls_mgm/tls_conn_ops.h:150
No locals.
#9 proto_tls_conn_clean (c=c@entry=0x7fcc082b20f0) at proto_tls.c:343
data =
#10 0x00000000005d6613 in _tcpconn_rm (c=c@entry=0x7fcc082b20f0) at net/net_tcp.c:712
r =
#11 0x000000000041599a in __tcpconn_lifetime (force=0) at net/net_tcp.c:1527
c = 0x7fcc082b20f0
next = 0x0
ticks = 2778
part =
h = 60
fd = 132
#12 0x00000000005e10f2 in tcp_main_server () at net/net_tcp.c:1604
now =
flags =
si =
last_sec = 2778
n =
#13 tcp_start_listener () at net/net_tcp.c:1875
pid =
FUNCTION = "tcp_start_listener"
#14 0x000000000041bbff in main_loop () at main.c:695
startup_done = 0x7fcc082451c0
chd_rank = 25
#15 main (argc=, argv=) at main.c:1283
cfg_stream =
c =
r =
tmp = 0x7ffc6a3daf95 ""
tmp_len =
port =
proto =
protos_no =
options = 0x61f5f8 "f:cCm:M:b:l:n:N:rRvdDFETSVhw:t:u:g:P:G:W:o:"
ret = -1
seed = 485504467
rfd =
FUNCTION = "main"
I am using

version: opensips 2.3.2 (x86_64/linux)
flags: STATS: On, DISABLE_NAGLE, USE_MCAST, SHM_MMAP, PKG_MALLOC, QM_MALLOC, FAST_LOCK-ADAPTIVE_WAIT
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
git revision: 935fd57
main.c compiled on 07:59:22 Sep 6 2017 with gcc 4.8.5

@vurgun
Copy link

vurgun commented Oct 2, 2017

Hello. I can confirm the same crash in opensips 2.3 under FreeBSD 11

Crash 1
<
GNU gdb (GDB) 8.0 [GDB v8.0 for FreeBSD]
Copyright (C) 2017 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 "x86_64-portbld-freebsd11.1".
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 /usr/local/sbin/opensips...done.
[New LWP 100149]
Core was generated by /usr/local/sbin/opensips -P /var/run/opensips.pid -m 1024 -M 32.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x000000000053006c in fm_remove_free (n=0x8047cac80, qm=0x803400000) at mem/f_malloc.c:200
200 *pf=n->u.nxt_free;
(gdb) bt full
#0 0x000000000053006c in fm_remove_free (n=0x8047cac80, qm=0x803400000) at mem/f_malloc.c:200
pf = 0x0
hash = 180
#1 fm_malloc (qm=0x803400000, size=size@entry=1440) at mem/f_malloc.c:428
frag = 0x8047cac80
n =
hash = 180
FUNCTION = "fm_malloc"
#2 0x0000000844f05cb6 in shm_malloc_unsafe (size=1440) at ../../mem/shm_mem.h:414
p =
#3 update_cloned_msg_from_msg (c_msg=0x804277d40, msg=msg@entry=0x801a89520) at sip_msg.c:1183
copy_mask =
l1_len =
l2_len =
l3_len =
p =
add_rm_aux = 0x8047cac98
body_lumps_aux = 0x0
reply_lump_aux = 0x0
body_bk = 0x0
FUNCTION = "update_cloned_msg_from_msg"
#4 0x0000000844f159f3 in do_t_cleanup (foo=0x801a89520, bar=) at tm.c:760
t =
#5 0x000000000050d3da in exec_post_cb (cb=0x801408460, msg=0x801a89520) at script_cb.c:180
No locals.
#6 exec_post_req_cb (msg=msg@entry=0x801a89520) at script_cb.c:198
No locals.
#7 0x0000000000507b91 in receive_msg (
buf=0x91b360 "INVITE sip:123456789@x.x.x.x;user=phone SIP/2.0\r\nFrom: sip:+987654321@y.y.y.y;tag=87891f5e2c\r\nTo: sip:123456789@x.x.x.x\r\nCall-ID: Ut36LJzvcPCGJ0-.T1da99a\r\nCSeq: 1 INVITE\r\nVia:"..., len=, rcv_info=rcv_info@entry=0x7fffffffe8a0, existing_context=existing_context@entry=0x0) at receive.c:213
ctx = 0x801a89f20
msg = 0x801a89520
start = {tv_sec = 140737488349296, tv_usec = 34372662650}
rc =
in_buff = {
s = 0x91b360 "INVITE sip:123456789@x.x.x.x;user=phone SIP/2.0\r\nFrom: sip:+987654321@y.y.y.y;tag=87891f5e2c\r\nTo: sip:123456789@x.x.x.x\r\nCall-ID: Ut36LJzvcPCGJ0-.T1da99a\r\nCSeq: 1 INVITE\r\nVia:"..., len = 991}
FUNCTION = "receive_msg"
#8 0x000000000060c927 in udp_read_req (si=, bytes_read=) at net/proto_udp/proto_udp.c:192
ri = {src_ip = {af = 2, len = 4, u = {addrl = {34532499641, 35}, addr32 = {172761273, 8, 35, 0}, addr16 = {8377, 2636, 8, 0, 35, 0, 0, 0}, addr = "\271 L\n\b\000\000\000#\000\000\000\000\000\000"}}, dst_ip = {af = 2, len = 4,
u = {addrl = {1510005666, 0}, addr32 = {1510005666, 0, 0, 0}, addr16 = {56226, 23040, 0, 0, 0, 0, 0, 0}, addr = "\242\333\000Z", '\000' <repeats 11 times>}}, src_port = 5060, dst_port = 5060, proto = 1, proto_reserved1 = 0,
proto_reserved2 = 0, src_su = {s = {sa_len = 16 '\020', sa_family = 2 '\002', sa_data = "\023\304\271 L\n\000\000\000\000\000\000\000"}, sin = {sin_len = 16 '\020', sin_family = 2 '\002', sin_port = 50195, sin_addr = {
s_addr = 172761273}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_len = 16 '\020', sin6_family = 2 '\002', sin6_port = 50195, sin6_flowinfo = 172761273, sin6_addr = {__u6_addr = {
__u6_addr8 = "\000\000\000\000\000\000\000\000p\351\377\377\377\177\000", __u6_addr16 = {0, 0, 0, 0, 59760, 65535, 32767, 0}, __u6_addr32 = {0, 0, 4294961520, 32767}}}, sin6_scope_id = 0}}, bind_address = 0x8014086d0}
len =
buf = "INVITE sip:123456789@x.x.x.x;user=phone SIP/2.0\r\nFrom: sip:+987654321@y.y.y.y;tag=87891f5e2c\r\nTo: sip:123456789@x.x.x.x\r\nCall-ID: Ut36LJzvcPCGJ0-.T1da99a\r\nCSeq: 1 INVITE\r\nVia:"...
fromlen = 16
p =
msg = {
s = 0x91b360 "INVITE sip:123456789@x.x.x.x;user=phone SIP/2.0\r\nFrom: sip:+987654321@y.y.y.y;tag=87891f5e2c\r\nTo: sip:123456789@x.x.x.x\r\nCall-ID: Ut36LJzvcPCGJ0-.T1da99a\r\nCSeq: 1 INVITE\r\nVia:"..., len = 991}
FUNCTION = "udp_read_req"
#9 0x00000000005fd820 in handle_io (idx=0, event_type=1, fm=) at net/net_udp.c:259
read = 1295614847
fm =
#10 io_wait_loop_kqueue (h=, t=1, repeat=0) at net/../io_wait_loop.h:285
ret =
tspec = {tv_sec = 1, tv_nsec = 0}
e =
n = 1
r = 0
#11 udp_start_processes (chd_rank=chd_rank@entry=0x8e01ec <chd_rank>, startup_done=startup_done@entry=0x0) at net/net_udp.c:389
si =
load_p = 0x803749078
pid =
i =
FUNCTION = "udp_start_processes"
#12 0x000000000041c455 in main_loop () at main.c:677
---Type to continue, or q to quit---
startup_done = 0x0
chd_rank = 3
#13 main (argc=, argv=) at main.c:1283
cfg_stream =
c =
r =
tmp = 0x7fffffffed9f ""
tmp_len =
port =
proto =
protos_no =
options = 0x626e70 "f:cCm:M:b:l:n:N:rRvdDFETSVhw:t:u:g:P:G:W:o:"
ret = -1
seed = 1295614847
rfd =
FUNCTION = "main"
(gdb)

Crash 2 2-3 minutes after the first
`
Reading symbols from /usr/local/sbin/opensips...done.
[New LWP 100099]
Core was generated by /usr/local/sbin/opensips -P /var/run/opensips.pid -m 1024 -M 32.
Program terminated with signal SIGABRT, Aborted.
#0 0x0000000800bc284a in thr_kill () from /lib/libc.so.7
(gdb) bt full
#0 0x0000000800bc284a in thr_kill () from /lib/libc.so.7
No symbol table info available.
#1 0x0000000800bc2814 in raise () from /lib/libc.so.7
No symbol table info available.
#2 0x0000000800bc2789 in abort () from /lib/libc.so.7
No symbol table info available.
#3 0x00000000004549fe in sig_alarm_abort (signo=) at main.c:414
FUNCTION = "sig_alarm_abort"
#4 0x00000008441cc926 in ?? () from /lib/libthr.so.3
No symbol table info available.
#5 0x00000008441cbecf in ?? () from /lib/libthr.so.3
No symbol table info available.
#6
No symbol table info available.
#7 0x0000000000531327 in fm_status (qm=0x803400000) at mem/f_malloc.c:710
f = 0x804623330
i = 3360723440
j = 3360700894
h = 64
unused = 0
size = 1720680098056
FUNCTION = "fm_status"
#8 0x000000000045536c in shm_status () at mem/shm_mem.h:611
No locals.
#9 cleanup (show_status=show_status@entry=1) at main.c:341
FUNCTION = "cleanup"
#10 0x0000000000455d8a in handle_sigs () at main.c:522
chld = 0
chld_status = 139
overall_status = 139
i =
do_exit =
FUNCTION = "handle_sigs"
#11 0x000000000041c7ed in main_loop () at main.c:722
startup_done =
chd_rank = 17
#12 main (argc=, argv=) at main.c:1283
cfg_stream =
c =
r =
tmp = 0x7fffffffed9f ""
tmp_len =
port =
proto =
protos_no =
options = 0x626e70 "f:cCm:M:b:l:n:N:rRvdDFETSVhw:t:u:g:P:G:W:o:"
ret = -1
seed = 1295614847
rfd =
FUNCTION = "main"
(gdb)

`

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

3 participants