Mopidy: Buffering Problems while playing audio streams

[escar42]

Hello everyone,

iam facing some problems playing internet radiostreams with mopidy 1.1.0 . Some times the stream stops playing for several seconds before continuing. I used mopidy debbuging capabilities to find out its a buffering issue. Logs look like this:

EBUG    2015-09-10 15:37:27,085 [12014:MainThread] mopidy.audio.gst
  Got state-changed message: old=GST_STATE_PLAYING new=GST_STATE_PAUSED pending=GST_STATE_VOID_PENDING
DEBUG    2015-09-10 15:37:27,085 [12014:MainThread] mopidy.audio.actor
  Audio event: state_changed(old_state=playing, new_state=paused, target_state=playing)
DEBUG    2015-09-10 15:37:27,086 [12014:MainThread] mopidy.audio.gst
  Got async-done.
DEBUG    2015-09-10 15:37:27,086 [12014:MainThread] mopidy.listener
  Sending state_changed to AudioListener: {'old_state': u'playing', 'target_state': u'playing', 'new_state': u'paused'}
DEBUG    2015-09-10 15:37:27,533 [12014:HttpServer] mopidy.http.handlers
  Received WebSocket message from 127.0.0.1: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":31252}'
DEBUG    2015-09-10 15:37:28,533 [12014:HttpServer] mopidy.http.handlers
  Received WebSocket message from 127.0.0.1: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":31253}'
TRACE    2015-09-10 15:37:29,268 [12014:MainThread] mopidy.audio.gst
  Got buffering message: percent=6%
DEBUG    2015-09-10 15:37:29,533 [12014:HttpServer] mopidy.http.handlers
  Received WebSocket message from 127.0.0.1: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":31254}'
TRACE    2015-09-10 15:37:29,737 [12014:MainThread] mopidy.audio.gst
  Got buffering message: percent=7%

When the buffers is filled to 100%, playback keeps on.

The reason i post this here is, this problem doesn't accur when using another player like mplayer, vlc etc.

I already increased buffer-time und latency time in my config, but Problem still persists.

[audio]
output = alsasink buffer-time=200000 latency-time=10000
mixer = software

I dont finde other possibilities to modify mopidy buffer handling. Maybe increasing the buffersize for gstreamer would solve my problem.

Is there any possiblity to tune this in recent mopidy builds ( iam using current 1.1.0 ).
If not, it would be great to see some optons or improvements for stream buffering in future versions.

Thanks alot for your great work.
Would be insane if you could help.

[stahlnow]

i can confirm having the same problem using mopidy version 1.1.1.

[vdbee]

So do I

[adamcik]

Messing with the alsasink buffer times probably won't do much for this. You probably would need to change the buffers inside the playbin2, or possibly the queue we have on the outputs. There is already a TODO in the code to make these queue setting more tweakable, which likely could help for cases like this.

There is also a bug I opened a while ago to review the buffer handling to make sure we are doing things correctly per GStreamers recommendations.

[basisbit]

can confirm having this problem using mopidy 2 on a banana pi with current bananian 16.04.

[karlmuuga]

I still encounter the exact same problem on Mopidy 2.0.1 with every single radio stream. Would somebody explain to me, how is such a devastating bug even possible to be unfixed on a god damn music server?

[allquixotic]

