Spotty-Plugin icon indicating copy to clipboard operation
Spotty-Plugin copied to clipboard

Irregular rebuffering/pauses/stopping at end of

Open PeterAOBell opened this issue 3 years ago • 8 comments

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.

PeterAOBell avatar Dec 08 '21 16:12 PeterAOBell

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?

michaelherger avatar Dec 08 '21 20:12 michaelherger

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

joerg-d avatar Sep 07 '22 17:09 joerg-d

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.

michaelherger avatar Sep 07 '22 21:09 michaelherger

The Connect Mode is already disabled:

Spotify-Connect-Settings

Or is there another way to configure this?

joerg-d avatar Sep 08 '22 06:09 joerg-d

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?

michaelherger avatar Sep 08 '22 06:09 michaelherger

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.

joerg-d avatar Sep 08 '22 08:09 joerg-d

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.

michaelherger avatar Sep 09 '22 04:09 michaelherger

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.

joerg-d avatar Sep 09 '22 17:09 joerg-d