michaelherger / Spotty-Plugin

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

Spotty stops playback at end of track #14

Closed error454 closed 10 months ago

error454 commented 4 years ago

System Details

Problem Statement

When streaming to a squeezelite device using spotty, once a song reaches the end, playback stops and the Spotify app gets disconnected from the spotify connect source. I can hit play again and re-select the device and it works fine, but playback always stops at the end of the track.

Sometimes toggling shuffle seems to fix this, other times it doesn't.

Any logs I can look at to figure out what's going on? My Squeezebox logs are empty.

michaelherger commented 4 years ago

Please enable INFO logging for plugin.spotty, reproduce, and check the server.log again.

Unfortunately the Spotify Connect mode never has been really stable. There issues all too often. But I haven't found any solution to this yet.

error454 commented 4 years ago

Thanks, I will keep my eye on these. Naturally, when I try to repro, I can't.

fletort commented 4 years ago

which daemon are you using for the spotify connect section ? ok it is based on librespot. the problem is on your side or in the lib ? (if i can help...)

hannemann commented 3 years ago

i am experiencing something similar but i don't know if it's related.

I like listenening to the Daily Drive Playlist. Almost everytime when news start to play, the playback is stopped after 10 seconds. I can restart playback by pressing the pause button in the LMS web frontend and than hit play on Spotify again.

Loglevel Info:

