Spotty-Plugin

Spotty-Plugin copied to clipboard

Steps to reproduce

1. Set client ID
2. let it play for a bit (2 hours - 5 hours)
3. sometimes change the volume (don't even know if that matters)
4. Music stops playing with error 429 in the log

Current behaviour (bug)

Absurd high number of calls to the spotify developer endpoint v1/me/player/volume which results in a error 429 and a timeout / aka no more playing for today

Expected behaviour (correct)

The Plugin should not connect to the v1/me/player/volume endpoint so often.

Relevant logs and/or media (optional)

As you can see only the v1/me/player/volume endpoint is called that often, and its not because i change the volume so often. In the days between those calls i wasn't home and before the 06/17 I had the issue #38.

Spotify Developer Page - Number of Requests/Endpoint - `v1/me/player/volume` only


Spotify Developer Page - Number of Requests/Endpoint - All endpoints


I don't see any relevant log entries in the log besides the error: 429 when I can't play anymore.

Other comment (optional)

Maybe this issue also is why for some people settings a client ID is necessary in the first place, while its not necessary with other solutions (e.g. vollibrespot)?

Are you using Spotty in Connect mode? Would shutting down the connect daemon (disabling the feature in Spotty) bring things back to normal?

That volume call indeed has been problematic for a while. I doubt it's the sole reason for 429s in Spotty. With thousands of users there's just a much higher level of requests overall. And events like the one you reported were obvious even then.

The fact that some projects don't face any rate limiting challenges probably is due to the fact that they use a Spotify owned client ID, extracted from official applications. And I don't want to do that, as it clearly is violating the TOU. But they can easily be found on Github and the like.

Yes I'm using the spotify connect to play music, since it is (imo) the most user friendly way.

I will try the other way and report back in a few days.

So I can finally report back,

I've deactivated the spotify connect checkboxes in the plugin. and since then there were 0 calls to the Endpoint 'v1/me/player/volume'

the problem is: since it just takes the few extra steps to get it to start playing, neither me or my girlfriend used it anymore. So it is sadly is not a good solution / workaround.

If I touch the volume while casting I get the following errors in my log. The device_id and bearer token have been scrambled.

22-10-25 07:48:41.9305] Plugins::Spotty::Connect::_bufferedSetVolume (355) Got a volume event - tell Spotify Connect controller to adjust volume, too: 53.9017264276228
[22-10-25 07:48:41.9324] Plugins::Spotty::API::__ANON__ (1340) Trying to read from cache for me
[22-10-25 07:48:41.9327] Plugins::Spotty::API::__ANON__ (1343) Returning cached data for me
[22-10-25 07:48:41.9336] Plugins::Spotty::API::__ANON__ (1349) API call: me/player/volume?device_id=c5ba5176e5a203b86405cea3c749fbfd0bb4ab59&volume_percent=53.9017264276228
[22-10-25 07:48:42.0415] Plugins::Spotty::API::AsyncRequest::onError (156) Failed to connect to https://api.spotify.com/v1/me/player/volume?device_id=c5ba5176e5a203b86405cea3c749fxxxxxxxxxx&volume_percent=53.9017264276228 (400 Bad Request)
[22-10-25 07:48:42.0417] Plugins::Spotty::API::__ANON__ (1446) error: 400 Bad Request
[22-10-25 07:48:42.0435] Plugins::Spotty::API::__ANON__ (1457) bless({
  _content => "",
  _headers => bless({
        "::std_case" => {
              "access-control-allow-credentials" => "Access-Control-Allow-Credentials",
              "access-control-allow-headers" => "Access-Control-Allow-Headers",
              "access-control-allow-methods" => "Access-Control-Allow-Methods",
              "access-control-allow-origin" => "Access-Control-Allow-Origin",
              "access-control-max-age" => "Access-Control-Max-Age",
              "alt-svc" => "Alt-Svc",
              "set-cookie" => "Set-Cookie",
              "set-cookie2" => "Set-Cookie2",
              "strict-transport-security" => "Strict-Transport-Security",
              "x-content-type-options" => "X-Content-Type-Options",
              "x-robots-tag" => "X-Robots-Tag",
            },
        "access-control-allow-credentials" => "true",
        "access-control-allow-headers" => "Accept, App-Platform, Authorization, Content-Type, Origin, Retry-After, Spotify-App-Version, X-Cloud-Trace-Context, client-token, content-access-token",
        "access-control-allow-methods" => "GET, POST, OPTIONS, PUT, DELETE, PATCH",
        "access-control-allow-origin" => "*",
        "access-control-max-age" => 604_800,
        "alt-svc" => "h3=\":443\"; ma=2592000,h3-29=\":443\"; ma=2592000",
        "cache-control" => "private, max-age=0",
        "content-encoding" => "gzip",
        "content-length" => 104,
        "content-type" => "application/json; charset=utf-8",
        date => "Tue, 25 Oct 2022 14:48:41 GMT",
        server => "envoy",
        "strict-transport-security" => "max-age=31536000",
        via => "HTTP/2 edgeproxy, 1.1 google",
        "x-content-type-options" => "nosniff",
        "x-robots-tag" => "noindex, nofollow",
      }, "HTTP::Headers"),
  _msg => "Bad Request",
  _previous => [],
  _rc => 400,
  _request => bless({
        _content  => "",
        _headers  => bless({
                       "::std_case"      => { "icy-metadata" => "Icy-Metadata" },
                       "accept"          => "application/json",
                       "accept-encoding" => ["deflate, gzip", "gzip"],
                       "accept-language" => "en",
                       authorization     => "Bearer XXXXX4eFjUW6w60RRcIsACqNzpSAMpAqVNSrEIrxJRyoS6zX9Vi1iQPT4MgEzLAKHqXBn-RJ75tZhEeMot7JXXXXibSa9kfCJ3SxwV8vSTq0tWjRLnSvbXXXyX4WF29erdoo7n2p7b-spruIgU26okEmlc0i29O51f7wenQMGLood4S42O06AARNn1L6_LXkI6vieFFzOVeMwIBTbBtX5vGhss54iTSxXXX81lipFVu6kfEbAW9e0wErKmXXXXVzeChqZmaU8LQUshQ7EXXXdH9PUvdLmsFGphRONl3tXRFZsqY",
                       "cache-control"   => "no-cache",
                       connection        => "close",
                       "content-length"  => 0,
                       host              => "api.spotify.com",
                       "icy-metadata"    => 1,
                       "user-agent"      => "iTunes/4.7.1 (Linux; N; Debian; x86_64-linux; EN; utf8) SqueezeCenter, Squeezebox Server, Logitech Media Server/8.2.0/1627922070",
                     }, "HTTP::Headers"),
        _method   => "PUT",
        _protocol => "HTTP/1.0",
        _uri      => bless(do{\(my $o = "https://api.spotify.com/v1/me/player/volume?device_id=c5ba5176e5a203b86405cea3c749fxxxxxxxxxx&volume_percent=53.9017264276228")}, "URI::https"),
      }, "HTTP::Request"),
}, "HTTP::Response")```

@giantorth You can use tripple backticks ``` to wrap code blocks in a readable way.

