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