Description

All as per #3563

Debugging Data

           PID: 4209 (kamailio)
           UID: 990 (kamailio)
           GID: 988 (kamailio)
        Signal: 6 (ABRT)
     Timestamp: Thu 2023-09-14 00:20:29 UTC (32min ago)
  Command Line: /usr/sbin/kamailio -DD -P /run/kamailio/kamailio.pid -f /etc/kamailio/kamailio.cfg -m 256 -M 8 --atexit=no
    Executable: /usr/sbin/kamailio
 Control Group: /system.slice/kamailio.service
          Unit: kamailio.service
         Slice: system.slice
       Boot ID: 3fc4251c606f4c6183610573f44c46ba
    Machine ID: 16e913e686424f13b970f9b1044cc6b3
      Hostname: kamrtc01.voiceflex.com
       Storage: /var/lib/systemd/coredump/core.kamailio.990.3fc4251c606f4c6183610573f44c46ba.4209.1694650829000000.zst (present)
  Size on Disk: 3.3M
       Message: Process 4209 (kamailio) of user 990 dumped core.
                
                Stack trace of thread 4209:
                #0  0x00007f1338ea158c __pthread_kill_implementation (libc.so.6 + 0xa158c)
                #1  0x00007f1338e54d46 raise (libc.so.6 + 0x54d46)
                #2  0x00007f1338e287f3 abort (libc.so.6 + 0x287f3)
                #3  0x00000000007164db qm_debug_check_frag (kamailio + 0x3164db)
                #4  0x000000000071a703 qm_free (kamailio + 0x31a703)
                #5  0x0000000000725209 qm_shm_free (kamailio + 0x325209)
                #6  0x00007f13370043d6 ser_free (tls.so + 0x313d6)
                #7  0x00007f1337dbc1ee state_machine.part.0 (libssl.so.3 + 0x621ee)
                #8  0x00007f133702c584 tls_accept (tls.so + 0x59584)
                #9  0x00007f13370378be tls_h_read_f (tls.so + 0x648be)
                #10 0x00000000006c79bc tcp_read_headers (kamailio + 0x2c79bc)
                #11 0x00000000006cfb94 tcp_read_req (kamailio + 0x2cfb94)
                #12 0x00000000006d4cc3 handle_io (kamailio + 0x2d4cc3)
                #13 0x00000000006c271d io_wait_loop_epoll (kamailio + 0x2c271d)
                #14 0x00000000006d7a47 tcp_receive_loop (kamailio + 0x2d7a47)
                #15 0x00000000006b7689 tcp_init_children (kamailio + 0x2b7689)
                #16 0x000000000042fae9 main_loop (kamailio + 0x2fae9)
                #17 0x0000000000439969 main (kamailio + 0x39969)
                #18 0x00007f1338e3feb0 __libc_start_call_main (libc.so.6 + 0x3feb0)
                #19 0x00007f1338e3ff60 __libc_start_main@@GLIBC_2.34 (libc.so.6 + 0x3ff60)
                #20 0x000000000041dc65 _start (kamailio + 0x1dc65)
                ELF object binary architecture: AMD x86-64

(gdb) bt full
#0  0x00007f1338ea158c in __pthread_kill_implementation () from /lib64/libc.so.6
No symbol table info available.
#1  0x00007f1338e54d46 in raise () from /lib64/libc.so.6
No symbol table info available.
#2  0x00007f1338e287f3 in abort () from /lib64/libc.so.6
No symbol table info available.
#3  0x00000000007164db in qm_debug_check_frag (qm=0x7f1326fd3000, f=0x7f1327793800, file=0x7f133704afe1 "tls: tls_init.c", line=405, efile=0x8a1659 "core/mem/q_malloc.c", eline=511) at core/mem/q_malloc.c:129
        p = 0x7f1327732cd0
        __func__ = "qm_debug_check_frag"
