Spotify: Error occurred while trying to retrieve current playback state: Cannot read properties of null (reading 'length')

[Eyeball753]

Hello,

For a while now I've been getting the following error from Spotify:

2023-05-18T20:57:04.571086648Z 2023-05-18T16:57:04-04:00 info    : [Sources] [Spotify - unnamed] Poll retries (0) less than max poll retries (5), restarting polling after 4 second delay...
2023-05-18T20:57:08.575863650Z 2023-05-18T16:57:08-04:00 info    : [Sources] [Spotify - unnamed] Polling started
2023-05-18T20:57:08.576167300Z 2023-05-18T16:57:08-04:00 debug   : [Sources] [Spotify - unnamed] Refreshing recently played
2023-05-18T20:57:08.780874419Z 2023-05-18T16:57:08-04:00 error   : [Sources] [Spotify - unnamed] Error occurred while trying to retrieve current playback state: Cannot read properties of null (reading 'length')
2023-05-18T20:57:08.781305542Z 2023-05-18T16:57:08-04:00 error   : [Sources] [Spotify - unnamed] Error occurred while polling
2023-05-18T20:57:08.781675061Z 2023-05-18T16:57:08-04:00 error   : [Sources] [Spotify - unnamed] Cannot read properties of null (reading 'length')
2023-05-18T20:57:08.781684991Z TypeError: 
2023-05-18T20:57:08.781688404Z     at /app/src/utils.js:76:75
2023-05-18T20:57:08.781691093Z     at SpotifySource.formatPlayObj (/app/src/sources/SpotifySource.js:261:62)
2023-05-18T20:57:08.781693693Z     at SpotifySource.getCurrentPlaybackState (/app/src/sources/SpotifySource.js:143:79)
2023-05-18T20:57:08.781696303Z     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
2023-05-18T20:57:08.781698835Z     at async SpotifySource.getRecentlyPlayed (/app/src/sources/SpotifySource.js:101:31)
2023-05-18T20:57:08.781701382Z     at async AbstractSource.doPolling (/app/src/sources/AbstractSource.js:151:38)
2023-05-18T20:57:08.781703929Z     at async AbstractSource.startPolling (/app/src/sources/AbstractSource.js:113:21)
2023-05-18T20:57:08.781706516Z     at async SpotifySource.poll (/app/src/sources/SpotifySource.js:218:13)

I'm not sure what triggers it. When I restart Multi-Scrobbler it'll work again for a while and then this happens randomly. Today I did the 0.4.0 changes in Unraid and at first I thought me not having done that caused this issue. Unfortunately it happened again so that wasn't it.
Re-authenticating and restarting the polling has also temporarily fixed it before.

For clarification, I've been using Multi-Scrobbler for a year or two and this has never been an issue until a few months ago.

Below you can find my full log. You'll see that most of it is good until near the end of the document where this error keeps occurring.

multi-scrobbler-2023-05-18T23-59-37.log

[FoxxMD]

Thanks for the detailed logs! I've made a change that should fix this. Can you try using foxxmd/multi-scrobbler:develop?

[Eyeball753]

Hi,

I changed to develop but now it seems like Spotify can't authenticate. I re-authenticated it, Spotify gives me OK and then I get:

2023-05-19T13:06:09-04:00 error : [Source - Spotify - unnamed ] Cannot start polling because user interaction is required for authentication

Maybe I'm doing something wrong on my end?

Here's the log:
multi-scrobbler-2023-05-19T17-07-14.log

[Eyeball753]

Just to give a quick update, I noticed this morning I was getting a different error:

