[BUG] WARNING:core:timer_ticker: timer task <b2bl-clean> already scheduled, delaying execution

[devoxy1]

Hello!

We experience bug which causes opensips to be unresponsive for SIP requests. At some point opensips just stops processing any requests and throws an error like this in log each second:

WARNING:core:timer_ticker: timer task <b2bl-clean> already scheduled 59710 ms ago (now 168359960 ms), delaying execution
WARNING:core:timer_ticker: timer task <b2bl-clean> already scheduled 60700 ms ago (now 168360950 ms), delaying execution

The problem persists until i restart opensips service, then it works ok for some time and then issue happens again. I don't know what causes it so i cannot reproduce, only act once it happens.
Opensips is configured with b2b module and acts like SBC.

OpenSIPS version you are running

version: opensips 3.4.1 (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: 6a60715e9
main.c compiled on 15:34:50 Sep 20 2023 with gcc 9

Describe the bug
Opensips stops responding to requests and calls to it results in 408 timeout.

To Reproduce
Cannot reproduce, the issue is intermittent.

Expected behavior
Opensips doesn't hang and keeps processing calls.

Relevant System Logs
Since i don't know what causes the issue i enabled debug 7 and waited for issue to rise up again so my log file is quite large. I copied logs preceding the Warning for couple of minutes, but if it is needed i can get logs earlier than this.
https://file.io/dNYt3ar7j2HN

OS/environment information

• Operating System: Ubuntu 20.04.5 LTS
• OpenSIPS installation: git
• other relevant information:

Additional context
I already submitted bug report earlier on this problem but after updating to latest version i haven't seen this for a while. However the issue still persists.

[andingv]

hi @devoxy1 are you doing any blocking operation such as querying the HTTP service or unresponsive DB? I have seen something similar also in the b2b scenarios when the DNS service does not respond, so in all those situations one can see the log lines like this one above about the delayed timer execution. It helped me lookking at the PCAP with DNS queries as an example. HTH

[devoxy1]

Hi @andingv, no, nothing like that. This is purely test stand so there are no integrations or anything, all hosts in dispatcher and drouting are added as IP so it doesn't do any queries to DNS(except for some basic may be), just simple b2b functional. Thanks for the suggestion though, i will try to check tcpdump when this happens next time.

[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.

[devoxy1]

Up, the problem still comes up

[devoxy1]

The issue seems to be a deadlock, I got opensips trap file and can see messages like
Cannot access memory at address 0x20005, but i'm not sure what's causing it as there many modules mentioned in file.

[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.

[devoxy1]

Up

[bogdan-iancu]

The way to progress here is to try to do a trap (via opensips-cli) while you are experiencing this un-responsivness from OpenSIPS.

[devoxy1]

Hello @bogdan-iancu!
Thanks for looking into this. I did several traps, here is the latest one from beginning of November - https://www.transfernow.net/dl/202311274mDfsN5Z.
I can collect another one if needed.

[devoxy1]

@bogdan-iancu
last link might be expired, here is new one https://file.io/hiVCJSl6YMWe

[bogdan-iancu]

thanks @devoxy1 , I might have a lead here pointing to the rtp_relay module....this is the one blocking the B2B engine actually. Let me do more digging here.

[devoxy1]

@bogdan-iancu sounds good! I'm up for providing any info that can help to resolve the issue.
Thanks

[razvancrainea]

@devoxy1 as @bogdan-iancu said, the logs show you are using the rtp_relay module. Can you tell us whether you are engaging rtp_relay in main/request route, or in local_route?

[devoxy1]

Hello @razvancrainea,

We engage rtp_relay under route{} prior to calling b2b_init_request

if (!has_totag()) {
        b2b_server_new("caller",,$avp(extra_hdrs),$avp(extra_hdr_bodies));
        b2b_client_new("callee", "$ru",,,,$avp(b2b_hdrs),$avp(b2b_hdr_bodies));

        $rtp_relay = "replace-origin replace-session-connection";
        $rtp_relay_peer = "replace-origin replace-session-connection";
        rtp_relay_engage("rtpengine",0);
        # initialize B2B session
        b2b_init_request("refer");

        exit;
    }

[devoxy1]

Hello @razvancrainea!

Is there any other information i can provide to help investigating this?

Thank you.

[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.

[devoxy1]

Hello guys! this is still actual

[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.

[devoxy1]

Up

[devoxy1]

Up

[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.

[devoxy1]

The issue is still actual even on the latest version unfortunately (

[devoxy1]

I gathered another trap for this issue https://file.io/0tx8sdqYBKmF
Hope this helps

[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.

[devoxy1]

@razvancrainea Hi, i followed some instructions on how to enable more debugging and was able to collect some more memory information once the issue arises.
Here is logfile with this info https://file.io/vybtUJju7fJh

[devoxy1]

@razvancrainea Hello! I also collected traps from 2 crashes with opensips compiled without any optimizations and more debug. Hope this can clear things up a bit.
https://file.io/XG0fm5z8YiVb

[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.

[devoxy1]

up

[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.

[devoxy1]

Up

[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.

[devoxy1]

up

[devoxy1]

It seems like this deadlock doesn't repeat if we don't use key no-late-sdp in bridge. We have REFER scenario with this key due to remote device not supporting it but recently we changed config to default behavior and we haven't seen this deadlock for couple of weeks. I will keep monitor

[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.

[github-actions]

Marking as closed due to lack of progress for more than 30 days. If this issue is still relevant, please re-open it with additional details.