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

[Andrew Yager]

Hi,

Procs had restarted; but repeated the exercise and it's pid 48 this time.

(gdb) bt full
#0  0x00007f6fe6d48297 in __libc_write (fd=fd at entry=203,
buf=buf at entry=0x7ffed7680050, nbytes=nbytes at entry=24) at
../sysdeps/unix/sysv/linux/write.c:26
        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  0x000055b7abca8d33 in __ipc_send_job (payload2=0x0,
payload1=0x55b7abc6e760 <rpc_get_pkg_stats>, type=0, fd=203) at
ipc.c:171
        job = {snd_proc = 1, handler_type = 0, payload1 =
0x55b7abc6e760 <rpc_get_pkg_stats>, payload2 = 0x0}
        n = <optimized out>
        job = <optimized out>
        n = <optimized out>
        __FUNCTION__ = "__ipc_send_job"
#2  ipc_send_rpc (dst_proc=dst_proc at entry=48,
rpc=rpc at entry=0x55b7abc6e760 <rpc_get_pkg_stats>,
param=param at entry=0x0) at ipc.c:194
[snip]
---

(gdb) p pt[48]
$1 = {pid = 2639896, type = TYPE_UDP, pg_filter = 0x7f6fc6b4a930, desc
= "SIP receiver udp:1.1.1.1:5060", '\000' <repeats 92 times>, flags =
228, ipc_pipe = {202,
    203}, ipc_pipe_holder = {202, 203}, ipc_sync_pipe = {204, 205},
ipc_sync_pipe_holder = {204, 205}, tcp_socks_holder = {642, 643},
unix_sock = 642, log_level = 4,
  default_log_level = 4, load_rt = 0x7f6ec9493f10, load_1m =
0x7f6ec9493fd0, load_10m = 0x7f6ec9494090, pkg_total = 0x7f6ec94d2048,
pkg_used = 0x7f6ec94d20f8,
  pkg_rused = 0x7f6ec94d3b80, pkg_mused = 0x7f6ec94d3c38, pkg_free =
0x7f6ec94d2e00, pkg_frags = 0x7f6ec94d8050, load = {ST_window = {0
<repeats 415 times>, 509,
      1000 <repeats 37 times>, 996, 1000 <repeats 109 times>, 996,
1000 <repeats 12 times>, 997, 1000, 1000, 1000, 1000, 1000, 1000,
1000, 1000, 997,
      1000 <repeats 32 times>, 996, 1000 <repeats 13 times>, 997, 1000
<repeats 60 times>, 997, 1000, 1000, 1000, 1000, 1000, 997, 1000
<repeats 13 times>, 967, 0, 0, 0,
      0, 0, 255, 151, 0, 0, 0, 0, 0, 0, 0, 0, 527, 1000, 906, 0
<repeats 268 times>}, LT_window = {0 <repeats 459 times>, 301288, 0
<repeats 140 times>},
    last_time = 1633625259739989, is_busy = 1 '\001'}}

Andrew

--
Andrew Yager, CEO (BCompSc, JNCIS-SP, MACS (Snr) CP)
business nbn™ advisor (advisor 01783150)
Real World Technology Solutions - IT People you can trust
Voice | Data | IT Procurement | Managed IT
rwts.com.au | 1300 798 718


Real World is a DellEMC Gold Partner

This document should be read only by those persons to whom it is
addressed and its content is not intended for use by any other
persons. If you have received this message in error, please notify us
immediately. Please also destroy and delete the message from your
computer. Any unauthorised form of reproduction of this message is
strictly prohibited. We are not liable for the proper and complete
transmission of the information contained in this communication, nor
for any delay in its receipt. Please consider the environment before
printing this e-mail.


On Fri, 8 Oct 2021 at 01:15, Bogdan-Andrei Iancu <bogdan at opensips.org> wrote:
>
> OK, getting closer :). Let's see who is the proc ID 46.
>
> In GDB, just do
>
> > p pt[46]
>
> 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/7/21 3:37 PM, Andrew Yager wrote:
>
> Hi Bogdan-Andrei,
>
> OK; my non expert opinion is that these two lines in ipc.c may be a pointer to a "symptom" of the problem…
>
> // FIXME - we should check if the destination process really listens
> // for read, otherwise we may end up filling in the pipe and block
>
> but, I really want to know why it's blocking on the IPC comms before that.
>
> Here's the BT.
>
> (gdb) bt full
> #0  0x00007f1e4ce9b297 in __libc_write (fd=fd at entry=195, buf=buf at entry=0x7fffc86261b0, nbytes=nbytes at entry=24) at ../sysdeps/unix/sysv/linux/write.c:26
>         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  0x000055ddea5cad33 in __ipc_send_job (payload2=0x0, payload1=0x55ddea590760 <rpc_get_pkg_stats>, type=0, fd=195) at ipc.c:171
>         job = {snd_proc = 1, handler_type = 0, payload1 = 0x55ddea590760 <rpc_get_pkg_stats>, payload2 = 0x0}
>         n = <optimized out>
>         job = <optimized out>
>         n = <optimized out>
>         __FUNCTION__ = "__ipc_send_job"
> #2  ipc_send_rpc (dst_proc=dst_proc at entry=46, rpc=rpc at entry=0x55ddea590760 <rpc_get_pkg_stats>, param=param at entry=0x0) at ipc.c:194
>
>