GNOME Bugzilla – Bug 698305
cache-test refcounting test fails sporadically
Last modified: 2013-08-23 17:36:00 UTC
If you run cache-test repeatedly, it will eventually fail with: ... Cache refcounting tests Checking that the base stream is properly unref'ed leaked GInputStream!
This seems to happen quite a lot on slow architectures (we have regular build failures in Debian/Ubuntu due to this). I have a really hard time reproducing this on my fast desktop machine (takes 150 repetitions and more), and in 300 iterations I hit it just once on my nexus 7 (arm). OTOH it is quite easy to reproduce on Debian's mips porter box, only takes two or three tries. However, at first sight this doesn't look timing related. None of this happens asynchronously, does it? GWeakNotifys are called synchronously, unreffing happens synchronously, and the test doesn't even have a GMainLoop. Are you aware of anything async in the test or libsoup which could perhaps grab a second ref to stream? Could this be a race condition with memory allocation/alignment? I tried to declare the base_stream pointer as "volatile", but that didn't help.
(In reply to comment #1) > Are you aware of anything async in the test or libsoup which could perhaps > grab a second ref to stream? I tested that theory, that's not it. G_IS_OBJECT(stream) is true right before g_object_unref (stream) and false afterwards, so that _unref call indeed was the last instance.
stepping through with gdb shows that the soup threads end at different times here. In the working case, one gets ------------ 8< -------------- 604 stream = soup_test_request_send (SOUP_REQUEST (req), NULL, flags, &error); (gdb) [New Thread 0x2c687450 (LWP 7413)] 605 if (!stream) { (gdb) 613 base_stream = g_filter_input_stream_get_base_stream (G_FILTER_INPUT_STREAM (stream)); (gdb) 614 g_object_add_weak_pointer (G_OBJECT (base_stream), (gpointer *)&base_stream); (gdb) 616 g_clear_object (&req); (gdb) p base_stream $1 = (GInputStream *) 0x557a80 (gdb) p stream $2 = (GInputStream *) 0x613f20 (gdb) n 617 debug_printf (1, "before unref: is object: %i, base stream: %p\n", G_IS_OBJECT(stream), base_stream); (gdb) n [Thread 0x2c687450 (LWP 7413) exited] before unref: is object: 1, base stream: 0x557a80 618 g_object_unref (stream); (gdb) n 619 debug_printf (1, "after unref: is object: %i, base stream: %p\n", G_IS_OBJECT(stream), base_stream); (gdb) n after unref: is object: 0, base stream: (nil) 621 debug_printf (1, " Checking that the base stream is properly unref'ed\n"); ------------ 8< -------------- i. e. the thread ends before the g_object_unref(), then base_stream gets NULLed properly. But in the failing case we get: ------------ 8< -------------- 613 base_stream = g_filter_input_stream_get_base_stream (G_FILTER_INPUT_STREAM (stream)); (gdb) n 614 g_object_add_weak_pointer (G_OBJECT (base_stream), (gpointer *)&base_stream); (gdb) n 616 g_clear_object (&req); (gdb) n 617 debug_printf (1, "before unref: is object: %i, base stream: %p\n", G_IS_OBJECT(stream), base_stream); (gdb) n before unref: is object: 1, base stream: 0x48b680 618 g_object_unref (stream); (gdb) 619 debug_printf (1, "after unref: is object: %i, base stream: %p\n", G_IS_OBJECT(stream), base_stream); (gdb) after unref: is object: 0, base stream: 0x48b680 621 debug_printf (1, " Checking that the base stream is properly unref'ed\n"); (gdb) p base_stream $3 = (GInputStream *) 0x48b680 (gdb) n Checking that the base stream is properly unref'ed [Thread 0x2c687450 (LWP 8102) exited] 622 if (base_stream) { ------------ 8< -------------- I. e. the soup thread ends after the _unref(). g_object_add_weak_pointer()'s documentation says Note that as with g_object_weak_ref(), the weak references created by this method are not thread-safe: they cannot safely be used in one thread if the object's last g_object_unref() might happen in another thread. Use GWeakRef if thread-safety is required. Now, it doesn't look like the unref would happen in another thread, but maybe that other thread still has some references?
> Now, it doesn't look like the unref would happen in another thread, but maybe > that other thread still has some references? Yeah, seems like this is probably somehow related to the cancel_request_thread() created by soup_test_request_send(), but I tried a few obvious-looking fixes (notably changing the g_thread_unref() to g_thread_join()) and they didn't fix it...
OK, I changed the test to wait for the stream to be destroyed, rather than asserting that it already has been.