[OpenSIPS-Users] mi_fifo lock on reply after a period of time in 3.1.3

Andrew Yager andrew at rwts.com.au
Fri Oct 8 11:43:59 EST 2021


Hi Bogdan-Andrei,

Have restarted since the last bt, but have recreated again and
attached. Earlier today we did also get another bt full on the second
blocked pid, but I didn't save it. In that case it was a UDP reply
from one of our upstream servers that had gone through mid_registrar
and was being relayed to a TCP endpoint. The TCP endpoint did have an
open file descriptor we could see, and it had sent and was blocked on
receive at the same point (I'm getting better at reading backtraces!
:D).

The thing I do note is happening is that every example I have is a UDP
message being received from an upstream server being relayed to a
client on a TCP/TLS connection via a UDP worker.

While we are using WolfSSL in this box, the other box where we have
the same behaviour (but I haven't taken backtraces yet) is running
OpenSSL and on 3.1.3; so it's not SSL library specific.

I'm going to see if I can get a backtrace from the 3.1.3 box shortly.

Andrew

On Fri, 8 Oct 2021 at 17:13, Bogdan-Andrei Iancu <bogdan at opensips.org> wrote:
>
> Hi Andrew,
>
> OK, interesting progress here. So, the FIFO process blocks as it is
> trying to send an IPC JOB to an UDP process which looks like also being
> blocked.
>
> Could you attach with GDB to the that UDP blocked process too ? (you
> have its PID in the printing of the pt[x] in first gdb)
>
> Regards,
>
> Bogdan-Andrei Iancu
>
> OpenSIPS Founder and Developer
>    https://www.opensips-solutions.com
> OpenSIPS eBootcamp 2021
>    https://opensips.org/training/OpenSIPS_eBootcamp_2021/
>
> On 10/8/21 1:43 AM, Andrew Yager wrote:
> > Interestingly, where I usually see a range of continued messages from
> > a process continually in the debug log, they appear to stop for this
> > PID at 3:47am, and that process seems blocked on a tcp/tls send:
> >
> >
>
-------------- next part --------------
(gdb) p pt[50]
$1 = {pid = 24103, type = TYPE_UDP, pg_filter = 0x7fb025689930, desc = "SIP receiver udp:114.141.98.21:5060", '\000' <repeats 92 times>, flags = 100, ipc_pipe = {210, 211}, ipc_pipe_holder = {210, 211}, ipc_sync_pipe = {212, 213}, ipc_sync_pipe_holder = {212, 213}, tcp_socks_holder = {646, 647}, unix_sock = 646, 
  log_level = 4, default_log_level = 4, load_rt = 0x7fafa819f590, load_1m = 0x7fafa819f650, load_10m = 0x7fafa819f710, pkg_total = 0x7fafa81e4ba0, pkg_used = 0x7fafa81e4c50, pkg_rused = 0x7fafa81e3d68, pkg_mused = 0x7fafa81e3e20, pkg_free = 0x7fafa81e2f30, pkg_frags = 0x7fafa81e2fe0, load = {ST_window = {1000, 1000, 1000, 
      1000, 1000, 1000, 1000, 1000, 1000, 997, 1000 <repeats 32 times>, 997, 1000 <repeats 28 times>, 997, 1000 <repeats 32 times>, 997, 1000, 1000, 1000, 1000, 924, 0 <repeats 332 times>, 390, 1000 <repeats 32 times>, 996, 1000 <repeats 75 times>, 997, 1000 <repeats 17 times>, 997, 1000 <repeats 119 times>, 995, 
      1000 <repeats 75 times>, 996, 1000, 1000, 1000, 1000, 1000, 1000, 1000, 1000, 1000, 1000, 997, 1000 <repeats 13 times>, 997, 1000 <repeats 11 times>, 998, 1000 <repeats 24 times>, 997, 1000 <repeats 18 times>, 997, 1000 <repeats 27 times>, 998, 1000, 1000, 1000, 1000, 1000, 1000, 1000, 1000, 1000, 1000, 998, 
      1000 <repeats 11 times>...}, LT_window = {0 <repeats 120 times>, 557337, 109912, 0 <repeats 478 times>}, last_time = 1633680121109927, is_busy = 1 '\001'}}
(gdb) q

root at hvprxy:/var/log# gdb opensips 24103
GNU gdb (Ubuntu 9.2-0ubuntu1~20.04) 9.2
Copyright (C) 2020 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:
<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 opensips...

[snip]

(gdb) bt full
#0  0x00007fb035888057 in __libc_recvmsg (fd=fd at entry=647, msg=msg at entry=0x7ffc2e266910, flags=flags at entry=256) at ../sysdeps/unix/sysv/linux/recvmsg.c:28
        resultvar = 18446744073709551104
        __arg3 = <optimized out>
        _a2 = <optimized out>
        sc_ret = <optimized out>
        __arg1 = <optimized out>
        _a3 = <optimized out>
        sc_cancel_oldtype = <optimized out>
        resultvar = <optimized out>
        resultvar = <optimized out>
        __arg2 = <optimized out>
        _a1 = <optimized out>
#1  0x000055e994af9fac in receive_fd (unix_socket=unix_socket at entry=647, data=data at entry=0x7ffc2e266a10, data_len=data_len at entry=8, fd=fd at entry=0x7ffc2e266a0c, flags=flags at entry=256) at net/tcp_passfd.c:213
        msg = {msg_name = 0x0, msg_namelen = 0, msg_iov = 0x7ffc2e266950, msg_iovlen = 1, msg_control = 0x7ffc2e266960, msg_controllen = 24, msg_flags = 0}
        iov = {{iov_base = 0x7ffc2e266a10, iov_len = 8}}
        new_fd = <optimized out>
        ret = <optimized out>
        n = <optimized out>
        cmsg = <optimized out>
        control_un = {cm = {cmsg_len = 0, cmsg_level = 222, cmsg_type = 0, __cmsg_data = 0x7ffc2e266970 "\220J\214%\260\177"}, control = "\000\000\000\000\000\000\000\000\336\000\000\000\000\000\000\000\220J\214%\260\177\000"}
        __FUNCTION__ = "receive_fd"
#2  0x000055e994aeffa3 in tcp_conn_get (id=<optimized out>, ip=ip at entry=0x7ffc2e266af0, port=port at entry=55087, proto=proto at entry=PROTO_TLS, proto_extra_id=proto_extra_id at entry=0x0, conn=conn at entry=0x7ffc2e266ae0, conn_fd=0x7ffc2e266adc, send_sock=0x7fb025689420) at net/net_tcp.c:529
        c = 0x7fafa84997e8
        tmp = <optimized out>
        a = <optimized out>
        hash = <optimized out>
        response = {140392419399656, 1}
        part = <optimized out>
        n = <optimized out>
        fd = 21993
        __FUNCTION__ = "tcp_conn_get"
#3  0x00007fafa26d7159 in proto_tls_send (send_sock=0x7fb025689420, buf=0x7fafa7ea5908 "NOTIFY sip:[snip]:55087;transport=tls SIP/2.0\r\nRecord-Route: <sip:[snip]:5061;transport=tls;r2=on;lr;ftag=8bba07a0-21e5-4958-a470-21c5d5b5b960>\r\nRecord-Route: <sip:hvp."..., len=927, to=0x7fafa71d8348, 
    id=<optimized out>) at proto_tls.c:490
        c = 0x7fb0258c5130
        dom = 0x0
        ip = {af = 2, len = 4, u = {addrl = {9385250162, 140392399733576}, addr32 = {795315570, 2, 2803729224, 32687}, addr16 = {36210, 12135, 2, 0, 33608, 42781, 32687, 0}, addr = "r\215g/\002\000\000\000H\203\035\247\257\177\000"}}
        port = <optimized out>
        fd = 21993
        n = <optimized out>
        rlen = <optimized out>
        __FUNCTION__ = "proto_tls_send"