@karlmuuga I guess this hasn't been addressed because (1) most users don't use Mopidy to stream other HTTP music streams, but rather play music off of e.g. Spotify or the local file system (if this weren't the case, a lot more users would suffer this issue); and (2) the problem is likely in GStreamer, a third party component that Mopidy can't directly fix.

I'm willing to bet that if you do a gst-launch (command line GStreamer client) with playbin and your streaming URI, you'll hit the same issue there. So we need to figure out if we can tune those parameters to be smarter about buffering data from souphttpsrc, which is likely the offending element ( https://gstreamer.freedesktop.org/data/doc/gstreamer/head/gst-plugins-good-plugins/html/gst-plugins-good-plugins-souphttpsrc.html ). Problem is that it's buried inside a playbin.

Swearing about it and expressing your indignity that your specific use case hasn't been as extensively tested does not bring us closer to a solution.

[tkem]

@allquixotic: Well, I use streaming _exclusively_ (plain M3U radio streams, podcasts, internetarchive, dleyna) and haven't noticed any major issues with recent Mopidy versions. Streaming performance is largely affected by external factors, most notably the quality your network connection, and there's only so much tweaking buffering settings can do about that.

[kingosticks]

It might be useful to know if anyone is experiencing this problem on a system other than a low powered arm board i.e their desktop machine.

[karlmuuga]

@allquixotic I'm sorry to tell you that you're absoluteluy wrong about the gstreamer. Gst-launch plays the stream so that it starts couple milliseconds after the enter hit and stream goes without hiccups (unlike mopidy). So, contrary to what you said, I did NOT encounter the same problem while streaming the URI directly from gst.

And what's else, I dived deep into the mopidy -v logs. From there I can see, that on an absolutely random moment gstreamer starts buffering (which is partially normal). Everything that happens after that is a total bs. Couple milliseconds later the buffer gets filled (Got ASYNC done message + buffered 100%) and then idiotically mopidy waits for darn 5 or more seconds until the playback gets resumed (and the whole time, time ticks ahead on the Now Playing clock, and silence fills the room). This is definitely not what you're talking about here.

@tkem Would you please let me know about your setup, configuration and internet speed (mine is 5/5 Mbps cable, clean Debian 7 minimal and Intel dual core). I have already tried to tweak the buffering settings but that affects nothing.

@kingosticks I guess that my Fujitsu Siemens Amilo lapto is not a seriously low-powered machine.

[karlmuuga]

After inserting a line of code into the mopidy/audio/actor.py file, the hiccuping was gone. https://discuss.mopidy.com/t/streaming-radio-station-pausing-buffering/1251

[adamcik]

1. Which line of code exactly? The set_live(True) bit? If I think it ties in to some old open bugs I have about live handling which someone should probably revisit. Ideally figuring out some way to backends to signal to audio that content is live or not.
2. The waiting for five seconds thing could be due to having to go through the pykka actors message queue. We try to ensure that async events get acted upon immediately, but it also has to play nice with thread safety, where we use an actor model. Any suggestions for reproducing that finding?

[karlmuuga]

1. Yes, that bit. I will let you know if I encounter any problems with that one.
2. Suggestions would be - create a playlists.m3u8 file with the following content (of course you can change the stream URI):

#EXTM3U
#EXTINF:0, Classic Rock
http://us2.internet-radio.com:8191

Play the playlist.

[karlmuuga]

@adamcik did you succeed in reproducing the finding? I have discovered that defining on_source_setup as

  def _on_source_setup(self, element, source):
        gst_logger.debug(
            'Got source-setup signal: element=%s', source.__class__.__name__)

        if source.get_factory().get_name() == 'appsrc':
            self._appsrc.configure(source)
        else:
            self._appsrc.reset()

        if source.__class__.__name__ == '__main__.GstSoupHTTPSrc':
            gst_logger.debug('HTTP Src - setting live mode')
            source.set_live(True)

        utils.setup_proxy(source, self._config['proxy'])

stops the radio hiccuping, but sometimes skips dozen or double that milliseconds of the stream. However, removing the if statement will do the skipping for all sources. So this solution is not correct, but better than silence.

[adamcik]

I've not had a chance to try anything out.

[mczerski]

the solution with is_live creates problems with normal http sources (those that have duration). for example dlna (mopidy-dleyna) uses http for streaming, the problem is that player won't skip to the next song after previous has finished.

does anyone has an idea how to check in _on_source_setup that he source is seekable or has duration or other property that tell if the source is not a live stream ?

[mbantz]

Just my two cents here :-) I'm experiencing the same buffer issue - only on a raspberry pi running updated raspian - not on my developerplatform, PCLinuxOS where everything is streaming fine.

I have boiled the issue down to these two streams:
Buffer issue on raspberry pi: gst-validate-1.0 playbin uri=http://stream-dc1.radioparadise.com/mp3-128
The buffer info in % is blinking between 0% and a couple percent, and the stream never start

With debug info: GST_DEBUG=*:5 gst-validate-1.0 playbin uri=http://stream-uk1.radioparadise.com/mp3-192

Playing on raspberry pi: gst-validate-1.0 playbin uri=http://streams.80s80s.de/love/mp3-192/radiosure/

I'm coding on a python 2.7 gstreamer 1.0 web radio, and are stuck with the pi playing only very few radio stations

[araczkowski]

I have the same "hiccuping" problem, on Orange Pi PC Plus, Mopidy version: 2.1.0-1
solution with source.set_live(True) helped for a moment... until I discovered that the player is not skipping to the next chapter in a book from Google Music (streamed as GstSoupHTTPSrc too)

Any advice?

Thx

[basisbit]

can additionally also confirm this problem for a decent haswell based desktop computer running "current" debian jessie, gstreamer 1 and mopidy 2 and alsa as mixer.
Mopidy is basically not usable for listening to radio stations in its current state. mopidy-youtube, mopidy-spotify and playing from local filestore work just fine for hours.
Is there any work-around or bugfix available for this?
No log entries relating that buffering issue.

[mczerski]

I can offer my solution, this is a patch against 2.1.0 version:

diff --git a/mopidy/audio/actor.py b/mopidy/audio/actor.py
index 6020bc1..6020d2f 100644
--- a/mopidy/audio/actor.py
+++ b/mopidy/audio/actor.py
@@ -415,6 +415,7 @@ class Audio(pykka.ThreadingActor):
         self._buffering = False
         self._tags = {}
         self._pending_uri = None
+        self._is_live = False
         self._pending_tags = None
         self._pending_metadata = None

@@ -547,9 +548,12 @@ class Audio(pykka.ThreadingActor):
         else:
             self._appsrc.reset()

+        if source.get_factory().get_name() == 'souphttpsrc':
+            source.set_property('is-live', self._is_live)
+
         utils.setup_proxy(source, self._config['proxy'])

-    def set_uri(self, uri):
+    def set_uri(self, uri, is_live):
         """
         Set URI of audio to be played.

@@ -558,7 +562,7 @@ class Audio(pykka.ThreadingActor):
         :param uri: the URI to play
         :type uri: string
         """
-
+        self._is_live = is_live
         # XXX: Hack to workaround issue on Mac OS X where volume level
         # does not persist between track changes. mopidy/mopidy#886
         if self.mixer is not None:
diff --git a/mopidy/backend.py b/mopidy/backend.py
index 7412ccc..f15b616 100644
--- a/mopidy/backend.py
+++ b/mopidy/backend.py
@@ -248,7 +248,7 @@ class PlaybackProvider(object):
                 'Backend translated URI from %s to %s', track.uri, uri)
         if not uri:
             return False
