mopidy (mpd frontend) stuck in playing state after last song of queue

Created on 3 Oct 2016  路  23Comments  路  Source: mopidy/mopidy

Since some time (I can't tell in versions), mopidy doesn't exit the playing state after the last queued song has been played. mpd clients continue to report that mopidy is still playing.

E.g. currently, the last song stopped (audibly) playing a few minutes ago and I receive this output:

languitar@miles ~ [1]> mpc -h 192.168.1.8
Andre Manoukian - Blow !
[playing] #12/12   0:00/3:06 (0%)
volume: 68%   repeat: off   random: off   single: off   consume: off

It is possible to manually stop playing in this state:

languitar@miles ~> mpc -h 192.168.1.8 stop
volume: 68%   repeat: off   random: off   single: off   consume: off
languitar@miles ~> mpc -h 192.168.1.8
volume: 68%   repeat: off   random: off   single: off   consume: off

I first thought this might be an issue with the spotify backend, but this also happens for local media files, so seems to be more general. This is also happening with and without consume mode.

I am using Mopidy 2.0.1 on archlinux 64 bit.

C-bug A-audio

Most helpful comment

I had the same problem when using Snapcast. By sending stream end message to listeners in case of an error gets me past the problem:

https://github.com/gotling/mopidy/commit/c13ab38b184f4b8902d1b0b8e75adcd423eaccc9

All 23 comments

We should check if this is related to #1512 / #1549 before releasing v2.1.

I cannot reproduce this with v2.0.1 on Ubuntu 16.04 and have never noticed it on any of my systems but none of them are archlinux, maybe that's significant.

@languitar can you provide the output of mopidy deps and a debug log where the problem occurs?

Here is the output of mopidy deps

Executable: /usr/bin/mopidy
Platform: Linux-4.8.4-1-ARCH-x86_64-with-glibc2.2.5
Python: CPython 2.7.12 from /usr/lib/python2.7
Mopidy: 2.0.1 from /usr/lib/python2.7/site-packages
  Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
  requests>=2.0: 2.11.1 from /usr/lib/python2.7/site-packages
  setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
  tornado>=2.3: 4.4.2 from /usr/lib/python2.7/site-packages
    singledispatch: 3.4.0.3 from /usr/lib/python2.7/site-packages
      six: 1.10.0 from /usr/lib/python2.7/site-packages
    backports_abc>=0.4: 0.4 from /usr/lib/python2.7/site-packages
Mopidy-MusicBox-Webclient: 2.3.0 from /usr/lib/python2.7/site-packages
  setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
  Mopidy>=1.1.0: 2.0.1 from /usr/lib/python2.7/site-packages
    Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
    requests>=2.0: 2.11.1 from /usr/lib/python2.7/site-packages
    setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
    tornado>=2.3: 4.4.2 from /usr/lib/python2.7/site-packages
      singledispatch: 3.4.0.3 from /usr/lib/python2.7/site-packages
        six: 1.10.0 from /usr/lib/python2.7/site-packages
      backports_abc>=0.4: 0.4 from /usr/lib/python2.7/site-packages
Mopidy-ALSAMixer: 1.0.3 from /usr/lib/python2.7/site-packages
  setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
  Mopidy>=0.19: 2.0.1 from /usr/lib/python2.7/site-packages
    Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
    requests>=2.0: 2.11.1 from /usr/lib/python2.7/site-packages
    setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
    tornado>=2.3: 4.4.2 from /usr/lib/python2.7/site-packages
      singledispatch: 3.4.0.3 from /usr/lib/python2.7/site-packages
        six: 1.10.0 from /usr/lib/python2.7/site-packages
      backports_abc>=0.4: 0.4 from /usr/lib/python2.7/site-packages
  Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
  pyalsaaudio: 0.8.2 from /usr/lib/python2.7/site-packages
Mopidy-Mopify: 1.6.0 from /usr/lib/python2.7/site-packages
  setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
  Mopidy>=0.19: 2.0.1 from /usr/lib/python2.7/site-packages
    Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
    requests>=2.0: 2.11.1 from /usr/lib/python2.7/site-packages
    setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
    tornado>=2.3: 4.4.2 from /usr/lib/python2.7/site-packages
      singledispatch: 3.4.0.3 from /usr/lib/python2.7/site-packages
        six: 1.10.0 from /usr/lib/python2.7/site-packages
      backports_abc>=0.4: 0.4 from /usr/lib/python2.7/site-packages
  ConfigObj: 5.0.6 from /usr/lib/python2.7/site-packages
Mopidy-Dirble: 1.3.0 from /usr/lib/python2.7/site-packages
  setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
  Mopidy>=1.0: 2.0.1 from /usr/lib/python2.7/site-packages
    Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
    requests>=2.0: 2.11.1 from /usr/lib/python2.7/site-packages
    setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
    tornado>=2.3: 4.4.2 from /usr/lib/python2.7/site-packages
      singledispatch: 3.4.0.3 from /usr/lib/python2.7/site-packages
        six: 1.10.0 from /usr/lib/python2.7/site-packages
      backports_abc>=0.4: 0.4 from /usr/lib/python2.7/site-packages
  Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
  requests: 2.11.1 from /usr/lib/python2.7/site-packages
Mopidy-InternetArchive: 0.5.0 from /usr/lib/python2.7/site-packages
  setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
  Mopidy>=0.18: 2.0.1 from /usr/lib/python2.7/site-packages
    Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
    requests>=2.0: 2.11.1 from /usr/lib/python2.7/site-packages
    setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
    tornado>=2.3: 4.4.2 from /usr/lib/python2.7/site-packages
      singledispatch: 3.4.0.3 from /usr/lib/python2.7/site-packages
        six: 1.10.0 from /usr/lib/python2.7/site-packages
      backports_abc>=0.4: 0.4 from /usr/lib/python2.7/site-packages
  Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
  requests>=2.0.0: 2.11.1 from /usr/lib/python2.7/site-packages
Mopidy-Local-SQLite: 1.0.0 from /usr/lib/python2.7/site-packages
  setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
  Mopidy>=1.1: 2.0.1 from /usr/lib/python2.7/site-packages
    Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
    requests>=2.0: 2.11.1 from /usr/lib/python2.7/site-packages
    setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
    tornado>=2.3: 4.4.2 from /usr/lib/python2.7/site-packages
      singledispatch: 3.4.0.3 from /usr/lib/python2.7/site-packages
        six: 1.10.0 from /usr/lib/python2.7/site-packages
      backports_abc>=0.4: 0.4 from /usr/lib/python2.7/site-packages
  Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
  uritools>=1.0: 1.0.1 from /usr/lib/python2.7/site-packages
    ipaddress>=1.0.6: 1.0.17 from /usr/lib/python2.7/site-packages
    ipaddress>=1.0.6: 1.0.17 from /usr/lib/python2.7/site-packages
Mopidy-Youtube: 2.0.2 from /usr/lib/python2.7/site-packages
  setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
  requests>=2.2.1: 2.11.1 from /usr/lib/python2.7/site-packages
  pafy>=0.3.35: 0.5.1 from /usr/lib/python2.7/site-packages
  Mopidy>=1.0: 2.0.1 from /usr/lib/python2.7/site-packages
    Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
    requests>=2.0: 2.11.1 from /usr/lib/python2.7/site-packages
    setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
    tornado>=2.3: 4.4.2 from /usr/lib/python2.7/site-packages
      singledispatch: 3.4.0.3 from /usr/lib/python2.7/site-packages
        six: 1.10.0 from /usr/lib/python2.7/site-packages
      backports_abc>=0.4: 0.4 from /usr/lib/python2.7/site-packages
  Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
Mopidy-SomaFM: 1.0.0 from /usr/lib/python2.7/site-packages
  setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
  Mopidy>=1.1: 2.0.1 from /usr/lib/python2.7/site-packages
    Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
    requests>=2.0: 2.11.1 from /usr/lib/python2.7/site-packages
    setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
    tornado>=2.3: 4.4.2 from /usr/lib/python2.7/site-packages
      singledispatch: 3.4.0.3 from /usr/lib/python2.7/site-packages
        six: 1.10.0 from /usr/lib/python2.7/site-packages
      backports_abc>=0.4: 0.4 from /usr/lib/python2.7/site-packages
  Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
  requests>=2.0.0: 2.11.1 from /usr/lib/python2.7/site-packages
Mopidy-Moped: 0.6.4 from /usr/lib/python2.7/site-packages
  setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
  Mopidy>=1.0.0: 2.0.1 from /usr/lib/python2.7/site-packages
    Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
    requests>=2.0: 2.11.1 from /usr/lib/python2.7/site-packages
    setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
    tornado>=2.3: 4.4.2 from /usr/lib/python2.7/site-packages
      singledispatch: 3.4.0.3 from /usr/lib/python2.7/site-packages
        six: 1.10.0 from /usr/lib/python2.7/site-packages
      backports_abc>=0.4: 0.4 from /usr/lib/python2.7/site-packages
Mopidy-Local-Images: 1.0.0 from /usr/lib/python2.7/site-packages
  setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
  Mopidy>=1.1: 2.0.1 from /usr/lib/python2.7/site-packages
    Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
    requests>=2.0: 2.11.1 from /usr/lib/python2.7/site-packages
    setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
    tornado>=2.3: 4.4.2 from /usr/lib/python2.7/site-packages
      singledispatch: 3.4.0.3 from /usr/lib/python2.7/site-packages
        six: 1.10.0 from /usr/lib/python2.7/site-packages
      backports_abc>=0.4: 0.4 from /usr/lib/python2.7/site-packages
  Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
  uritools>=1.0: 1.0.1 from /usr/lib/python2.7/site-packages
    ipaddress>=1.0.6: 1.0.17 from /usr/lib/python2.7/site-packages
    ipaddress>=1.0.6: 1.0.17 from /usr/lib/python2.7/site-packages
Mopidy-Spotify-Tunigo: 1.0.0 from /usr/lib/python2.7/site-packages
  Mopidy>=0.19.0: 2.0.1 from /usr/lib/python2.7/site-packages
    Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
    requests>=2.0: 2.11.1 from /usr/lib/python2.7/site-packages
    setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
    tornado>=2.3: 4.4.2 from /usr/lib/python2.7/site-packages
      singledispatch: 3.4.0.3 from /usr/lib/python2.7/site-packages
        six: 1.10.0 from /usr/lib/python2.7/site-packages
      backports_abc>=0.4: 0.4 from /usr/lib/python2.7/site-packages
  Mopidy-Spotify>=1.2.0: 3.0.0 from /usr/lib/python2.7/site-packages
    Mopidy>=2.0: 2.0.1 from /usr/lib/python2.7/site-packages
      Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
      requests>=2.0: 2.11.1 from /usr/lib/python2.7/site-packages
      setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
      tornado>=2.3: 4.4.2 from /usr/lib/python2.7/site-packages
        singledispatch: 3.4.0.3 from /usr/lib/python2.7/site-packages
          six: 1.10.0 from /usr/lib/python2.7/site-packages
        backports_abc>=0.4: 0.4 from /usr/lib/python2.7/site-packages
    Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
    pyspotify>=2.0.5: 2.0.5 from /usr/lib/python2.7/site-packages
      cffi>=1.0.0: 1.8.3 from /usr/lib/python2.7/site-packages
        pycparser: 2.14 from /usr/lib/python2.7/site-packages
    requests>=2.0: 2.11.1 from /usr/lib/python2.7/site-packages
    setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
  Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
  setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
  tunigo>=1.0.0: 1.0.0 from /usr/lib/python2.7/site-packages
    requests>=2.0.0: 2.11.1 from /usr/lib/python2.7/site-packages
    setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
Mopidy-Spotify: 3.0.0 from /usr/lib/python2.7/site-packages
  Mopidy>=2.0: 2.0.1 from /usr/lib/python2.7/site-packages
    Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
    requests>=2.0: 2.11.1 from /usr/lib/python2.7/site-packages
    setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
    tornado>=2.3: 4.4.2 from /usr/lib/python2.7/site-packages
      singledispatch: 3.4.0.3 from /usr/lib/python2.7/site-packages
        six: 1.10.0 from /usr/lib/python2.7/site-packages
      backports_abc>=0.4: 0.4 from /usr/lib/python2.7/site-packages
  Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages
  pyspotify>=2.0.5: 2.0.5 from /usr/lib/python2.7/site-packages
    cffi>=1.0.0: 1.8.3 from /usr/lib/python2.7/site-packages
      pycparser: 2.14 from /usr/lib/python2.7/site-packages
  requests>=2.0: 2.11.1 from /usr/lib/python2.7/site-packages
  setuptools: 28.6.1 from /usr/lib/python2.7/site-packages
GStreamer: 1.9.90.0 from /usr/lib/python2.7/site-packages/gi
  Detailed information:
    Python wrapper: python-gi 3.22.0
    Relevant elements:
      Found:
        uridecodebin
        souphttpsrc
        appsrc
        alsasink
        osssink
        oss4sink
        pulsesink
        id3demux
        id3v2mux
        lamemp3enc
        mad
        mpegaudioparse
        mpg123audiodec
        vorbisdec
        vorbisenc
        vorbisparse
        oggdemux
        oggmux
        oggparse
        flacdec
        flacparse
        shout2send
      Not found:
        flump3dec

How do I create a debug log?

Ok, got it.
log.zip

This a fresh restart of mopidy with my usual config except for logging on level DEBUG. I startet ncmpcpp, added to songs from local files and let them play. ncmpcpp was constantly running in the background and potentially also a system service which periodically polls for the current playing state. As expected, mopidy got stuck in the playing state. What I have noticed in the log is this:

2016-10-25 08:03:37,985 DEBUG [2755:Audio-3] mopidy.audio.actor: Position query failed

And maybe also this:

2016-10-25 08:02:57,064 DEBUG [2755:MainThread] mopidy.audio.gst: Got ERROR bus message: error=u'gst-resource-error-quark: Error while seeking in file "/tmp/snapfifo". (11)' debug=u'gstfilesink.c(619): gst_file_sink_event (): /GstPlayBin:playbin0/GstPlaySink:playsink/GstBin:abin/GstBin:audio-sink/mopidy+audio+actor+_Outputs:mopidy+audio+actor+_outputs0/GstBin:bin0/GstFileSink:filesink0:\nsystem error: Illegal seek'

I am using mopidy with snapcast for output on multiple rooms. Maybe this is also an important aspect which triggers this bug?

And just for the reference, this is my config:

[core]
cache_dir = /var/cache/mopidy
config_dir = /etc/mopidy
data_dir = /var/lib/mopidy

[logging]
config_file = /etc/mopidy/logging.conf
debug_file = /var/log/mopidy/mopidy-debug.log

[local]
enabled = true
library = json
scan_flush_threshold = 100
data_dir = /var/lib/mopidy/local
media_dir = /mnt/data/music
excluded_file_extensions =
  .directory
  .html
  .jpeg
  .jpg
  .log
  .nfo
  .png
  .txt
  .pdf
  .gif

[file]
enabled = true
media_dirs =
    /mnt/data/music|local

[m3u]
playlists_dir = /mnt/data/music/_playlists
base_dir = /mnt/data/music/

[youtube]
enabled = true

[dirble]
api_key = BLA
countries = DE,US,GB

[mpd]
enabled = true
hostname = ::

[softwaremixer]
enabled = false

[audio]
mixer = alsamixer
#output = alsasink device=hw:0,0
output = audioresample ! audioconvert ! audio/x-raw,rate=48000,channels=2,format=S16LE ! wavenc ! filesink location=/tmp/snapfifo

[alsamixer]
card = 0
control = PCM

[http]
hostname = ::

[somafm]
#encoding = aac
#quality = highest

[qsaver]
enabled = true
backup_file = /var/lib/mopidy/tracklist_backup.json

[spotify]
enabled = true
username = BLA
password = BLA
bitrate = 320
private_session = true

Thanks for all this. Are you able to try without the filesink output?

Once I am back home ;-)

