[Dapper] ogg stream operations causes Rhythmbox to lock

[ian marcinkowski]

There seem to be a couple causes for this.

1) Sometimes switching between two of the default ubuntu ogg streams (http://ubuntu.hbr1.com:19800/trance.ogg or ambient.ogg) will cause rhythmbox to crash. This happens seemingly random, but only after playing a stream for a while. Using the pause/play button to turn the stream off somtimes causes this.

2) When the end of the stream is reached, instead of either stopping playback or reconnecting to the stream, rhythmbox crashes.

Reproducing this bug is a pain because the conditions seem random for #1 and you've got to wait for the ogg stream to end for #2, which only happens every 30-90 minutes.

Here's somg GDB info:

[Thread -1314939984 (LWP 17942) exited]
[Thread -1281369168 (LWP 17944) exited]
[Thread -1245336656 (LWP 17941) exited]
[Thread -1342178384 (LWP 18091) exited]
[Thread -1298154576 (LWP 18093) exited]
[New Thread -1298154576 (LWP 18094)]
[New Thread -1314939984 (LWP 18095)]
[Thread -1289761872 (LWP 18092) exited]

(rhythmbox:17907): GStreamer-WARNING **: Name selector_audio_src0 is not unique in bin playbin, not adding

(rhythmbox:17907): GStreamer-WARNING **: Name preroll_audio_src0 is not unique i n bin playbin, not adding
[New Thread -1289761872 (LWP 18096)]
[New Thread -1342178384 (LWP 18097)]

(rhythmbox:17907): GStreamer-CRITICAL **: pad selector_audio_src0:src returned N ULL caps from getcaps function

** (rhythmbox:17907): WARNING **: could not link EMPTY: -1
[Thread -1342178384 (LWP 18097) exited]
[New Thread -1342178384 (LWP 18098)]
[New Thread -1245336656 (LWP 18099)]
[Thread -1342178384 (LWP 18098) exited]

(rhythmbox:17907): GStreamer-WARNING **: Element preroll_audio_src0 is not in bi n playbin

(rhythmbox:17907): GStreamer-WARNING **: Element selector_audio_src0 is not in b in playbin
[Thread -1298154576 (LWP 18094) exited]

(rhythmbox:17907): GStreamer-WARNING **: Name selector_audio_src0 is not unique in bin playbin, not adding

(rhythmbox:17907): GStreamer-WARNING **: Name preroll_audio_src0 is not unique i n bin playbin, not adding
[New Thread -1298154576 (LWP 18104)]
[New Thread -1342178384 (LWP 18105)]

(rhythmbox:17907): GStreamer-CRITICAL **: pad selector_audio_src0:src returned N ULL caps from getcaps function

** (rhythmbox:17907): WARNING **: could not link EMPTY: -1
[Thread -1342178384 (LWP 18105) exited]
[New Thread -1269826640 (LWP 18106)]
[Thread -1269826640 (LWP 18106) exited]

Above is general debug information generated while rhythmbox was playing the streams normally. Below is what happened when I was switching between the trance and ambient streams.

(rhythmbox:17907): GStreamer-CRITICAL **:
Trying to dispose element preroll_audio_src1, but it is not in the NULL state.
You need to explicitly set elements to the NULL state before
dropping the final reference, to allow them to clean up.

(rhythmbox:17907): GStreamer-CRITICAL **:
Trying to dispose element selector_audio_src1, but it is not in the NULL state.
You need to explicitly set elements to the NULL state before
dropping the final reference, to allow them to clean up.

(rhythmbox:17907): GStreamer-CRITICAL **: gst_object_ref: assertion `GST_IS_OBJECT (object)' failed

(rhythmbox:17907): GLib-GObject-WARNING **: invalid uninstantiatable type `<invalid>' in cast to `GstObject'

[Sebastien Bacher (seb128)]

Thanks for your bug. Could you get a backtrace with gdb?
- gdb rhythmbox
(gdb) run
... get the crash
(gdb) thread apply all bt

[ian marcinkowski (ianmarcinkowski)]

I hope I didn't take you too literally...