#4  0x000000000071a703 in qm_free (qmp=0x7f1326fd3000, p=0x7f1327793838, file=0x7f133704afe1 "tls: tls_init.c", func=0x7f133704cae0 <__func__.0> "ser_free", line=405, mname=0x7f133704af52 "tls") at core/mem/q_malloc.c:511
        qm = 0x7f1326fd3000
        f = 0x7f1327793800
        size = 140729200190032
        next = 0x1
        prev = 0x7f132700c6c8
        __func__ = "qm_free"
#5  0x0000000000725209 in qm_shm_free (qmp=0x7f1326fd3000, p=0x7f1327793838, file=0x7f133704afe1 "tls: tls_init.c", func=0x7f133704cae0 <__func__.0> "ser_free", line=405, mname=0x7f133704af52 "tls") at core/mem/q_malloc.c:1350
No locals.
#6  0x00007f13370043d6 in ser_free (ptr=0x7f1327793838, fname=0x7f1337dd6146 "crypto/packet.c", fline=509) at tls_init.c:405
        __func__ = "ser_free"
#7  0x00007f1337dbc1ee in WPACKET_cleanup (pkt=0x7ffe11fca310) at crypto/packet.c:509
        sub = <optimized out>
        parent = 0x0
#8  write_state_machine (s=0x7f1327f185e0) at ssl/statem/statem.c:873
        post_work = <optimized out>
        mt = 2
        pkt = {buf = 0x7f1327da93e0, staticbuf = 0x0, curr = 122, written = 122, maxsize = 18446744073709551615, subs = 0x7f1327793838, endfirst = 0}
        ret = <optimized out>
        pre_work = 0x7f1337dc9260 <ossl_statem_server_pre_work>
        get_construct_message_f = 0x7f1337dc2920 <ossl_statem_server_construct_message>
        confunc = 0x7f1337dca970 <tls_construct_server_hello>
        st = 0x7f1327f18628
        transition = 0x7f1337dc9cf0 <ossl_statem_server_write_transition>
        cb = 0x7f1336ff1e72 <sr_ssl_ctx_info_callback>
        st = <optimized out>
        ret = <optimized out>
        transition = <optimized out>
        pre_work = <optimized out>
        post_work = <optimized out>
        get_construct_message_f = <optimized out>
        cb = <optimized out>
        confunc = <optimized out>
        mt = <optimized out>
        pkt = {buf = <optimized out>, staticbuf = <optimized out>, curr = <optimized out>, written = <optimized out>, maxsize = <optimized out>, subs = <optimized out>, endfirst = <optimized out>}
        __func__ = {<optimized out> <repeats 20 times>}
        tmpret = <optimized out>
#9  state_machine (s=0x7f1327f185e0, server=<optimized out>) at ssl/statem/statem.c:451
        buf = 0x0
        cb = <optimized out>
        st = <optimized out>
        ret = <optimized out>
        ssret = <optimized out>
        __func__ = {<optimized out> <repeats 14 times>}
#10 0x00007f133702c584 in tls_accept (c=0x7f1327b9eed8, error=0x7ffe11fea584) at tls_server.c:470
        ret = 0
        ssl = 0x7f1327f185e0
        cert = 0x1
        tls_c = 0x7f13277de980
        tls_log = 32766
        __func__ = "tls_accept"
