Mopidy stops playing randomly. The logs say stuff like this:
2019-10-25 07:58:10,811 ERROR [27139:MainThread] mopidy.audio.gst: GStreamer error: gst-resource-error-quark: Resource not found. (3)
Looking at ‘ncmpcpp’ the playback is stuck on 0:00. If I do ‘mpc pause’ / ‘mpc play’ then the playback starts up again.
Can we get more information e.g. what system, deps, config, debug log (see: https://docs.mopidy.com/en/latest/troubleshooting/ and if running as a service also see: https://docs.mopidy.com/en/latest/service/).
Hi!
[core]
cache_dir = /var/cache/mopidy
config_dir = /etc/mopidy
data_dir = /var/lib/mopidy
max_tracklist_length = 10000
restore_state = true
[logging]
color = true
console_format = %(levelname)-8s %(message)s
debug_format = %(levelname)-8s %(asctime)s [%(process)d:%(threadName)s] %(name)s\n %(message)s
debug_file = /var/log/mopidy/mopidy-debug.log
config_file = /etc/mopidy/logging.conf
[audio]
mixer = alsamixer
mixer_volume =
output = autoaudiosink
buffer_time =
[proxy]
scheme =
hostname =
port =
username =
password =
[mpd]
enabled = true
hostname = 127.0.0.1
port = 6600
password =
max_connections = 20
connection_timeout = 60
zeroconf = Mopidy MPD server on $hostname
command_blacklist =
listall
listallinfo
default_playlist_scheme = m3u
[http]
enabled = true
hostname = 127.0.0.1
port = 6680
static_dir =
zeroconf = Mopidy HTTP server on $hostname
allowed_origins =
csrf_protection = true
[stream]
enabled = true
protocols =
http
https
mms
rtmp
rtmps
rtsp
metadata_blacklist =
timeout = 5000
[m3u]
enabled = true
base_dir =
default_encoding = latin-1
default_extension = .m3u8
playlists_dir = /var/lib/mopidy/playlists
[softwaremixer]
enabled = true
[file]
enabled = true
media_dirs =
$XDG_MUSIC_DIR|Music
~/|Home
excluded_file_extensions =
.directory
.html
.jpeg
.jpg
.log
.nfo
.pdf
.png
.txt
.zip
show_dotfiles = false
follow_symlinks = false
metadata_timeout = 1000
[local]
enabled = true
library = sqlite
media_dir = /data/audio
scan_timeout = 1000
scan_flush_threshold = 100
scan_follow_symlinks = false
excluded_file_extensions =
.directory
.html
.jpeg
.jpg
.log
.nfo
.pdf
.png
.txt
.zip
[spotify]
enabled = true
username = XXXXXXXXXXXXXXXXX
password = ********
client_id = XXXXXXXXXXXXXXXXXXX
client_secret = ********
bitrate = 160
volume_normalization = true
private_session = false
timeout = 10
allow_cache = true
allow_network = true
allow_playlists = true
search_album_count = 20
search_artist_count = 10
search_track_count = 50
toplist_countries =
[local-sqlite]
enabled = true
directories =
Albums local:directory?type=album
Artists local:directory?type=artist
Composers local:directory?type=artist&role=composer
Genres local:directory?type=genre
Performers local:directory?type=artist&role=performer
Release Years local:directory?type=date&format=%25Y
Tracks local:directory?type=track
Last Week's Updates local:directory?max-age=604800
Last Month's Updates local:directory?max-age=2592000
timeout = 10
use_album_mbid_uri = true
use_artist_mbid_uri = false
use_artist_sortname = false
[alsamixer]
enabled = true
card = 0
control = PCM
I’m currently running on Ubuntu 18.04.3 with the following packages installed:
ii mopidy 2.2.3-1 all music server with support for MPD/HTTP clients
ii mopidy-alsamixer 1.0.3-3 all Mopidy extension for extension for ALSA volume control
ii mopidy-local-sqlite 1.0.0-2 all Mopidy extension for keeping your local library in SQLite
ii mopidy-spotify 3.1.0-0mopidy1 all Mopidy extension for playing music from Spotify
ii python-spotify 2.0.5-0mopidy1 amd64 Python bindings for libspotify (Python 2)
How do I turn on debugging information when running as a service?
And the output of sudo mopidyctl deps please, so we know exactly what gstreamer versions and plugins you have installed.
Change the level line in /etc/mopidy/logging.conf to DEBUG:
[handler_fileHandler]
class = FileHandler
formatter = simpleFormatter
level = DEBUG
args = ('/var/log/mopidy/mopidy.log',)
Then restart the service, reproduce the issue, and find the log in /var/log/mopidy/mopidy.log.
Running "/usr/bin/mopidy --config /usr/share/mopidy/conf.d:/etc/mopidy/mopidy.conf deps" as user mopidy
Executable: /usr/bin/mopidy
Platform: Linux-4.15.0-55-generic-x86_64-with-Ubuntu-18.04-bionic
Python: CPython 2.7.15+ from /usr/lib/python2.7
Mopidy: 2.2.3 from /usr/lib/python2.7/dist-packages
Mopidy-ALSAMixer: 1.0.3 from /usr/lib/python2.7/dist-packages
Mopidy>=0.19: 2.2.3 from /usr/lib/python2.7/dist-packages
Pykka>=1.1: 1.2.1 from /usr/lib/python2.7/dist-packages
pyalsaaudio: 0.7 from /usr/lib/python2.7/dist-packages
Mopidy-Local-SQLite: 1.0.0 from /usr/lib/python2.7/dist-packages
Mopidy-Spotify: 3.1.0 from /usr/lib/python2.7/dist-packages
Mopidy>=2.0: 2.2.3 from /usr/lib/python2.7/dist-packages
Pykka>=1.1: 1.2.1 from /usr/lib/python2.7/dist-packages
pyspotify>=2.0.5: 2.0.5 from /usr/lib/python2.7/dist-packages
cffi>=1.0.0: 1.11.5 from /usr/lib/python2.7/dist-packages
requests>=2.0: 2.18.4 from /usr/lib/python2.7/dist-packages
GStreamer: 1.14.5.0 from /usr/lib/python2.7/dist-packages/gi
Detailed information:
Python wrapper: python-gi 3.26.1
Relevant elements:
Found:
uridecodebin
souphttpsrc
appsrc
alsasink
osssink
oss4sink
pulsesink
id3demux
id3v2mux
lamemp3enc
mpegaudioparse
mpg123audiodec
vorbisdec
vorbisenc
vorbisparse
oggdemux
oggmux
oggparse
flacdec
flacparse
shout2send
Not found:
flump3dec
mad
I have turned on debugging now, will let you know my findings once it happens again.
No, but the audio files are NFS mounted. So there’s network involved.
Ok, got it:
2019-10-31 06:37:51,377 DEBUG [4740:Dummy-22] mopidy.audio.gst: Got about-to-finish event.
2019-10-31 06:37:51,377 DEBUG [4740:Dummy-22] mopidy.audio.actor: Running about-to-finish callback.
2019-10-31 06:37:51,378 DEBUG [4740:LocalBackend-7] mopidy.backend: Backend translated URI from local:track:arbs/musikk/talking_heads_-_once_in_a_lifetime.mp3 to file:///data/audio/arbs/musikk/talking_heads_-_once_in_a_lifetime.mp3
2019-10-31 06:37:51,382 DEBUG [4740:Dummy-22] mopidy.audio.gst: Got source-setup signal: element=GstFileSrc
2019-10-31 06:37:51,383 DEBUG [4740:MainThread] mopidy.audio.gst: Got ERROR bus message: error=u'gst-resource-error-quark: Resource not found. (3)' debug=u'gstfilesrc.c(533): gst_file_src_start (): /GstPlayBin:playbin0/GstURIDecodeBin:uridecodebin0/GstFileSrc:source:\nNo such file "/data/audio/arbs/musikk/talking_heads_-_once_in_a_lifetime.mp3"'
2019-10-31 06:37:51,383 ERROR [4740:MainThread] mopidy.audio.gst: GStreamer error: gst-resource-error-quark: Resource not found. (3)
2019-10-31 06:37:51,402 DEBUG [4740:MainThread] mopidy.audio.gst: Changing state to GST_STATE_NULL: result=GST_STATE_CHANGE_SUCCESS
Mopidy is now stuck waiting to finish playing the previous song.
EDIT: Oh, I see this is in fact a file that has been removed since the last time it was played. So it’s basically a file that’s not found. But why does mopidy stop playing when this happens? It should just move on?
Indeed, this happens to me too; I have some m3u8 playlist which point to missing files. When Mopidy reach one of them it continuously restarts the previous played song; simply clicking “play next” button force it to move on but this is annoying, it should just skip the missing files. Is it possible to configure such behavior?