filesinks and fifos aren't really friends though, lots of cases where filesink won't quite do the right thing last I checked. #775 fixes some of these, but it was never completed.

Ok, it stops playing correctly when using the ALSA device directly.

I had the same problem when using Snapcast. By sending stream end message to listeners in case of an error gets me past the problem:

https://github.com/gotling/mopidy/commit/c13ab38b184f4b8902d1b0b8e75adcd423eaccc9

Is there anything I can do to get a fix for this? Is there a problem with the proposed one by @gotling?

I would love a fix for this. Did anyone find a solution? Could we merge the change by @gotling ?

Hey. I recently switched on the option to save the state for when Mopidy is restarted. I'm finding that, even though I'm using Consume mode, and the tracklist that I was previously listening to finished, the final track wasn't removed from the tracklist. So, when I start up, that last track starts playing from the beginning again.
It sounds like it might be the same as this issue. Does anyone know if that's the case? Thanks.

I've just started using Mopidy by itself, without Snapcast, and this issue has gone away for me.

With the release of Mopidy 3 this seems to be working in all cases except when using a filesink with a fifo (as you would for snapcast). The hack of sending an EOS to all listeners on receiving a GStreamer error does "fix" it. My hack inlcuded checking error.message for the string '/tmp/snapfifo', as a 'safety net'.

