After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 670846 - deadlock: GStreamer-WARNING **: wrong STREAM_LOCK count 0
deadlock: GStreamer-WARNING **: wrong STREAM_LOCK count 0
Status: RESOLVED FIXED
Product: glib
Classification: Platform
Component: gthread
2.31.x
Other Linux
: Normal blocker
: ---
Assigned To: gtkdev
gtkdev
: 671668 (view as bug list)
Depends on:
Blocks:
 
 
Reported: 2012-02-26 19:57 UTC by Jacob Peddicord
Modified: 2012-03-09 15:38 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
GDB backtrace of frozen Totem (14.37 KB, text/plain)
2012-02-26 19:57 UTC, Jacob Peddicord
  Details
Totem trace near warning (45.95 KB, text/plain)
2012-02-27 21:41 UTC, Jacob Peddicord
  Details
Fix race condition in g_static_rec_mutex_unlock_full() (518 bytes, patch)
2012-03-09 12:11 UTC, Mark Janossy
none Details | Review
deprecated threads: fix race in GStaticRecMutex (1.45 KB, patch)
2012-03-09 15:09 UTC, Allison Karlitskaya (desrt)
committed Details | Review

Description Jacob Peddicord 2012-02-26 19:57:59 UTC
Created attachment 208450 [details]
GDB backtrace of frozen Totem