-        self.audio.set_uri(uri).get()
+        self.audio.set_uri(uri, track.length is None).get()
         return True
     def resume(self):

[basisbit]

@mczerski could you create a pull request for this and link it to this issue? Thanks!

[basisbit]

or in UAudioDecorder_FFmpeg line 1020 set LIBAVCODEC_VERSION to something like 60 instead of 57 and retry with ffmpeg 2.8

[adamcik]

Sadly the proposed fix is just a workaround. We can't hardcode that all http streams should be live as this simply is not the case. What needs to happen is that mopidy.audio needs a new way for backends to tell it that a source is live. Then the stream backend and other backends that are highly likely to have live streams can call this in their playback backend.

To make this easier for people it would also be nice if this was encapsulated in a BaseStreamingBackend that could be reused for such backends.

[mczerski]

@adamcik my solution does not assume that all http streams are live. I check if track.length is None to distinguish between live and non-live streams. track.length is set in mopidy.stream.actor by StreamLibraryProvider.lookup method which in turn uses mopidy.audio.scan. There is also available atribute 'seekable' but it is thrown away in StreamLibraryProvider.lookup. I think that track that has no lenght and is not seekable alwas can be treated as a live stream.

@basisbit I will make pull request when i get home.

[adamcik]

@mczerski sorry a bit to early in the morning for me, so skimmed over a bit to fast. I see now you've changed set_uri to pass in is live. Two suggestions for this:

