Mopidy mpd status() not always updated with gmusic

General
#1

I’m using Mopidy with GMusic.
I try to debug using the python mpd client.

Sometimes, after after a manual song change in the current playlist (using previous or next or “addid”), mopidy does not update the “current” playing song, and the status() display the “old” song.

Also next (manual) “next” use that same information and replay the same song.
Looks like mopidy does not “know” that gmusic changed song.

#2

Looking at gmusicapi logs, it shows that the GetStreamUrl return the right URL on song change. So the problem is somewhere between the gmusicapi and mopidy.

#3

Fixed in pull request:

#4

Please provide a debug log and versions.

#5

Hi, log not useful, they shot correct URI change.
The problem exists only with the bitrate = 320
The problem does not shows if song is short (33s)
Here is two programs to reproduce the problem:

With the problem:

# Test next() but song is repeated (you have to listen to test)
# Song is 169 seconds long
#
# Problem is present only if bitrate = 320 !

import datetime
import time
import mpd

ALBUM = 'Sheik Yerbouti'
SONG = 'bobby'

c = mpd.MPDClient()
c.connect('localhost', 6600)
c.clear()
a = [t for t in c.find('title', ALBUM)
     if t.get('file').startswith('gmusic:album')][0]
c.add(a['file'])
sid = [s['id'] for s in c.playlistinfo() if SONG in s['title'].lower()][0]
c.playid(sid)
time.sleep(1)  # let start
print "[%s] Song ID: %s" % (datetime.datetime.now(), sid)
time.sleep(5)
c.next()
print "[%s] Song should have changed but not" % datetime.datetime.now()
sid = c.status()['songid']
print "[%s] Song ID is now: %s" % (datetime.datetime.now(), sid)

Working as expected:

# Test next() working
# Song is 33 seconds long

import datetime
import time
import mpd

ALBUM = 'Sheik Yerbouti'
SONG = 'minute'

c = mpd.MPDClient()
c.connect('localhost', 6600)
c.clear()
a = [t for t in c.find('title', ALBUM)
     if t.get('file').startswith('gmusic:album')][0]
c.add(a['file'])
sid = [s['id'] for s in c.playlistinfo() if SONG in s['title'].lower()][0]
c.playid(sid)
time.sleep(1)  # let start
print "[%s] Song ID: %s" % (datetime.datetime.now(), sid)
time.sleep(5)
c.next()
print "[%s] Song have indeed changed" % datetime.datetime.now()
sid = c.status()['songid']
print "[%s] Song ID is now: %s" % (datetime.datetime.now(), sid)
#6

A debug log is what’s needed, thanks. And better yet, a Gstreamer debug log. Unfortunately a gmusic account is also needed to reproduce the problem.

This also sounds a lot like https://github.com/mopidy/mopidy-gmusic/issues/183

#7

Looks like the same issue, indeed.

Here are the logs:

Working: https://pastebin.com/WuLZVdDt
Problem: https://pastebin.com/reU4Sxpt

GST logs show only:
0:00:19.387782421 6861 0x55f89dfa3e80 WARN audio-resampler audio-resampler.c:274:convert_taps_gint16_c: can’t find exact taps
0:00:25.341543074 6861 0x7feb9809c720 WARN audio-resampler audio-resampler.c:274:convert_taps_gint16_c: can’t find exact taps

In both case, even following the gst debug log intructions

#8

I can give you a gmusic account for a limited time if you want to reproduce the problem.
Email me to jean@schurger.org

#9

With GST_DEBUG=7

mopidy.log: https://pastebin.com/6spvF6Un
gstreamer.log (120MB): http://sch.sh/6spvF6Un.log