search

OpenSIPS / opensips

OpenSIPS is a GPL implementation of a multi-functionality SIP Server that targets to deliver a high-level technical solution (performance, security and quality) to be used in professional SIP server platforms.
https://opensips.org
Other
1.28k stars 582 forks source link

[CRASH] 3.4 Statistics Variable do_action Segfault #3136

Closed Integration-IT closed 1 year ago

Integration-IT commented 1 year ago

OpenSIPS version you are running

version: opensips 3.4.0 (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: 46e889e02
main.c compiled on 22:45:40 Jul 26 2023 with gcc 10

Crash Core Dump

action.c:1047
val = {rs = {s = 0xe10 <error: Cannot access memory at address 0xe10>, len = 1515006644}, ri = -78613944, flags = 0}

Describe that generated the bug

Function: update_stat_series

To Reproduce

Extra Hint You can hit millions times stat_custo1:junk, but need only one time stat_custo2:junk to segfault.

To NOT Reproduce

modparam("statistics", "stat_series_profile", "stat_custo1: algorithm=accumulate window=86400")
modparam("statistics", "stat_series_profile", "stat_custo2: algorithm=accumulate window=86400")
...
update_stat_series("stat_custo1", "junk_1", 1);
update_stat_series("stat_custo2", "junk_2", 1);

OS/environment information - Opensips Versions

github-actions[bot] commented 1 year ago

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.

rwilkinson87 commented 1 year ago

This appears to be the same issue I reported in #2983 but with more context and has identified the specific reproducibility steps

I can also confirm that the crash happens when updating a second variable in a second series. If I only ever update 1 series the crash never happens.

I have just updated to 3.2.13 and still see the crash.

Does anyone require any more information? The new stats module has the potential to be very powerful, but this issue severely limits its safe use.

rwilkinson87 commented 1 year ago

If it's any help, I've got several core dumps after a crash and gdb outputs the following:-

Cannot access memory at address 0x9dd277b7
Cannot access memory at address 0x9dd277af
Core was generated by `/usr/sbin/opensips -P /run/opensips/opensips.pid -f /etc/opensips/opensips.cfg'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x00000000004dbe10 in shm_threshold_check () at mem/shm_mem.h:258
258     size = SHM_GET_SIZE(shm_block);
bogdan-iancu commented 1 year ago

Guys, could you post a full backtrace of this crash ?

razvancrainea commented 1 year ago

Also, can you please provide the steps to reproduce the crash?

rwilkinson87 commented 1 year ago

Hi,

Here's what I managed to get. I'm not an expert when it comes to debugging so please let me know if this isn't complete.

[root@opensips]# coredumpctl gdb -1
           PID: 951206 (opensips)
           UID: 986 (opensips)
           GID: 983 (opensips)
        Signal: 11 (SEGV)
     Timestamp: Mon 2023-09-25 13:22:09 BST (58s ago)
  Command Line: /usr/sbin/opensips -P /run/opensips/opensips.pid -f /etc/opensips/opensips.cfg -m 512 -M 8
    Executable: /usr/sbin/opensips
 Control Group: /system.slice/opensips.service
          Unit:
         Slice: system.slice
       Boot ID: 527911c225f343928629b694a0101943
    Machine ID: 69b555f20f7848cb8ad8e44c06c835d3
       Storage: /var/lib/systemd/coredump/core.opensips.986.527911c225f343928629b694a0101943.951206.1695644529000000.lz4
       Message: Process 951206 (opensips) of user 986 dumped core.

                Stack trace of thread 951206:
                #0  0x00000000004dc7c0 __register_stat (opensips)
                #1  0x00000000004df4c5 register_stat2 (opensips)
                #2  0x00007f59aa309321 new_stat_series (statistics.so)
                #3  0x0000000000436185 do_action (opensips)
                #4  0x00000000004391d0 run_action_list (opensips)
                #5  0x0000000000438211 do_action (opensips)
                #6  0x00000000004391d0 run_action_list (opensips)
                #7  0x000000000043950d run_actions (opensips)
                #8  0x00007f59ab85b891 run_failure_handlers (tm.so)
                #9  0x00007f59ab85c414 relay_reply (tm.so)
                #10 0x00007f59ab85ea45 reply_received (tm.so)
                #11 0x00000000004669f8 forward_reply (opensips)
                #12 0x000000000044640f receive_msg (opensips)
                #13 0x00000000005b8536 udp_read_req (opensips)
                #14 0x0000000000590baf handle_io (opensips)
                #15 0x0000000000596017 udp_start_processes (opensips)
                #16 0x000000000041bd32 main_loop (opensips)
                #17 0x00007f59ce952d85 __libc_start_main (libc.so.6)
                #18 0x000000000041c7ae _start (opensips)

GNU gdb (GDB) Red Hat Enterprise Linux 8.2-19.el8
Copyright (C) 2018 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".
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/sbin/opensips...Reading symbols from /usr/lib/debug/usr/sbin/opensips-3.2.14-1.el8.x86_64.debug...done.
done.

warning: Can't open file (null) during file-backed mapping note processing
[New LWP 951206]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Missing separate debuginfo for /usr/lib64/opensips/modules/db_mysql.so
Try: yum --enablerepo='*debug*' install /usr/lib/debug/.build-id/cb/7262be04c0ff48d2b18f88699b4df72a272dac.debug
Core was generated by `/usr/sbin/opensips -P /run/opensips/opensips.pid -f /etc/opensips/opensips.cfg'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  __register_stat (module=module@entry=0x7ffdb9c2d420, name=name@entry=0x7ffdb9c2d430, pvar=pvar@entry=0x7f59aa308860 <get_stat_series>, flags=flags@entry=9, ctx=ctx@entry=0x7f59af4fdfd0, unsafe=unsafe@entry=0) at statistics.c:521
521                 *pvar = it;
Missing separate debuginfos, use: yum debuginfo-install glibc-2.28-225.el8.x86_64 libgcc-8.5.0-18.el8.x86_64 libstdc++-8.5.0-18.el8.x86_64 mysql-libs-8.0.32-1.module+el8.8.0+1283+4b88a3a8.0.1.x86_64 openssl-libs-1.1.1k-9.el8_7.x86_64 zlib-1.2.11-21.el8_7.x86_64
razvancrainea commented 1 year ago

@rwilkinson87 something is not wrong - you reported that you are using opensips 3.4.0, but you're reading the debugging info from 3.2.14-1 - can you tell us the exact version you are using?

Also, when opening gdb, can you send us the output of backtrace full?

rwilkinson87 commented 1 year ago

Hi @razvancrainea I'm running 3.2.14-1 (3.2 LTS from YUM repo). I believe it is @Integration-IT the original poster who is running 3.4 - although the issue appears to be identical and his steps to reproduce would be the same as mine.

Here's the output from backtrace full

I have changed the phone numbers and anonymised domains/IPs, but kept each one consistent throughout.

(gdb) backtrace full
#0  __register_stat (module=module@entry=0x7ffdb9c2d420, name=name@entry=0x7ffdb9c2d430, pvar=pvar@entry=0x7f59aa308860 <get_stat_series>, flags=flags@entry=9, ctx=ctx@entry=0x7f59af4fdfd0,
    unsafe=unsafe@entry=0) at statistics.c:521
        mods = <optimized out>
        shash = 0x7f59ae1e5ec8
        stat = <optimized out>
        it = 0x7f59af4e2ad8
        hash = <optimized out>
        __FUNCTION__ = "__register_stat"
