Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
languitar opened this issue Oct 3, 2016 · 23 comments
Open
Labels
A-audio Area: Audio layer C-bug Category: This is a bug

Comments

@languitar
Copy link

languitar commented Oct 3, 2016

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.

@jodal jodal added this to the v2.1 - The rest of v2.0 milestone Oct 24, 2016
@jodal
Copy link
Member

jodal commented Oct 24, 2016

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

@kingosticks
Copy link
Member

kingosticks commented Oct 24, 2016

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.

@kingosticks
Copy link
Member

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

@languitar
Copy link
Author

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

@languitar
Copy link
Author

How do I create a debug log?

@languitar
Copy link
Author

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?

@languitar
Copy link
Author

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

@kingosticks
Copy link
Member

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

@languitar
Copy link
Author

Once I am back home ;-)

@adamcik
Copy link
Member

adamcik commented Oct 25, 2016

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.

@languitar
Copy link
Author

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

@jodal jodal modified the milestones: v2.1.1 - Bug fixes, v2.1 - The rest of v2.0 Jan 2, 2017
@gotling
Copy link
Contributor

gotling commented Mar 25, 2017

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:

gotling@c13ab38

@languitar
Copy link
Author

languitar commented Aug 14, 2017

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

@ryanrdetzel
Copy link

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

@jodal jodal modified the milestones: v2.1.1 - Bug fixes, v2.2 Mar 30, 2018
@jodal jodal added C-bug Category: This is a bug A-audio Area: Audio layer labels Mar 31, 2018
@jodal jodal removed this from the v2.2 milestone Apr 9, 2018
@jjok
Copy link
Contributor

jjok commented Apr 28, 2018

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.

@jjok
Copy link
Contributor

jjok commented Sep 19, 2018

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

@fatg3erman
Copy link
Contributor

fatg3erman commented Dec 31, 2019

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'.

@adamcik
Copy link
Member

adamcik commented Dec 31, 2019

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.

@fatg3erman
Copy link
Contributor

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.

@kingosticks
Copy link
Member

Has anyone tried with the very latest gstreamer?

There's also badaix/snapcast#511

@fatg3erman
Copy link
Contributor

@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.

@KraigoMpls
Copy link

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

@KraigoMpls
Copy link

KraigoMpls commented Jan 25, 2020

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!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
A-audio Area: Audio layer C-bug Category: This is a bug
Projects
None yet
Development

No branches or pull requests

9 participants