mopidy: Next track is loaded in currently playing track / Mopidy never changes track

I’m having an issue where the track never changes track. The next track just starts playing after the current track ends, but continues past the total time of the current track. Eventually, it realizes that the track it finished and just stops playing. This happens no matter what output or mixer I use. It might be hard to picture what I’m saying, so attached is a picture of what it looks like from ncmpcpp.

Note: mopidy is currently playing the next track, Unsre Stärke heißt zu schwach, despite displaying the previous track, Verstummt!

2016-06-13-141459_1146x63_scrot

Unfortunately, I can’t track down relevant data from the mopidy log. It seems to simply not realize that the track has changed, thus it does not log any change there.

Note that I can manually change the track with mpc next etc. Also, if it reaches the end of the playlist while still displaying the first song selected, it will end normally with this in the log:

DEBUG 2016-06-13 14:13:34,350 [29984:MpdSession-13] mopidy.mpd.session Request from [::ffff:50.76.48.109]:5684: idle

Version: Mopidy 2.0.0

Extensions tested:

  • Mopidy-GMusic (1.0.0)
  • Mopidy-SoundCloud (2.0.2)
  • Mopidy-Youtube (2.0.2)

Edit: It eventually gets to this:

DEBUG    2016-06-13 14:47:26,482 [29984:MpdSession-18] mopidy.mpd.session
  Request from [::ffff:50.76.48.109]:25131: status
DEBUG    2016-06-13 14:47:26,486 [29984:MpdSession-18] mopidy.mpd.session
  Response to [::ffff:50.76.48.109]:25131: 
    volume: 100
    repeat: 0
    random: 0
    single: 0
    consume: 0
    playlist: 7
    playlistlength: 4
    xfade: 0
    state: play
    song: 0
    songid: 3
    time: 523:215
    elapsed: 523.607
    bitrate: 320
    OK
DEBUG    2016-06-13 14:47:26,582 [29984:MainThread] mopidy.audio.gst
  Got TAG bus message: tags={'audio-codec': [u'MPEG-1 Layer 3 (MP3)'], 'bitrate': [320000], 'has-crc': [False], 'channel-mode': [u'stereo']}
DEBUG    2016-06-13 14:47:26,584 [29984:MainThread] mopidy.audio.gst
  Got TAG bus message: tags={'audio-codec': [u'MPEG-1 Layer 3 (MP3)'], 'bitrate': [320000], 'channel-mode': [u'joint-stereo']}
DEBUG    2016-06-13 14:47:26,620 [29984:MpdSession-18] mopidy.mpd.session
  Request from [::ffff:50.76.48.109]:25131: idle
DEBUG    2016-06-13 14:47:26,791 [29984:MainThread] mopidy.audio.gst
  Got TAG bus message: tags={'audio-codec': [u'MPEG-1 Layer 3 (MP3)'], 'minimum-bitrate': [320031], 'bitrate': [320000], 'maximum-bitrate': [320031], 'channel-mode': [u'joint-stereo']}
DEBUG    2016-06-13 14:47:26,843 [29984:MainThread] mopidy.audio.gst
  Got TAG bus message: tags={'audio-codec': [u'MPEG-1 Layer 3 (MP3)'], 'minimum-bitrate': [319725], 'bitrate': [320000], 'maximum-bitrate': [320031], 'channel-mode': [u'joint-stereo']}
DEBUG    2016-06-13 14:47:27,624 [29984:MpdSession-18] mopidy.mpd.session
  Request from [::ffff:50.76.48.109]:25131: noidle
DEBUG    2016-06-13 14:47:27,627 [29984:MpdSession-18] mopidy.mpd.session
  Response to [::ffff:50.76.48.109]:25131: OK
DEBUG    2016-06-13 14:47:27,755 [29984:MpdSession-18] mopidy.mpd.session
  Request from [::ffff:50.76.48.109]:25131: status