[20-11-06 11:50:31.6227] Plugins::Spotty::Connect::DaemonManager::initHelpers (90) Checking Spotty Connect helper daemons...
[20-11-06 11:50:31.6231] Plugins::Spotty::Connect::DaemonManager::initHelpers (120) This is the sync group's master, or a standalone player with Spotify Connect enabled: b8:27:eb:d8:8d:4e
[20-11-06 11:50:31.6234] Plugins::Spotty::Connect::DaemonManager::initHelpers (120) This is the sync group's master, or a standalone player with Spotify Connect enabled: b8:27:eb:e0:e8:a1
[20-11-06 11:50:31.6237] Plugins::Spotty::Connect::DaemonManager::initHelpers (120) This is the sync group's master, or a standalone player with Spotify Connect enabled: 00:1e:e5:ed:b4:69
[20-11-06 11:51:31.6242] Plugins::Spotty::Connect::DaemonManager::initHelpers (90) Checking Spotty Connect helper daemons...
[20-11-06 11:51:31.6245] Plugins::Spotty::Connect::DaemonManager::initHelpers (120) This is the sync group's master, or a standalone player with Spotify Connect enabled: b8:27:eb:d8:8d:4e
[20-11-06 11:51:31.6248] Plugins::Spotty::Connect::DaemonManager::initHelpers (120) This is the sync group's master, or a standalone player with Spotify Connect enabled: b8:27:eb:e0:e8:a1
[20-11-06 11:51:31.6251] Plugins::Spotty::Connect::DaemonManager::initHelpers (120) This is the sync group's master, or a standalone player with Spotify Connect enabled: 00:1e:e5:ed:b4:69
[20-11-06 11:51:48.1835] Plugins::Spotty::API::__ANON__ (1322) Trying to read from cache for me
[20-11-06 11:51:48.1839] Plugins::Spotty::API::__ANON__ (1325) Returning cached data for me
[20-11-06 11:51:48.1843] Plugins::Spotty::Connect::_getNextTrack (208) We're approaching the end of a track - get the next track
[20-11-06 11:51:48.1846] Plugins::Spotty::Connect::Context::addPlay (126) Adding track to played list: spotify://track:6ffqzH0cLZdKHuZB0rqec0
[20-11-06 11:51:48.1858] Plugins::Spotty::API::__ANON__ (1331) API call: me/player/next
[20-11-06 11:51:48.3254] Plugins::Spotty::API::__ANON__ (1331) API call: me/player?market=from_token
[20-11-06 11:51:48.4279] Plugins::Spotty::Connect::DaemonManager::checkAPIConnectPlayers (215) Updating id of Connect connected dameon for b8:27:eb:d8:8d:4e
[20-11-06 11:51:48.4738] Plugins::Spotty::Connect::_connectEvent (356) Ignoring request, as it's a follow up to a new track event: change
[20-11-06 11:51:59.0274] Plugins::Spotty::Connect::_onPause (321) Got a pause event - tell Spotify Connect controller to pause, too
[20-11-06 11:51:59.0284] Plugins::Spotty::API::__ANON__ (1322) Trying to read from cache for me
[20-11-06 11:51:59.0287] Plugins::Spotty::API::__ANON__ (1325) Returning cached data for me
[20-11-06 11:51:59.0297] Plugins::Spotty::API::__ANON__ (1331) API call: me/player/pause?device_id=d5886ecdbfaa39636050cddef68b12346cea7c62
[20-11-06 11:51:59.1779] Plugins::Spotty::Connect::_connectEvent (361) Got called from spotty helper: stop
[20-11-06 11:51:59.1789] Plugins::Spotty::API::__ANON__ (1322) Trying to read from cache for me
[20-11-06 11:51:59.1793] Plugins::Spotty::API::__ANON__ (1325) Returning cached data for me
[20-11-06 11:51:59.1800] Plugins::Spotty::API::__ANON__ (1331) API call: me/player?market=from_token
[20-11-06 11:51:59.2723] Plugins::Spotty::Connect::DaemonManager::checkAPIConnectPlayers (215) Updating id of Connect connected dameon for b8:27:eb:d8:8d:4e
[20-11-06 11:51:59.3631] Plugins::Spotty::Connect::__ANON__ (397) Current Connect state: 
do {
  my $a = {
    actions                  => {
                                  disallows => {
                                        "toggling_repeat_track" => bless(do{\(my $o = 1)}, "JSON::XS::Boolean"),
                                      },
                                },
    context                  => undef,
    "currently_playing_type" => "episode",
    device                   => {
                                  id => "d5886ecdbfaa39636050cddef68b12346cea7c62",
                                  is_active => 'fix',
                                  is_private_session => bless(do{\(my $o = 0)}, "JSON::XS::Boolean"),
                                  is_restricted => 'fix',
                                  name => "HifiPI",
                                  type => "Speaker",
                                  volume_percent => 50,
                                },
    is_playing               => 'fix',
    item                     => undef,
    progress                 => "10.819",
    progress_ms              => 10_819,
    repeat_state             => "off",
    shuffle_state            => 'fix',
    timestamp                => "1604659919165",
  };
  $a->{device}{is_active} = \${$a->{actions}{disallows}{"toggling_repeat_track"}};
  $a->{device}{is_restricted} = \${$a->{device}{is_private_session}};
  $a->{is_playing} = \${$a->{device}{is_private_session}};
  $a->{shuffle_state} = \${$a->{device}{is_private_session}};
  ($a, "stop");
}
[20-11-06 11:51:59.3634] Plugins::Spotty::Connect::__ANON__ (457) Spotify told us to pause: b8:27:eb:d8:8d:4e
[20-11-06 11:51:59.3647] Plugins::Spotty::ProtocolHandler::getMetadataFor (181) Returning metadata cached in song object for spotify://track:6ffqzH0cLZdKHuZB0rqec0
[20-11-06 11:51:59.6682] Plugins::Spotty::ProtocolHandler::getMetadataFor (181) Returning metadata cached in song object for spotify://track:6ffqzH0cLZdKHuZB0rqec0
[20-11-06 11:51:59.6690] Plugins::Spotty::ProtocolHandler::getMetadataFor (181) Returning metadata cached in song object for spotify://track:6ffqzH0cLZdKHuZB0rqec0
[20-11-06 11:52:31.6256] Plugins::Spotty::Connect::DaemonManager::initHelpers (90) Checking Spotty Connect helper daemons...
[20-11-06 11:52:31.6259] Plugins::Spotty::Connect::DaemonManager::initHelpers (120) This is the sync group's master, or a standalone player with Spotify Connect enabled: b8:27:eb:d8:8d:4e
[20-11-06 11:52:31.6262] Plugins::Spotty::Connect::DaemonManager::initHelpers (120) This is the sync group's master, or a standalone player with Spotify Connect enabled: b8:27:eb:e0:e8:a1
[20-11-06 11:52:31.6265] Plugins::Spotty::Connect::DaemonManager::initHelpers (120) This is the sync group's master, or a standalone player with Spotify Connect enabled: 00:1e:e5:ed:b4:69

Kind of annoying though... Please tell me if i can help to resolve this issue.

hannemann commented 3 years ago

Just happened again... But this time between two songs and the playback startet again without any action with an offset of about 2 minutes.

A few minutes later Playback stopped entirely (token expired). I was able to restart playback after 10 Minutes or so. In the meantime no token could be fetched server.log

michaelherger commented 3 years ago

I'm not sure whether this is related. But something's going wrong right now, as the number of requests done from Spotty against the Spotify servers has about doubled in the past two days. I'm therefore also seeing "429 - too many requests" errors. I hope the situation will settle soon, or we'll have to find some other solution.

ju2256 commented 2 years ago

Hi, i'm having same trouble, is the problem solved ? I have picoreplayer v8.0.0.

Thanks.

michaelherger commented 10 months ago

Please see #82.