#11 0x00007f13370378be in tls_h_read_f (c=0x7f1327b9eed8, flags=0x7ffe11fea9c0) at tls_server.c:1175
        r = 0x7f1327b9f000
        bytes_free = 16383
        bytes_read = 617
        read_size = 16383
        ssl_error = 0
        ssl_read = 0
        ssl = 0x7f1327f185e0
        rd_buf = "\026\003\001\002d\001\000\002`\003\003\037\017\360\302a4J\025k\341\210\000B\216ݖ\023\243#\n?\267]\214A\017\370P\374\063a( \241^2\243\006\360>\334\033(+\363d\b\350$\rt\311\321\351\205l\024\021\322|z\\o\235\353\000 \372\372\023\001\023\002\023\003\300+\300/\300,\300\060̨̩\300\023\300\024\000\234\000\235\000/\000\065\001\000\001\367\252\252\000\000\000\005\000\005\001\000\000\000\000\000\n\000\n\000\b\n\n\000\035\000\027\000\030\000#\000\000\000\033\000\003\002\000\002\000\027\000\000\000+\000\a\006\312\312\003\004\003\003\000\063\000+\000)\n\n\000\001\000\000\035\000 2\326\305\"봉\332\366\363SV\036ɩ\322u\316\061\030\225\353Yi"...
        wr_buf = "\027\003\003\001\032j\276\373Ӥw:1\221<uUV;\357&\211N\001#M\"`\234\370\365\213C\265B\004\006y\250/\246Nd\334h\f\343\065:k\341\321\023\257\360T\020,\255\271\235\201_\003\272\005\237A\356\326\313\355\351\340D^f\023_J\223\360\303:\310gi\313v\306\025\352d\360\343\246/,-\207+\301x\217\246F\300\361\064F\212\377YN\323\065A\323\365Zɞb!3\"8\024\235\066\033\311\t\361\334[\225\227\004c\230\223\210ʑL\213\331\027\022\370\257\265\352s\225\066\370jc\256(\246@\"\245f%\335\026\071\232\374\065\066ar\265\066B\213\024cT/\356\315`\233\350\234\027N\375\254]\360\064\064\305\070z\355"...
        rd = {buf = 0x7ffe11fda580 "\026\003\001\002d\001", pos = 617, used = 617, size = 65536}
        wr = {
          buf = 0x7ffe11fca580 "\027\003\003\001\032j\276\373Ӥw:1\221<uUV;\357&\211N\001#M\"`\234\370\365\213C\265B\004\006y\250/\246Nd\334h\f\343\065:k\341\321\023\257\360T\020,\255\271\235\201_\003\272\005\237A\356\326\313\355\351\340D^f\023_J\223\360\303:\310gi\313v\306\025\352d\360\343\246/,-\207+\301x\217\246F\300\361\064F\212\377YN\323\065A\323\365Zɞb!3\"8\024\235\066\033\311\t\361\334[\225\227\004c\230\223\210ʑL\213\331\027\022\370\257\265\352s\225\066\370jc\256(\246@\"\245f%\335\026\071\232\374\065\066ar\265\066B\213\024cT/\356\315`\233\350\234\027N\375\254]\360\064", <incomplete sequence \305>..., pos = 0, used = 0, size = 65536}
        tls_c = 0x7f13277de980
        enc_rd_buf = 0x0
        n = 0
        flush_flags = 0
        err_src = 0x7f13370545a0 "TLS read:"
        ip_buf = '\000' <repeats 63 times>
        x = 954920009
        tls_dbg = 4095
        __func__ = "tls_h_read_f"
#12 0x00000000006c79bc in tcp_read_headers (c=0x7f1327b9eed8, read_flags=0x7ffe11fea9c0) at core/tcp_read.c:441
        bytes = 65535
        remaining = 0
        p = 0x7f1327a0789b "l'\244\016v \247T~ \267E\"l\350Um \356Uj'\260\032-z\261\025+z\267\020\062+\340E'c\340\027~\177\371\030|-\342\r*y\341E)*\262\025|y\265\025!l\357Eg>\275Rz=\351\026/~\331*^\"\270Oht\364a\\\005\370c^"
        r = 0x7f1327b9f000
        mc = 32531
        body_len = 10144
        mfline = 0x7f13276af2b8 "\201\376\002\367\025p\362%G5\265lF$\267w5\003\233U/\a\227Gg\004\221\v{\025\220Py\021\233U;\023\235H5#\273u:B\334\025\030z\244LtJ\322v\\ \335\027;@\335rF#\322Fc@\313My\002\203U\"B\233\v|\036\204Dy\031\226\036w\002\223Kv\030\317_,\030\265\021w;\313\022-B\303\022!}\370ht\b\337cz\002\205Dg\024\201\037\065G\302(\037$\235\037\065L\201LeJ\205@w\002\206FU\a\227Gg\004\221\v{\025\220Py\021\233U;\023\235H+}\370cg\037\237\037\065L\201LeJ\205@w\002\206FU\a\227Gg\004\221\v{\025\220Py\021\233U"...
        mtransid = {s = 0x7f1327a072d0 "C", len = 664826600}
        __func__ = "tcp_read_headers"