(Originally reported on Launchpad: https://bugs.launchpad.net/ubuntu/+source/gstreamer0.10/+bug/941229)

Banshee, Totem, and other GStreamer applications all suffer from a very annoying bug where they will lock up when trying to interact with them while media is playing. It's hard to describe, but here are the main points:

* When the application locks up, "GStreamer-WARNING **: wrong STREAM_LOCK count 0" is output.
* I have tested this with quite a diverse MP3 library.
* This happens **most frequently** using gstreamer0.10-fluendo-mp3.
* This happens less frequently when using lame/mad from gstreamer0.10-plugins-ugly.
* I am unable to reproduce this issue with OGG/Vorbis audio.

Steps to reproduce (Ubuntu 12.04):
1. Install gstreamer0.10-fluendo-mp3, as it is easiest to trigger the bug (works with gstreamer0.10-plugins-ugly as well, just not as often).
2. Open any MP3 in Totem from the terminal.
3. Seek madly for 5-10 seconds or until it freezes. (Sometimes the freeze is instantaneous, sometimes it takes a few seconds of trying.)
4. Observe the GStreamer warning message and deadlock.

This has been *very* difficult to pin down, as it happens seemingly at random. I'm attaching a backtrace of Totem's state during the freeze. Some points of note:

* The "GStreamer-CRITICAL" message is unrelated to the freezing from what I can tell, as it doesn't show up during other traces I've done.
* ^C is where it froze.
* #10 is libgstflump3dec.so -- could not find debugging symbols for this, but as it happens with the other MP3 decoders as well, I don't think the problem lies in the MP3 plugins themselves.

Something I've noticed while testing this: it appears to freeze more often around when threads are created/destroyed.

I've marked this as "major" because it often prevents somewhat basic functionality (seeking and track switching) from happening, please switch if I misjudged.
Let me know if there's any more information I can provide.
Comment 1 Tim-Philipp Müller 2012-02-26 20:21:09 UTC
What GLib version is this with?

What gst-plugins-good version? (gst-inspect-0.10 mpegaudioparse | grep Version)
Comment 2 Jacob Peddicord 2012-02-26 20:25:18 UTC
GLib 2.31.18 (-0ubuntu2).
gst-plugins-good 0.10.31.

Also, I forgot to mention this, but I tried to get a dump with GST_DEBUG=*:5, however the log quickly grew to hundreds of megabytes just starting Totem. Can still try to get one around the lockup if it's useful.
Comment 3 Tim-Philipp Müller 2012-02-27 13:02:53 UTC
Not sure yet if this is a GLib regression or something on our side, but marking as blocker for now so we don't forget.

However, could you make a new stack trace please, using 'break g_logv' before starting ('run' in gdb), then doing 'c' (for continue) at the first break, so you stop again at the second warning.

Then do 'thread apply bt all' when you've reached the right warning.
Comment 4 Jacob Peddicord 2012-02-27 21:41:27 UTC
Created attachment 208535 [details]
Totem trace near warning

Attaching a backtrace of totem around the warning message. Also includes a bunch of continues from the gdb session; there was a lot of debug-level logging going on. Interesting stuff happens at the break on line 312, followed by the backtrace, followed by the freeze.
Comment 5 Tim-Philipp Müller 2012-02-28 12:53:45 UTC
Also seen this warning in -base unit tests on Edward's gentoo build bot, so confirming.
Comment 6 Mark Janossy 2012-03-06 15:04:39 UTC
Had the same problem, and it seems like glib is the source. Using the 2.31.6 development build, I was getting the same deadlock when trying to seek repeatedly. Completely downgrading the glib version was not an option on the platform, but I changed the GStaticRecMutex implementation back to that of 2.30.2, and the deadlock seems to have gone.
Hope someone can confirm this, and report it as a glib bug. In the meantime, I suggest checking your glib version and updating to the last stable release (2.30.2).
Btw the GStaticRecMutex is deprecated in the new glib, so updated versions of gstreamer will hopefully avoid it along with this bug it causes.
Comment 7 Tim-Philipp Müller 2012-03-06 15:26:17 UTC
> Btw the GStaticRecMutex is deprecated in the new glib, so updated versions of
> gstreamer will hopefully avoid it along with this bug it causes.

GStaticRecMutex is part of our API and ABI, we can't change it in the 0.10.x series (but it has already been changed in the 0.11.x development series).
Comment 8 Allison Karlitskaya (desrt) 2012-03-06 15:35:40 UTC
Maybe see bug 661914?
Comment 9 Tim-Philipp Müller 2012-03-06 21:00:53 UTC
This happens even with older gstreamer core/base versions.

It's also racy here (the adder test, need to do make elements/adder.torture to trigger it). The fact that it's racy makes me think the issue might be in GStreamer, though it's a mystery to me why this wouldn't have shown up before as well.

If anyone's interested, it seems to be the stream lock for the sourcepad of one of the two sources that's causing the problem.
Comment 10 Mark Janossy 2012-03-09 12:11:06 UTC
Created attachment 209312 [details] [review]
Fix race condition in g_static_rec_mutex_unlock_full()

The mutex->depth member is tested without holding the lock. If another thread is waiting for the lock, it can modify it while the while loop test it. This can lead to the loop running once too may times, potentially causing a deadlock later.
Comment 11 Allison Karlitskaya (desrt) 2012-03-09 14:27:34 UTC
Review of attachment 209312 [details] [review]:

arghgh.  And after so much care taken to ensure that the decrement happened while holding the lock.

This is obviously correct.  Thanks for the research.  Just one minor fix before committing, please.

Also, I assume you ran the tests? :)

::: glib/deprecated/gthread-deprecated.c.orig
@@ +817,1 @@
     {

don't use braces for single statements.
Comment 12 Allison Karlitskaya (desrt) 2012-03-09 15:09:41 UTC
Created attachment 209321 [details] [review]
deprecated threads: fix race in GStaticRecMutex

The very last access to the 'depth' field of GStaticRecMutex in
g_static_rec_mutex_unlock_full() was being performed after dropping the
implementation mutex for the last time.

This allowed the lock to be dropped an additional time if it was
acquired in another thread right at that instant (which is somewhat
likely, since another thread could have just been woken up by the lock
being released).
Comment 13 Allison Karlitskaya (desrt) 2012-03-09 15:10:32 UTC
Attachment 209321 [details] pushed as 265f265 - deprecated threads: fix race in GStaticRecMutex
Comment 14 Tim-Philipp Müller 2012-03-09 15:38:10 UTC
*** Bug 671668 has been marked as a duplicate of this bug. ***