#4  0x00007fafa480c3af in msg_send (msg=0x0, len=<optimized out>, buf=0x7fafa7ea5908 "NOTIFY sip:[snip]:55087;transport=tls SIP/2.0\r\nRecord-Route: <sip:[snip]:5061;transport=tls;r2=on;lr;ftag=8bba07a0-21e5-4958-a470-21c5d5b5b960>\r\nRecord-Route: <sip:hvp."..., id=<optimized out>, 
    to=0x7fafa71d8348, proto=3, send_sock=0x7fb025689420) at ../../forward.h:123
        out_buff = {s = 0x7fafa7ea5908 "NOTIFY sip:[snip]:55087;transport=tls SIP/2.0\r\nRecord-Route: <sip:[snip]:5061;transport=tls;r2=on;lr;ftag=8bba07a0-21e5-4958-a470-21c5d5b5b960>\r\nRecord-Route: <sip:hvp."..., len = 927}
        port = <optimized out>
        ip = <optimized out>
        out_buff = <optimized out>
        port = <optimized out>
        ip = <optimized out>
        __FUNCTION__ = "msg_send"
        __ip = <optimized out>
#5  send_pr_buffer (rb=rb at entry=0x7fafa71d8328, buf=0x7fafa7ea5908, len=<optimized out>, ctx=ctx at entry=0x0) at t_funcs.c:68
        __FUNCTION__ = "send_pr_buffer"
