search

spocon / spocon

SpoCon - A Spotify Connect Client for Debian , Ubuntu and Raspberry Pi based on librespot-java
https://spocon.github.io/spocon
MIT License
134 stars 9 forks source link

Couldn't establish a new session #58

Closed ninjarobots closed 1 year ago

ninjarobots commented 1 year ago

I have implemented the fix from issue 57 which fixed "premium account required" errors, but now I get mercuryclient errors only with some users. Some users are able to cast just fine, but others are getting a 403 from the mercury client. Below are the logs that I believe show the issue.

un 01 03:27:36 mopidy java[9428]: 2023-06-01 03:27:36,158 INFO ZeroconfServer:345 - Accepted new user from pop-os. {deviceId: 871ce4fe5365c56ffefb95de63719df7136b2bcd} Jun 01 03:27:36 mopidy java[9428]: 2023-06-01 03:27:36,568 DEBUG TimeProvider:90 - Loaded time offset from NTP: -5ms Jun 01 03:27:38 mopidy java[9428]: 2023-06-01 03:27:38,118 INFO ApResolver:99 - Loaded aps into pool: {accesspoint=[ap-gue1.spotify.com:4070, ap-gue1.spotify.com:443, ap-gue1.spotify.com:80, ap-gew4.spotify.com:4070, ap-gew1.spotify.com:443, ap-gae2.spotify.com:80], dealer=[gue1-dealer.spotify.com:443, gew4-dealer.spotify.com:443, gew1-dealer.spotify.com:443, gae2-dealer.spotify.com:443], spclient=[gue1-spclient.spotify.com:443, gew4-spclient.spotify.com:443, gew1-spclient.spotify.com:443, gae2-spclient.spotify.com:443]} Jun 01 03:27:38 mopidy java[9428]: 2023-06-01 03:27:38,433 INFO Session:140 - Created new session! {deviceId: 871ce4fe5365c56ffefb95de63719df7136b2bcd, ap: ap-gew4.spotify.com:4070, proxy: false} Jun 01 03:27:39 mopidy java[9428]: 2023-06-01 03:27:39,440 INFO Session:334 - Connected successfully! Jun 01 03:27:39 mopidy java[9428]: 2023-06-01 03:27:39,915 TRACE Session:1413 - Session.Receiver started Jun 01 03:27:39 mopidy java[9428]: 2023-06-01 03:27:39,987 INFO CacheManager:95 - There are 0 cached entries. Jun 01 03:27:40 mopidy java[9428]: 2023-06-01 03:27:40,007 TRACE AsyncProcessor:52 - AsyncProcessor{dealer-worker} has started Jun 01 03:27:40 mopidy java[9428]: 2023-06-01 03:27:40,017 TRACE AsyncProcessor:52 - AsyncProcessor{event-service-sender} has started Jun 01 03:27:40 mopidy java[9428]: 2023-06-01 03:27:40,021 INFO Session:1495 - Skipping SecretBlock Jun 01 03:27:40 mopidy java[9428]: 2023-06-01 03:27:40,023 INFO Session:1467 - Received LicenseVersion: 0 Jun 01 03:27:40 mopidy java[9428]: 2023-06-01 03:27:40,025 DEBUG TokenProvider:68 - Token expired or not suitable, requesting again. {scopes: [playlist-read], oldToken: null} Jun 01 03:27:40 mopidy java[9428]: 2023-06-01 03:27:40,025 INFO Session:1457 - Received CountryCode: US Jun 01 03:27:40 mopidy java[9428]: 2023-06-01 03:27:40,064 TRACE MercuryClient:148 - Send Mercury request, seq: 1, uri: hm://keymaster/token/authenticated?scope=playlist-read&client_id=65b708073fc0480ea92a077233ca87bd&device_id=871ce4fe5365c56ffefb95de63719df7136b2bcd, method: GET Jun 01 03:27:40 mopidy java[9428]: 2023-06-01 03:27:40,089 TRACE Session:784 - Parsed product info: {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=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=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, ab-mobile-running-tempo-detection=Control, is_email_verified=0, 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, 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, multiuserplan-current-size=4, shuffle=0, instant-search=0, instant-search-expand-sidebar=0, use-playlist-uris=0, user-profile-show-invitation-codes=0, multiuserplan-member-type=FAMILY_MANAGER, 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=7, 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=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_US_default_new-family-master-1m_15.99_USD_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=771, player-license=premium} Jun 01 03:27:40 mopidy java[9428]: 2023-06-01 03:27:40,090 INFO Session:1495 - Skipping UnknownData_AllZeros Jun 01 03:27:40 mopidy java[9428]: 2023-06-01 03:27:40,091 INFO Session:1495 - Skipping LegacyWelcome Jun 01 03:27:40 mopidy java[9428]: 2023-06-01 03:27:40,094 TRACE MercuryClient:191 - Handling packet, cmd: MercuryEvent, seq: 4903148958764761088, flags: 1, parts: 1 Jun 01 03:27:40 mopidy java[9428]: 2023-06-01 03:27:40,105 DEBUG MercuryClient:226 - Couldn't dispatch Mercury event {seq: 4903148958764761088, uri: hm://pusher/v1/connections/ODcxY2U0ZmU1MzY1YzU2ZmZlZmI5NWRlNjM3MTlkZjcxMzZiMmJjZCtBUCt0Y3A6Ly9nZXc0LWFjY2Vzc3BvaW50LWMtbWtybi5nZXc0LnNwb3RpZnkubmV0OjUwMDYrOTUzREQzNDM1MTdBRjNCNkI4RkRERjAwRkQyNEFCQjAzQUQ1NjY0QTREOTk0NDMxNjYzNjk1RkM1RjIxMUU4Rg%3D%3D, code: 200, payload: []} Jun 01 03:27:40 mopidy java[9428]: 2023-06-01 03:27:40,255 DEBUG Session:1471 - Received 0x10: 732810381780EC4725FE812556C93860E211D4BA Jun 01 03:27:40 mopidy java[9428]: 2023-06-01 03:27:40,403 TRACE MercuryClient:191 - Handling packet, cmd: MercuryReq, seq: 1, flags: 1, parts: 2 Jun 01 03:27:40 mopidy java[9428]: 2023-06-01 03:27:40,406 ERROR ZeroconfServer:375 - Couldn't establish a new session. Jun 01 03:27:40 mopidy java[9428]: xyz.gianlu.librespot.mercury.MercuryClient$MercuryException: status: 403 Jun 01 03:27:40 mopidy java[9428]: at xyz.gianlu.librespot.mercury.MercuryClient.sendSync(MercuryClient.java:107) ~[librespot-java-api-v1.6.2.jar:1.6.3] Jun 01 03:27:40 mopidy java[9428]: at xyz.gianlu.librespot.core.TokenProvider.getToken(TokenProvider.java:69) ~[librespot-java-api-v1.6.2.jar:1.6.3] Jun 01 03:27:40 mopidy java[9428]: at xyz.gianlu.librespot.core.TokenProvider.get(TokenProvider.java:80) ~[librespot-java-api-v1.6.2.jar:1.6.3] Jun 01 03:27:40 mopidy java[9428]: at xyz.gianlu.librespot.dealer.DealerClient.connect(DealerClient.java:78) ~[librespot-java-api-v1.6.2.jar:1.6.3] Jun 01 03:27:40 mopidy java[9428]: at xyz.gianlu.librespot.core.Session.authenticate(Session.java:362) ~[librespot-java-api-v1.6.2.jar:1.6.3] Jun 01 03:27:40 mopidy java[9428]: at xyz.gianlu.librespot.core.Session.access$600(Session.java:77) ~[librespot-java-api-v1.6.2.jar:1.6.3] Jun 01 03:27:40 mopidy java[9428]: at xyz.gianlu.librespot.core.Session$Builder.create(Session.java:1057) ~[librespot-java-api-v1.6.2.jar:1.6.3] Jun 01 03:27:40 mopidy java[9428]: at xyz.gianlu.librespot.ZeroconfServer.handleAddUser(ZeroconfServer.java:367) ~[librespot-java-api-v1.6.2.jar:1.6.3] Jun 01 03:27:40 mopidy java[9428]: at xyz.gianlu.librespot.ZeroconfServer.access$200(ZeroconfServer.java:56) ~[librespot-java-api-v1.6.2.jar:1.6.3] Jun 01 03:27:40 mopidy java[9428]: at xyz.gianlu.librespot.ZeroconfServer$HttpRunner.handleRequest(ZeroconfServer.java:499) ~[librespot-java-api-v1.6.2.jar:1.6.3] Jun 01 03:27:40 mopidy java[9428]: at xyz.gianlu.librespot.ZeroconfServer$HttpRunner.handle(ZeroconfServer.java:574) ~[librespot-java-api-v1.6.2.jar:1.6.3] Jun 01 03:27:40 mopidy java[9428]: at xyz.gianlu.librespot.ZeroconfServer$HttpRunner.lambda$run$1(ZeroconfServer.java:482) ~[librespot-java-api-v1.6.2.jar:1.6.3] Jun 01 03:27:40 mopidy java[9428]: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?] Jun 01 03:27:40 mopidy java[9428]: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?] Jun 01 03:27:40 mopidy java[9428]: at java.lang.Thread.run(Thread.java:829) [?:?] Jun 01 03:27:40 mopidy java[9428]: 2023-06-01 03:27:40,596 INFO Session:1422 - Skipping unknown command {cmd: 0x75, payload: 000000}

spocon commented 1 year ago

new version should fix this issue: 1.6.3 released