[sr-dev] [kamailio/kamailio] Segfault when using kamailio 5.8.4 as a presence proxy (Issue #4102)

<!-- Kamailio Project uses GitHub Issues only for bugs in the code or feature requests. Please use this template only for bug reports. If you have questions about using Kamailio or related to its configuration file, ask on sr-users mailing list: * https://lists.kamailio.org/mailman3/postorius/lists/sr-users.lists.kamailio… If you have questions about developing extensions to Kamailio or its existing C code, ask on sr-dev mailing list: * https://lists.kamailio.org/mailman3/postorius/lists/sr-dev.lists.kamailio.o… Please try to fill this template as much as possible for any issue. It helps the developers to troubleshoot the issue. Note that an issue report may be closed automatically after about 2 months if there is no interest from developers or community users on pursuing it, being considered expired. In such case, it can be reopened by writing a comment that includes the token `/notexpired`. About two weeks before considered expired, the issue is marked with the label `stale`, trying to notify the submitter and everyone else that might be interested in it. To remove the label `stale`, write a comment that includes the token `/notstale`. Also, any comment postpone the `expire` timeline, being considered that there is interest in pursuing the issue. If there is no content to be filled in a section, the entire section can be removed. You can delete the comments from the template sections when filling. You can delete next line and everything above before submitting (it is a comment). --> ### Description We are now using kamailio on the edge as a presence proxy to scale presence. We have 3 internal kamailio instances handling the actual subscriptions and publishing. This works well, however, once per 24-36hours we experience a crash on the border proxy instance. We did not experience this when using the border proxy as a presence server (there was no proxying SUBSCRIBE). ### Troubleshooting #### Reproduction I believe this is happening when a customers network randomly experiences issues where it doesn't receive our replies to subscribes (and continues to send a subscribe). Logs are below. #### Debugging Data <!-- If you got a core dump, use gdb to extract troubleshooting data - full backtrace, local variables and the list of the code at the issue location. gdb /path/to/kamailio /path/to/corefile bt full info locals list If you are familiar with gdb, feel free to attach more of what you consider to be relevant. --> Here's the output while replacing any sensitive info in the payload. ``` GNU gdb (Debian 13.1-3) 13.1 Copyright (C) 2023 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-linux-gnu". Type "show configuration" for configuration details. For bug reporting instructions, please see: <https://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/sbin/kamailio... Reading symbols from /usr/lib/debug/.build-id/ce/c19d0ed1a928e4e25a84ae20d77e9c904a4892.debug... warning: Can't open file /dev/zero (deleted) during file-backed mapping note processing [New LWP 26] [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1". Core was generated by `kamailio -DD -E -m 8000 -M 512 -f /etc/kamailio/kamailio.cfg -P /var/run/kamail'. Program terminated with signal SIGSEGV, Segmentation fault. #0 via_builder (len=len@entry=0x7ffed7e3ecb8, msg=msg@entry=0x7ff9529548b0, send_info=send_info@entry=0x7ff764d20bb0, branch=branch@entry=0x7ffed7e3ecc0, extra_params=0x0, hp=hp@entry=0x7ffed7e3ebb0) at core/msg_translator.c:2910 2910 core/msg_translator.c: No such file or directory. (gdb) bt full #0 via_builder (len=len@entry=0x7ffed7e3ecb8, msg=msg@entry=0x7ff9529548b0, send_info=send_info@entry=0x7ff764d20bb0, branch=branch@entry=0x7ffed7e3ecc0, extra_params=0x0, hp=hp@entry=0x7ffed7e3ebb0) at core/msg_translator.c:2910 via_len = <optimized out> extra_len = <optimized out> line_buf = <optimized out> max_len = <optimized out> via_prefix_len = <optimized out> address_str = <optimized out> port_str = 0x0 send_sock = 0x0 comp_len = <optimized out> comp_name_len = <optimized out> port = <optimized out> proto = <optimized out> ip = {af = 536870912, len = 0, u = {addrl = {534820896, 1586192}, addr32 = {534820896, 0, 1586192, 0}, addr16 = {47136, 8160, 0, 0, 13328, 24, 0, 0}, addr = " \270\340\037\000\000\000\000\0204\030\000\000\000\000"}} from = 0x0 local_addr = {s = {sa_family = 16, sa_data = "#\000\000\000\000\000\020\000\000\000\000\000\000"}, sin = {sin_family = 16, sin_port = 35, sin_addr = {s_addr = 0}, sin_zero = "\020\000\000\000\000\000\000"}, sin6 = {sin6_family = 16, sin6_port = 35, sin6_flowinfo = 0, sin6_addr = {__in6_u = { __u6_addr8 = "\020\000\000\000\000\000\000\000\003\000\000\000\000\000\000", __u6_addr16 = {16, 0, 0, 0, 3, 0, 0, 0}, __u6_addr32 = {16, 0, 3, 0}}}, sin6_scope_id = 3000082688}, sas = {ss_family = 16, __ss_padding = "#\000\000\000\000\000\020\000\000\000\000\000\000\000\003\000\000\000\000\000\000\000\000\241\321\262cg\357`@\000\000\000\000\000\000\000X\f-\177!V\000\000\020\016\217R\371\177\000\000\001\000\000\000!V\000\000*\000\000\000\000\000\000\000\001\000\000\000\376\177\000\000\004\360;\177!V\000\000\250,A\177!V\000\000\000\355\343\327\376\177\000\000\000\241\321\262cg\357`h\256\006R\371\177\000", __ss_align = 94701866020241}} con = 0x0 rxavp = 0x0 xname = {s = 0x0, len = -2141140176} __func__ = "via_builder" #1 0x000056217f155030 in create_via_hf (len=len@entry=0x7ffed7e3ecb8, msg=msg@entry=0x7ff9529548b0, send_info=send_info@entry=0x7ff764d20bb0, branch=branch@entry=0x7ffed7e3ecc0) at core/msg_translator.c:3232 via = <optimized out> extra_params = {s = 0x0, len = 0} hp = {host = 0x56217f4fb380 <default_global_address>, port = 0x56217f4fb370 <default_global_port>} sbuf = "\331\023\000\000\001", '\000' <repeats 18 times> --Type <RET> for more, q to quit, c to continue without paging--info locals slen = <optimized out> xparams = <optimized out> id_buf = <optimized out> id_len = 0 __func__ = "create_via_hf" __llevel = <optimized out> __kld = <optimized out> #2 0x000056217f1592f7 in build_req_buf_from_sip_req (msg=msg@entry=0x7ff9529548b0, returned_len=returned_len@entry=0x7ffed7e3eeac, send_info=send_info@entry=0x7ff764d20bb0, mode=mode@entry=128) at core/msg_translator.c:2096 len = 581 new_len = <optimized out> received_len = 0 rport_len = 0 uri_len = 0 via_len = 0 body_delta = 0 line_buf = 0x0 received_buf = 0x0 rport_buf = 0x0 new_buf = 0x0 buf = 0x56217f5866c0 <buf> "SUBSCRIBE sip:74@sip.domain.co SIP/2.0\r\nVia: SIP/2.0/UDP 12.171.207.82:25744;branch=z9hG4bK1805670803;rport\r\nFrom: \"Heather Myers\" <sip:1086448@sip.domain.co>;tag=1805518213\r\nTo: <sip:74@sip.domain.co>\r\nCa"... path_buf = {s = 0x0, len = 0} offset = 0 s_offset = 0 size = <optimized out> via_anchor = 0x7ff952951300 via_lump = <optimized out> via_rm = <optimized out> via_insert_param = 0x0 path_anchor = <optimized out> path_lump = <optimized out> branch = {s = 0x7ff952954ed8 "z9hG4bKc7ed.5819b4295fe83f981a2fc19b7f739d7e.0", len = 46} flags = 262273 --Type <RET> for more, q to quit, c to continue without paging--list udp_mtu = <optimized out> di = {send_sock = 0x0, to = {s = {sa_family = 18608, sa_data = "\225R\371\177\000\000\002\000\023\331\n4\001\r"}, sin = {sin_family = 18608, sin_port = 21141, sin_addr = { s_addr = 32761}, sin_zero = "\002\000\023\331\n4\001\r"}, sin6 = {sin6_family = 18608, sin6_port = 21141, sin6_flowinfo = 32761, sin6_addr = {__in6_u = { __u6_addr8 = "\002\000\023\331\n4\001\r\000\000\000\000\000\000\000", __u6_addr16 = {2, 55571, 13322, 3329, 0, 0, 0, 0}, __u6_addr32 = {3641901058, 218182666, 0, 0}}}, sin6_scope_id = 0}, sas = {ss_family = 18608, __ss_padding = "\225R\371\177\000\000\002\000\023\331\n4\001\r", '\000' <repeats 103 times>, __ss_align = 0}}, id = 0, send_flags = {f = 0, blst_imask = 0}, proto = 0 '\000', proto_pad0 = 0 '\000', proto_pad1 = 0} ret = <optimized out> __func__ = "build_req_buf_from_sip_req" error00 = <optimized out> #3 0x00007ff951fbe90d in prepare_new_uac (t=t@entry=0x7ff764d20880, i_req=i_req@entry=0x7ff9529548b0, branch=branch@entry=0, uri=<optimized out>, uri@entry=0x7ff9529548e8, path=<optimized out>, path@entry=0x7ff952954f60, next_hop=<optimized out>, fsocket=0x7ff9528f0e10, snd_flags=..., fproto=<optimized out>, flags=<optimized out>, instance=<optimized out>, ruid=<optimized out>, location_ua=<optimized out>) at ./src/modules/tm/t_fwd.c:482 shbuf = 0x0 add_rm_backup = <optimized out> body_lumps_backup = <optimized out> parsed_uri_bak = {user = { s = 0x56217f5866ce <buf+14> &quot;74(a)sip.domain.co SIP/2.0\r\nVia: SIP/2.0/UDP 12.171.207.82:25744;branch=z9hG4bK1805670803;rport\r\nFrom: \"Heather Myers\" <sip:1086448@sip.domain.co>;tag=1805518213\r\nTo: <sip:74@sip.domain.co>\r\nCall-ID: 0_18056"..., len = 2}, passwd = {s = 0x0, len = 0}, host = { s = 0x56217f5866d1 <buf+17> "sip.domain.co SIP/2.0\r\nVia: SIP/2.0/UDP 12.171.207.82:25744;branch=z9hG4bK1805670803;rport\r\nFrom: \"Heather Myers\" <sip:1086448@sip.domain.co>;tag=1805518213\r\nTo: <sip:74@sip.domain.co>\r\nCall-ID: 0_18056078"..., len = 11}, port = {s = 0x0, len = 0}, params = {s = 0x0, len = 0}, sip_params = {s = 0x0, len = 0}, headers = { s = 0x0, len = 0}, port_no = 0, proto = 0, type = SIP_URI_T, flags = 0, 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}, 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}} ret = -1 len = 32761 parsed_uri_ok_bak = <optimized out> free_new_uri = 1 msg_uri_bak = {s = 0x0, len = 0} dst_uri_bak = {s = 0x7ff9529525f0 "sip:10.52.1.13:5081", len = 19} dst_uri_backed_up = 1 path_bak = {s = 0x0, len = 0} free_path = 1 instance_bak = {s = 0x0, len = 0} ``` #### Log Messages <!-- Check the syslog file and if there are relevant log messages printed by Kamailio, add them next, or attach to issue, or provide a link to download them (e.g., to a pastebin site). --> ``` ERROR 2025-01-10T06:00:31.847348563Z [resource.labels.containerName: kamailio] 8(28) CRITICAL: {1 1 SUBSCRIBE 0_1907143137(a)192.168.100.28} tm [timer.h:188]: _set_fr_retr(): already added: 0x7ff763e62250 , tl=0x7ff763e62270!!! ERROR 2025-01-10T06:00:31.847388483Z [resource.labels.containerName: kamailio] 8(28) CRITICAL: {1 1 SUBSCRIBE 0_1907143137(a)192.168.100.28} tm [t_fwd.c:1613]: t_send_branch(): BUG: retransmission already started for: 0x7ff763e62250 ERROR 2025-01-10T06:00:31.847394809Z [resource.labels.containerName: kamailio] 8(28) ERROR: {1 1 SUBSCRIBE 0_1907143137(a)192.168.100.28} sl [sl_funcs.c:428]: sl_reply_error(): stateless error reply used: No error (0/SL) ERROR 2025-01-10T06:00:31.847400738Z [resource.labels.containerName: kamailio] 8(28) BUG: {1 1 SUBSCRIBE 0_1907143137(a)192.168.100.28} tm [t_lookup.c:2052]: t_unref(): REQ_ERR DELAYED should have been caught much earlier for 0x7ff763e61f70: 24 (hex 18) ERROR 2025-01-10T06:00:47.346744773Z [resource.labels.containerName: kamailio] 45(65) ERROR: <core> [core/tcp_main.c:4818]: tcpconn_main_timeout(): connect 64.63.142.90:12190 failed (timeout) ERROR 2025-01-10T06:00:58.274915089Z [resource.labels.containerName: kamailio] 45(65) CRITICAL: <core> [core/pass_fd.c:281]: receive_fd(): EOF on 20 ERROR 2025-01-10T06:01:02.715789076Z [resource.labels.containerName: kamailio] 0(1) ALERT: <core> [main.c:805]: handle_sigs(): child process 26 exited by a signal 11 ERROR 2025-01-10T06:01:02.715827333Z [resource.labels.containerName: kamailio] 0(1) ALERT: <core> [main.c:809]: handle_sigs(): core was generated ERROR 2025-01-10T06:01:02.718815287Z [resource.labels.containerName: kamailio] 45(65) CRITICAL: <core> [core/pass_fd.c:281]: receive_fd(): EOF on 25 ERROR 2025-01-10T06:01:02.720985493Z [resource.labels.containerName: kamailio] 45(65) CRITICAL: <core> [core/pass_fd.c:281]: receive_fd(): EOF on 23 ERROR 2025-01-10T06:01:02.725450552Z [resource.labels.containerName: kamailio] 45(65) CRITICAL: <core> [core/pass_fd.c:281]: receive_fd(): EOF on 30 ``` #### SIP Traffic <!-- If the issue is exposed by processing specific SIP messages, grab them with ngrep or save in a pcap file, then add them next, or attach to issue, or provide a link to download them (e.g., to a pastebin site). --> ``` (paste your sip traffic here) ``` ### Possible Solutions I can atleast say that when this segfault happens that these logs are always present right before the crash. However, I also see instances of these logs without a crash immediately following. On the proxy we are doing this is withindlg route to send subscribes to the presence route: ``` if KSR.is_SUBSCRIBE() and KSR.is_myself_ruri() then -- in-dialog subscribe requests ksr_route_presence(); KSR.x.exit(); end ``` Any then this is our ksr_route_presence(): ``` function ksr_route_presence() if not KSR.is_SUBSCRIBE() then return 1; end local fuser = KSR.kx.get_fuser(); if fuser=='' then KSR.xlog.xinfo('Subscription attempt without username from IP ' .. KSR.kx.get_srcip() .. ' - Rejecting\n'); KSR.sl.sl_send_reply(404, 'Not Found'); KSR.x.exit(); end KSR.pv.sets('$avp(s:tenant)', string.match(fuser, '-(.*)')); local setId = '6' .. KSR.kx.get_def('DEFAULT_DISPATCH_SET'); local modeId = '7'; if KSR.dispatcher.ds_select_dst(setId, modeId)<0 then KSR.sl.send_reply(404, 'No destination'); KSR.x.exit(); end KSR.corex.set_send_socket(KSR.kx.get_def('PRIVATE_LISTEN_IP') .. ':' .. KSR.kx.get_def('INTERNAL_PORT')); KSR.tm.t_on_failure('ksr_route_rtf_dispatch'); ksr_route_relay(); end ``` ### Additional Information * **Kamailio Version** - output of `kamailio -v` ``` version: kamailio 5.8.4 (x86_64/linux) flags: USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MMAP, PKG_MALLOC, MEM_JOIN_FREE, Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLOCKLIST, HAVE_RESOLV_RES, TLS_PTHREAD_MUTEX_SHARED ADAPTIVE_WAIT_LOOPS 1024, MAX_RECV_BUFFER_SIZE 262144, MAX_SEND_BUFFER_SIZE 262144, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: unknown compiled with gcc 12.2.0 ``` * **Operating System**: <!-- Details about the operating system, the type: Linux (e.g.,: Debian 8.4, Ubuntu 16.04, CentOS 7.1, ...), MacOS, xBSD, Solaris, ...; Kernel details (output of `lsb_release -a` and `uname -a`) --> ``` PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" ``` ``` Linux gke-us-south1-external-sip-800ca69e-qyb3 5.15.0-1048-gke #53-Ubuntu SMP Tue Nov 28 00:39:01 UTC 2023 x86_64 GNU/Linux ``` -- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/4102 You are receiving this because you are subscribed to this thread. Message ID: &lt;kamailio/kamailio/issues/4102(a)github.com&gt;