search

librespot-org / librespot-java

The most up-to-date open source Spotify client
Apache License 2.0
389 stars 96 forks source link

Couldn't establish a new session. MercuryClient$MercuryException: status: 403 #697

Open Justus-G opened 1 year ago

Justus-G commented 1 year ago

Describe the bug Since a few days, Librespot is not working anymore and instead logs a 403 authentication error.

To Reproduce Occurs every time, on any machine.

Screenshots/Stracktraces/Logs Librespot log:

2023-08-24 21:54:13,782 INFO  Utils:104 - Cryptography restrictions removal not needed.
2023-08-24 21:54:13,948 INFO  ZeroconfServer:472 - Zeroconf HTTP server started successfully on port 18508!
2023-08-24 21:54:15,409 INFO  Zeroconf:500 - Announced Service{alias='librespot-java', service='spotify-connect', port=18508, text={VERSION=1.0, CPath=/, Stack=SP}, addresses=[/192.168.217.56], domain='.local', protocol='tcp', host='raspberrypi4'}.
2023-08-24 21:54:19,974 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/121700834 OSX_ARM64/0 (Mac14,2), Host=192.168.217.56, Accept-Encoding=gzip, Content-Type=application/x-www-form-urlencoded}
2023-08-24 21:54:22,203 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/121700834 OSX_ARM64/0 (Mac14,2), Host=192.168.217.56, Accept-Encoding=gzip, Content-Type=application/x-www-form-urlencoded}
2023-08-24 21:54:22,270 TRACE ZeroconfServer:536 - Handling request: POST / HTTP/1.1, headers: {Keep-Alive=0, Connection=keep-alive, User-Agent=Spotify/121700834 OSX_ARM64/0 (Mac14,2), Host=192.168.217.56, Accept-Encoding=gzip, Content-Length=863, Content-Type=application/x-www-form-urlencoded}
2023-08-24 21:54:22,507 INFO  ZeroconfServer:345 - Accepted new user from <censored>. {deviceId: b457cbd5840886003282c0bc498000bb2842e13f}
2023-08-24 21:54:22,681 DEBUG TimeProvider:90 - Loaded time offset from NTP: 0ms
2023-08-24 21:54:23,376 INFO  ApResolver:99 - Loaded aps into pool: {accesspoint=[ap-gew4.spotify.com:4070, ap-gew4.spotify.com:443, ap-gew4.spotify.com:80, ap-gae2.spotify.com:4070, ap-gew1.spotify.com:443, ap-gue1.spotify.com:80], dealer=[gew4-dealer.spotify.com:443, gae2-dealer.spotify.com:443, gew1-dealer.spotify.com:443, gue1-dealer.spotify.com:443], spclient=[gew4-spclient.spotify.com:443, gae2-spclient.spotify.com:443, gew1-spclient.spotify.com:443, gue1-spclient.spotify.com:443]}
2023-08-24 21:54:23,592 INFO  Session:140 - Created new session! {deviceId: b457cbd5840886003282c0bc498000bb2842e13f, ap: ap-gae2.spotify.com:4070, proxy: false} 
2023-08-24 21:54:24,518 INFO  Session:334 - Connected successfully!
2023-08-24 21:54:24,984 TRACE Session:1413 - Session.Receiver started
2023-08-24 21:54:25,047 INFO  CacheManager:95 - There are 0 cached entries.
2023-08-24 21:54:25,058 TRACE AsyncProcessor:52 - AsyncProcessor{dealer-worker} has started
2023-08-24 21:54:25,064 TRACE AsyncProcessor:52 - AsyncProcessor{event-service-sender} has started
2023-08-24 21:54:25,066 INFO  Session:1495 - Skipping SecretBlock
2023-08-24 21:54:25,067 INFO  Session:1467 - Received LicenseVersion: 0
2023-08-24 21:54:25,068 INFO  Session:1457 - Received CountryCode: DE
2023-08-24 21:54:25,070 DEBUG TokenProvider:68 - Token expired or not suitable, requesting again. {scopes: [playlist-read], oldToken: null}
2023-08-24 21:54:25,091 TRACE MercuryClient:148 - Send Mercury request, seq: 1, uri: hm://keymaster/token/authenticated?scope=playlist-read&client_id=<censored>&device_id=b457cbd5840886003282c0bc498000bb2842e13f, method: GET
2023-08-24 21:54:25,095 TRACE Session:784 - Parsed product info: {audiobook-onboarding-completed=0, remote-control=6, publish-activity=1, 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=0, 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=0, 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, lock-filter-explicit-content=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=1, 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, filter-explicit-content=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, public-toplist=0, network-operator-premium-activation=1, video-device-blacklisted=0, collection=1, fb-grant-permission-local-render=0, backend-advised-bitrate=0, autoplay=0, catalogue=premium, storage-size-config=10240,90,500,3, ads=0, head-files-url=https://heads-ak-spotify-com.akamaized.net/head/{file_id}, ab-collection-followed-artists-only=0, browse-overview-enabled=1, on-demand=1, ap-resolve-pods=1, 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,rt:v2_DE_default_new-family-sub-1m_0_EUR_default, 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=831, player-license=premium}
2023-08-24 21:54:25,096 INFO  Session:1495 - Skipping UnknownData_AllZeros
2023-08-24 21:54:25,097 INFO  Session:1495 - Skipping LegacyWelcome
2023-08-24 21:54:25,149 TRACE MercuryClient:191 - Handling packet, cmd: MercuryEvent, seq: -1577529805509754880, flags: 1, parts: 1
2023-08-24 21:54:25,155 DEBUG MercuryClient:226 - Couldn't dispatch Mercury event {seq: -1577529805509754880, uri: hm://pusher/v1/connections/<censored>%3D%3D, code: 200, payload: []}
2023-08-24 21:54:25,392 DEBUG Session:1471 - Received 0x10: <censored>
2023-08-24 21:54:25,596 TRACE MercuryClient:191 - Handling packet, cmd: MercuryReq, seq: 1, flags: 1, parts: 2
2023-08-24 21:54:25,598 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-1.6.3.jar:1.6.3]
    at xyz.gianlu.librespot.core.TokenProvider.getToken(TokenProvider.java:69) ~[librespot-player-1.6.3.jar:1.6.3]
    at xyz.gianlu.librespot.core.TokenProvider.get(TokenProvider.java:80) ~[librespot-player-1.6.3.jar:1.6.3]
    at xyz.gianlu.librespot.dealer.DealerClient.connect(DealerClient.java:78) ~[librespot-player-1.6.3.jar:1.6.3]
    at xyz.gianlu.librespot.core.Session.authenticate(Session.java:362) ~[librespot-player-1.6.3.jar:1.6.3]
    at xyz.gianlu.librespot.core.Session.access$600(Session.java:77) ~[librespot-player-1.6.3.jar:1.6.3]
    at xyz.gianlu.librespot.core.Session$Builder.create(Session.java:1057) ~[librespot-player-1.6.3.jar:1.6.3]
    at xyz.gianlu.librespot.ZeroconfServer.handleAddUser(ZeroconfServer.java:367) ~[librespot-player-1.6.3.jar:1.6.3]
    at xyz.gianlu.librespot.ZeroconfServer.access$200(ZeroconfServer.java:56) ~[librespot-player-1.6.3.jar:1.6.3]
    at xyz.gianlu.librespot.ZeroconfServer$HttpRunner.handleRequest(ZeroconfServer.java:499) ~[librespot-player-1.6.3.jar:1.6.3]
    at xyz.gianlu.librespot.ZeroconfServer$HttpRunner.handle(ZeroconfServer.java:574) ~[librespot-player-1.6.3.jar:1.6.3]
    at xyz.gianlu.librespot.ZeroconfServer$HttpRunner.lambda$run$1(ZeroconfServer.java:482) ~[librespot-player-1.6.3.jar:1.6.3]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641) [?:?]
    at java.lang.Thread.run(Thread.java:844) [?:?]
2023-08-24 21:54:25,801 INFO  Session:1422 - Skipping unknown command {cmd: 0x75, payload: 000000}

Version/Commit Freshly re-downloaded jar of Player v1.6.3 & default config.toml created by the application

Justus-G commented 1 year ago

seems to have fixed itself, haven't changed anything on either the host device, librespot configuration nor the network though.

Justus-G commented 1 year ago

Just had the same thing again, probably only temporarily fixed itself. What do to here? Restarts don't help at all.

mbeijen commented 1 year ago

I have the same error, on both 1.6.3 and on the dev branch. I can reproduce it 100% when I try to connect from Spotify Desktop (macOS). If I connect from an iOS or Android device, there is no problem.

This might be a duplicate of https://github.com/librespot-org/librespot-java/issues/697

mbeijen commented 1 year ago

The same issue seems to have a pending PR in librespot-the-rust-version --> https://github.com/librespot-org/librespot/pull/1220