#13 0x00000000006cfb94 in tcp_read_req (con=0x7f1327b9eed8, bytes_read=0x7ffe11fea9c4, read_flags=0x7ffe11fea9c0) at core/tcp_read.c:1469
        bytes = -1
        total_bytes = 0
        resp = 1
        size = 0
        req = 0x7f1327b9f000
        dst = {send_sock = 0x7f1327a072d0, to = {s = {sa_family = 0, sa_data = "\000\020\002\000\000\000\001\000\376\021\022\000\000"}, sin = {sin_family = 0, sin_port = 4096, sin_addr = {s_addr = 2}, sin_zero = "\001\000\376\021\022\000\000"}, sin6 = {sin6_family = 0, sin6_port = 4096, sin6_flowinfo = 2, sin6_addr = {__in6_u = {__u6_addr8 = "\001\000\376\021\022\000\000\000ಙ\000\000\000\000", __u6_addr16 = {1, 4606, 
                    18, 0, 45792, 153, 0, 0}, __u6_addr32 = {301858817, 18, 10072800, 0}}}, sin6_scope_id = 955546528}, sas = {ss_family = 0, 
              __ss_padding = "\000\020\002\000\000\000\001\000\376\021\022\000\000\000ಙ\000\000\000\000\000\240{\364\070\023\177\000\000ht\240'\023\177\000\000\000\251\376\021\353:\"%\240\264\231\000\000\000\000\000\024\000\000\000\000\000\000\000\001\000\000\000\001\000\000\000\023\000\000\000\376\177\000\000-uQ\000\000\000\000\000\270\251\376\021\376\177\000\000\b", '\000' <repeats 22 times>, 
              __ss_align = 140729200322640}}, id = 1, send_flags = {f = 0, blst_imask = 0}, proto = 48 '0', proto_pad0 = -88 '\250', proto_pad1 = 4606}
        c = 108 'l'
        ret = 0
        __func__ = "tcp_read_req"
#14 0x00000000006d4cc3 in handle_io (fm=0x7f1338799c88, events=1, idx=-1) at core/tcp_read.c:1780
        ret = 8
--Type <RET> for more, q to quit, c to continue without paging--
        n = 8
        read_flags = RD_CONN_SHORT_READ
        con = 0x7f1327b9eed8
        s = 19
        resp = 1
        t = 623000299
        ee = 0x0
        __func__ = "handle_io"
#15 0x00000000006c271d in io_wait_loop_epoll (h=0x99b2e0 <io_w>, t=2, repeat=0) at core/io_wait.h:1070
        n = 1
        r = 0
        fm = 0x7f1338799c88
        revents = 1
        __func__ = "io_wait_loop_epoll"
#16 0x00000000006d7a47 in tcp_receive_loop (unix_sock=43) at core/tcp_read.c:1976
        __func__ = "tcp_receive_loop"
#17 0x00000000006b7689 in tcp_init_children (woneinit=0x7ffe11fead7c) at core/tcp_main.c:5239
        r = 1
        i = 3
        reader_fd_1 = 43
        pid = 0
        si_desc = "tcp receiver (generic)\000\000\000\000\000\000\000\000\000\000\023e\204\000\000\000\000\000\033\000\000\000\000\000\000\000\240{\364\070\023\177\000\000\000\000\000\020\000\000\000\000\020\255\376\021\376\177\000\000\034\003e\000\000\000\000\000\020\255\376\021\376\177\000\000\345\030n\000\000\000\000\000\300\254\376\021\376\177\000\000\252\264~\000\000\000\000\000\023e\204\000\000\000\000\000\310\311\000' \000\000"
        si = 0x0
        __func__ = "tcp_init_children"