#6  0x00007fafa4846bfa in t_forward_nonack (t=t at entry=0x7fafa71d8150, p_msg=p_msg at entry=0x7fb0258c2c00, proxy=proxy at entry=0x0, reset_bcounter=reset_bcounter at entry=0, locked=locked at entry=0) at t_fwd.c:838
        reply_reason_487 = {s = 0x7fafa4854c2c "Request Terminated", len = 18}
        backup_uri = <optimized out>
        backup_dst = {s = 0x0, len = 0}
        branch_ret = <optimized out>
        lowest_ret = <optimized out>
        current_uri = {s = 0x0, len = 0}
        added_branches = 1
        i = 0
        q = -1
        t_invite = <optimized out>
        success_branch = 0
        dst_uri = {s = 0x0, len = 0}
        bk_sock = <optimized out>
        br_flags = 0
        bk_bflags = <optimized out>
        idx = <optimized out>
        path = {s = 0x55e994bd7e50 <log_level> "\320q\023\250\257\177", len = -1799507584}
        bk_path = <optimized out>
        __FUNCTION__ = "t_forward_nonack"
#7  0x00007fafa480e153 in t_relay_to (p_msg=p_msg at entry=0x7fb0258c2c00, proxy=proxy at entry=0x0, flags=flags at entry=0) at t_funcs.c:260
        ret = 0
        new_tran = 1
--Type <RET> for more, q to quit, c to continue without paging--c
        reply_ret = <optimized out>
        t = 0x7fafa71d8150
        __FUNCTION__ = "t_relay_to"
#8  0x00007fafa482aefc in w_t_relay (p_msg=0x7fb0258c2c00, flags=0x0, proxy=<optimized out>) at tm.c:1216
        p = 0x0
        t = 0x0
        ret = <optimized out>
        __FUNCTION__ = "w_t_relay"
#9  0x000055e99498a4df in do_action (a=0x7fb0256a2df8, msg=0x7fb0258c2c00) at action.c:961
        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 = 0x7ffc2e266fa0 "", len = 88}, ri = 628027600, flags = 32688}
        start = {tv_sec = 0, tv_usec = 140394788144323}
        end_time = <optimized out>
        cmd = 0x7fafa485dd30 <cmds+720>
        acmd = <optimized out>
        cmdp = {0x0, 0x0, 0x7fb0256a0138, 0x55e994d263c0 <_oser_err_info>, 0x7fb0258c2c00, 0x7fb0258c2c00, 0x0, 0xe9e1c4cf8a290c00}
        tmp_vals = {{rs = {s = 0x0, len = 4}, ri = 628208464, flags = 32688}, {rs = {s = 0x1 <error: Cannot access memory at address 0x1>, len = 629943296}, ri = 774270920, flags = 32764}, {rs = {s = 0x55e994d263c0 <_oser_err_info> "", len = 627707152}, ri = 629943296, flags = 88}, {rs = {s = 0x0, len = 629943296}, ri = -1977021440, flags = -371079985}, {rs = {s = 0x0, len = 627708744}, ri = -1799519392, flags = 21993}, {rs = {s = 0x55e994bd8350 <core_cmds+1200> "뜱\224\351U", len = 627708752}, ri = 629943296, flags = 32688}, {rs = {s = 0x1 <error: Cannot access memory at address 0x1>, len = -1801935623}, ri = 774271184, flags = 32764}, {rs = {s = 0x7ffc2e2670c0 "H\333i%\260\177", len = 5}, ri = -1801337868, flags = 21993}}
        sval = {s = 0x3000000028 <error: Cannot access memory at address 0x3000000028>, len = 774270896}
        __FUNCTION__ = "do_action"