Please enable INFO logging for plugin.spotty, try again, and post the result. Wouldn't the error returned by Spotify be logged?

Please enable INFO logging for plugin.spotty, try again, and post the result. Wouldn't the error returned by Spotify be logged?

As soon as I enabled debugging it started working again, when it was only sending whole numbers. When in a group sometimes the average volume doesn't come out to a whole number and spotify doesn't accept those values:

[22-10-25 08:11:55.9487] Plugins::Spotty::Connect::_bufferedSetVolume (355) Got a volume event - tell Spotify Connect controller to adjust volume, too: 31.3691333198962
[22-10-25 08:11:55.9497] Plugins::Spotty::API::Token::get (203) Found cached token: xxxxxxxxxxxxxxxxxxxxxxxxxxxxSAMpAqVNSrEIrxJRyoS6zX9Vi1iQPT4MgEzLAKHqXBn-RJ75tZhEeMot7JRXAPibSa9kfCJ3SxwV8vSTq0tWxxxxxxxxxxxxxxxxxx29erdoo7n2p7b-spruIgUxxxxxxxxxxxxxxxd4S42O06AARNn1L6_LXkI6vieFFzOVeMwIBTbBtX5vGhss54iTSxRu481lipFVu6kfEbAW9e0wErKmXQT2VzeChqZmaU8LQUshQ7ExxxxxxxxxxxxxxxsFGphRONl3tXRFZsqY
[22-10-25 08:11:55.9499] Plugins::Spotty::API::__ANON__ (1340) Trying to read from cache for me
[22-10-25 08:11:55.9501] Plugins::Spotty::API::__ANON__ (1343) Returning cached data for me
[22-10-25 08:11:55.9509] Plugins::Spotty::API::__ANON__ (1344) do {
  my $a = {
    country => "US",
    display_name => "XXXXXXXX",
    explicit_content => {
          filter_enabled => bless(do{\(my $o = 0)}, "JSON::XS::Boolean"),
          filter_locked  => 'fix',
        },
    external_urls => { spotify => "https://open.spotify.com/user/XXXXXXX" },
    followers => { href => undef, total => 2 },
    href => "https://api.spotify.com/v1/users/XXXXXXX",
    id => "XXXXXXX",
    images => [],
    product => "premium",
    type => "user",
    uri => "spotify:user:XXXXXX",
  };
  $a->{explicit_content}{filter_locked} = \${$a->{explicit_content}{filter_enabled}};
  $a;
}
[22-10-25 08:11:55.9514] Plugins::Spotty::API::Token::get (203) Found cached token: xxxxxxxxxxxxxxxxxxxxxxxxxxxxSAMpAqVNSrEIrxJRyoS6zX9Vi1iQPT4MgEzLAKHqXBn-RJ75tZhEeMot7JRXAPibSa9kfCJ3SxwV8vSTq0tWxxxxxxxxxxxxxxxxxx29erdoo7n2p7b-spruIgUxxxxxxxxxxxxxxxd4S42O06AARNn1L6_LXkI6vieFFzOVeMwIBTbBtX5vGhss54iTSxRu481lipFVu6kfEbAW9e0wErKmXQT2VzeChqZmaU8LQUshQ7ExxxxxxxxxxxxxxxsFGphRONl3tXRFZsqY
[22-10-25 08:11:55.9516] Plugins::Spotty::API::__ANON__ (1349) API call: me/player/volume?device_id=c5ba5176e5a203b86405cea3c749fbfd0bb4ab59&volume_percent=31.3691333198962
[22-10-25 08:11:56.0445] Plugins::Spotty::API::AsyncRequest::onError (156) Failed to connect to https://api.spotify.com/v1/me/player/volume?device_id=XXXXX76e5aXXXXXXXa3c749fbfd0bb4XXX&volume_percent=31.3691333198962 (400 Bad Request)
[22-10-25 08:11:56.0448] Plugins::Spotty::API::__ANON__ (1446) error: 400 Bad Request
[22-10-25 08:11:56.0463] Plugins::Spotty::API::__ANON__ (1457) bless({
  _content => "",
  _headers => bless({
        "::std_case" => {
              "access-control-allow-credentials" => "Access-Control-Allow-Credentials",
              "access-control-allow-headers" => "Access-Control-Allow-Headers",
              "access-control-allow-methods" => "Access-Control-Allow-Methods",
              "access-control-allow-origin" => "Access-Control-Allow-Origin",
              "access-control-max-age" => "Access-Control-Max-Age",
              "alt-svc" => "Alt-Svc",
              "set-cookie" => "Set-Cookie",
              "set-cookie2" => "Set-Cookie2",
              "strict-transport-security" => "Strict-Transport-Security",
              "x-content-type-options" => "X-Content-Type-Options",
              "x-robots-tag" => "X-Robots-Tag",
            },
        "access-control-allow-credentials" => "true",
        "access-control-allow-headers" => "Accept, App-Platform, Authorization, Content-Type, Origin, Retry-After, Spotify-App-Version, X-Cloud-Trace-Context, client-token, content-access-token",
        "access-control-allow-methods" => "GET, POST, OPTIONS, PUT, DELETE, PATCH",
        "access-control-allow-origin" => "*",
        "access-control-max-age" => 604_800,
        "alt-svc" => "h3=\":443\"; ma=2592000,h3-29=\":443\"; ma=2592000",
        "cache-control" => "private, max-age=0",
        "content-encoding" => "gzip",
        "content-length" => 104,
        "content-type" => "application/json; charset=utf-8",
        date => "Tue, 25 Oct 2022 15:11:55 GMT",
        server => "envoy",
        "strict-transport-security" => "max-age=31536000",
        via => "HTTP/2 edgeproxy, 1.1 google",
        "x-content-type-options" => "nosniff",
        "x-robots-tag" => "noindex, nofollow",
      }, "HTTP::Headers"),
  _msg => "Bad Request",
  _previous => [],
  _rc => 400,
  _request => bless({
        _content  => "",
        _headers  => bless({
                       "::std_case"      => { "icy-metadata" => "Icy-Metadata" },
                       "accept"          => "application/json",
                       "accept-encoding" => ["deflate, gzip", "gzip"],
                       "accept-language" => "en",
                       authorization     => "Bearer BQCXXXXXXXXXXXXXXXXXXXxpSAMpAqVNSrEIrxJRyoS6zX9Vi1iQPT4MgEzLAKHqXBn-RJ75tZhEeMXXXXXXXXXXXXXXXXXXXXXXXXXX0tWjRLnSvbAQdyX4WF29erdoo7n2p7b-spruIgU26okEmlc0i29O51XXXXXXXXXXXXXXXXXkI6vieFFzOVeMwIBTbBtX5vGhss54iTSxRu481lipFVu6kfEbAW9e0wErKmXQT2VzeChqZmaU8LQUshQ7XXXXXXXXXXXXXXXXXGphRONl3tXRFZsqY",
                       "cache-control"   => "no-cache",
                       connection        => "close",
                       "content-length"  => 0,
                       host              => "api.spotify.com",
                       "icy-metadata"    => 1,
                       "user-agent"      => "iTunes/4.7.1 (Linux; N; Debian; x86_64-linux; EN; utf8) SqueezeCenter, Squeezebox Server, Logitech Media Server/8.2.0/1627922070",
                     }, "HTTP::Headers"),
        _method   => "PUT",
        _protocol => "HTTP/1.0",
        _uri      => bless(do{\(my $o = "https://api.spotify.com/v1/me/player/volume?device_id=XXXX176e5a203xxxxxxxxxxxxxxxxxxxfd0bb4aXXX&volume_percent=31.3691333198962")}, "URI::https"),
      }, "HTTP::Request"),
}, "HTTP::Response")

Ok, thanks! I can confirm that sending non-integer values would break the request. I'll release an update soon.

Is this still an issue? Or can we close this ticket?