In general, as soon as you put a "non-standard" endpoint like a FIFO or even just mopidy-spotify with its use of appsrc GStreamer tends to run into corner cases that break things. This is still part of the reason that we never to proper multioutput support and than streaming isn't considered a first class citizen.

Note that I would not recommend just using a filesink with a fifo, ideally you would want a fifosink from gstreamer (last I checked this does not exist) or something like what I tested in #775 which is essentially making our own one in python.

Thanks. It's a real shame Gstreamer doesn't work properly with fifos as Snapcast + Mopidy is a really nice multi-room Spotify player.

The hack workaround works as far as it goes but it has a habit of making playback stop after every single track, at least when paying streams. I don't think I have the knowledge to make a proper Gstreamer fifo output (I looked at #775 but wasn't able to follow it) but if I can come up with a safe workaround for this issue - with a config flag to switch it on perhaps - I'll post back here.

Has anyone tried with the very latest gstreamer?

There's also https://github.com/badaix/snapcast/issues/511

@kingsticks thanks for that, I built the new snapserver and am now using a TCP sink instead of a FIFO and so far it's working a treat. No errors from GStreamer and EOS is correctly detected.

It's good to know there are options. I'm thrilled that the team got the port to Python 3 done, I'm not unhappy that mopidy-local was split out. I'm concerned that there's no maintainer for it yet as it's my main use of Mopidy. I'm not thrilled that I'm forced back to mopidy-sqlite as the tagging done on files is pretty rag-tag - is it "The Clash" or "Clash" or "Clash, The"? Not mopidy-sqlite's fault, but I wish there was a "folder view" where all I had to do was fix the naming in the file structure and it'd be fine.

Lastly, and on point: Mopidy/gstreamer/SnapCast has been working pretty well for me for a few years now. It sort of spooks me that all of the progress that has been made to this point may fail because SnapCast is integral to my system. Happily BadAix has put forth the TCP option. It's on my year's goals to get enough Python development experience under my belt that I can help with mopidy-local going forward.

Thanks to all and a happy new year!

KO

It looks as though two days ago BadAix bumped the version of Snapcast to 18.0 which, if I'm reading correctly, moved his TCP stream into the Master branch and I've confirmed that he has compiled armhf versions on his download page.

woot!

Was this page helpful?
0 / 5 - 0 ratings

Related issues

szuniverse picture szuniverse  路  13Comments

flyingrub picture flyingrub  路  15Comments

kingosticks picture kingosticks  路  12Comments

jodal picture jodal  路  32Comments

mczerski picture mczerski  路  9Comments