librespot: Error 403

Hello,

suddenly my librespot instance on libreelec stopped playing any songs.

[2023-06-20T05:24:59Z INFO  librespot] librespot 0.5.0-dev d07b2ce (Built on 2023-06-18, Build ID: e4T4YlCt, Profile: release)
*** WARNING *** The program 'librespot' uses the Apple Bonjour compatibility layer of Avahi.
*** WARNING *** Please fix your application to use the native API of Avahi!
*** WARNING *** For more information see <http://0pointer.de/blog/projects/avahi-compat.html>
[2023-06-20T05:24:59Z INFO  librespot_playback::mixer::softmixer] Mixing with softvol and volume control: Log(60.0)
[2023-06-20T05:24:59Z INFO  librespot_playback::convert] Converting with ditherer: tpdf
[2023-06-20T05:24:59Z INFO  librespot_playback::audio_backend::alsa] Using AlsaSink with format: S16
[2023-06-20T05:24:59Z INFO  librespot_core::session] Connecting to AP "ap-gew4.spotify.com:4070"
[2023-06-20T05:24:59Z INFO  librespot_core::session] Authenticated as "11127372133" !
[2023-06-20T05:24:59Z INFO  librespot_core::session] Country: "CZ"
[2023-06-20T05:25:08Z INFO  librespot_core::spclient] Resolved "gew4-spclient.spotify.com:443" as spclient access point
[2023-06-20T05:25:08Z ERROR librespot_core::mercury] error 403 for uri hm://keymaster/token/authenticated?scope=playlist-read&client_id=65b708073fc0480ea92a077233ca87bd&device_id=78f3d06ba0952bdccb9e15230ae4f8c6891f6292
[2023-06-20T05:25:08Z ERROR librespot_connect::spirc] ContextError: Error { kind: Unavailable, error: Response(MercuryResponse { uri: "hm://keymaster/token/authenticated?scope=playlist-read&client_id=65b708073fc0480ea92a077233ca87bd&device_id=78f3d06ba0952bdccb9e15230ae4f8c6891f6292", status_code: 403, payload: [[123, 34, 99, 111, 100, 101, 34, 58, 52, 44, 34, 101, 114, 114, 111, 114, 68, 101, 115, 99, 114, 105, 112, 116, 105, 111, 110, 34, 58, 34, 73, 110, 118, 97, 108, 105, 100, 32, 114, 101, 113, 117, 101, 115, 116, 34, 125]] }) }
[2023-06-20T05:25:08Z ERROR librespot_core::mercury] error 403 for uri hm://keymaster/token/authenticated?scope=playlist-read&client_id=65b708073fc0480ea92a077233ca87bd&device_id=78f3d06ba0952bdccb9e15230ae4f8c6891f6292
[2023-06-20T05:25:08Z ERROR librespot_playback::player] Unable to load audio item: Error { kind: Unavailable, error: Response(MercuryResponse { uri: "hm://keymaster/token/authenticated?scope=playlist-read&client_id=65b708073fc0480ea92a077233ca87bd&device_id=78f3d06ba0952bdccb9e15230ae4f8c6891f6292", status_code: 403, payload: [[123, 34, 99, 111, 100, 101, 34, 58, 52, 44, 34, 101, 114, 114, 111, 114, 68, 101, 115, 99, 114, 105, 112, 116, 105, 111, 110, 34, 58, 34, 73, 110, 118, 97, 108, 105, 100, 32, 114, 101, 113, 117, 101, 115, 116, 34, 125]] }) }
[2023-06-20T05:25:08Z ERROR librespot_playback::player] Skipping to next track, unable to load track <SpotifyId("spotify:track:4vGFfCD9PvBuKDbTourDdW")>: ()
[2023-06-20T05:25:08Z ERROR librespot_core::mercury] error 403 for uri hm://keymaster/token/authenticated?scope=playlist-read&client_id=65b708073fc0480ea92a077233ca87bd&device_id=78f3d06ba0952bdccb9e15230ae4f8c6891f6292
[2023-06-20T05:25:08Z ERROR librespot_playback::player] Unable to load audio item: Error { kind: Unavailable, error: Response(MercuryResponse { uri: "hm://keymaster/token/authenticated?scope=playlist-read&client_id=65b708073fc0480ea92a077233ca87bd&device_id=78f3d06ba0952bdccb9e15230ae4f8c6891f6292", status_code: 403, payload: [[123, 34, 99, 111, 100, 101, 34, 58, 52, 44, 34, 101, 114, 114, 111, 114, 68, 101, 115, 99, 114, 105, 112, 116, 105, 111, 110, 34, 58, 34, 73, 110, 118, 97, 108, 105, 100, 32, 114, 101, 113, 117, 101, 115, 116, 34, 125]] }) }