#10 0x000055e99498c828 in run_action_list (a=<optimized out>, msg=msg at entry=0x7fb0258c2c00) at action.c:181
        ret = -1
        t = 0x7fb0256a2df8
#11 0x000055e9949cdacc in eval_elem (e=0x7fb0256a2f20, msg=0x7fb0258c2c00, val=0x0) at route.c:613
        ret = -5
        ival = <optimized out>
        lval = {rs = {s = 0x55e995fdb6e0 "", len = -1801207699}, ri = 627953912, flags = 32688}
        rval = {rs = {s = 0x12 <error: Cannot access memory at address 0x12>, len = -1977021440}, ri = 629943296, flags = 32688}
        p = <optimized out>
        i = <optimized out>
        n = <optimized out>
        __FUNCTION__ = "eval_elem"
#12 0x000055e9949cd4b5 in eval_expr (e=0x7fb0256a2f20, msg=<optimized out>, val=<optimized out>) at route.c:937
        rec_lev = 2
        ret = <optimized out>
        __FUNCTION__ = "eval_expr"
#13 0x000055e9949cd569 in eval_expr (e=0x7fb0256a2f88, msg=msg at entry=0x7fb0258c2c00, val=val at entry=0x0) at route.c:953
        rec_lev = 2
        ret = <optimized out>
        __FUNCTION__ = "eval_expr"
#14 0x000055e99498a1f7 in do_action (a=0x7fb0256a3788, msg=0x7fb0258c2c00) at action.c:725
        ret = -5
        v = <optimized out>
        i = <optimized out>
        len = <optimized out>
        cmatch = <optimized out>
        aitem = <optimized out>
        adefault = <optimized out>
        spec = <optimized out>
        val = {rs = {s = 0x55e994bd7e50 <log_level> "\320q\023\250\257\177", len = -1977021440}, ri = 0, flags = 0}
        start = {tv_sec = 0, tv_usec = 140394518917184}
        end_time = <optimized out>
        cmd = 0x0
        acmd = <optimized out>
        cmdp = {0x18, 0x7fb0258c4430, 0x0, 0x0, 0x1300000018, 0x7fb0258c4af8, 0x7fb0258c4b60, 0x7ffc2e2673d0}
        tmp_vals = {{rs = {s = 0x3 <error: Cannot access memory at address 0x3>, len = -1977021440}, ri = 774271960, flags = 32764}, {rs = {s = 0x7fb0258c4af8 "", len = 629951120}, ri = 0, flags = 0}, {rs = {s = 0x7fb0258c4430 "4XД\351U", len = 774271952}, ri = 774271960, flags = 32764}, {rs = {s = 0x7fafa47ea550 <record_route+768> "ZY\205\300\017\211o\376\377\377H\213\005\067j", len = 0}, ri = -1977021440, flags = -371079985}, {rs = {s = 0x55e994bd7e50 <log_level> "\320q\023\250\257\177", len = 2}, ri = 627945832, flags = 32688}, {rs = {s = 0x55e994d263c0 <_oser_err_info> "", len = 629943296}, ri = 629943296, flags = 32688}, {rs = {s = 0x0, len = -1801661259}, ri = -1473601864, flags = 32687}, {rs = {s = 0xe9e1c4cf8a290c00 <error: Cannot access memory at address 0xe9e1c4cf8a290c00>, len = 627944240}, ri = -1977021440, flags = -371079985}}
        sval = {s = 0x7fb0258c2c00 "\027", len = -1798151232}
        __FUNCTION__ = "do_action"
#15 0x000055e99498c828 in run_action_list (a=<optimized out>, msg=msg at entry=0x7fb0258c2c00) at action.c:181
        ret = -1
        t = 0x7fb0256a3788