DEBUG    2016-06-13 14:47:27,759 [29984:MpdSession-18] mopidy.mpd.session
  Response to [::ffff:50.76.48.109]:25131: 
    volume: 100
    repeat: 0
    random: 0
    single: 0
    consume: 0
    playlist: 7
    playlistlength: 4
    xfade: 0
    state: play
    song: 0
    songid: 3
    time: 2:215
    elapsed: 2.194
    bitrate: 320
    OK

where the song that it started playing initially just restarts.

About this issue

  • Original URL
  • State: closed
  • Created 8 years ago
  • Comments: 39 (11 by maintainers)

Commits related to this issue

Most upvoted comments

The fix for this will be in the upcoming v2.2.3 release.

+3
kingosticks on Jan 30, 2019

@kingosticks: thanks for the suggestion. I confirm that with the following changes (to mopidy 2.2.2):

--- mopidy/audio/actor.py.old	2019-01-13 14:22:34.377491564 +0200
+++ mopidy/audio/actor.py	2019-01-13 14:22:55.836419833 +0200
@@ -134,7 +134,10 @@
         logger.info('Audio output set to "%s"', description)
 
     def _add(self, element):
-        queue = Gst.ElementFactory.make('queue')
+        if os.environ.get('MOPIDY_QUEUE2', '0').strip() == '1':
+            queue = Gst.ElementFactory.make('queue2')
+        else:
+            queue = Gst.ElementFactory.make('queue')
         self.add(element)
         self.add(queue)
         queue.link(element)
@@ -492,7 +495,10 @@
 
     def _setup_audio_sink(self):
         audio_sink = Gst.ElementFactory.make('bin', 'audio-sink')
-        queue = Gst.ElementFactory.make('queue')
+        if os.environ.get('MOPIDY_QUEUE2', '0').strip() == '1':
+            queue = Gst.ElementFactory.make('queue2')
+        else:
+            queue = Gst.ElementFactory.make('queue')
         volume = Gst.ElementFactory.make('volume')
 
         # Queue element to buy us time between the about-to-finish event and

the issue is present 100% of the time when running MOPIDY_QUEUE2=0 mopidy and never present with MOPIDY_QUEUE2=1 mopidy.

The smallest repro I found is the two ogg files attached — they have to be both added to the now playing, and the playback with queue (gstreamer 1.14.4) hangs when switching from a.ogg to b.ogg whereas queue2 seems to switch fine. a-b-ogg.zip

Perhaps there are multiple issues causing similar looking problems, but the queue/queue2 thing at least seems reproducible here, and was at fault for the problems I was seeing.

+1
pv on Jan 13, 2019

I’ve done a little more experimentation with my container, and initially removed Moped to help rule out any conflicts, but that did nothing.

What did help was removing the following line from my configuration:

output = audioresample ! audioconvert ! vorbisenc ! oggmux ! shout2send mount=stream.ogg ip=icecast port=8000 password=hackme

I was able to check the status with MPC and see the tracks progressing as expected.

Adding the following line allowed me to restore output with Icecast, and without this bug occurring.

output = lamemp3enc ! shout2send mount=stream.mp3 ip=icecast port=8000 password=hackme

So my conclusion at this point is that there is some bad interaction with the Ogg Vorbis encoding of the output. I wonder if it’s worth removing that example from https://docs.mopidy.com/en/latest/audio/#streaming-through-icecast, as it feels rather misleading.

+1
danielwhite on May 8, 2017

steps to reproduce here:

  • add tracks to an empty queue from a Local album (fresh mopidy start)
  • start to play with first track
  • observe at the end of 1st track the current track is not updated, neither is the playing progress (this can be observed from any http client, from the api and from a mpd client)

I don’t have spotify to try and reproduce with it. At the moment I’m going to try the debian package to see if I can reproduce with it. mopidy.deps.txt mopidy.conf.txt

edit: confirmed with debian/stretch package as well

# lsof -p $(pgrep mopidy)|grep mp3
mopidy  6856 mopidy   19r   REG              253,1  3700844 15990956 /data/media/mp3/Archive/Londinium/02 - All Time.mp3
mopidy  6856 mopidy   20r   REG              253,1  3700844 15990956 /data/media/mp3/Archive/Londinium/02 - All Time.mp3

