[CRASH] segfault in tracer.so

[gostkov]

OpenSIPS version you are running

version: opensips 3.4.9 (x86_64/linux)
flags: STATS: On, DISABLE_NAGLE, USE_MCAST, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, HP_MALLOC, DBG_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, sigio_rt, select.
git revision: cd02af8d9
main.c compiled on  with gcc 12

Crash Core Dump
can be send if needed

(gdb) bt full
#0  0x00007effbad6a4f5 in context_put_ptr (type=<optimized out>, data=<optimized out>, pos=<optimized out>, ctx=<optimized out>) at ../tm/../../context.h:161
        __FUNCTION__ = "context_put_ptr"
#1  trace_transaction (msg=0x7ffc8df40fb0, info=0x7effc05e1cf0, reverse_dir=0) at ./modules/tracer/tracer.c:1506
        __FUNCTION__ = "trace_transaction"
#2  0x00007effbad72b99 in siptrace_dlg_cancel (t=0x7ffc8df40fb0, type=-1067574032, param=0x7ffc8df40d20) at ./modules/tracer/tracer.c:1593
        req = 0x7ffc8df40fb0
        info = {flags = 0, conn_id = 0, ref = 0, ref_lock = 0x0, instances = 0x0}
        __FUNCTION__ = "siptrace_dlg_cancel"
#3  0x00007effbd9b977d in run_any_trans_callbacks (list=<optimized out>, type=type@entry=2048, trans=0x7effc116ce70, req=req@entry=0x7ffc8df40fb0, rpl=rpl@entry=0x0, code=code@entry=0) at ./modules/tm/t_hooks.c:214
        params = {req = 0x7ffc8df40fb0, rpl = 0x0, code = 0, param = 0x7effbeb9e4e0, extra1 = 0x0, extra2 = 0x0}
        cbp = 0x7effbeb9e4d0
        backup = 0x564b89cd6f88 <global_avps>
        trans_backup = 0xffffffffffffffff
        __FUNCTION__ = "run_any_trans_callbacks"
#4  0x00007effbd9ba94a in run_trans_callbacks (type=type@entry=2048, trans=<optimized out>, req=req@entry=0x7ffc8df40fb0, rpl=rpl@entry=0x0, code=code@entry=0) at ./modules/tm/t_hooks.c:233
No locals.
#5  0x00007effbd9bc891 in t_lookupOriginalT (p_msg=p_msg@entry=0x7ffc8df40fb0) at ./modules/tm/t_lookup.c:688
        p_cell = 0x7effc116ce70
        hash_index = <optimized out>
        t_msg = <optimized out>
        branch = <optimized out>
        ret = <optimized out>
        __FUNCTION__ = "t_lookupOriginalT"