#16 0x000055e99498b70c in run_actions (msg=<optimized out>, a=<optimized out>) at action.c:128
        ret = <optimized out>
        has_name = <optimized out>
        top_route = <optimized out>
        ret = <optimized out>
        has_name = <optimized out>
        top_route = <optimized out>
        __FUNCTION__ = "run_actions"
#17 do_action (a=0x7fb0256dd940, msg=0x7fb0258c2c00) at action.c:716
        ret = -5
        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 = -1977021440}, ri = 24, flags = 48}
        start = {tv_sec = 140394518914560, tv_usec = 140721082758736}
        end_time = <optimized out>
        cmd = 0x0
        acmd = <optimized out>
        cmdp = {0x0, 0x7ffc2e2675b0, 0x7fb0256da438, 0x7fb0256da420, 0x0, 0x2, 0x7fb0258c2c00, 0x55e9949cdacc <eval_elem+1100>}
        tmp_vals = {{rs = {s = 0x55e995f55a70 "", len = -1801207699}, ri = 629947040, flags = 32688}, {rs = {s = 0x2e74656e0000000d <error: Cannot access memory at address 0x2e74656e0000000d>, len = 627942912}, ri = -1977021440, flags = -371079985}, {rs = {s = 0x7fb0258c2c00 "\027", len = 774272592}, ri = 1, flags = 32688}, {rs = {s = 0x12 <error: Cannot access memory at address 0x12>, len = 629943296}, ri = 774272592, flags = 32764}, {rs = {s = 0x0, len = -1801337868}, ri = 627943016, flags = 32688}, {rs = {s = 0x7fb0256da668 "\022", len = 627942432}, ri = 18, flags = 0}, {rs = {s = 0x7fb0258c2c00 "\027", len = -1801941390}, ri = 1, flags = 2}, {rs = {s = 0xe9e1c4cf8a290c00 <error: Cannot access memory at address 0xe9e1c4cf8a290c00>, len = 9}, ri = 2, flags = 0}}
        sval = {s = 0x55e994b181ec "unknown", len = 7}
        __FUNCTION__ = "do_action"
#18 0x000055e99498c828 in run_action_list (a=<optimized out>, msg=msg at entry=0x7fb0258c2c00) at action.c:181
        ret = -1
        t = 0x7fb0256dd940
#19 0x000055e99498c1c2 in do_action (a=0x7fb0256ddb90, msg=0x7fb0258c2c00) at action.c:743
        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 = -1534788736}, ri = 0, flags = 0}
        start = {tv_sec = 140394520914944, tv_usec = 140394788144323}
        end_time = <optimized out>
        cmd = 0x0
        acmd = <optimized out>
        cmdp = {0x7ffc2e2677b8, 0x7ffc2e2677d0, 0x7fb0256bba50, 0xe9e1c4cf8a290c00, 0x0, 0xe9e1c4cf8a290c00, 0x7fb0258c2c00, 0x87fb}
        tmp_vals = {{rs = {s = 0x0, len = 0}, ri = 627686640, flags = 32688}, {rs = {s = 0x400 <error: Cannot access memory at address 0x400>, len = 629943296}, ri = -1535008410, flags = 32687}, {rs = {s = 0x7f00258c4390 <error: Cannot access memory at address 0x7f00258c4390>, len = 40}, ri = 0, flags = 4}, {rs = {s = 0x3 <error: Cannot access memory at address 0x3>, len = 0}, ri = 3, flags = 0}, {rs = {s = 0x400000000 <error: Cannot access memory at address 0x400000000>, len = 2}, ri = 627675016, flags = 32688}, {rs = {s = 0x55e994d263c0 <_oser_err_info> "", len = 629943296}, ri = 629943296, flags = 32688}, {rs = {s = 0x0, len = -1977021440}, ri = 841382304, flags = 858796340}, {rs = {s = 0x7fb02569bce8 "\a", len = 629943296}, ri = -1534728800, flags = 32687}}
        sval = {s = 0x3000000020 <error: Cannot access memory at address 0x3000000020>, len = 774272976}
        __FUNCTION__ = "do_action"
#20 0x000055e99498c828 in run_action_list (a=<optimized out>, msg=msg at entry=0x7fb0258c2c00) at action.c:181
        ret = -1
        t = 0x7fb0256ddb90