I think it is similar to #972 if it is not the same, but I have not found any way how to fix it yet…

~ # curl http://apresolve.spotify.com/
{"ap_list":["ap-gew4.spotify.com:4070","ap-gew4.spotify.com:443","ap-gew4.spotify.com:80","ap-gue1.spotify.com:4070","ap-gew1.spotify.com:443","ap-guc3.spotify.com:80"]}

About this issue

  • Original URL
  • State: open
  • Created a year ago
  • Comments: 43 (34 by maintainers)

Commits related to this issue

Most upvoted comments

I can’t remember what state it is in. I’ll take a look when I get time

I’m away for the next week without a computer. Anyone who has the time is welcome to take the code and submit a PR. I can’t remember what state I left it in.

No, but I can test it with an iPhone, I’ll be back.

I can confirm that @kingosticks branch fixes it for me. Any chance this get merged?

Hi - will the @kingosticks’s PR be merged? I don’t know if the solution is optimal but for me it works 😃

I had the same 403 problem, and it was also solved by using @kingosticks branch. I now have librespot running on piCore (14.0) and Raspbian (11 Bullseye), connecting to it with the windows and android spotify app, all working fine. Thanks kingosticks!

I have no time now to look closer to the log, but it seems to me that librespot-java also ends with 403 here in Czechia…