#18 0x000000000042fae9 in main_loop () at main.c:1851
        i = 4
        pid = 4200
        si = 0x0
        si_desc = "udp receiver child=3 sock=172.16.128.55:5090\000\062\216\366\340\255\376\021\376\177\000\000\000\000\000\000\000\000\000\000@\263\376\021\376\177\000\000\023e\204\000\000\000\000\000\033\000\000\000\000\000\000\000X_j8\023\177\000\000\000\000\000\020\000\000\000\000:|\364\070\023\177\000\000\060\000\000\000\060\000\000\000\370\256\376\021\376\177\000"
        nrprocs = 4
        woneinit = 1
        __func__ = "main_loop"
#19 0x0000000000439969 in main (argc=11, argv=0x7ffe11feb458) at main.c:3086
        cfg_stream = 0xa20380
        c = -1
        r = 0
        tmp = 0x7ffe11febea4 ""
        tmp_len = 0
        port = 0
        proto = 0
        ahost = 0x0
        aport = 0
        options = 0x8322d8 ":f:cm:M:dVIhEeb:l:L:n:vKrRDTN:W:w:t:u:g:P:G:SQ:O:a:A:x:X:Y:"
        ret = -1
        seed = 444252184
        rfd = 4
        debug_save = 0
        debug_flag = 0
        dont_fork_cnt = 2
        n_lst = 0x200000064
        p = 0x0
        st = {st_dev = 24, st_ino = 891, st_nlink = 2, st_mode = 16832, st_uid = 990, st_gid = 988, __pad0 = 0, st_rdev = 0, st_size = 100, st_blksize = 4096, st_blocks = 0, st_atim = {tv_sec = 1694643229, tv_nsec = 729000000}, st_mtim = {tv_sec = 1694648370, tv_nsec = 514732637}, st_ctim = {tv_sec = 1694648370, tv_nsec = 514732637}, __glibc_reserved = {0, 0, 0}}
        tbuf = "\331l\030\071\023\177\000\000\070+\025\071\023\177\000\000а\376\021\376\177\000\000\a\000\000\000\000\000\000\000\330\030\025\071\023\177\000\000\a\000\000\000#\000\000\000\060z\030\071\023\177\000\000\245F\026\071\023\177\000\000\000\000\000\000\000\000\000\000\220Y\026\071\023\177\000\000\070\000\341\070\023\177\000\000\000\212\024\071\023\177\000\000\000\000\000\000\000\000\000\000\240\260\376\021\376\177\000\000\360n\030\071\023\177\000\000\330*\025\071\023\177\000\000\330*\025\071\023\177\000\000\000\000\000\000\000\000\000\000ؘ\024\071\023\177\000\000\240\260\376\021\376\177\000\000\220\205\030\071\023\177\000\000\000\020\025\071\023\177\000\000\022\034\025\071\023\177\000\000\066\021\026\071\023\177\000\000\344#\340\070\023\177\000\000\272\250"...
        option_index = 12
        long_options = {{name = 0x834976 "help", has_arg = 0, flag = 0x0, val = 104}, {name = 0x82f4f4 "version", has_arg = 0, flag = 0x0, val = 118}, {name = 0x83497b "alias", has_arg = 1, flag = 0x0, val = 1024}, {name = 0x834981 "subst", has_arg = 1, flag = 0x0, val = 1025}, {name = 0x834987 "substdef", has_arg = 1, flag = 0x0, val = 1026}, {name = 0x834990 "substdefs", has_arg = 1, flag = 0x0, val = 1027}, {
            name = 0x83499a "server-id", has_arg = 1, flag = 0x0, val = 1028}, {name = 0x8349a4 "loadmodule", has_arg = 1, flag = 0x0, val = 1029}, {name = 0x8349af "modparam", has_arg = 1, flag = 0x0, val = 1030}, {name = 0x8349b8 "log-engine", has_arg = 1, flag = 0x0, val = 1031}, {name = 0x8349c3 "debug", has_arg = 1, flag = 0x0, val = 1032}, {name = 0x8349c9 "cfg-print", has_arg = 0, flag = 0x0, val = 1033}, {
            name = 0x8349d3 "atexit", has_arg = 1, flag = 0x0, val = 1034}, {name = 0x8349da "all-errors", has_arg = 0, flag = 0x0, val = 1035}, {name = 0x0, has_arg = 0, flag = 0x0, val = 0}}
        __func__ = "main"