#21 0x000055e99498b70c in run_actions (msg=<optimized out>, a=<optimized out>) at action.c:128
        ret = <optimized out>
        has_name = <optimized out>
        top_route = <optimized out>
        ret = <optimized out>
        has_name = <optimized out>
        top_route = <optimized out>
        __FUNCTION__ = "run_actions"
#22 do_action (a=0x7fb02569c290, msg=0x7fb0258c2c00) at action.c:716
        ret = -5
        v = <optimized out>
        i = <optimized out>
        len = <optimized out>
        cmatch = <optimized out>
        aitem = <optimized out>
        adefault = <optimized out>
        spec = <optimized out>
        val = {rs = {s = 0x7ffc2e267a80 " ", len = 2}, ri = -1779082640, flags = 21993}
        start = {tv_sec = 140721082759808, tv_usec = 140394789003488}
        end_time = <optimized out>
        cmd = 0x0
        acmd = <optimized out>
        cmdp = {0x55e995fdb6e0, 0x5d, 0x200000001, 0x800000013, 0x7900000009, 0x11800000005, 0x55e900000001, 0x9ab0}
        tmp_vals = {{rs = {s = 0x55e995f55cc0 "AEDT", len = -1977021440}, ri = -1798284836, flags = 21993}, {rs = {s = 0x7fb0258c3818 "\r", len = -1798284836}, ri = -1798284890, flags = 21993}, {rs = {s = 0xd <error: Cannot access memory at address 0xd>, len = -1800975277}, ri = 604, flags = 0}, {rs = {s = 0x7fb03579c4c3 <__syslog_chk+163> "H\213D$\030dH3\004%(", len = 48}, ri = -1801207699, flags = 21993}, {rs = {s = 0x7ffc2e267a40 "", len = -1977021440}, ri = 0, flags = 0}, {rs = {s = 0x7ffc2e267c40 "\002", len = 629943296}, ri = -1798285440, flags = 21993}, {rs = {s = 0x0, len = 0}, ri = 604, flags = 0}, {rs = {s = 0x7fb03579c4c3 <__syslog_chk+163> "H\213D$\030dH3\004%(", len = 32}, ri = 774273888, flags = 32764}}
        sval = {s = 0x55e994b181ec "unknown", len = 7}
        __FUNCTION__ = "do_action"
#23 0x000055e99498c828 in run_action_list (a=a at entry=0x7fb0256997f0, msg=msg at entry=0x7fb0258c2c00) at action.c:181
        ret = -1
        t = 0x7fb02569c290
#24 0x000055e99498cb0a in run_actions (msg=0x7fb0258c2c00, a=0x7fb0256997f0) at action.c:128
        ret = <optimized out>
        has_name = <optimized out>
        top_route = <optimized out>
        ret = <optimized out>
        has_name = <optimized out>
        top_route = <optimized out>
        __FUNCTION__ = "run_actions"
#25 run_top_route (sr=..., msg=msg at entry=0x7fb0258c2c00) at action.c:228
        bk_action_flags = 0
        ret = <optimized out>
        ctx = 0x0
        __FUNCTION__ = "run_top_route"
#26 0x000055e994999ce6 in receive_msg (buf=0x55e994d05780 <buf> "NOTIFY sip:[snip]:5060 SIP/2.0\r\nv: SIP/2.0/UDP [snip]:5060;rport;branch=z9hG4bKPj09aaa116-0357-4a19-acfa-5bcad4d21836\r\nf: <sip:[snip]@[snip]>;tag=8bba07a0-21e5-4958-a"..., len=<optimized out>, rcv_info=rcv_info at entry=0x7ffc2e267c40, existing_context=existing_context at entry=0x0, msg_flags=msg_flags at entry=0) at receive.c:213
        ctx = 0x7fb0258c2b90
        msg = 0x7fb0258c2c00
        start = {tv_sec = 94461731626176, tv_usec = 0}
        rc = 3
        old_route_type = <optimized out>
        tmp = <optimized out>
        in_buff = {s = 0x55e994d05780 <buf> "NOTIFY sip:[snip]:5060 SIP/2.0\r\nv: SIP/2.0/UDP [snip]:5060;rport;branch=z9hG4bKPj09aaa116-0357-4a19-acfa-5bcad4d21836\r\nf: <sip:[snip]@[snip]>;tag=8bba07a0-21e5-4958-a"..., len = 604}
        __FUNCTION__ = "receive_msg"