two file handles for the same track

edit 2:

  • first track: one file handle (the one to the current track)
# lsof -p $(pgrep mopidy)|grep mp3
mopidy  6856 mopidy   19r   REG              253,1  5953883 15990957 /data/media/mp3/Archive/Londinium/03 - So Few Words.mp3
  • 2nd track: 2 file handles, (the one from the previous track which was not closed, and a new one to the 2nd track)
# lsof -p $(pgrep mopidy)|grep mp3
mopidy  6856 mopidy   19r   REG              253,1  5953883 15990957 /data/media/mp3/Archive/Londinium/03 - So Few Words.mp3
mopidy  6856 mopidy   22r   REG              253,1  4051133 15990958 /data/media/mp3/Archive/Londinium/04 - Headspace.mp3
  • after 2nd track it loops
# lsof -p $(pgrep mopidy)|grep mp3
mopidy  6856 mopidy   19r   REG              253,1  4051133 15990958 /data/media/mp3/Archive/Londinium/04 - Headspace.mp3
mopidy  6856 mopidy   22r   REG              253,1  4051133 15990958 /data/media/mp3/Archive/Londinium/04 - Headspace.mp3

I haven’t looked at the code, but I’m pretty sure it should give you some pretty good hint 😉

+1
lolorc on Mar 24, 2017

Hi, From what I can tell it only happens for me when I have [audio]->output set to something other than default. For example,

mopidy config (when it’s working): [core] cache_dir = $XDG_CACHE_DIR/mopidy config_dir = $XDG_CONFIG_DIR/mopidy data_dir = $XDG_DATA_DIR/mopidy max_tracklist_length = 10000 restore_state = false