#1  0x00000000004df4c5 in register_stat2 (module=<optimized out>, name=0x7f59af4fe008 "486", pvar=pvar@entry=0x7f59aa308860 <get_stat_series>, flags=flags@entry=9, ctx=ctx@entry=0x7f59af4fdfd0,
    unsafe=unsafe@entry=0) at statistics.c:580
        smodule = {s = 0x7f59ce126138 "carriererrorsout", len = 16}
        sname = {s = 0x7f59af4fe008 "486", len = 3}
#2  0x00007f59aa309321 in new_stat_series (name=0x7ffdb9c2d660, name=0x7ffdb9c2d660, profile=0x7f59ce1260e0) at statistics.c:1021
        ss = 0x7f59af4fdfd0
        ss = <optimized out>
        __FUNCTION__ = "new_stat_series"
#3  w_update_stat_series (msg=<optimized out>, value=0x7ffdb9c2d688, name=0x7ffdb9c2d660, profile=0x7f59ce1260e0) at statistics.c:1098
        hentry = 4
        ss = 0x7f59af4c0920
        hentry = <optimized out>
        ss = <optimized out>
        __FUNCTION__ = "w_update_stat_series"
#4  w_update_stat_series (msg=<optimized out>, profile=0x7f59ce1260e0, name=0x7ffdb9c2d660, value=0x7ffdb9c2d688) at statistics.c:1080
        hentry = <optimized out>
        ss = <optimized out>
        __FUNCTION__ = "w_update_stat_series"