#27 0x000055e994affd28 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 = {140721556458866, 0}, addr32 = {1247972722, 32764, 0, 0}, addr16 = {36210, 19042, 32764, 0, 0, 0, 0, 0}, addr = "r\215bJ\374\177\000\000\000\000\000\000\000\000\000"}}, dst_ip = {af = 2, len = 4, u = {addrl = {358780274, 0}, addr32 = {358780274, 0, 0, 0}, addr16 = {36210, 5474, 0, 0, 0, 0, 0, 0}, addr = "r\215b\025", '\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\304r\215bJ\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 50195, sin_addr = {s_addr = 1247972722}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 50195, sin6_flowinfo = 1247972722, 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 = 628260768}}, bind_address = 0x7fb025689930}
        len = <optimized out>
        buf = "NOTIFY sip:[snip]:5060 SIP/2.0\r\nv: SIP/2.0/UDP [snip]:5060;rport;branch=z9hG4bKPj09aaa116-0357-4a19-acfa-5bcad4d21836\r\nf: <sip:[snip]@[snip]>;tag=8bba07a0-21e5-4958-a"...
        tmp = <optimized out>
        fromlen = 16
        p = <optimized out>
        msg = {s = 0x55e994d05780 <buf> "NOTIFY sip:[snip]:5060 SIP/2.0\r\nv: SIP/2.0/UDP [snip]:5060;rport;branch=z9hG4bKPj09aaa116-0357-4a19-acfa-5bcad4d21836\r\nf: <sip:[snip]@[snip]>;tag=8bba07a0-21e5-4958-a"..., len = 604}
        __FUNCTION__ = "udp_read_req"
#28 0x000055e994ad8ec0 in handle_io (idx=<optimized out>, event_type=<optimized out>, fm=<optimized out>) at net/net_udp.c:272
        n = <optimized out>
        read = 21993
        n = <optimized out>
        read = <optimized out>
        __FUNCTION__ = "handle_io"
#29 io_wait_loop_epoll (repeat=0, t=1, h=<optimized out>) at net/../io_wait_loop.h:308
        ret = <optimized out>
        n = <optimized out>
        r = 0
        i = <optimized out>
        e = 0x7fb025727fa0
        ep_event = {events = 1, data = {ptr = 0x2400000000, fd = 0, u32 = 0, u64 = 154618822656}}
        fd = <optimized out>
        curr_time = 3555
        __FUNCTION__ = "io_wait_loop_epoll"
#30 0x000055e994add4fd in fork_dynamic_udp_process (si_filter=0x7fb025689930) at net/net_udp.c:377
        si = 0x7fb025689930
        p_id = <optimized out>
        __FUNCTION__ = "fork_dynamic_udp_process"
#31 0x000055e99498452e in do_workers_auto_scaling () at pt_scaling.c:348
        pg = 0x7fafa8268ac0
        i = <optimized out>
        k = <optimized out>
        idx = 6
        load = <optimized out>
        procs_no = 36
        cnt_under = <optimized out>
        cnt_over = <optimized out>
        p_id = <optimized out>
        last_idx_in_pg = <optimized out>
        __FUNCTION__ = "do_workers_auto_scaling"
#32 0x000055e994967b8b in main_loop () at main.c:297
        startup_done = <optimized out>
        last_check = 3553300000
        rc = <optimized out>
        chd_rank = 41
        startup_done = <optimized out>
        last_check = <optimized out>
        rc = <optimized out>
        __FUNCTION__ = "main_loop"
#33 main (argc=<optimized out>, argv=<optimized out>) at main.c:916
        c = <optimized out>
        r = <optimized out>
        tmp = 0x7ffc2e268e75 ""
        tmp_len = <optimized out>
        port = <optimized out>
        proto = <optimized out>
        protos_no = <optimized out>
        options = 0x55e994b2a498 "f:cCm:M:b:l:n:N:rRvdDFEVhw:t:u:g:p:P:G:W:o:a:k:s:"
        seed = 153131742
        rfd = <optimized out>
        __FUNCTION__ = "main"


More information about the Users mailing list