GNOME Bugzilla – Bug 758282
OGG streams buffer constantly even with plenty of bandwidth
Last modified: 2016-03-11 15:56:24 UTC
Using: Fedora 23 Rhythmbox 3.2.1, installed from Fedora's official repositories When listening to streaming music, Rhythmbox buffers constantly. The buffering widget fills up, then "empties" and proceeds to fill up again. This cycle repeats every ~2 seconds, and while this cycle happens, music is infrequently played. This happened while playing an MP3 stream and an OGG stream. The same stream, when played through any other application that can play streaming audio, plays with no issue (i. e. VLC, the web page itself in Firefox via HTML5 Audio). The other applications buffer nowhere at the same rate as in Rhythmbox, so I don't believe it is the result of a slow internet connection. Steps to reproduce: 1. Open Rhythmbox 2. Play the stream: http://relay-nyc.gameowls.com:8000/chiptune.ogg Expected results: 1. Music plays. Buffering occurs infrequently. Received results: 1. Music may play, and buffering may occur in ~10-15 seconds. Once the current song ends, the title of the next song displays and the buffering widget displays "Buffering" with a climbing progress bar. When the progress bar becomes full, it empties, no audio is played, and the buffering process begins again. This doesn't happen 100% of the time, but the likelihood that this does happen increases the longer one listens to a stream.
The symptoms described above now only happen with OGG streams. I think that I've updated gstreamer since the last bug report, but Rhythmbox remains unchanged. I now doubt Rhythmbox is involved, but I'm unsure how to debug this further. The version of gstreamer in the original report was 1.6.0. The version of gstreamer I currently have is 1.6.2.
I'm able to duplicate the symptoms with this OGG radio stream as well: http://stream-dc1.radioparadise.com/rp_192m.ogg I was incorrect about the symptoms being unchanged. If I select an OGG stream, the currently playing song in the stream plays fine. When the stream changes to the next song, buffering issues begin. I was trying to find out how to produce more debugging info. Running rhythmbox -d led me to rb-player-gst.c There's a block that begins on line 599 that begins: case GST_MESSAGE_BUFFERING: { gint progress; structure = gst_message_get_structure (message); if (!gst_structure_get_int (structure, "buffer-percent", &progress)) { g_warning ("Could not get value from BUFFERING message"); break; } ... } I added the line: rb_debug("buffering percent: %d", progress); so I could see how much has been buffered. After the first song finishes playing, I get output like this: (20:37:30) [0x1fc0590] [streaming_title_request_cb] rb-streaming-source.c:262: returning streaming title "John Butler Trio - Losing You" to extra metadata request (20:37:30) [0x1fc0590] [tick_cb] rb-shell-player.c:2582: tick: [http://stream-dc1.radioparadise.com/rp_96m.ogg, 205567159113:0(0)] (20:37:30) [0x1fc0590] [emit_properties_idle] rb-mpris-plugin.c:168: emitting Seeked; new time 205567159 (20:37:31) [0x1fc0590] [bus_cb] rb-player-gst.c:608: buffering percent: 2 (20:37:31) [0x1fc0590] [rb_header_sync] rb-header.c:848: syncing with http://stream-dc1.radioparadise.com/rp_96m.ogg (20:37:31) [0x1fc0590] [streaming_title_request_cb] rb-streaming-source.c:262: returning streaming title "John Butler Trio - Losing You" to extra metadata request (20:37:31) [0x1fc0590] [bus_cb] rb-player-gst.c:608: buffering percent: 0 (20:37:31) [0x1fc0590] [rb_header_sync] rb-header.c:848: syncing with http://stream-dc1.radioparadise.com/rp_96m.ogg (20:37:31) [0x1fc0590] [streaming_title_request_cb] rb-streaming-source.c:262: returning streaming title "John Butler Trio - Losing You" to extra metadata request (20:37:31) [0x1fc0590] [bus_cb] rb-player-gst.c:608: buffering percent: 2 (20:37:31) [0x1fc0590] [rb_header_sync] rb-header.c:848: syncing with http://stream-dc1.radioparadise.com/rp_96m.ogg (20:37:31) [0x1fc0590] [streaming_title_request_cb] rb-streaming-source.c:262: returning streaming title "John Butler Trio - Losing You" to extra metadata request (20:37:31) [0x1fc0590] [bus_cb] rb-player-gst.c:608: buffering percent: 0 (20:37:31) [0x1fc0590] [rb_header_sync] rb-header.c:848: syncing with http://stream-dc1.radioparadise.com/rp_96m.ogg (20:37:31) [0x1fc0590] [streaming_title_request_cb] rb-streaming-source.c:262: returning streaming title "John Butler Trio - Losing You" to extra metadata request (20:37:31) [0x1fc0590] [bus_cb] rb-player-gst.c:608: buffering percent: 1 (20:37:31) [0x1fc0590] [rb_header_sync] rb-header.c:848: syncing with http://stream-dc1.radioparadise.com/rp_96m.ogg (20:37:31) [0x1fc0590] [streaming_title_request_cb] rb-streaming-source.c:262: returning streaming title "John Butler Trio - Losing You" to extra metadata request (20:37:31) [0x1fc0590] [bus_cb] rb-player-gst.c:608: buffering percent: 0 (20:37:31) [0x1fc0590] [rb_header_sync] rb-header.c:848: syncing with http://stream-dc1.radioparadise.com/rp_96m.ogg (20:37:31) [0x1fc0590] [streaming_title_request_cb] rb-streaming-source.c:262: returning streaming title "John Butler Trio - Losing You" to extra metadata request (20:37:31) [0x1fc0590] [tick_cb] rb-shell-player.c:2582: tick: [http://stream-dc1.radioparadise.com/rp_96m.ogg, 205567159113:0(0)] (20:37:31) [0x1fc0590] [tick_cb] rb-shell-player.c:2582: tick: [http://stream-dc1.radioparadise.com/rp_96m.ogg, 205567159113:0(0)] (20:37:31) [0x1fc0590] [bus_cb] rb-player-gst.c:608: buffering percent: 2 (20:37:31) [0x1fc0590] [rb_header_sync] rb-header.c:848: syncing with http://stream-dc1.radioparadise.com/rp_96m.ogg (20:37:31) [0x1fc0590] [streaming_title_request_cb] rb-streaming-source.c:262: returning streaming title "John Butler Trio - Losing You" to extra metadata request (20:37:31) [0x1fc0590] [bus_cb] rb-player-gst.c:608: buffering percent: 0 (20:37:31) [0x1fc0590] [rb_header_sync] rb-header.c:848: syncing with http://stream-dc1.radioparadise.com/rp_96m.ogg Does anyone know why the buffering percent would oscillate between 2 and 0?
Do you get the same symptoms if you run 'gst-launch-1.0 -m playbin uri=http://stream-dc1.radioparadise.com/rp_192m.ogg' in a terminal?
Yes; whatever song is currently being streamed continues to play normally until finished. When the next song in the stream begins to play, I get no audio and console output resembling the following: Buffering, setting pipeline to PAUSED ... Done buffering, setting pipeline to PLAYING Buffering, setting pipeline to PAUSED ... Buffering... 60% I've also tried changing the buffer-size, and this doesn't seem to give different results. This seems to be a gstreamer issue and not a rhythmbox issue.
I can see the problem with gst-play-1.0 (with both streams). So it's definitely a gst bug.
It looks like the running time is not getting accumulated, causing the next chain to restart from 0 in basesink, which drops all buffers. This used to work, but a quick revert a few months back shows it's still broken.
Created attachment 320501 [details] [review] fix chaining causing running time to restart from 0 As usual, segments confuse the hell out of me.
commit 603e2fe24afeaae64807b1abd4ef1b04b03b82d5 Author: Vincent Penquerc'h <vincent.penquerch@collabora.co.uk> Date: Fri Feb 5 14:14:37 2016 +0000 oggdemux: fix chaining causing running time to restart from 0 This fixes: gst-play-1.0 http://relay-nyc.gameowls.com:8000/chiptune.ogg https://bugzilla.gnome.org/show_bug.cgi?id=758282