#5  0x0000000000436185 in do_action (a=0x7f59ce1387d0, msg=0x7f59abab7d40 <faked_req>) at action.c:1048
        ret = 0
        v = <optimized out>
        i = <optimized out>
        len = <optimized out>
        cmatch = <optimized out>
        aitem = <optimized out>
        adefault = <optimized out>
        spec = <optimized out>
        val = {rs = {s = 0x0, len = 0}, ri = 0, flags = 0}
        start = {tv_sec = 0, tv_usec = 0}
        end_time = <optimized out>
        cmd = 0x7f59aa50e620 <cmds+960>
        acmd = <optimized out>
        cmdp = {0x7f59ce1260e0, 0x7ffdb9c2d660, 0x7ffdb9c2d688, 0x4391d0 <run_action_list+80>, 0x0, 0x0, 0x0, 0x2}
        tmp_vals = {{rs = {s = 0x7f59ce138350 "\002", len = 4704157}, ri = 0, flags = 0}, {rs = {s = 0x0, len = 0}, ri = 0, flags = 0}, {rs = {s = 0x7f59ce138718 "486", len = 3}, ri = 0, flags = 0}, {rs = {
              s = 0x0, len = 0}, ri = 1, flags = 0}, {rs = {s = 0x0, len = 0}, ri = 0, flags = 0}, {rs = {s = 0x0, len = 0}, ri = 0, flags = 0}, {rs = {s = 0x0, len = 0}, ri = 0, flags = 0}, {rs = {s = 0x0,
              len = 0}, ri = 1803871488, flags = 1196103969}}
        route_p = <optimized out>
        sval = {s = 0x0, len = 0}
        __FUNCTION__ = "do_action"
#6  0x00000000004391d0 in run_action_list (a=<optimized out>, msg=msg@entry=0x7f59abab7d40 <faked_req>) at action.c:190
        ret = -1
        t = 0x7f59ce1387d0
