Janus-gateway: Core dump crash on stop_rtp_forward request in videoroom plugin

[digitalsamba]

Hi,

We are noticing every couple of days a core dump crash on Janus in production with a heavy usage. It happens when stop_rtp_forward request is being executed. Here is the GDB backtrace https://pastebin.com/ZjPyC0ei

Looking at the janus_videoroom_rtp_forwarder_destroy method it executes:

g_source_destroy(forward->rtcp_recv);
g_source_unref(forward->rtcp_recv);

And that rtcp_recv is probably used inside g_main_loop_run(rtcpfwd_loop) where crash occurs;

static void *janus_videoroom_rtp_forwarder_rtcp_thread(void *data) {
    JANUS_LOG(LOG_VERB, "Joining RTCP thread for RTP forwarders...\n");
    /* Run the main loop */
    g_main_loop_run(rtcpfwd_loop);
    /* When the loop ends, we're done */
    JANUS_LOG(LOG_VERB, "Leaving RTCP thread for RTP forwarders...\n");
    return NULL;
}

Our understanding is maybe a race condition occurs where that forward->rtcp_recv is being destroyed and somehow that variable is trying to be dereferenced in the rtcpfwd_loop. Basically processing a rtcp packet while the forwarder is being destroyed. Is that a plausible explanation?

Note that it is on Janus 0.9.5, but we searched heavily for commits after 0.9.5 which fix a similar issue and cannot find such a fix. So it is very much possible this issue still exists on master. We will be keep trying hard to reproduce it on master locally, but it is not easy since it happens either under heavy usage/rarely in production. We have a large janus environment and its just not feasible/easily possible to always be on master.

Thank you in advance for any help!

[lminiero]

Sorry but you'll need to test on master before I can check this. Too much has changed since then, especially on addressing how we get rid of users (publishers/subscribers) which may be related.

[lminiero]

PS: you may want to use libasan to collect debugging info in the future, and/or add symbols for glib stuff, as the dump you shared is unfortunately of little use. It just says that something happened while handling an event in the persistent RTCP loop, but nothing else.

[digitalsamba]

Ok, thank you for the answer! We will concentrate on reproducing on master with libasan enabled and share our findings if we manage to reproduce.

[digitalsamba]

Hi again!

We managed to reproduce on 0.10.7 (latest tag from 2 weeks ago) with Libasan enabled. There is more specific info now:

https://pastebin.com/kSbMBxKf

Crash is inside this method:

static void janus_videoroom_rtp_forwarder_rtcp_finalize(GSource *source) {
    janus_videoroom_rtcp_receiver *r = (janus_videoroom_rtcp_receiver *)source;
    /* Remove the reference to the forwarder */
    if(r && r->forward)
        janus_refcount_decrease(&r->forward->ref);
}

If we are understanding correctly the libasan dump -> line 1541 is the if(r && r->forward) check which is crashing. Probably the *source variable is already freed and it is trying to be dereferenced? Is that plausible explanation? A lock is needed?

Hope the info is enough. Thanks in advance!

[atoppi]

The message

GLib-CRITICAL **: 14:10:24.333: source_remove_from_context: assertion 'source_list != NULL' failed

shows that when calling g_source_unref(forward->rtcp_recv) from janus_videoroom_rtp_forwarder_destroy, the GMainContext bound to the source has actually no sources in its list.
It is not clear if this critical from glib has been the cause of the crash however. For sure it is an indication of a problem.

Meanwhile libasan seems to report that while the source is being finalized in janus_videoroom_rtp_forwarder_rtcp_finalize, that source has been already freed and it is weird because glib will call finalize when a source refcount goes to 0 but it waits that finalize ends before actually freeing the source.
Unfortunately the part of libasan that should point to WHERE the data has been freed looks broken.
Did you use these CFLAGS ?
CFLAGS="-O0 -fno-omit-frame-pointer -g3 -ggdb3 -fsanitize=address -fsanitize-address-use-after-scope"

[digitalsamba]

We used these CFLAGS="-O1 -g3 -ggdb3 -fno-omit-frame-pointer -fsanitize=address -fno-sanitize-recover=all -fsanitize-address-use-after-scope" LDFLAGS="-fsanitize=address".
The ones written here -> https://janus.conf.meetecho.com/docs/debug.html
You wrote "-O0" instead of "-O1". Is this a typo? We have no practical libasan experience, that's why we are asking.

[atoppi]

It is not a typo. O0 is the lowest level of optimization, that should grant the most accurate stack trace in case of crash.

[digitalsamba]

Ok, thanks for info. So if we change O1 to O0 there is a possibility you will see the "should point to WHERE the data has been freed looks broken."?

[atoppi]

It is worth a try.
And since we're gathering more info, also enable refcount debug (uncomment #define REFCOUNT_DEBUG) in refcount.h.
It will largely increase the log output size (so check your available space) but it will also track any ref/unref done in janus.

[atoppi]

@digitalsamba is it possibile that you are trying to destroy a forwarder while it is being created ?

[digitalsamba]

@atoppi - We checked, but it doesn't seem to be the case.

[digitalsamba]

@atoppi - What do you think about this GLib issue -> https://gitlab.gnome.org/GNOME/glib/-/merge_requests/675 ?
Could it be related to the GSource* issue we are experiencing? We are using currently glib version "2.56.4", which is before that fix. What version of glib are you using/do you recommend when deploying Janus to production? Hope we are not barking up the wrong tree with this GLib issue, but we thought it is worth asking.

[atoppi]

@digitalsamba it is mentioned that "finalize of a GSource is apparently called twice" and that could explain the issue on janus I guess.
A test with a recent glib is worth a try for sure.

[atoppi]

@digitalsamba did you have the chance to test with a recent glib ?

[digitalsamba]

@atoppi - We upgraded to glib 2.64.3 on one of our installations, we will be rolling out to other installations very soon. We need a few days (up to a week) to run Janus without problems, to be sure that issue is fixed. For now cannot give a definitive answer if issue is fixed, but as soon as we have more data, we will share.

[lminiero]

Any update on this? Can this be closed? If so, we'll add a warning to the logs if glib is older than that.

[digitalsamba]

Hi Lorenzo,

we haven't seen the crash since the glib upgrade, so we are somewhat positive that the issue is fixed.
You can close it, and if we see the issue again, we will reopen, but for now we don't see such crashes.

[digitalsamba]

@lminiero - Closing, since it is not reproducable now, will reopen if it somehow appears again.