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 612971 - [alsasink] reset() doesn't unblock write()
[alsasink] reset() doesn't unblock write()
Status: RESOLVED OBSOLETE
Product: GStreamer
Classification: Platform
Component: gst-plugins-base
unspecified
Other Linux
: Normal critical
: git master
Assigned To: GStreamer Maintainers
GStreamer Maintainers
Depends on:
Blocks:
 
 
Reported: 2010-03-15 19:06 UTC by Dan
Modified: 2010-03-18 13:11 UTC
See Also:
GNOME target: ---
GNOME version: 2.27/2.28


Attachments
Rhythmbox stack trace (25.10 KB, text/plain)
2010-03-15 19:20 UTC, Dan
  Details
output of $ GST_DEBUG=alsa*:5 rhythmbox (64.35 KB, text/plain)
2010-03-16 16:13 UTC, Dan
  Details
alsasink: Exit write loop if _reset() is called (1.99 KB, patch)
2010-03-16 19:41 UTC, Sebastian Dröge (slomo)
rejected Details | Review

Description Dan 2010-03-15 19:06:41 UTC
Version: 0.12.7

Overview:
After I start rhythmbox and play any file (mp3, ogg, m4a, flac) the file will play for 0-2 seconds, then cease.  If I press the next track button, or double-click another file, rhythmbox fades to gray and stays like that until I kill it.

Steps to Reproduce:
1. Play any file.

Build Date & Platform:
Rhythmbox 0.12.7 on Ubuntu 9.10 Karmic x64


Additional Information:
I had the same bug with Songbird 1.4.3 which has a workaround of passing the
SB_GST_NO_SYSTEM environment variable to songbird at startup.  (That has
something to do with Songbird not playing well with gstreamer-ugly.)
SB_GST_NO_SYSTEM=1 /usr/bin/songbird

I am experiencing a very similar bug with Banshee.  https://bugzilla.gnome.org/show_bug.cgi?id=612756


Distribution: Ubuntu 9.10 (karmic)
Gnome Release: 2.28.1 2009-11-03 (Ubuntu)
BugBuddy Version: 2.28.0
Comment 1 Dan 2010-03-15 19:20:48 UTC
Created attachment 156210 [details]
Rhythmbox stack trace
Comment 2 Jonathan Matthew 2010-03-15 20:12:43 UTC
If you're seeing the same bug with three different GStreamer applications, it's pretty safe to assume it's a GStreamer bug.
Comment 3 Fabio Durán Verdugo 2010-03-15 20:41:21 UTC
here paste de trace

(gdb) thread apply all bt