--Type <RET> for more, q to quit, c to continue without paging--c
#7  0x0000000000438211 in do_action (a=0x7f59ce138900, msg=0x7f59abab7d40 <faked_req>) at action.c:830
        ret = 1
        v = 1
        i = <optimized out>
        len = <optimized out>
        cmatch = <optimized out>
        aitem = <optimized out>
        adefault = <optimized out>
        spec = <optimized out>
        val = {rs = {s = 0x0, len = 0}, ri = 0, flags = 0}
        start = {tv_sec = 0, tv_usec = 0}
        end_time = <optimized out>
        cmd = 0x0
        acmd = <optimized out>
        cmdp = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}
        tmp_vals = {{rs = {s = 0x0, len = 0}, ri = 0, flags = 0}, {rs = {s = 0x0, len = 0}, ri = 0, flags = 0}, {rs = {s = 0x0, len = 0}, ri = 0, flags = 0}, {rs = {s = 0x0, len = 0}, ri = 0, flags = 0}, {rs = {s = 0x0, len = 5220907}, ri = 0, flags = 0}, {rs = {s = 0x0, len = 0}, ri = 1803871488, flags = 1196103969}, {rs = {s = 0x0, len = -1178412512}, ri = 0, flags = 0}, {rs = {s = 0x63f860 "\250\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\020\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\020\177\362\377\270~\362\377\272\177\362\377@~\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377\272\177\362\377"..., len = 1}, ri = -837494696, flags = 32601}}
        route_p = <optimized out>
        sval = {s = 0x0, len = 0}
        __FUNCTION__ = "do_action"
#8  0x00000000004391d0 in run_action_list (a=a@entry=0x7f59ce136300, msg=msg@entry=0x7f59abab7d40 <faked_req>) at action.c:190
        ret = -1
        t = 0x7f59ce138900
#9  0x000000000043950d in run_actions (msg=0x7f59abab7d40 <faked_req>, a=0x7f59ce136300) at action.c:136
        ret = <optimized out>
        _ = <optimized out>
        top_route = <optimized out>
        ret = <optimized out>opensips.doma
        _ = <optimized out>
        top_route = <optimized out>
        __FUNCTION__ = "run_actions"
#10 run_top_route (sr=..., msg=msg@entry=0x7f59abab7d40 <faked_req>) at action.c:250
        recursing = 1
        bk_action_flags = 0
        route_stack_start_bkp = -1
        route_stack_size_bkp = 1
        ret = <optimized out>
        ctx = 0x0
        __FUNCTION__ = "run_top_route"