Log Messages

Sep 14 00:20:29 kamrtc01 /usr/sbin/kamailio[4209]: CRITICAL: [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed pointer (0x7f13277938b0), called from tls: tls_init.c: ser_free(405), first free tls: tls_init.c: ser_free(405) - ignoring
Sep 14 00:20:29 kamrtc01 /usr/sbin/kamailio[4209]: CRITICAL: [core/mem/q_malloc.c:123]: qm_debug_check_frag(): BUG: qm: fragm. 0x7f1327793800 (address 0x7f1327793838) beginning overwritten (0)! Memory allocator was called from tls: tls_init.c:405. Fragment marked by (null):0. Exec from core/mem/q_malloc.c:511.
Sep 14 00:20:29 kamrtc01 systemd[1]: Started Process Core Dump (PID 5579/UID 0).
Sep 14 00:20:29 kamrtc01 systemd-coredump[5580]: Process 4209 (kamailio) of user 990 dumped core.#12#012Stack trace of thread 4209:#12#0 0x00007f1338ea158c __pthread_kill_implementation (libc.so.6 + 0xa158c)#12#1 0x00007f1338e54d46 raise (libc.so.6 + 0x54d46)#12#2 0x00007f1338e287f3 abort (libc.so.6 + 0x287f3)#12#3 0x00000000007164db qm_debug_check_frag (kamailio + 0x3164db)#12#4 0x000000000071a703 qm_free (kamailio + 0x31a703)#12#5 0x0000000000725209 qm_shm_free (kamailio + 0x325209)#12#6 0x00007f13370043d6 ser_free (tls.so + 0x313d6)#12#7 0x00007f1337dbc1ee state_machine.part.0 (libssl.so.3 + 0x621ee)#12#8 0x00007f133702c584 tls_accept (tls.so + 0x59584)#12#9 0x00007f13370378be tls_h_read_f (tls.so + 0x648be)#12#10 0x00000000006c79bc tcp_read_headers (kamailio + 0x2c79bc)#12#11 0x00000000006cfb94 tcp_read_req (kamailio + 0x2cfb94)#12#12 0x00000000006d4cc3 handle_io (kamailio + 0x2d4cc3)#12#13 0x00000000006c271d io_wait_loop_epoll (kamailio + 0x2c271d)#12#14 0x00000000006d7a47 tcp_receive_loop (kamailio + 0x2d7a47)#12#15 0x00000000006b7689 tcp_init_children (kamailio + 0x2b7689)#12#16 0x000000000042fae9 main_loop (kamailio + 0x2fae9)#12#17 0x0000000000439969 main (kamailio + 0x39969)#12#18 0x00007f1338e3feb0 __libc_start_call_main (libc.so.6 + 0x3feb0)#12#19 0x00007f1338e3ff60 __libc_start_main@@GLIBC_2.34 (libc.so.6 + 0x3ff60)#12#20 0x000000000041dc65 _start (kamailio + 0x1dc65)#012ELF object binary architecture: AMD x86-64

SIP Traffic

There is sip traffic logged via the siptrace module to homer but the only packets logged are REGISTERs and I suspect this bug is in TLS somewhere further up the chain before it ever gets to sip traffic.


Reply to this email directly, view it on GitHub, or unsubscribe.
You are receiving this because you are subscribed to this thread.Message ID: <kamailio/kamailio/issues/3566@github.com>