2023-05-20T13:17:31.634268968Z ErrorWithCause: 
2023-05-20T13:17:31.634273766Z     at SpotifySource.testAuth (/app/src/sources/SpotifySource.js:72:35)
2023-05-20T13:17:31.634277175Z     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
2023-05-20T13:17:31.634280213Z     at async ScrobbleSources.addSource (/app/src/sources/ScrobbleSources.js:451:31)
2023-05-20T13:17:31.634283153Z     at async ScrobbleSources.buildSourcesFromConfig (/app/src/sources/ScrobbleSources.js:361:29)
2023-05-20T13:17:31.634285918Z     at async /app/src/index.js:126:9
2023-05-20T13:17:31.634288666Z 
2023-05-20T13:17:31.634291337Z caused by: WebapiAuthenticationError: An authentication error occurred while communicating with Spotify's Web API.
2023-05-20T13:17:31.634309289Z Details: invalid_grant Refresh token revoked.
2023-05-20T13:17:31.634313286Z     at _toError (/app/node_modules/spotify-web-api-node/src/http-manager.js:43:12)
2023-05-20T13:17:31.634316291Z     at /app/node_modules/spotify-web-api-node/src/http-manager.js:71:25
2023-05-20T13:17:31.634319125Z     at Request.callback (/app/node_modules/superagent/lib/node/index.js:867:3)
2023-05-20T13:17:31.634322061Z     at /app/node_modules/superagent/lib/node/index.js:1070:18
2023-05-20T13:17:31.634324856Z     at IncomingMessage.<anonymous> (/app/node_modules/superagent/lib/node/parsers/json.js:21:7)
2023-05-20T13:17:31.634327961Z     at Stream.emit (node:events:513:28)
2023-05-20T13:17:31.634330738Z     at Unzip.<anonymous> (/app/node_modules/superagent/lib/node/unzip.js:54:12)
2023-05-20T13:17:31.634333701Z     at Unzip.emit (node:events:513:28)
2023-05-20T13:17:31.634336509Z     at endReadableNT (node:internal/streams/readable:1359:12)
2023-05-20T13:17:31.634339388Z     at process.processTicksAndRejections (node:internal/process/task_queues:82:21)
2023-05-20T13:17:31.634655756Z 2023-05-20T09:17:31-04:00 warn    : [Sources] spotify (unnamed) source auth failed.
2023-05-20T13:17:31.634924073Z 2023-05-20T09:17:31-04:00 debug   : [Sources] (unnamed) Constructing tautulli source
2023-05-20T13:17:31.635476403Z 2023-05-20T09:17:31-04:00 info    : [Sources] [Tautulli - unnamed] Initializing with the following filters => Users: snortsicle | Libraries: N/A | Servers: N/A
2023-05-20T13:17:31.635797352Z 2023-05-20T09:17:31-04:00 info    : [Sources] tautulli (unnamed) source initialized
2023-05-20T13:17:33.141241331Z 2023-05-20T09:17:33-04:00 info    : [App] Server started at http://localhost:9078
2023-05-20T13:17:33.269432868Z 2023-05-20T09:17:33-04:00 debug   : [Sources] [Spotify - unnamed] Access token was not valid, attempting to refresh
2023-05-20T13:17:33.412490638Z 2023-05-20T09:17:33-04:00 warn    : [Sources] [Spotify - unnamed] multi-scrobbler does not have sufficient permissions to access Spotify API "Get Playback State". MS will continue to work but accuracy for determining if/when a track played from a Spotify Connect device (smart device controlled through Spotify app) may be degraded. To fix this re-authenticate MS with Spotify and restart polling.
2023-05-20T13:17:33.412880841Z 2023-05-20T09:17:33-04:00 info    : [Sources] [Spotify - unnamed] Checking recently played API for tracks to backlog...
2023-05-20T13:17:33.540804862Z 2023-05-20T09:17:33-04:00 debug   : [Sources] [Spotify - unnamed] Access token was not valid, attempting to refresh

I restarted MS, re-authenticated and it logged my backlog but it went back to saying:
05/20/2023 9:20:20 AM 2023-05-20T09:20:20-04:00 error : [Sources] [Spotify - unnamed] Cannot start polling because user interaction is required for authentication

Here's the full log:
multi-scrobbler-2023-05-20T13-17-36.log

Thank you.

[FoxxMD]

Please update develop again and let me know if you still have issues. I added a fix that should address cannot start polling after authenticating.

The invalid_grant Refresh token revoked error is new to me. This can happen if the json file generated to store the spotify credentials is tampered with or if the Multi-Scrobbler app has its access removed from your Spotify Account. In either case re-authenticating should fix this.

[Eyeball753]

So far so good. I'll continue using it and monitor it a few times a day to see if something happens. Thank you!

…

On Wed, 24 May 2023 at 11:08, Matt Foxx ***@***.***> wrote: Please update develop again and let me know if you still have issues. I added a fix that should address cannot start polling after authenticating. The invalid_grant Refresh token revoked error is new to me. This can happen if the json file generated to store the spotify credentials is tampered with or if the Multi-Scrobbler app has its access removed from your Spotify Account. In either case re-authenticating should fix this. — Reply to this email directly, view it on GitHub <#76 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/APDRB6JKBR5IZN2PKXLRQQTXHYP73ANCNFSM6AAAAAAYHDIFSI> . You are receiving this because you authored the thread.Message ID: ***@***.***>

[Eyeball753]

I've not had a single issue anymore so I'm gonna say this is resolved. Thanks again.