Mopidy Discourse

Often doesn't switch to next track

here it is:

Can you do a DEBUG level one pleaese. It’ll be big so I suggest you put the verbosity back to something higher afterwards.

I’m wondering if it’s related to

2021-06-07 18:18:12,976 ERROR [516:MainThread] mopidy.audio.gst: GStreamer error: Server does not support seeking.

but I guess it can’t be because you said there was nothing in the log previously so this must be something else going on…

what do you mean by “DEBUG level one”?

[logging]
verbosity = 4

?
In the meantime, I have discovered that this problem is limited to Spotify’s playlists.

I meant, give me a log with DEBUG level verbosity. The log you provided had (EDIT: no) DEBUG logging present. Limited to just Spotify’s playlists? So playing back through a queue of search results is fine?

Just tried with the Search, but I can’t load tracks. This is the error:

2021-06-23 15:01:53,203 INFO [514:SpotifyBackend-9] mopidy_spotify.lookup: Failed to lookup 'spotify:track:2r1FiNXh5mDNEP8K07YRVp': Session must be logged in and online to load objects: <ConnectionState.DISCONNECTED: 2>

…but I am logged in and online!

EDIT:
Only Radio Streams are working. I tried to restart mopidy, but the problems with Spotify remains.

I think you are running into Spotify login error: <ErrorType.UNABLE_TO_CONTACT_SERVER: 8> - #7 by 01tot10 as well now

Yes, without any doubt. And this is confusing my troubleshooting!

It stops from a queue of search results too…
How to set the logging level to DEBUG for mopidy-spotify? I am running it as a service.

(P.S…: could it be an Iris issue?)

You would add this to your config.

[loglevels]
mopidy_spotify = debug

But I want a full debug log because we need to see the track change occuring (or not), for which you would add

[logging]
verbosity = 1

as per the docs.

maybe. Try a different frontend and see.

Did it. After restarting mopidy the tracks are now changing. I have to wait (maybe one or more days) for the issue. Thanks @kingosticks .

Got it! The issue came up soon. I am pasting here latest lines from the log. The failing event is around the last 2 or 3 lines:

Jul 05 15:24:25 pab mopidy[3965]: DEBUG    [MpdFrontend-21] mopidy.listener Sending playlist to MpdSession: {}
Jul 05 15:24:25 pab mopidy[3965]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.1.5: '{"jsonrpc": "2.0", "i
Jul 05 15:24:25 pab mopidy[3965]: DEBUG    [HttpServer] mopidy.http.handlers Received RPC message from 192.168.1.90: b'{"jsonrpc":"2.0","i
Jul 05 15:24:25 pab mopidy[3965]: DEBUG    [HttpServer] mopidy.http.handlers Received RPC message from 192.168.1.90: b'{"jsonrpc":"2.0","i
Jul 05 15:24:25 pab mopidy[3965]: DEBUG    [HttpServer] mopidy.http.handlers Received RPC message from 192.168.1.90: b'{"jsonrpc":"2.0","i
Jul 05 15:24:25 pab mopidy[3965]: DEBUG    [HttpServer] mopidy_iris.handlers Iris websocket message received: {"jsonrpc":"2.0","id":162549
Jul 05 15:24:25 pab mopidy[3965]: DEBUG    [HttpServer] mopidy_iris.core {'method': 'queue_metadata_changed', 'params': {'queue_metadata':
Jul 05 15:24:25 pab mopidy[3965]: DEBUG    [HttpServer] mopidy_iris.core {'id': 162549146541172, 'jsonrpc': '2.0', 'method': 'add_queue_me
Jul 05 15:24:25 pab mopidy[3965]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.1.5: '{"method":"core
Jul 05 15:24:25 pab mopidy[3965]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.1.5: '{"jsonrpc": "2.0", "i
Jul 05 15:24:25 pab mopidy[3965]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.1.5: '{"method":"core
Jul 05 15:24:25 pab mopidy[3965]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.1.5: '{"jsonrpc": "2.0", "i
Jul 05 15:24:25 pab mopidy[3965]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.1.5: '{"method":"core
Jul 05 15:24:25 pab mopidy[3965]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.1.5: '{"jsonrpc": "2.0", "i
Jul 05 15:24:25 pab mopidy[3965]: DEBUG    [HttpServer] mopidy_iris.core {'method': 'connection_removed', 'params': {'connection': {'conne
Jul 05 15:24:25 pab mopidy[3965]: DEBUG    [HttpServer] mopidy.http.handlers Closed WebSocket connection from 192.168.1.5
Jul 05 15:27:39 pab mopidy[3965]: DEBUG    [SpotifyEventLoop] mopidy_spotify.playback End of track reached
Jul 05 15:27:39 pab mopidy[3965]: DEBUG    [Audio-2] mopidy.audio.gst Sending appsrc end-of-stream event.
Jul 05 15:27:45 pab mopidy[3965]: DEBUG    [Dummy-26] mopidy.audio.gst Got about-to-finish event.
Jul 05 15:27:45 pab mopidy[3965]: DEBUG    [Dummy-26] mopidy.audio.actor Running about-to-finish callback.
Jul 05 15:27:45 pab mopidy[3965]: DEBUG    [SpotifyBackend-9] mopidy_spotify.playback Audio requested change of track; loading and startin
Jul 05 15:27:45 pab mopidy[3965]: DEBUG    [Audio-2] mopidy.audio.gst Sending TAG event for track 'spotify:track:7Kc3hZoCRTs5dNHU7GqT9x': 
Jul 05 15:27:45 pab mopidy[3965]: DEBUG    [Dummy-26] mopidy.audio.gst Got source-setup signal: element=GstAppSrc
Jul 05 15:27:45 pab mopidy[3965]: DEBUG    [Dummy-26] mopidy.audio.gst Enabling live stream mode
Jul 05 15:27:45 pab mopidy[3965]: DEBUG    [SpotifyBackend-9] mopidy_spotify.playback Audio requested seek to 0
Jul 05 15:27:45 pab mopidy[3965]: DEBUG    [SpotifyBackend-9] mopidy_spotify.playback Skipping seek due to issue mopidy/mopidy#300
Jul 05 15:31:08 pab mopidy[3965]: DEBUG    [HttpServer] mopidy.http.handlers New WebSocket connection from 192.168.1.5

OK, I see the problem there

[Dummy-26] mopidy.audio.gst Enabling live stream mode

and I was just trying to work out how this was still happening but then I realised it’s because we never released this fix I did back in Jan. That is frustrating (for both of us, I imagine). I will attempt to cut a new release later today.

1 Like

Thanks! And - pls - update apt mopidy too with the new version!

Nick, I’ve seen you published a new release with this fix, thank you!
As my mopidy installation is configured through apt, don’t you know when the new release will be available on apt.mopidy.com?

I appreciate that but it’ll be published there within the next few days hopefully.

Thanks.
Is there any workaround to apply, waiting for the .deb update?

You can install from source

sudo python3 -m pip install https://github.com/mopidy/mopidy/archive/refs/heads/master.zip

But personally I’d wait.

I think bug should only manifest when you go from playing something from TuneIn to Spotify. I think if you played a track from some other backend between those two backends that would be a workaround. I’m not 100% sure on that but you now know the line you don’t want to see before a Spotify track plays so you could just try it out.

Yes, you’re right. This happens when switching from Radio to Spotify.
Ok, I will wait for apt.
Thanks

Should now be available. Thanks @jodal !

1 Like

Yes, it is! Thank you!