Thread 1 (Thread 0x7ffff7fb77d0 (LWP 30253))

  • #0 __lll_lock_wait
    from /lib/libpthread.so.0
  • #1 _L_lock_949
    from /lib/libpthread.so.0
  • #2 pthread_mutex_lock
    from /lib/libpthread.so.0
  • #3 gst_alsasink_reset
    at gstalsasink.c line 942
  • #4 gst_audioringbuffer_pause
    at gstaudiosink.c line 516
  • #5 gst_ring_buffer_pause_unlocked
    at gstringbuffer.c line 1189
  • #6 gst_ring_buffer_pause
    at gstringbuffer.c line 1232
  • #7 gst_base_audio_sink_change_state
    at gstbaseaudiosink.c line 1799
  • #8 gst_element_change_state
    at gstelement.c line 2548
  • #9 gst_element_set_state_func
  • #10 gst_bin_element_set_state
    at gstbin.c line 2118
  • #11 gst_bin_change_state_func
    at gstbin.c line 2417
  • #12 gst_element_change_state
    at gstelement.c line 2548
  • #13 gst_element_set_state_func
    at gstelement.c line 2504
  • #14 gst_bin_element_set_state
    at gstbin.c line 2118
  • #15 gst_bin_change_state_func
    at gstbin.c line 2417
  • #16 gst_switch_sink_change_state
    at gstswitchsink.c line 255
  • #17 gst_gconf_audio_sink_change_state
    at gstgconfaudiosink.c line 299
  • #18 gst_element_change_state
    at gstelement.c line 2548
  • #19 gst_element_set_state_func
    at gstelement.c line 2504
  • #20 gst_bin_element_set_state
  • #21 gst_bin_change_state_func
    at gstbin.c line 2417
  • #22 gst_element_change_state
    at gstelement.c line 2548
  • #23 gst_element_set_state_func
    at gstelement.c line 2504
  • #24 gst_bin_element_set_state
    at gstbin.c line 2118
  • #25 gst_bin_change_state_func
    at gstbin.c line 2417
  • #26 gst_element_change_state
    at gstelement.c line 2548
  • #27 gst_element_set_state_func
    at gstelement.c line 2504
  • #28 gst_bin_element_set_state
    at gstbin.c line 2118
  • #29 gst_bin_change_state_func
    at gstbin.c line 2417
  • #30 gst_play_sink_change_state
    at gstplaysink.c line 2679
  • #31 gst_element_change_state
    at gstelement.c line 2548
  • #32 gst_element_set_state_func
    at gstelement.c line 2504
  • #33 gst_bin_element_set_state
    at gstbin.c line 2118
  • #34 gst_bin_change_state_func
    at gstbin.c line 2417
  • #35 gst_pipeline_change_state
    at gstpipeline.c line 467
  • #36 gst_play_bin_change_state
    at gstplaybin2.c line 2865
  • #37 gst_element_change_state
    at gstelement.c line 2548
  • #38 gst_element_set_state_func
    at gstelement.c line 2504
  • #39 set_state_and_wait
    at rb-player-gst.c line 580
  • #40 impl_play
    at rb-player-gst.c line 846
  • #41 rb_shell_player_open_location
    at rb-shell-player.c line 1551
  • #42 rb_shell_player_set_playing_entry
    at rb-shell-player.c line 1667
  • #43 rb_shell_player_do_next_internal
    at rb-shell-player.c line 2119
  • #44 rb_shell_player_cmd_next
    at rb-shell-player.c line 2187
  • #45 IA__g_closure_invoke
    at /build/buildd/glib2.0-2.22.3/gobject/gclosure.c line 767
  • #46 signal_emit_unlocked_R
    at /build/buildd/glib2.0-2.22.3/gobject/gsignal.c line 3247
  • #47 IA__g_signal_emit_valist
    at /build/buildd/glib2.0-2.22.3/gobject/gsignal.c line 2980
  • #48 IA__g_signal_emit
    at /build/buildd/glib2.0-2.22.3/gobject/gsignal.c line 3037
  • #49 _gtk_action_emit_activate
    at /build/buildd/gtk+2.0-2.18.3/gtk/gtkaction.c line 727
  • #50 button_clicked
    at /build/buildd/gtk+2.0-2.18.3/gtk/gtktoolbutton.c line 705
  • #51 IA__g_closure_invoke
    at /build/buildd/glib2.0-2.22.3/gobject/gclosure.c line 767
  • #52 signal_emit_unlocked_R
    at /build/buildd/glib2.0-2.22.3/gobject/gsignal.c line 3247
  • #53 IA__g_signal_emit_valist
    at /build/buildd/glib2.0-2.22.3/gobject/gsignal.c line 2980
  • #54 IA__g_signal_emit
    at /build/buildd/glib2.0-2.22.3/gobject/gsignal.c line 3037
  • #55 gtk_real_button_released
    at /build/buildd/gtk+2.0-2.18.3/gtk/gtkbutton.c line 1707
  • #56 IA__g_closure_invoke
  • #57 signal_emit_unlocked_R
    at /build/buildd/glib2.0-2.22.3/gobject/gsignal.c line 3177
  • #58 IA__g_signal_emit_valist
    at /build/buildd/glib2.0-2.22.3/gobject/gsignal.c line 2980
  • #59 IA__g_signal_emit
    at /build/buildd/glib2.0-2.22.3/gobject/gsignal.c line 3037
  • #60 gtk_button_button_release
    at /build/buildd/gtk+2.0-2.18.3/gtk/gtkbutton.c line 1599
  • #61 _gtk_marshal_BOOLEAN__BOXED
    at /build/buildd/gtk+2.0-2.18.3/gtk/gtkmarshalers.c line 84
  • #62 IA__g_closure_invoke
  • #63 signal_emit_unlocked_R
    at /build/buildd/glib2.0-2.22.3/gobject/gsignal.c line 3285
  • #64 IA__g_signal_emit_valist
    at /build/buildd/glib2.0-2.22.3/gobject/gsignal.c line 2990
  • #65 IA__g_signal_emit
    at /build/buildd/glib2.0-2.22.3/gobject/gsignal.c line 3037
  • #66 gtk_widget_event_internal
    at /build/buildd/gtk+2.0-2.18.3/gtk/gtkwidget.c line 4767
  • #67 IA__gtk_propagate_event
    at /build/buildd/gtk+2.0-2.18.3/gtk/gtkmain.c line 2417
  • #68 IA__gtk_main_do_event
    at /build/buildd/gtk+2.0-2.18.3/gtk/gtkmain.c line 1622
  • #69 gdk_event_dispatch
    at /build/buildd/gtk+2.0-2.18.3/gdk/x11/gdkevents-x11.c line 2369
  • #70 g_main_dispatch
    at /build/buildd/glib2.0-2.22.3/glib/gmain.c line 1960
  • #71 IA__g_main_context_dispatch
    at /build/buildd/glib2.0-2.22.3/glib/gmain.c line 2513
  • #72 g_main_context_iterate
    at /build/buildd/glib2.0-2.22.3/glib/gmain.c line 2591
  • #73 IA__g_main_loop_run
    at /build/buildd/glib2.0-2.22.3/glib/gmain.c line 2799
  • #74 IA__gtk_main
    at /build/buildd/gtk+2.0-2.18.3/gtk/gtkmain.c line 1218
  • #75 main
    at main.c line 332