2023-06-30 12:04:44,181 TRACE FileConfiguration:148 - Added new entry to configuration file: clientToken
2023-06-30 12:04:44,183 TRACE FileConfiguration:148 - Added new entry to configuration file: network.connectionTimeout
2023-06-30 12:04:44,183 TRACE FileConfiguration:148 - Added new entry to configuration file: proxy.ssl
2023-06-30 12:04:44,183 TRACE FileConfiguration:148 - Added new entry to configuration file: shell.onTrackSeeked
2023-06-30 12:04:44,183 TRACE FileConfiguration:148 - Added new entry to configuration file: shell.onStartedLoading
2023-06-30 12:04:44,184 TRACE FileConfiguration:148 - Added new entry to configuration file: shell.onConnectionDropped
2023-06-30 12:04:44,184 TRACE FileConfiguration:148 - Added new entry to configuration file: shell.onMetadataAvailable
2023-06-30 12:04:44,184 TRACE FileConfiguration:148 - Added new entry to configuration file: shell.onTrackChanged
2023-06-30 12:04:44,184 TRACE FileConfiguration:148 - Added new entry to configuration file: shell.onPlaybackFailed
2023-06-30 12:04:44,184 TRACE FileConfiguration:148 - Added new entry to configuration file: shell.onPanicState
2023-06-30 12:04:44,184 TRACE FileConfiguration:148 - Added new entry to configuration file: shell.onFinishedLoading
2023-06-30 12:04:44,185 TRACE FileConfiguration:148 - Added new entry to configuration file: shell.enabled
2023-06-30 12:04:44,185 TRACE FileConfiguration:148 - Added new entry to configuration file: shell.onPlaybackResumed
2023-06-30 12:04:44,185 TRACE FileConfiguration:148 - Added new entry to configuration file: shell.onConnectionEstablished
2023-06-30 12:04:44,185 TRACE FileConfiguration:148 - Added new entry to configuration file: shell.onPlaybackEnded
2023-06-30 12:04:44,185 TRACE FileConfiguration:148 - Added new entry to configuration file: shell.onContextChanged
2023-06-30 12:04:44,185 TRACE FileConfiguration:148 - Added new entry to configuration file: shell.executeWithBash
2023-06-30 12:04:44,185 TRACE FileConfiguration:148 - Added new entry to configuration file: shell.onPlaybackPaused
2023-06-30 12:04:44,185 TRACE FileConfiguration:148 - Added new entry to configuration file: shell.onInactiveSession
2023-06-30 12:04:44,185 TRACE FileConfiguration:148 - Added new entry to configuration file: shell.onVolumeChanged
2023-06-30 12:04:44,186 TRACE FileConfiguration:148 - Added new entry to configuration file: player.bypassSinkVolume
2023-06-30 12:04:44,186 TRACE FileConfiguration:148 - Added new entry to configuration file: player.localFilesPath
2023-06-30 12:04:44,186 TRACE FileConfiguration:148 - Added new entry to configuration file: player.outputClass
2023-06-30 12:04:44,201 INFO  Utils:104 - Cryptography restrictions removal not needed.
2023-06-30 12:04:44,229 INFO  ZeroconfServer:472 - Zeroconf HTTP server started successfully on port 53259!
2023-06-30 12:04:44,997 TRACE ZeroconfServer:536 - Handling request: GET /?action=getInfo HTTP/1.1, headers: {Keep-Alive=0, Connection=keep-alive, User-Agent=Spotify/121300661 Linux/0 (PC desktop), Host=10.88.0.26, Accept-Encoding=gzip, Content-Type=application/x-www-form-urlencoded}
2023-06-30 12:04:45,666 INFO  Zeroconf:500 - Announced Service{alias='librespot-java-player', service='spotify-connect', port=53259, text={VERSION=1.0, CPath=/, Stack=SP}, addresses=[/10.88.0.26], domain='.local', protocol='tcp', host='jules-ntb'}.
2023-06-30 12:04:50,343 TRACE ZeroconfServer:536 - Handling request: GET /?action=getInfo&version=2.7.1 HTTP/1.1, headers: {Keep-Alive=0, Connection=keep-alive, User-Agent=Spotify/121300661 Linux/0 (PC desktop), Host=10.88.0.26, Accept-Encoding=gzip, Content-Type=application/x-www-form-urlencoded}
2023-06-30 12:04:54,374 TRACE ZeroconfServer:536 - Handling request: GET /?action=getInfo&version=2.7.1 HTTP/1.1, headers: {Keep-Alive=0, Connection=keep-alive, User-Agent=Spotify/121300661 Linux/0 (PC desktop), Host=10.88.0.26, Accept-Encoding=gzip, Content-Type=application/x-www-form-urlencoded}
2023-06-30 12:04:54,390 TRACE ZeroconfServer:536 - Handling request: POST / HTTP/1.1, headers: {Keep-Alive=0, Connection=keep-alive, User-Agent=Spotify/121300661 Linux/0 (PC desktop), Host=10.88.0.26, Accept-Encoding=gzip, Content-Length=822, Content-Type=application/x-www-form-urlencoded}
2023-06-30 12:04:54,452 INFO  ZeroconfServer:345 - Accepted new user from jules-ntb. {deviceId: 95125d2c2a63cfc6f6d2aa267bfa8443d425b37b}
2023-06-30 12:04:54,515 DEBUG TimeProvider:90 - Loaded time offset from NTP: 0ms
2023-06-30 12:04:54,778 INFO  ApResolver:99 - Loaded aps into pool: {accesspoint=[ap-gew4.spotify.com:4070, ap-gew4.spotify.com:443, ap-gew4.spotify.com:80, ap-gew1.spotify.com:4070, ap-guc3.spotify.com:443, ap-gue1.spotify.com:80], dealer=[gew4-dealer.spotify.com:443, gew1-dealer.spotify.com:443, guc3-dealer.spotify.com:443, gue1-dealer.spotify.com:443], spclient=[gew4-spclient.spotify.com:443, gew1-spclient.spotify.com:443, guc3-spclient.spotify.com:443, gue1-spclient.spotify.com:443]}
2023-06-30 12:04:54,822 INFO  Session:140 - Created new session! {deviceId: 95125d2c2a63cfc6f6d2aa267bfa8443d425b37b, ap: ap-gew1.spotify.com:4070, proxy: false}
2023-06-30 12:04:55,330 INFO  Session:334 - Connected successfully!
2023-06-30 12:04:55,563 TRACE Session:1413 - Session.Receiver started
2023-06-30 12:04:55,576 INFO  CacheManager:95 - There are 0 cached entries.
2023-06-30 12:04:55,579 TRACE AsyncProcessor:52 - AsyncProcessor{dealer-worker} has started
2023-06-30 12:04:55,580 TRACE AsyncProcessor:52 - AsyncProcessor{event-service-sender} has started
2023-06-30 12:04:55,581 INFO  Session:1495 - Skipping SecretBlock
2023-06-30 12:04:55,581 INFO  Session:1467 - Received LicenseVersion: 0
2023-06-30 12:04:55,581 INFO  Session:1457 - Received CountryCode: CZ
2023-06-30 12:04:55,581 DEBUG TokenProvider:68 - Token expired or not suitable, requesting again. {scopes: [playlist-read], oldToken: null}
2023-06-30 12:04:55,587 TRACE MercuryClient:148 - Send Mercury request, seq: 1, uri: hm://keymaster/token/authenticated?scope=playlist-read&client_id=65b708073fc0480ea92a077233ca87bd&device_id=95125d2c2a63cfc6f6d2aa267bfa8443d425b37b, method: GET
2023-06-30 12:04:55,591 TRACE Session:784 - Parsed product info: {audiobook-onboarding-completed=0, remote-control=6, publish-activity=0, audio-preview-url-template=https://p.scdn.co/mp3-preview/{id}, incognito_mode_timeout=21600, ad-formats-preroll-video=0, type=premium, ab_recently_played_feature_time_filter_threshold=com.spotify.gaia=30,driving-mode=120,spotify%3Ainternal%3Astartpage=30, license-agreements=, publish-playlist=1, buffering-strategy=0, expiry=1, ab-desktop-hide-follow=0, ab-collection-hide-unavailable-albums=0, capper-profile=, payments-initial-campaign=default, profile-image-upload=1, enable-annotations=2, ab-ad-player-targeting=1, india-experience=0, video-wifi-initial-bitrate=800000, ab-mobile-running-onlymanualmode=only-manual, playlist-annotations-markup=0, prefetch-keys=1, allow-override-internal-prefs=0, prefetch-window-max=2, send-email=1, ad-formats-video-takeover=1, ab-collection-bookmark-model=1, pause-after=0, local-files-import=0, video-manifest-url=https://spclient.wg.spotify.com/manifests/v6/{type}/sources/{source_id}/options/supports_drm, ab-sugarpills-sanity-check=0, playlist-folders=1, arsenal_country=1, track-cap=0, audiobook-onboarding-dismissed=0, ab-mobile-running-tempo-detection=Control, is_email_verified=1, shows-collection=1, enable-annotations-read=0, addon-hifi=0, mobile-browse=0, payments-locked-state=0, employee-free-opt-in=0, shows-collection-jam=0, ab-browse-music-tuesday=1, offline=1, streaming=1, fb-info-confirmation=control, audio-quality=1, wanted-licenses=, lastfm-session=, ab-desktop-playlist-annotation-edit=1, ab-mobile-discover=0, widevine-license-url=https://spclient.wg.spotify.com/widevine-license/v1/video/license, key-caching-max-count=10000, hifi-eligible=0, ad-session-persistence=1, video-initial-bitrate=200000, ab-play-history=0, mobile-payment=0, payment-state=, key-caching-max-offline-seconds=1800, ugc-abuse-report-url=https://support.spotify.com/abuse/?uri={uri}, shuffle-algorithm=1, use-pl3=0, image-url=https://i.scdn.co/image/{file_id}, use-playlist-app=0, enable-autostart=1, metadata-link-lookup-modes=0, shuffle=0, instant-search=0, instant-search-expand-sidebar=0, use-playlist-uris=0, user-profile-show-invitation-codes=0, ab-ad-requester=1, nft-disabled=1, ab-collection-union=1, key-memory-cache-mode=1:15,300, libspotify=1, high-bitrate=1, head-file-caching=1, radio=1, key-caching-auto-offline=0, explicit-content=1, video-cdn-sampling=1, ab-android-push-notifications=1, unrestricted=1, use-fb-publish-backend=2, app-developer=0, buffering-strategy-parameters=0.8:0.2:0.0:0.0:0.0:0.0:1.0:10:10:2000:10000:10485760, enable-gapless=1, ab-playlist-extender=5, enable-crossfade=1, ad-persist-reward-time=0, network-operator-premium-activation=1, video-device-blacklisted=0, collection=1, fb-grant-permission-local-render=0, backend-advised-bitrate=1, autoplay=1, catalogue=premium, storage-size-config=10240,90,500,3, ads=0, head-files-url=https://heads-fa.scdn.co/head/{file_id}, ab-collection-followed-artists-only=0, browse-overview-enabled=1, on-demand=1, ap-resolve-pods=0, name=Spotify Premium, sidebar-navigation-enabled=0, loudness-levels=1:-5.0,0.0,3.0:-2.0, mobile-login=1, hifi-optin-intent=0, preferred-locale=en, license-acceptance-grace-days=30, prefetch-strategy=18, ugc-abuse-report=1, ab-watch-now=0, financial-product=pr:premium,tc:0, ab-collection-offline-mode=0, streaming-rules=, head-files=1, capping-bar-threshold=3601, ab-new-share-flow=0, video-keyframe-url=http://keyframes-fa.cdn.spotify.com/keyframes/v1/sources/{source_id}/keyframe/heights/{height}/timestamps/{timestamp_ms}.jpg, mobile=1, is_maybe_in_social_session=0, ab-mobile-startpage=0, ab-moments-experience=0, ab-mobile-social-feed=1, ab-test-group=976, player-license=premium}
2023-06-30 12:04:55,591 INFO  Session:1495 - Skipping UnknownData_AllZeros
2023-06-30 12:04:55,591 INFO  Session:1495 - Skipping LegacyWelcome
2023-06-30 12:04:55,592 TRACE MercuryClient:191 - Handling packet, cmd: MercuryEvent, seq: 6906288720270327808, flags: 1, parts: 1
2023-06-30 12:04:55,594 DEBUG MercuryClient:226 - Couldn't dispatch Mercury event {seq: 6906288720270327808, uri: hm://pusher/v1/connections/OTUxMjVkMmMyYTYzY2ZjNmY2ZDJhYTI2N2JmYTg0NDNkNDI1YjM3YitBUCt0Y3A6Ly9nZXcxLWFjY2Vzc3BvaW50LWMtcDR6Zi5nZXcxLnNwb3RpZnkubmV0OjUwMTErRUM2NDg0NEE2NkNCNTEyQkMwNEMzNTFGRDhBNTBFMUJCMDQyQzlFMDA1M0E0Mjk5OUQwNUQxRDg5MDhGQzNDQQ%3D%3D, code: 200, payload: []}
2023-06-30 12:04:55,652 DEBUG Session:1471 - Received 0x10: EF217D8324B2DA4B50052920D623A1FEBB1328CC
2023-06-30 12:04:55,726 TRACE MercuryClient:191 - Handling packet, cmd: MercuryReq, seq: 1, flags: 1, parts: 2
2023-06-30 12:04:55,729 ERROR ZeroconfServer:375 - Couldn't establish a new session.
xyz.gianlu.librespot.mercury.MercuryClient$MercuryException: status: 403
        at xyz.gianlu.librespot.mercury.MercuryClient.sendSync(MercuryClient.java:107) ~[librespot-player.jar:1.6.3]
        at xyz.gianlu.librespot.core.TokenProvider.getToken(TokenProvider.java:69) ~[librespot-player.jar:1.6.3]
        at xyz.gianlu.librespot.core.TokenProvider.get(TokenProvider.java:80) ~[librespot-player.jar:1.6.3]
        at xyz.gianlu.librespot.dealer.DealerClient.connect(DealerClient.java:78) ~[librespot-player.jar:1.6.3]
        at xyz.gianlu.librespot.core.Session.authenticate(Session.java:362) ~[librespot-player.jar:1.6.3]
        at xyz.gianlu.librespot.core.Session.access$600(Session.java:77) ~[librespot-player.jar:1.6.3]
        at xyz.gianlu.librespot.core.Session$Builder.create(Session.java:1057) ~[librespot-player.jar:1.6.3]
        at xyz.gianlu.librespot.ZeroconfServer.handleAddUser(ZeroconfServer.java:367) ~[librespot-player.jar:1.6.3]
        at xyz.gianlu.librespot.ZeroconfServer.access$200(ZeroconfServer.java:56) ~[librespot-player.jar:1.6.3]
        at xyz.gianlu.librespot.ZeroconfServer$HttpRunner.handleRequest(ZeroconfServer.java:499) ~[librespot-player.jar:1.6.3]
        at xyz.gianlu.librespot.ZeroconfServer$HttpRunner.handle(ZeroconfServer.java:574) ~[librespot-player.jar:1.6.3]
        at xyz.gianlu.librespot.ZeroconfServer$HttpRunner.lambda$run$1(ZeroconfServer.java:482) ~[librespot-player.jar:1.6.3]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
        at java.lang.Thread.run(Thread.java:829) [?:?]
2023-06-30 12:04:55,744 ERROR ZeroconfServer:501 - Failed handling addUser!
java.net.SocketException: Broken pipe (Write failed)
        at java.net.SocketOutputStream.socketWrite0(Native Method) ~[?:?]
        at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:110) ~[?:?]
        at java.net.SocketOutputStream.write(SocketOutputStream.java:138) ~[?:?]
        at xyz.gianlu.librespot.ZeroconfServer.handleAddUser(ZeroconfServer.java:382) ~[librespot-player.jar:1.6.3]
        at xyz.gianlu.librespot.ZeroconfServer.access$200(ZeroconfServer.java:56) ~[librespot-player.jar:1.6.3]
        at xyz.gianlu.librespot.ZeroconfServer$HttpRunner.handleRequest(ZeroconfServer.java:499) ~[librespot-player.jar:1.6.3]
        at xyz.gianlu.librespot.ZeroconfServer$HttpRunner.handle(ZeroconfServer.java:574) ~[librespot-player.jar:1.6.3]
        at xyz.gianlu.librespot.ZeroconfServer$HttpRunner.lambda$run$1(ZeroconfServer.java:482) ~[librespot-player.jar:1.6.3]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
        at java.lang.Thread.run(Thread.java:829) [?:?]
2023-06-30 12:04:56,015 INFO  Session:1422 - Skipping unknown command {cmd: 0x75, payload: 000000}
čen 30 12:05:25 jules-ntb systemd[1]: Stopping A spotify playing daemon...
čen 30 12:05:26 jules-ntb systemd[1]: librespot-java.service: Main process exited, code=exited, status=143/n/a
čen 30 12:05:26 jules-ntb systemd[1]: librespot-java.service: Failed with result 'exit-code'.
čen 30 12:05:26 jules-ntb systemd[1]: Stopped A spotify playing daemon.
čen 30 12:05:26 jules-ntb systemd[1]: librespot-java.service: Consumed 3.424s CPU time.

If possible can you double check that the same access point hostname definitely resolves to the same IP in both working and non-working cases? Presumably it was the same user account in both cases also?