Program received signal SIGINT, Interrupt.
[Switching to Thread -1226848576 (LWP 19247)]
0xffffe410 in __kernel_vsyscall ()
(gdb) er-CRITICAL **: gst_object_ref: assertion `GST_IS_OBJECT (object)' failed
Undefined command: "er-CRITICAL". Try "help".
(gdb) thread apply all bt

Thread 131 (Thread -1298158672 (LWP 20822)):
#0 0xffffe410 in __kernel_vsyscall ()
#1 0xb796e2ae in __lll_mutex_lock_wait ()
   from /lib/tls/i686/cmov/libpthread.so.0
#2 0xb796afbb in _L_mutex_lock_33 () from /lib/tls/i686/cmov/libpthread.so.0
#3 0xb29f9158 in ?? ()
#4 0xb7aa46ac in gst_object_get_type () from /usr/lib/libgstreamer-0.10.so.0
#5 0xb7aa5e6e in gst_object_check_uniqueness ()
   from /usr/lib/libgstreamer-0.10.so.0
#6 0xb7aa73f6 in gst_bin_new () from /usr/lib/libgstreamer-0.10.so.0
#7 0xb7aa7b2d in gst_bin_add () from /usr/lib/libgstreamer-0.10.so.0
#8 0xb6bcb2ea in gst_play_base_bin_get_type ()
   from /usr/lib/gstreamer-0.10/libgstplaybin.so
#9 0xb6c0ca8b in gst_play_marshal_VOID__OBJECT_BOOLEAN ()
   from /usr/lib/gstreamer-0.10/libgstdecodebin.so
#10 0xb71e279f in IA__g_closure_invoke (closure=0x88a3928,
    return_value=0xfffffffc, n_param_values=4294967292,
    param_values=0xfffffffc, invocation_hint=0xfffffffc) at gclosure.c:490
#11 0xb71f12ea in signal_emit_unlocked_R (node=0x81a5bb8, detail=0,
    instance=0x816f0e8, emission_return=0x0, instance_and_params=0xb29f953c)
    at gsignal.c:2438
#12 0xb71f2b19 in IA__g_signal_emit_valist (instance=0x816f0e8, signal_id=27,

    detail=0, var_args=<value optimized out>) at gsignal.c:2197
#13 0xb71f2e89 in IA__g_signal_emit (instance=0xfffffffc,
    signal_id=4294967292, detail=4294967292) at gsignal.c:2241
#14 0xb6c0b2e4 in ?? () from /usr/lib/gstreamer-0.10/libgstdecodebin.so
#15 0x0816f0e8 in ?? ()
#16 0x0000001b in ?? ()
#17 0x00000000 in ?? ()

Thread 130 (Thread -1289765968 (LWP 20821)):
#0 0xffffe410 in __kernel_vsyscall ()
#1 0xb796bc76 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /lib/tls/i686/cmov/libpthread.so.0
#2 0xb7ae1061 in gst_task_get_type () from /usr/lib/libgstreamer-0.10.so.0
#3 0xb713f428 in g_thread_pool_thread_proxy (data=0x860ac68)
    at gthreadpool.c:265
#4 0xb713d582 in g_thread_create_proxy (data=0x8a602c8) at gthread.c:582
#5 0xb7969341 in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
#6 0xb70834ee in clone () from /lib/tls/i686/cmov/libc.so.6

Thread 129 (Thread -1256195152 (LWP 20816)):
#0 0xffffe410 in __kernel_vsyscall ()
#1 0xb796bc76 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /lib/tls/i686/cmov/libpthread.so.0

#2 0xb7adc78e in gst_system_clock_obtain ()
   from /usr/lib/libgstreamer-0.10.so.0
#3 0xb713d582 in g_thread_create_proxy (data=0x895b438) at gthread.c:582
#4 0xb7969341 in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
#5 0xb70834ee in clone () from /lib/tls/i686/cmov/libc.so.6

Thread 125 (Thread -1298158672 (LWP 20822)):
#0 0xffffe410 in __kernel_vsyscall ()
#1 0xb796e2ae in __lll_mutex_lock_wait ()
   from /lib/tls/i686/cmov/libpthread.so.0
#2 0xb796afbb in _L_mutex_lock_33 () from /lib/tls/i686/cmov/li...

[Sebastien Bacher (seb128)]

Thank you for the work on that. Could you do the same with the libgstreamer0.10-0-dbg gstreamer0.10-plugins-base-dbg packages installed?

[Sitsofe Wheeler (sitsofe)]

Setting to needsinfo pending reply from ian.

[ian marcinkowski (ianmarcinkowski)]

I havn't had the problem lately because I havn't been listening to those stations and they're currently unreachable.

While rhythmbox (and ogg123, as well) is trying to connect to these streams while they're unreachable, it becomes unresponsive.

After about 5 minutes, Rhythmbox generates the following in gdb during the lock up:
(rhythmbox:21975): Rhythmbox-WARNING **: do_next_idle: Unhandled error: Unknown playback error

After Rhythmbox locks up, I've never waited for it to come back before. Perhaps this is the problem.

ogg123 also locks in the same way. Could it be a protocol error, or an error with the ubuntu.hbr1.com server?

[Sebastien Bacher (seb128)]

do you still have that issue? Does it happen only when the server is not available?

[Oliver Sic (soliver)]

same bug

[Sebastien Bacher (seb128)]

Oliver, your crash happens to libsmooth and is a different problem

[Daniel Holbach (dholbach)]

Can somebody answer https://launchpad.net/ubuntu/+source/rhythmbox/+bug/38754/comments/6 ?

[ian marcinkowski (ianmarcinkowski)]

Things seem pretty good now that I'm using Edgy.

I get a nice little error dialog when the server is unavailable now. I'll try listening for a few hours and see if rhythmbox crashes.

[ian marcinkowski (ianmarcinkowski)]

I hope this is helpful. I installed the rhythmbox-dbg package, if that makes a difference.

Program received signal SIGINT, Interrupt.
[Switching to Thread -1228597056 (LWP 22640)]
0xffffe410 in __kernel_vsyscall ()
(gdb) thread apply all bt

Thread 41 (Thread -1327428704 (LWP 22816)):
#0 0xffffe410 in __kernel_vsyscall ()
#1 0xb7bea816 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /lib/tls/i686/cmov/libpthread.so.0
#2 0xb71ffb38 in gst_system_clock_async_thread (clock=0x8790e00)
    at gstsystemclock.c:257
#3 0xb700038f in g_thread_create_proxy (data=0x887dd88) at gthread.c:553
#4 0xb7be7504 in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
#5 0xb6f0b51e in clone () from /lib/tls/i686/cmov/libc.so.6

Thread 39 (Thread -1339032672 (LWP 22814)):
#0 0xffffe410 in __kernel_vsyscall ()
#1 0xb7bed698 in connect () from /lib/tls/i686/cmov/libpthread.so.0
#2 0xb732554a in gnome_vfs_inet_connection_create_from_address ()
   from /usr/lib/libgnomevfs-2.so.0
#3 0xb2411a6d in ne_sock_connect ()
   from /usr/lib/gnome-vfs-2.0/modules/libhttp.so
#4 0xb2405007 in ne_add_request_header ()
   from /usr/lib/gnome-vfs-2.0/modules/libhttp.so
#5 0xb24064cb in ne_request_dispatch ()
   from /usr/lib/gnome-vfs-2.0/modules/libhttp.so
#6 0xb2405cd9 in ne_begin_request ()
   from /usr/lib/gnome-vfs-2.0/modules/libhttp.so
#7 0xb2402b42 in vfs_module_shutdown ()
   from /usr/lib/gnome-vfs-2.0/modules/libhttp.so
#8 0xb2402f0e in vfs_module_shutdown ()
   from /usr/lib/gnome-vfs-2.0/modules/libhttp.so
#9 0xb731d059 in gnome_vfs_open_uri_cancellable ()
   from /usr/lib/libgnomevfs-2.so.0
#10 0xb7333ff3 in gnome_vfs_open_uri () from /usr/lib/libgnomevfs-2.so.0
#11 0xb3589300 in gst_gnome_vfs_src_start (basesrc=0x866fda0)
    at gstgnomevfssrc.c:793
#12 0xb724c79c in gst_base_src_start (basesrc=0x866fda0) at gstbasesrc.c:1722
#13 0xb724d9cf in gst_base_src_activate_push (pad=0x81deef0, active=1)
    at gstbasesrc.c:1853
#14 0xb71f09c4 in gst_pad_activate_push (pad=0x81deef0, active=1)
    at gstpad.c:860
#15 0xb71f0d05 in gst_pad_activate_default (pad=0x81deef0) at gstpad.c:560
#16 0xb71f0db4 in gst_pad_set_active (pad=0x81deef0, active=1) at gstpad.c:648
#17 0xb71d9adb in activate_pads (pad=0x81deef0, ret=0xb02fee38,
    active=0xb02fee98) at gstelement.c:2261
#18 0xb71e5757 in gst_iterator_fold (it=0x871e860,
    func=0xb71d9ab0 <activate_pads>, ret=0xb02fee38, user_data=0xb02fee98)
    at gstiterator.c:503
#19 0xb71d9552 in iterator_activate_fold_with_resync (iter=0x871e860,
    func=0xb71d9ab0 <activate_pads>, user_data=0xb02fee98) at gstelement.c:2293
#20 0xb71d95ee in gst_element_pads_activate (element=0x866fda0, active=1)
    at gstelement.c:2328
#21 0xb71d9986 in gst_element_change_state_func (element=0x866fda0,
    transition=GST_STATE_CHANGE_READY_TO_PAUSED) at gstelement.c:2401
#22 0xb724ef0f in gst_base_src_change_state (element=0x866fda0,
    transition=GST_STATE_CHANGE_READY_TO_PAUSED) at gstbasesrc.c:1973
#23 0xb71d616a in gst_element_change_state (element=0x866fda0,
    transition=GST_STATE_CHANGE_READY_TO_PAUSED) at gstelement.c:2182
#24 0xb71d6252 in gst_element_change_state (element=0x866fda0,
    transition=GST_STATE_CHANG...

[Sebastien Bacher (seb128)]

Your backtraces don't look like a crash, SIGINT usually means that you got a backtrace with gdb while the program was still working. Could you wait for a crash and then type "thread apply all bt" to get a backtrace from the problem?

[Daniel Holbach (dholbach)]

As described in the previous comments, your report lacks the information we need to investigate the problem further. We'll close this report for now - please reopen it if you can give us the missing information.

[ian marcinkowski (ianmarcinkowski)]

I havn't had this problem in a while.

I've recently upgraded to Feisty Beta and have been listening to rhythmbox a lot. If I get a crash, I'll try to be useful.