Comment 4 Sebastian Dröge (slomo) 2010-03-16 14:38:59 UTC
Looks like a problem in alsasink's _reset() function. It takes the alsa sink lock before doing anything but the same lock is also hold by the _write() function. _write() could in theory loop forever while holding the lock.

It might be possible to release the lock after every iteration instead.
Comment 5 Sebastian Dröge (slomo) 2010-03-16 14:49:13 UTC
But that's only the hanging when switching to the next track it seems. Would be interesting to know why it stops at first.

Could you run rhythmbox with GST_DEBUG=alsa*:5 , get it to hang again and attach the output here?
Comment 6 Dan 2010-03-16 16:13:35 UTC
Created attachment 156279 [details]
output of $ GST_DEBUG=alsa*:5 rhythmbox

This generated a lot of output to the terminal.  Thousands of lines per second.  I think I caught the highlights.

Playback is choppy, but now it usually doesn't quit after just a few seconds.

I hope this helps, let me know if I can give you anything else.
Comment 7 Sebastian Dröge (slomo) 2010-03-16 19:41:15 UTC
Created attachment 156298 [details] [review]
alsasink: Exit write loop if _reset() is called
Comment 8 Sebastian Dröge (slomo) 2010-03-16 19:43:12 UTC
(In reply to comment #7)
> Created an attachment (id=156298) [details] [review]
> alsasink: Exit write loop if _reset() is called

This should fix the hanging after switching to the next track. Can you confirm this?

The other, first problem, seems to be a bug in the pulseaudio alsa module or something. For some reason it reports that the resource is temporary unavailable after some time and then nothing works anymore.
Comment 9 Dan 2010-03-16 20:08:05 UTC
I'd be happy to test this patch, but I'll need some help.  I don't know where to begin.
Comment 10 Sebastian Dröge (slomo) 2010-03-17 08:22:19 UTC
You could download http://gstreamer.freedesktop.org/src/gst-plugins-base/gst-plugins-base-0.10.28.tar.gz , uncompress it ( tar xfz ), apply the patch in the newly created directory ( patch -Np1 < file ), call ./configure && make and copy the ext/alsa/.libs/libgstalsa.so file to /usr/lib/gstreamer-0.10

Which distribution are you using btw? If you're using Ubuntu karmic you should update your gstreamer packages from https://launchpad.net/~gstreamer-developers/+archive/ppa first.
Comment 11 Dan 2010-03-18 12:37:04 UTC
I am using Karmic, so I added the gstreamer-developers ppa and updated.  There was a new kernel in the update manager, so I restarted.  After the restart, rhythmbox and banshee sound great and I can't reproduce the bug.

When I run:$ GST_DEBUG=alsa*:5 rhythmbox 
I get a lot of this:

0:03:25.762074648  4978 0x7f390800b270 DEBUG                   alsa gstalsasink.c:886:gst_alsasink_write:<alsasink2> written 441 frames out of 441
0:03:25.762087755  4978 0x7f390800b270 LOG                     alsa gstalsasink.c:871:gst_alsasink_write:<alsasink2> received audio samples buffer of 1764 bytes
0:03:25.802165770  4978 0x7f390800b270 DEBUG                   alsa gstalsasink.c:886:gst_alsasink_write:<alsasink2> written -11 frames out of 441
0:03:25.802209360  4978 0x7f390800b270 DEBUG                   alsa gstalsasink.c:888:gst_alsasink_write:<alsasink2> Write error: Resource temporarily unavailable
0:03:25.812469680  4978 0x7f390800b270 DEBUG                   alsa gstalsasink.c:886:gst_alsasink_write:<alsasink2> written 441 frames out of 441
0:03:25.812494004  4978 0x7f390800b270 LOG                     alsa gstalsasink.c:871:gst_alsasink_write:<alsasink2> received audio samples buffer of 1764 bytes
0:03:25.812511579  4978 0x7f390800b270 DEBUG                   alsa gstalsasink.c:886:gst_alsasink_write:<alsasink2> written 441 frames out of 441
0:03:25.812524323  4978 0x7f390800b270 LOG                     alsa gstalsasink.c:871:gst_alsasink_write:<alsasink2> received audio samples buffer of 1764 bytes
0:03:25.812540254  4978 0x7f390800b270 DEBUG                   alsa gstalsasink.c:886:gst_alsasink_write:<alsasink2> written 441 frames out of 441
0:03:25.812552783  4978 0x7f390800b270 LOG                     alsa gstalsasink.c:871:gst_alsasink_write:<alsasink2> received audio samples buffer of 1764 bytes
0:03:25.812567905  4978 0x7f390800b270 DEBUG                   alsa gstalsasink.c:886:gst_alsasink_write:<alsasink2> written 441 frames out of 441
0:03:25.812580284  4978 0x7f390800b270 LOG                     alsa gstalsasink.c:871:gst_alsasink_write:<alsasink2> received audio samples buffer of 1764 bytes
0:03:25.812596745  4978 0x7f390800b270 DEBUG                   alsa gstalsasink.c:886:gst_alsasink_write:<alsasink2> written 441 frames out of 441
0:03:25.812609438  4978 0x7f390800b270 LOG                     alsa gstalsasink.c:871:gst_alsasink_write:<alsasink2> received audio samples buffer of 1764 bytes
0:03:25.852685186  4978 0x7f390800b270 DEBUG                   alsa gstalsasink.c:886:gst_alsasink_write:<alsasink2> written -11 frames out of 441
0:03:25.852726884  4978 0x7f390800b270 DEBUG                   alsa gstalsasink.c:888:gst_alsasink_write:<alsasink2> Write error: Resource temporarily unavailable
0:03:25.866386089  4978 0x7f390800b270 DEBUG                   alsa gstalsasink.c:886:gst_alsasink_write:<alsasink2> written 441 frames out of 441

Should I still go ahead and test that patch?
Comment 12 Sebastian Dröge (slomo) 2010-03-18 13:11:14 UTC
No, it's all fine then I guess. Please file a bug against the pulseaudio alsa module for the "Resource
temporarily unavailable" errors though, that should really be fixed :)