#6  0x00007effbd99ccb7 in tm_repl_cancel (packet=packet@entry=0x7ffc8df41ab0, buf=buf@entry=0x7ffc8df419d0, ri=ri@entry=0x7ffc8df419e0) at ./modules/tm/cluster.c:125
        itmp = 47
        tmp = <optimized out>
        stmp = {s = 0x7effbf59ce7f "Reason: Q.850;cause=16;text=\"Normal call clearing\"\r\nˣ", len = 52}
        t = <optimized out>
        msg = {id = 0, first_line = {type = 0, len = 0, u = {request = {method = {s = 0x0, len = 0}, uri = {s = 0x0, len = 0}, version = {s = 0x0, len = 0}, method_value = 2}, reply = {version = {s = 0x0, len = 0}, status = {s = 0x0, len = 0}, reason = {s = 0x0, len = 0}, statuscode = 2}}}, 
          via1 = 0x7ffc8df40ec0, via2 = 0x0, headers = 0x0, last_header = 0x0, parsed_flag = 0, h_via1 = 0x0, h_via2 = 0x0, callid = 0x0, to = 0x0, cseq = 0x0, from = 0x0, contact = 0x0, maxforwards = 0x0, route = 0x0, record_route = 0x0, path = 0x0, content_type = 0x0, content_length = 0x0, 
          authorization = 0x0, expires = 0x0, proxy_auth = 0x0, supported = 0x0, proxy_require = 0x0, unsupported = 0x0, allow = 0x0, event = 0x0, accept = 0x0, accept_language = 0x0, organization = 0x0, priority = 0x0, subject = 0x0, user_agent = 0x0, content_disposition = 0x0, accept_disposition = 0x0, 
          diversion = 0x0, rpid = 0x0, refer_to = 0x0, session_expires = 0x0, min_se = 0x0, ppi = 0x0, pai = 0x0, privacy = 0x0, call_info = 0x0, www_authenticate = 0x0, proxy_authenticate = 0x0, min_expires = 0x0, feature_caps = 0x0, replaces = 0x0, body = 0x0, eoh = 0x0, unparsed = 0x0, rcv = {src_ip = {
              af = 0, len = 0, u = {addrl = {0, 0}, addr32 = {0, 0, 0, 0}, addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, addr = '\000' <repeats 15 times>}}, dst_ip = {af = 0, len = 0, u = {addrl = {0, 0}, addr32 = {0, 0, 0, 0}, addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, addr = '\000' <repeats 15 times>}}, src_port = 0, 
            dst_port = 0, proto = 0, proto_reserved1 = 0, proto_reserved2 = 0, src_su = {s = {sa_family = 0, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, 
                sin6_flowinfo = 0, sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}, bind_address = 0x0}, buf = 0x0, len = 0, new_uri = {s = 0x0, len = 0}, dst_uri = {s = 0x0, len = 0}, ruri_q = 0, 
          ruri_bflags = 0, force_send_socket = 0x0, path_vec = {s = 0x0, len = 0}, parsed_uri_ok = 0, parsed_uri = {user = {s = 0x0, len = 0}, passwd = {s = 0x0, len = 0}, host = {s = 0x0, len = 0}, port = {s = 0x0, len = 0}, params = {s = 0x0, len = 0}, headers = {s = 0x0, len = 0}, port_no = 0, proto = 0, 
            type = ERROR_URI_T, transport = {s = 0x0, len = 0}, ttl = {s = 0x0, len = 0}, user_param = {s = 0x0, len = 0}, maddr = {s = 0x0, len = 0}, method = {s = 0x0, len = 0}, lr = {s = 0x0, len = 0}, r2 = {s = 0x0, len = 0}, gr = {s = 0x0, len = 0}, pn_provider = {s = 0x0, len = 0}, pn_prid = {s = 0x0, 
              len = 0}, pn_param = {s = 0x0, len = 0}, pn_purr = {s = 0x0, len = 0}, transport_val = {s = 0x0, len = 0}, ttl_val = {s = 0x0, len = 0}, user_param_val = {s = 0x0, len = 0}, maddr_val = {s = 0x0, len = 0}, method_val = {s = 0x0, len = 0}, lr_val = {s = 0x0, len = 0}, r2_val = {s = 0x0, len = 0}, 
            gr_val = {s = 0x0, len = 0}, pn_provider_val = {s = 0x0, len = 0}, pn_prid_val = {s = 0x0, len = 0}, pn_param_val = {s = 0x0, len = 0}, pn_purr_val = {s = 0x0, len = 0}, u_name = {{s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, 
                len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}}, u_val = {{s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, 
                len = 0}}, u_params_no = 0}, parsed_orig_ruri_ok = 0, parsed_orig_ruri = {user = {s = 0x0, len = 0}, passwd = {s = 0x0, len = 0}, host = {s = 0x0, len = 0}, port = {s = 0x0, len = 0}, params = {s = 0x0, len = 0}, headers = {s = 0x0, len = 0}, port_no = 0, proto = 0, type = ERROR_URI_T, 
            transport = {s = 0x0, len = 0}, ttl = {s = 0x0, len = 0}, user_param = {s = 0x0, len = 0}, maddr = {s = 0x0, len = 0}, method = {s = 0x0, len = 0}, lr = {s = 0x0, len = 0}, r2 = {s = 0x0, len = 0}, gr = {s = 0x0, len = 0}, pn_provider = {s = 0x0, len = 0}, pn_prid = {s = 0x0, len = 0}, pn_param = {
              s = 0x0, len = 0}, pn_purr = {s = 0x0, len = 0}, transport_val = {s = 0x0, len = 0}, ttl_val = {s = 0x0, len = 0}, user_param_val = {s = 0x0, len = 0}, maddr_val = {s = 0x0, len = 0}, method_val = {s = 0x0, len = 0}, lr_val = {s = 0x0, len = 0}, r2_val = {s = 0x0, len = 0}, gr_val = {s = 0x0, 
              len = 0}, pn_provider_val = {s = 0x0, len = 0}, pn_prid_val = {s = 0x0, len = 0}, pn_param_val = {s = 0x0, len = 0}, pn_purr_val = {s = 0x0, len = 0}, u_name = {{s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, 
                len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}}, u_val = {{s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}}, 
            u_params_no = 0}, add_rm = 0x0, body_lumps = 0x0, reply_lump = 0x0, add_to_branch_s = '\000' <repeats 57 times>, add_to_branch_len = 0, hash_index = 41931, flags = 0, msg_flags = 0, set_global_address = {s = 0x0, len = 0}, set_global_port = {s = 0x0, len = 0}, time = {tv_sec = 0, tv_usec = 0}, 
          msg_cb = 0x0}
        via = {error = -1913383824, hdr = {s = 0x564b899dc7a9 <fm_malloc+281> "I\215D$8H\213T$\030dH+\024%(", len = 11}, name = {s = 0x7effffb41133 "H\205\300\017\211d\376\377\377\200=\231\223\r", len = -1}, version = {s = 0xe8638aebcd457b00 <error: Cannot access memory at address 0xe8638aebcd457b00>, 
            len = 0}, transport = {s = 0x7effbf59cd12 "UDP 10.7.78.8;rport;branch=z9hG4bK35vFXcej2465m\r\nMax-Forwards: 70\r\nFrom: \"5422227\" <sip:[email protected]>;tag=jUUy6aD9X4j5g\r\nTo: <sip:[email protected]>\r\nCall-ID: 51b9bcc0-9a3f-1200-a484-e828c1df3d3b\r\nC"..., len = 3}, host = {
            s = 0x7effbf59cd16 "10.7.78.8;rport;branch=z9hG4bK35vFXcej2465m\r\nMax-Forwards: 70\r\nFrom: \"5422227\" <sip:[email protected]>;tag=jUUy6aD9X4j5g\r\nTo: <sip:[email protected]>\r\nCall-ID: 51b9bcc0-9a3f-1200-a484-e828c1df3d3b\r\nCSeq:"..., len = 9}, proto = 32120, port = 0, port_str = {
            s = 0x7ffc8df40fe0 "", len = -1123153234}, params = {s = 0x0, len = -1913384992}, comment = {s = 0x7efffdefa030 "\001ip:[email protected]", len = -1986148439}, bsize = 2381582304, param_lst = 0x7ffc8df40fcc, last_param = 0x7c00000001, branch = 0x7ffc8df40e80, tid = {
            s = 0x7effbf59cd34 "35vFXcej2465m\r\nMax-Forwards: 70\r\nFrom: \"5422227\" <sip:[email protected]>;tag=jUUy6aD9X4j5g\r\nTo: <sip:[email protected]>\r\nCall-ID: 51b9bcc0-9a3f-1200-a484-e828c1df3d3b\r\nCSeq: 98442 CANCEL\r\nUser-Agent: TAU"..., len = 13}, received = 0x78, rport = 0x7effc0c7e400, 
          i = 0x7effbd68bbd0 <__dialog_sendpublish>, alias = 0x7effc0fe5448, maddr = 0x564b89cdb490 <shm_block>, next = 0x7effbd096f1c <register_dlgcb+140>}
        branch = {type = -1913383936, name = {s = 0x7ffc8df40fa0 "\220\264͉KV", len = -1913383824}, value = {
            s = 0x7effbf59cd2d "z9hG4bK35vFXcej2465m\r\nMax-Forwards: 70\r\nFrom: \"5422227\" <sip:[email protected]>;tag=jUUy6aD9X4j5g\r\nTo: <sip:[email protected]>\r\nCall-ID: 51b9bcc0-9a3f-1200-a484-e828c1df3d3b\r\nCSeq: 98442 CANCEL\r\nUser-Age"..., len = 20}, 
          start = 0x84 <error: Cannot access memory at address 0x84>, size = -1913383936, next = 0x7ffc8df40fc0}
        __FUNCTION__ = "tm_repl_cancel"
#7  0x00007effbd99e144 in receive_tm_repl (packet=0x7ffc8df41ab0) at ./modules/tm/cluster.c:219
        proto = 1
        port = 5060
        tmp = {s = 0x7effbf59cce3 "CANCEL sip:[email protected] SIP/2.0\r\nVia: SIP/2.0/UDP 10.7.78.8;rport;branch=z9hG4bK35vFXcej2465m\r\nMax-Forwards: 70\r\nFrom: \"5422227\" <sip:[email protected]>;tag=jUUy6aD9X4j5g\r\nTo: <sip:[email protected]>\r\nC"..., len = 381}
        ri = {src_ip = {af = 2, len = 4, u = {addrl = {193412859658, 0}, addr32 = {139331338, 45, 0, 0}, addr16 = {1802, 2126, 45, 0, 0, 0, 0, 0}, addr = "\n\aN\b-\000\000\000\000\000\000\000\000\000\000"}}, dst_ip = {af = 2, len = 4, u = {addrl = {16781484, 0}, addr32 = {16781484, 0, 0, 0}, addr16 = {4268, 
                256, 0, 0, 0, 0, 0, 0}, addr = "\254\020\000\001", '\000' <repeats 11 times>}}, src_port = 5060, dst_port = 0, proto = 1, proto_reserved1 = 0, proto_reserved2 = 0, src_su = {s = {sa_family = 0, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0}, 
              sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}, bind_address = 0x7efffda471f0}
--Type <RET> for more, q to quit, c to continue without paging--
        __FUNCTION__ = "receive_tm_repl"
#8  0x00007effbd723229 in run_mod_packet_cb (sender=<optimized out>, param=0x7effbf59cc70) at ./modules/clusterer/clusterer.c:1246
        p = <optimized out>
        packet = {buffer = {s = 0x7effbf59cc98 "P4CK+\002", len = 543}, front_pointer = 0x7effbf59ceb7 "329137.206230.0\r\n\020", next = 0xe8638aebcd457b00, size = 543, type = 3, flags = 0, src_id = 2}
        cap_name = {s = 0x0, len = 0}
        data_version = 0
        __FUNCTION__ = "run_mod_packet_cb"
#9  0x0000564b89940b89 in ipc_handle_job (fd=<optimized out>) at ./ipc.c:304
        job = {snd_proc = 304, handler_type = 0, payload1 = 0x7effbd7231e0 <run_mod_packet_cb>, payload2 = 0x7effbf59cc70}
        n = <optimized out>
        __FUNCTION__ = "ipc_handle_job"
#10 0x0000564b89a8d868 in handle_io (fm=0x7efffdab12c0, idx=idx@entry=1, event_type=event_type@entry=1) at net/net_tcp_proc.c:219
        ret = 0
        n = <optimized out>
        con = <optimized out>
        s = 0
        rw = <optimized out>
        resp = <optimized out>
        response = {139637937203984, 307}
        __FUNCTION__ = "handle_io"
#11 0x0000564b89a8eef7 in io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>) at net/../io_wait_loop.h:305
        ep_event = {events = 3182483352, data = {ptr = 0x8999fdd900007eff, fd = 32511, u32 = 32511, u64 = 9915235163082620671}}
        curr_time = <optimized out>
        ret = <optimized out>
        n = <optimized out>
        r = 1
        e = <optimized out>
        fd = <optimized out>
        i = <optimized out>
        error = <optimized out>
        ret = <optimized out>
        n = <optimized out>
        r = <optimized out>
        i = <optimized out>
        e = <optimized out>
        ep_event = <optimized out>
        fd = <optimized out>
        curr_time = <optimized out>
        again = <optimized out>
        __FUNCTION__ = "io_wait_loop_epoll"
        error = <optimized out>
#12 tcp_worker_proc_loop () at net/net_tcp_proc.c:450
        __FUNCTION__ = "tcp_worker_proc_loop"
#13 0x0000564b89a86786 in tcp_start_processes (chd_rank=chd_rank@entry=0x564b89bcc218 <chd_rank>, startup_done=startup_done@entry=0x0) at net/net_tcp.c:2138
        r = 6
        n = <optimized out>
        p_id = <optimized out>
        reader_fd = {1930, 1931}
        si = <optimized out>
        ifp_sr_tcp = {proc_desc = 0x564b89b3388d "SIP receiver TCP", flags = 4, type = TYPE_TCP}
        __FUNCTION__ = "tcp_start_processes"
        error = <optimized out>
#14 0x0000564b8990d9d4 in main_loop () at ./main.c:243
        startup_done = 0x0
        last_check = 0
        rc = <optimized out>
        chd_rank = 307
        startup_done = <optimized out>
        last_check = <optimized out>
        rc = <optimized out>
        profiling_handler = {desc = 0x564b89ac1fb6 "_ProfilerStart_child()", on_child_init = 0x564b89940f10 <_ProfilerStart_child>, _next = 0x0}
        __FUNCTION__ = "main_loop"
        error = <optimized out>
#15 main (argc=<optimized out>, argv=<optimized out>) at ./main.c:966
--Type <RET> for more, q to quit, c to continue without paging--
        c = <optimized out>
        r = <optimized out>
        tmp = 0x7ffc8df42e6a ""
        tmp_len = <optimized out>
        port = <optimized out>
        proto = 0
        protos_no = <optimized out>
        options = 0x564b89ac2280 "f:cCm:M:b:l:n:N:rRvdDFEVhw:t:u:g:p:P:G:W:o:a:k:s:"
        ret = -1
        seed = 3136291542
        rfd = <optimized out>
        procs_no = <optimized out>
        __FUNCTION__ = "main"

Describe the traffic that generated the bug
Unknown

To Reproduce
Unknown.

Relevant System Logs

Nov 13 13:01:11  /usr/sbin/opensips[329349]: WARNING:presence:p_tm_callback: completed with status [408] and to_tag [7206-84802e5c463340f6ca7e8b41e42fde4f], cseq [CSeq: 1]
Nov 13 13:07:00  /usr/sbin/opensips[329349]: CRITICAL:core:sig_usr: segfault in process pid: 329349, id: 313
Nov 13 13:07:00  kernel: opensips[329349]: segfault at 3c ip 00007effbad6a4f5 sp 00007ffc8df40c20 error 6 in tracer.so[7effbad66000+13000] likely on CPU 5 (core 1, socket 1)
Nov 13 13:07:09  systemd-coredump[471532]: Process 329349 (opensips) of user 107 dumped core.
Nov 13 13:07:09  /usr/sbin/opensips[329036]: INFO:core:handle_sigs: child process 329349 exited by a signal 11

Nov 13 13:06:58 /usr/sbin/opensips[329348]: WARNING:presence:p_tm_callback: completed with status [408] and to_tag [7206-58c54835cd71f958c14dbd9f5f787859], cseq [CSeq: 35]
Nov 13 13:06:58 /usr/sbin/opensips[329348]: WARNING:presence:p_tm_callback: completed with status [408] and to_tag [7206-feacff2df5735bf1d45b4086f47ed1d1], cseq [CSeq: 35]
Nov 13 13:07:01 /usr/sbin/opensips[329348]: CRITICAL:core:sig_usr: segfault in process pid: 329348, id: 312
Nov 13 13:07:01 kernel: opensips[329348]: segfault at 3c ip 00007effbad6a4f5 sp 00007ffc8df40c20 error 6 in tracer.so[7effbad66000+13000] likely on CPU 0 (core 0, socket 0)
Nov 13 13:07:09 systemd-coredump[471534]: Process 329348 (opensips) of user 107 dumped core.
Nov 13 13:07:09 /usr/sbin/opensips[329036]: INFO:core:shutdown_opensips: process 312(329348) [TCP receiver] terminated, still waiting for 30 more

Nov 13 13:07:03  /usr/sbin/opensips[329346]: CRITICAL:core:sig_usr: segfault in process pid: 329346, id: 310
Nov 13 13:07:03  kernel: opensips[329346]: segfault at 3c ip 00007effbad6a4f5 sp 00007ffc8df40c20 error 6 in tracer.so[7effbad66000+13000] likely on CPU 5 (core 1, socket 1)
Nov 13 13:07:11  systemd-coredump[471539]: Process 329346 (opensips) of user 107 dumped core.
Nov 13 13:07:11  /usr/sbin/opensips[329036]: INFO:core:shutdown_opensips: process 310(329346) [TCP receiver] terminated, still waiting for 0 more

core_short_1.txt
core_short_2.txt
core_short_3.txt

OS/environment information

• Operating System: Debian 12.7
• OpenSIPS installation: apt.opensips.org bookworm 3.4-releases

Additional context
We catch the crash per one-three days. We have same problem with 3.4.8 version.

[github-actions]

Any updates here? No progress has been made in the last 15 days, marking as stale. Will close this issue if no further updates are made in the next 30 days.

[gostkov]

no feedback :(