1. Perhaps use a check like https://github.com/mopidy/mopidy/blob/develop/mopidy/audio/utils.py#L67 for is-live existing instead of hardcoding a source type?
2. Make sure to make it set_uri(uri, is_live=False) (or just perhaps live=False, but that is more of a bikeshed). We don't want to break the API of set_uri. And if we do need to break it we can only do so in a major release, and there are a bunch of backends that would need updating.

I'm also open to not backing this in to set_uri, but having a separate method. Though I have not thought through pros/cons of such a choice.

[mczerski]

@adamcik thanks for advise. I'm not familiar with mopidy code and my fix was just a fast ugly fix :) If You agree with the idea behind my fix I may try to write a production solution if I will find time for this.

[tkem]

I'm kind of wondering how other players (which, according to user comments apparently get this right) handle this. Do they treat all network sources as "live" streams? Or is there some magic involved, which could be transplanted into the stream backends, leaving extensions blessfully unaware of that distinction?

[kingosticks]

@tkem I failed to find anything in Rhythmbox that does this, but I did find: https://github.com/GNOME/totem/blob/80709b95f16258c68d47a0a8587c41f93d291e54/src/backend/bacon-video-widget.c#L2570 (which is what we have suggested as the change here)

EDIT: and this one https://github.com/xfce-mirror/parole/blob/1a952fe9b632969f5ecbdc4f783ae285959c435c/src/misc/parole-stream.c#L169

I don't understand why this isn't more explicit in the gstreamer documentation.

[tkem]

@kingosticks: Nice one!
So, is there any chance that a similar "workaround" based on @mczerski's proposal will make it into Mopidy short-term? Though I like the idea of backends specifying explicitly whether a stream is live or not, I guess this won't happen anytime soon...

[kingosticks]

I see no downside of this, if we handle it in set_uri with a default value we can have this in the next minor release. With @adamcik's two comments in mind, do you want to submit a PR @mczerski? Failing that I will.

[mczerski]

@kingosticks I do not mind if you do that. I just have no time for that.

[mczerski]

unfortunately my solution is not perfectly good ... the problem is with this line of code in backend.py (line 251):
self.audio.set_uri(uri, track.length is None).get()

sometimes the track.length is None despite the fact that the track is not a live stream :/ this happened with spotify and youtube tracks. This behaviour is random, sometimes the track.length is None and sometimes it is not None. In the web gui the track always has its length displayed.

[basisbit]

what would be the downside of the change for those songs where gstreamer or our mopidy code thinks that the length is 0? (except for one not being able to jump within the track) Please someone just commit some magically good solution... XD

[adamcik]

Pause ends up discarding data instead of pausing. So having something like set_uri(uri, live=False) (or a set_live(live)) is probably still feasible, you just need backends to be smart about if they set it to true, or base it on the track length.

As for length sometimes being none, that might be a data race, but I'm not quite sure.

[mczerski]

@basisbit the biggest downside is the fact that track with is-live attribute set to true will not end, so if you have other tracks in the playlist after, they will be not played unless you manually skip currently played track. I believe that the correct solution would be to set is-live in different place of the code, where track length is guaranteed to be set correctly, but i have very little knowledge of the mopidy code and currently no time to learn it so i can't find the correct solution :(

[LeoCal]

Hi all,

I'm hitting the same issue with reproducing radio web streams. I was wondering if this got eventually fixed in the latest mopidy release?

Thanks

[ettom]

Hi,

I'm having this issue and the fixes mentioned above are not working for me.