[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 = mopidy.log config_file =

[audio] mixer = software 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

[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 =

[softwaremixer] enabled = true

[file] enabled = true media_dirs = $XDG_MUSIC_DIR|Music ~/|Home excluded_file_extensions = .jpg .jpeg show_dotfiles = false follow_symlinks = false metadata_timeout = 1000

[local] enabled = true library = sqlite media_dir = /home/lilmike/Music scan_timeout = 1000 scan_flush_threshold = 100 scan_follow_symlinks = false excluded_file_extensions = .directory .html .jpeg .jpg .log .nfo .png .txt

[spotify] enabled = false ; Extension disabled by user config.

[qsaver] enabled = true backup_file = ./tracklist_backup.json

[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

To get it to break, at least for me, uncomment this:

#output = tee name=t t. ! queue ! audioconvert ! audioresample ! autoaudiosink t. ! queue ! audioresample ! audioconvert ! vorbisenc ! oggmux ! shout2send ip=xxx port=8000 password=xxx mount=mopidy

mopidy deps: Executable: /usr/bin/mopidy Platform: Linux-4.10.3-1-ARCH-x86_64-with-glibc2.2.5 Python: CPython 2.7.13 from /usr/lib/python2.7 Mopidy: 2.1.0 from /usr/lib/python2.7/site-packages Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages requests>=2.0: 2.13.0 from /usr/lib/python2.7/site-packages setuptools: 34.3.2 from /usr/lib/python2.7/site-packages packaging>=16.8: 16.8 from /usr/lib/python2.7/site-packages pyparsing: 2.2.0 from /usr/lib/python2.7/site-packages six: 1.10.0 from /usr/lib/python2.7/site-packages six>=1.6.0: 1.10.0 from /usr/lib/python2.7/site-packages appdirs>=1.4.0: 1.4.3 from /usr/lib/python2.7/site-packages tornado>=3.2: 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.5 from /usr/lib/python2.7/site-packages Mopidy-Local-SQLite: 1.0.0 from /usr/lib/python2.7/site-packages setuptools: 34.3.2 from /usr/lib/python2.7/site-packages packaging>=16.8: 16.8 from /usr/lib/python2.7/site-packages pyparsing: 2.2.0 from /usr/lib/python2.7/site-packages six: 1.10.0 from /usr/lib/python2.7/site-packages six>=1.6.0: 1.10.0 from /usr/lib/python2.7/site-packages appdirs>=1.4.0: 1.4.3 from /usr/lib/python2.7/site-packages Mopidy>=1.1: 2.1.0 from /usr/lib/python2.7/site-packages Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages requests>=2.0: 2.13.0 from /usr/lib/python2.7/site-packages setuptools: 34.3.2 from /usr/lib/python2.7/site-packages packaging>=16.8: 16.8 from /usr/lib/python2.7/site-packages pyparsing: 2.2.0 from /usr/lib/python2.7/site-packages six: 1.10.0 from /usr/lib/python2.7/site-packages six>=1.6.0: 1.10.0 from /usr/lib/python2.7/site-packages appdirs>=1.4.0: 1.4.3 from /usr/lib/python2.7/site-packages tornado>=3.2: 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.5 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.18 from /usr/lib/python2.7/site-packages ipaddress>=1.0.6: 1.0.18 from /usr/lib/python2.7/site-packages Mopidy-Qsaver: 0.1.0 from /usr/lib/python2.7/site-packages setuptools: 34.3.2 from /usr/lib/python2.7/site-packages packaging>=16.8: 16.8 from /usr/lib/python2.7/site-packages pyparsing: 2.2.0 from /usr/lib/python2.7/site-packages six: 1.10.0 from /usr/lib/python2.7/site-packages six>=1.6.0: 1.10.0 from /usr/lib/python2.7/site-packages appdirs>=1.4.0: 1.4.3 from /usr/lib/python2.7/site-packages Mopidy>=1.0: 2.1.0 from /usr/lib/python2.7/site-packages Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages requests>=2.0: 2.13.0 from /usr/lib/python2.7/site-packages setuptools: 34.3.2 from /usr/lib/python2.7/site-packages packaging>=16.8: 16.8 from /usr/lib/python2.7/site-packages pyparsing: 2.2.0 from /usr/lib/python2.7/site-packages six: 1.10.0 from /usr/lib/python2.7/site-packages six>=1.6.0: 1.10.0 from /usr/lib/python2.7/site-packages appdirs>=1.4.0: 1.4.3 from /usr/lib/python2.7/site-packages tornado>=3.2: 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.5 from /usr/lib/python2.7/site-packages Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages Mopidy-Spotify: 3.0.0 from /usr/lib/python2.7/site-packages Mopidy>=2.0: 2.1.0 from /usr/lib/python2.7/site-packages Pykka>=1.1: 1.2.0 from /usr/lib/python2.7/site-packages requests>=2.0: 2.13.0 from /usr/lib/python2.7/site-packages setuptools: 34.3.2 from /usr/lib/python2.7/site-packages packaging>=16.8: 16.8 from /usr/lib/python2.7/site-packages pyparsing: 2.2.0 from /usr/lib/python2.7/site-packages six: 1.10.0 from /usr/lib/python2.7/site-packages six>=1.6.0: 1.10.0 from /usr/lib/python2.7/site-packages appdirs>=1.4.0: 1.4.3 from /usr/lib/python2.7/site-packages tornado>=3.2: 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.5 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.9.1 from /usr/lib/python2.7/site-packages pycparser: 2.17 from /usr/lib/python2.7/site-packages requests>=2.0: 2.13.0 from /usr/lib/python2.7/site-packages setuptools: 34.3.2 from /usr/lib/python2.7/site-packages packaging>=16.8: 16.8 from /usr/lib/python2.7/site-packages pyparsing: 2.2.0 from /usr/lib/python2.7/site-packages six: 1.10.0 from /usr/lib/python2.7/site-packages six>=1.6.0: 1.10.0 from /usr/lib/python2.7/site-packages appdirs>=1.4.0: 1.4.3 from /usr/lib/python2.7/site-packages GStreamer: 1.10.4.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

-Michael.

+1
lilmike on Mar 23, 2017
Read more comments on GitHub
← mopidy: mopidy (mpd frontend) stuck in playing state after last song of queue
mopidy: Sorting in ncmpcpp working very slow and unstable (may be only with Spotify backend) →