Strange lack of status updates to Android/Mac official clients (but not web)

[mfeif]

Version d26153a; compiled from master a couple of days ago.

I've got librespot running on a rPi like device. Playback works. Some clients connected to it are behaving strangely:

1. When starting a new song, the seek/scrub widgets immediately parks itself at the end of the song on connected clients.

2. Other clients may not reflect the song change, and may display the "old" song, though they appear to be connected to a listening stream (their UI is in the playing state, with the play/pause button showing the pause button, meaning it thinks it's playing).

3. IF you press pause on one of those clients, then the scrub/timeline bar updates to the correct position on that client.

4. At that point, all the clients seem to react properly to showing state.

It seems like web based client (play.spotify.com) works a little better than my MacOS or Android clients (both of which are updated to most recent available versions). It shows the proper status always.

Weirdly, even if you start a song with say the Mac client NOT running, then launch it, it displays the incorrect status too: seek bar ui pegged to the end. Pushing pause anywhere causes the UI to update correctly anywhere.

Changing the playback device to one of these official clients and re-running the above scenario results in the expected playback behavior: seek bar updates normally; pause/play too.

Seems like there is some bug in the broadcast of current state, and it may get cleared out or reset to proper functioning after certain events?

[devgianlu]

I think this is a duplicate of #310

[mfeif]

Bummer; I lost a pretty comprehensive post; seemed to disappear into the ether.

I looked into the ntp theory; my playback device DOES do a sync every night, but just in case, I forced a sync. The device my client is on was about +0.041s off, and the librespot device was about -0.011 off. So they were less than 0.05s off from NTP "reality" and about that from one another. Is this level of tolerance required?

I restarted librespot, and indeed things were better. But within a couple of minutes, they were back to the same behavior... so more likely it's a different bug, and it just was "good" for the first few minutes after a restart.

As I write this, I'm listening. If I start a new MacOS desktop client from scratch, it sees the playback device, sees the right song, but has the UI seek bar set to the end. Same with Android. Upon track change, the title changes but the seek bar stays pegged to the end, thought the total song length does update. Again, the web client doesn't do this (though it does grab the stream away from Librespot.)

BUT, after I engage the web client, and after re-directing the playback back to librespot, all the other clients suddenly get good data.

If I quit the problematic clients, but leave the web ui running, and THEN launch Android/MacOS clients, they both show the broken behavior again.

So here's my hypothesis... Somehow librespot gets a broken status state, which confuses (some) clients. Something about the way the web client works seems to "reset" this and make it back into a valid state, and then all connected clients are showing good data. Again, 'till they disconnect and reconnect.

I wish I could be more systematic about this; what else do we need? Console logs?

[sashahilton00]

@mfeif NTP sync is not necessary. The clients send/receive a sequence of commands on start to synchronise time with the server. We should implement the same logic, and that'll solve the wierd timing problems.

The play bar behaviour is weird. I actually see this occasionally with the official clients. There appears to be some sort of event that occurs that just causes a cascade of bizarre errors, leading to the paly bar being broken, songs not skipping on the first attempt, then skipping twice, etc. I think we may have to monitor that bug for a bit and try and work out what causes it, as it's not clear at the moment what triggers it. Similarly to librespot, the official clients require a restart to get things working again.

[mfeif]

I'm able to trigger is (by means unknown) completely regularly, so if I can capture some output that helps, I'm happy to give that a go.

[zhjb7]

Version 14721f4 time problems remain.

[aykevl]

Version 14721f4 time problems remain.

I can confirm this. In fact, I did not have this issue before. However, right now I can't reproduce it anymore. I'll get back to this issue when it happens again.

Is it possible that with the better time syncing, somehow a negative value is sent right at the start of the song? That might explain why the player is stuck at the end until a play/pause.