michaelherger / Spotty-Plugin

A Spotify plugin for the Lyrion Music Server (fka. Logitech Media Server) and Squeezebox compatible players
117 stars 20 forks source link

Irregular rebuffering/pauses/stopping at end of #49

Open PeterAOBell opened 2 years ago

PeterAOBell commented 2 years ago

Currently running LMS in a docker (Ubuntu 20.04) on Xeon E3-1230v2. Players are RPi2, running Max2Play. Internet is a reasonably reliable 100+Mbps fibre. I'm a long-time Squeeze user since SB3 days (2005). I've very recently started using Spotty. It will run fine for hours. Then, for a track or two, it will pause frequently, sometimes reporting 'rebuffering', sometimes not. Often, skipping to the next track, or the beginning of current track, will make the issue go away. Sometimes, playback will stop at the end of a track and has to be restarted by skipping to next track.

Are these known issues, and is there a fix, or do I need to post some log files (from where?)?

No such issues appear when running Spotify on a FireCube v2.

michaelherger commented 2 years ago

The "Connect" mode indeed (and unfortunately) is known to be a bit fragile, often stopping seemingly randomly. Would you see the same behaviour if you used the LMS UI to Spotty?

Maybe #14 is related?

joerg-d commented 2 years ago

I also have LMS running in Docker container. And I also have the disconnects with "rebuffering". I do not use the "Connect" mode.

More precisely, this is what happens to me: After startup, Spotty often runs for a long time without any problems. The Spotty helper application is started. If the error occurs, first the playback stops. After some seconds spotty-x86_64 terminates and a new process is started. After that it takes some seconds again until the replay continues. A compressed server log at this moment looks like this:

[22-09-07 19:26:04.8575] Plugins::Spotty::ProtocolHandler::getMetadataFor (181) Returning metadata cached in song object for spotify://episode:4X0rYBoLgijLmn9N6xhXSc
[22-09-07 19:26:04.8720] Plugins::Spotty::ProtocolHandler::getMetadataFor (181) Returning metadata cached in song object for spotify://episode:4X0rYBoLgijLmn9N6xhXSc
[22-09-07 19:26:04.8753] Plugins::Spotty::ProtocolHandler::getMetadataFor (181) Returning metadata cached in song object for spotify://episode:4X0rYBoLgijLmn9N6xhXSc

<<< Crash???>>>

[22-09-07 19:26:11.2509] Plugins::Spotty::Connect::DaemonManager::initHelpers (92) Checking Spotty Connect helper daemons...
[22-09-07 19:26:11.2522] Plugins::Spotty::Connect::DaemonManager::initHelpers (126) This is a standalone player with Spotify Connect disabled: 00:04:20:2e:2c:59
[22-09-07 19:26:11.2533] Plugins::Spotty::Connect::DaemonManager::initHelpers (126) This is a standalone player with Spotify Connect disabled: 00:04:20:22:52:94
[22-09-07 19:26:11.2544] Plugins::Spotty::Connect::DaemonManager::initHelpers (126) This is a standalone player with Spotify Connect disabled: b8:27:eb:9a:9e:d5
[22-09-07 19:26:11.5244] Plugins::Spotty::ProtocolHandler::getMetadataFor (181) Returning metadata cached in song object for spotify://episode:4X0rYBoLgijLmn9N6xhXSc
[22-09-07 19:26:11.5275] Plugins::Spotty::ProtocolHandler::getMetadataFor (181) Returning metadata cached in song object for spotify://episode:4X0rYBoLgijLmn9N6xhXSc
[22-09-07 19:26:11.5404] Plugins::Spotty::ProtocolHandler::getMetadataFor (181) Returning metadata cached in song object for spotify://episode:4X0rYBoLgijLmn9N6xhXSc
michaelherger commented 2 years ago

If you don't use the Connect mode, then please disable it. The messages you're posting have mostly to do with Connect only, and are irrelevant for "normal" playback.

joerg-d commented 2 years ago

The Connect Mode is already disabled:

Spotify-Connect-Settings

Or is there another way to configure this?

michaelherger commented 2 years ago

Ok, that's fine. I probably have to review how I deal with non-Connect players. The message in the log actually mentions Connect was disabled.

But what about the <<< Crash???>>> you put in there? What makes you think there was a crash there? Is the log file missing some pieces? And would the same track resume after the buffering?

joerg-d commented 2 years ago

Sorry, I did not explain this clearly.

The log file is complete. I only added the line <<< Crash???>>> at the point where the playback stopped. At this point the spotty-x86_64 process was terminated and a new one with a different PID was started.

During error-free playback without interruptions the spotty-x86_64 process is never terminated, not even when starting a new title. Therefore I assume that in case of an interruption the spotty-x86_64 process is crashed, which is the reason for the interruption.

michaelherger commented 2 years ago

Unless you have Connect enabled there should only ever be a spotty helper instance while a track is playing. And it should terminate once the track has ended, with a new instance being launched to get the next track. If you check the process list you should see that the --single-track parameter would change on each track.

joerg-d commented 2 years ago

Since I ran some tests yesterday with different options (Streaming mode for HTTP(S), Crossfade, Connect Mode, Bitrate, ...), the behavior is now as you described: For each new track a new helper instance is started. But I am 99% sure that this was not the case before. I controlled the helper process with

while sleep 1; do ps --no-headers -fC spotty-x86_64; done

there was no change until there was an interruption, but not when there was a track change. Can this behavior be explained? Otherwise I would have done something wrong in my analyses. Unfortunately I only observed the PID and not the parameters of spotty-x86_64 in the output of the above command, so I can't say anything about --single-track.

Furthermore, no more interrupts occurred today. I could have observed the LMS with Spotty the whole day today, that ran completely without interruptions. Although I changed all test parameters back to the initial values, I can no longer reproduce the problems with disconnections. I'm happy about that, but if it remains like this I can't contribute to the solving of the dropouts that probably also occur with others.