#11 0x00007f59ab85b891 in run_failure_handlers (t=0x7f59af531af8) at t_reply.c:609
        shmem_msg = 0x7f59af533568
        uac = <optimized out>
        on_failure = <optimized out>
        old_route_type = 2
        faked_req = {id = 47, first_line = {type = 1, len = 67, u = {request = {method = {s = 0x7f59af533f10 "INVITE sip:+337399722921@opensips.domain;user=phone SIP/2.0\r\nVia: SIP/2.0/UDP 1.1.1.1:5060;branch=z9hG4bK2a72aa64\r\nMax-Forwards: 69\r\nFrom: \"+337729181046\" <sip:+337729181046@outsidedomain.tld>;"..., len = 6}, uri = {s = 0x7f59af533f17 "sip:+337399722921@opensips.domain;user=phone SIP/2.0\r\nVia: SIP/2.0/UDP 1.1.1.1:5060;branch=z9hG4bK2a72aa64\r\nMax-Forwards: 69\r\nFrom: \"+337729181046\" <sip:+337729181046@outsidedomain.tld>;tag=as1"..., len = 50}, version = {s = 0x7f59af533f4a "SIP/2.0\r\nVia: SIP/2.0/UDP 1.1.1.1:5060;branch=z9hG4bK2a72aa64\r\nMax-Forwards: 69\r\nFrom: \"+337729181046\" <sip:+337729181046@outsidedomain.tld>;tag=as12348987\r\nTo: <sip:+337399722921@opensips.doma"..., len = 7}, method_value = 1}, reply = {version = {s = 0x7f59af533f10 "INVITE sip:+337399722921@opensips.domain;user=phone SIP/2.0\r\nVia: SIP/2.0/UDP 1.1.1.1:5060;branch=z9hG4bK2a72aa64\r\nMax-Forwards: 69\r\nFrom: \"+337729181046\" <sip:+337729181046@outsidedomain.tld>;"..., len = 6}, status = {s = 0x7f59af533f17 "sip:+337399722921@opensips.domain;user=phone SIP/2.0\r\nVia: SIP/2.0/UDP 1.1.1.1:5060;branch=z9hG4bK2a72aa64\r\nMax-Forwards: 69\r\nFrom: \"+337729181046\" <sip:+337729181046@outsidedomain.tld>;tag=as1"..., len = 50}, reason = {s = 0x7f59af533f4a "SIP/2.0\r\nVia: SIP/2.0/UDP 1.1.1.1:5060;branch=z9hG4bK2a72aa64\r\nMax-Forwards: 69\r\nFrom: \"+337729181046\" <sip:+337729181046@outsidedomain.tld>;tag=as12348987\r\nTo: <sip:+337399722921@opensips.doma"..., len = 7}, statuscode = 1}}}, via1 = 0x7f59af534330, via2 = 0x0, headers = 0x7f59ce14d738, last_header = 0x7f59af534fd0, parsed_flag = 18446744073709551615, h_via1 = 0x7f59ce14d738, h_via2 = 0x0, callid = 0x7f59ce14d8a0, to = 0x7f59ce14d810, cseq = 0x7f59ce14d8e8, from = 0x7f59ce14d7c8, contact = 0x7f59ce14d858, maxforwards = 0x7f59ce14d780, route = 0x0, record_route = 0x0, path = 0x0, content_type = 0x7f59ce14db28, content_length = 0x7f59ce14db70, authorization = 0x0, expires = 0x0, proxy_auth = 0x0, supported = 0x7f59ce14da98, proxy_require = 0x0, unsupported = 0x0, allow = 0x7f59ce14da50, event = 0x0, accept = 0x0, accept_language = 0x0, organization = 0x0, priority = 0x0, subject = 0x0, user_agent = 0x7f59ce14d930, content_disposition = 0x0, accept_disposition = 0x0, diversion = 0x0, rpid = 0x0, refer_to = 0x0, session_expires = 0x7f59ce14d9c0, min_se = 0x7f59ce14da08, ppi = 0x0, pai = 0x7f59ce14dae0, privacy = 0x0, call_info = 0x0, www_authenticate = 0x0, proxy_authenticate = 0x0, min_expires = 0x0, feature_caps = 0x0, replaces = 0x0, body = 0x0, eoh = 0x7f59af5341ee "\r\nv=0\r\no=root 1485644087 1485644087 IN IP4 1.1.1.1\r\ns=MediaServer\r\nc=IN IP4 1.1.1.1\r\nt=0 0\r\nm=audio 18008 RTP/AVP 8 101\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:101 telephone-event/8000\r"..., unparsed = 0x7f59af5341ee "\r\nv=0\r\no=root 1485644087 1485644087 IN IP4 1.1.1.1\r\ns=MediaServer\r\nc=IN IP4 1.1.1.1\r\nt=0 0\r\nm=audio 18008 RTP/AVP 8 101\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:101 telephone-event/8000\r"..., rcv = {src_ip = {af = 2, len = 4, u = {addrl = {3005431474, 0}, addr32 = {3005431474, 0, 0, 0}, addr16 = {16050, 45859, 0, 0, 0, 0, 0, 0}, addr = "\262>#\263", '\000' <repeats 11 times>}}, dst_ip = {af = 2, len = 4, u = {addrl = {3461781765, 0}, addr32 = {3461781765, 0, 0, 0}, addr16 = {39173, 52822, 0, 0, 0, 0, 0, 0}, addr = "\005\231V\316", '\000' <repeats 11 times>}}, src_port = 5060, dst_port = 5060, proto = 1, proto_reserved1 = 0, proto_reserved2 = 0, src_su = {s = {sa_family = 2, sa_data = "\023IJ>#\263\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 50195, sin_addr = {s_addr = 3005431474}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 50195, sin6_flowinfo = 3005431474, 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 = 1}}, bind_address = 0x7f59ce141850}, buf = 0x7f59af533f10 "INVITE sip:+337399722921@opensips.domain;user=phone SIP/2.0\r\nVia: SIP/2.0/UDP 1.1.1.1:5060;branch=z9hG4bK2a72aa64\r\nMax-Forwards: 69\r\nFrom: \"+337729181046\" <sip:+337729181046@outsidedomain.tld>;"..., len = 980, new_uri = {s = 0x0, len = 0}, dst_uri = {s = 0x0, len = 0}, ruri_q = -1, ruri_bflags = 0, force_send_socket = 0x0, path_vec = {s = 0x0, len = 0}, parsed_uri_ok = 1, parsed_uri = {user = {s = 0x7f59af533f1b "+337399722921@opensips.domain;user=phone SIP/2.0\r\nVia: SIP/2.0/UDP 1.1.1.1:5060;branch=z9hG4bK2a72aa64\r\nMax-Forwards: 69\r\nFrom: \"+337729181046\" <sip:+337729181046@outsidedomain.tld>;tag=as12348"..., len = 13}, passwd = {s = 0x0, len = 0}, host = {s = 0x7f59af533f29 "opensips.domain;user=phone SIP/2.0\r\nVia: SIP/2.0/UDP 1.1.1.1:5060;branch=z9hG4bK2a72aa64\r\nMax-Forwards: 69\r\nFrom: \"+337729181046\" <sip:+337729181046@outsidedomain.tld>;tag=as12348987\r\nTo: <sip:"..., len = 21}, port = {s = 0x0, len = 0}, params = {s = 0x7f59af533f3f "user=phone SIP/2.0\r\nVia: SIP/2.0/UDP 1.1.1.1:5060;branch=z9hG4bK2a72aa64\r\nMax-Forwards: 69\r\nFrom: \"+337729181046\" <sip:+337729181046@outsidedomain.tld>;tag=as12348987\r\nTo: <sip:+337399722921@cic1.mks"..., len = 10}, headers = {s = 0x0, len = 0}, port_no = 0, proto = 0, type = SIP_URI_T, transport = {s = 0x0, len = 0}, ttl = {s = 0x0, len = 0}, user_param = {s = 0x7f59af533f3f "user=phone SIP/2.0\r\nVia: SIP/2.0/UDP 1.1.1.1:5060;branch=z9hG4bK2a72aa64\r\nMax-Forwards: 69\r\nFrom: \"+337729181046\" <sip:+337729181046@outsidedomain.tld>;tag=as12348987\r\nTo: <sip:+337399722921@cic1.mks"..., len = 10}, 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 = 0x7f59af533f44 "phone SIP/2.0\r\nVia: SIP/2.0/UDP 1.1.1.1:5060;branch=z9hG4bK2a72aa64\r\nMax-Forwards: 69\r\nFrom: \"+337729181046\" <sip:+337729181046@outsidedomain.tld>;tag=as12348987\r\nTo: <sip:+337399722921@opensips.doma"..., len = 5}, 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 = 0x7f59ae571990, body_lumps = 0x0, reply_lump = 0x0, add_to_branch_s = '\000' <repeats 57 times>, add_to_branch_len = 0, hash_index = 43436, flags = 0, msg_flags = 360480, set_global_address = {s = 0x0, len = 0}, set_global_port = {s = 0x0, len = 0}, time = {tv_sec = 0, tv_usec = 0}, msg_cb = 0x0}
        shmem_msg = <optimized out>
        uac = <optimized out>
        on_failure = <optimized out>
        old_route_type = <optimized out>
        __FUNCTION__ = "run_failure_handlers"
#12 t_should_relay_response (Trans=Trans@entry=0x7f59af531af8, new_code=new_code@entry=486, branch=branch@entry=0, should_store=should_store@entry=0x7ffdb9c2dca0, should_relay=should_relay@entry=0x7ffdb9c2dc9c, cancel_bitmap=cancel_bitmap@entry=0x7ffdb9c2dd94, reply=<optimized out>) at t_reply.c:995
        branch_cnt = <optimized out>
        picked_code = <optimized out>
        inv_through = 0
        do_cancel = <optimized out>
        __FUNCTION__ = "t_should_relay_response"
#13 0x00007f59ab85c414 in relay_reply (t=0x7f59af531af8, p_msg=0x7f59ce14c8e8, branch=0, msg_status=486, cancel_bitmap=0x7ffdb9c2dd94) at t_reply.c:1240
        relay = 0
        save_clone = 128
        buf = 0x0
        res_len = 0
        relayed_code = 0
        relayed_msg = 0x0
        bm = {to_tag_val = {s = 0x7f59ce141850 "\236", len = -1417282580}}
        totag_retr = 0
        reply_status = <optimized out>
        uas_rb = <optimized out>
        cb_s = {s = 0x7f5900000000 <error: Cannot access memory at address 0x7f5900000000>, len = -1353507600}
        text = {s = 0x634b62344768397a <error: Cannot access memory at address 0x634b62344768397a>, len = 778123617}
        __FUNCTION__ = "relay_reply"
#14 0x00007f59ab85ea45 in reply_received (p_msg=0x7f59ce14c8e8) at t_reply.c:1660
        msg_status = 486
        last_uac_status = <optimized out>
        branch = 0
        reply_status = <optimized out>
        timer = 140023686282745
        cancel_bitmap = 0
        uac = 0x7f59af531cd0
        t = 0x7f59af531af8
        backup_list = <optimized out>
        has_reply_route = <optimized out>
        old_route_type = <optimized out>
        __FUNCTION__ = "reply_received"
#15 0x00000000004669f8 in forward_reply (msg=msg@entry=0x7f59ce14c8e8) at forward.c:499
        new_buf = 0x0
        to = 0x0
        new_len = 0
        mod = 0x7f59ce1229f8
        proto = <optimized out>
        id = 0
        send_sock = <optimized out>
        s = <optimized out>
        len = <optimized out>
        __FUNCTION__ = "forward_reply"
#16 0x000000000044640f in receive_msg (buf=0x9ace20 <buf> "SIP/2.0 486 Busy here\r\nVia: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bKca9a.f3c19e17.0\r\nTo: <sip:+337399722921@opensips.domain;user=phone>;tag=3904633329-363897402\r\nFrom: <sip:+337729181046@ipb"..., len=<optimized out>, rcv_info=rcv_info@entry=0x7ffdb9c2dfa0, existing_context=existing_context@entry=0x0, msg_flags=msg_flags@entry=0) at receive.c:279
        ctx = 0x7f59ce14c878
        msg = 0x7f59ce14c8e8
        start = {tv_sec = 2314885530818453536, tv_usec = 5137227431274669312}
        rc = 3
        old_route_type = 4
        tmp = <optimized out>
        in_buff = {s = 0x7f59ce14bda0 "SIP/2.0 486 Busy here\r\nVia: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bKca9a.f3c19e17.0\r\nTo: <sip:+337399722921@opensips.domain;user=phone>;tag=3904633329-363897402\r\nFrom: <sip:+337729181046@ipb"..., len = 442}
        __FUNCTION__ = "receive_msg"
#17 0x00000000005b8536 in udp_read_req (si=<optimized out>, bytes_read=<optimized out>) at net/proto_udp/proto_udp.c:186
        ri = {src_ip = {af = 2, len = 4, u = {addrl = {657905496, 0}, addr32 = {657905496, 0, 0, 0}, addr16 = {55128, 10038, 0, 0, 0, 0, 0, 0}, addr = "X\327\066'", '\000' <repeats 11 times>}}, dst_ip = {af = 2, len = 4, u = {addrl = {3461781765, 0}, addr32 = {3461781765, 0, 0, 0}, addr16 = {39173, 52822, 0, 0, 0, 0, 0, 0}, addr = "\005\231V\316", '\000' <repeats 11 times>}}, src_port = 5060, dst_port = 5060, proto = 1, proto_reserved1 = 0, proto_reserved2 = 0, src_su = {s = {sa_family = 2, sa_data = "\023\304X\327\066'\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 50195, sin_addr = {s_addr = 657905496}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 50195, sin6_flowinfo = 657905496, 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 = 1}}, bind_address = 0x7f59ce141850}
        len = <optimized out>
        buf = "SIP/2.0 486 Busy here\r\nVia: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bKca9a.f3c19e17.0\r\nTo: <sip:+337399722921@opensips.domain;user=phone>;tag=3904633329-363897402\r\nFrom: <sip:+337729181046@ipb"...
        tmp = <optimized out>
        fromlen = 16
        p = <optimized out>
        msg = {s = 0x9ace20 <buf> "SIP/2.0 486 Busy here\r\nVia: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bKca9a.f3c19e17.0\r\nTo: <sip:+337399722921@opensips.domain;user=phone>;tag=3904633329-363897402\r\nFrom: <sip:+337729181046@ipb"..., len = 463}
        __FUNCTION__ = "udp_read_req"
#18 0x0000000000590baf in handle_io (idx=<optimized out>, event_type=<optimized out>, fm=<optimized out>) at net/net_udp.c:278
        n = <optimized out>
        read = 0
        n = <optimized out>
        read = <optimized out>
        __FUNCTION__ = "handle_io"
#19 io_wait_loop_epoll (repeat=0, t=1, h=<optimized out>) at net/../io_wait_loop.h:311
        ret = <optimized out>
        n = <optimized out>
        r = 0
        i = <optimized out>
        e = 0x7f59ce1a6f78
        ep_event = {events = 0, data = {ptr = 0xce14185000000000, fd = 0, u32 = 0, u64 = 14849520603223818240}}
        fd = <optimized out>
        curr_time = <optimized out>
        __FUNCTION__ = "io_wait_loop_epoll"
#20 0x0000000000596017 in udp_start_processes (chd_rank=chd_rank@entry=0x997258 <chd_rank>, startup_done=startup_done@entry=0x0) at net/net_udp.c:503
        si = <optimized out>
        p_id = <optimized out>
        i = <optimized out>
        p = <optimized out>
        __FUNCTION__ = "udp_start_processes"
#21 0x000000000041bd32 in main_loop () at main.c:227
        startup_done = 0x0
        last_check = 0
        rc = <optimized out>
        chd_rank = 7
        startup_done = <optimized out>
        last_check = <optimized out>
        rc = <optimized out>
        __FUNCTION__ = "main_loop"
#22 main (argc=<optimized out>, argv=<optimized out>) at main.c:916
        c = <optimized out>
        r = 0
        tmp = 0x7ffdb9c2fedb ""
        tmp_len = <optimized out>
        port = <optimized out>
        proto = <optimized out>
        protos_no = <optimized out>
        options = 0x5e3368 "f:cCm:M:b:l:n:N:rRvdDFEVhw:t:u:g:p:P:G:W:o:a:k:s:"
        seed = 3010331475
        rfd = <optimized out>
        __FUNCTION__ = "main"
razvancrainea commented 1 year ago

I believe I found the culprit here, but not sure how to get this sorted out. Will update as soon as I have more information.

Best regards, Răzvan

rwilkinson87 commented 1 year ago

Hi, I have just updated to 3.2.15 which includes this patch on our production environment. When the scenario above is matched, instead of a segfault I now see

ERROR:statistics:w_update_stat_series: could not create new stat series!

And the series doesn't get updated.

Is this the current expected behaviour after your patch @razvancrainea ? It's no longer segfaulting (which is great :) ) but it still doesn't update the statistics series.

razvancrainea commented 1 year ago

Hi, @rwilkinson87 ! Yes, this is expected - the idea is that you are not allowed to use the same statistic name within two different groups. Make sure you use different names for different purposes stats.

Best regards, Razvan