spocon / lovspotify

Spotify GUI + Spotify Client for Raspberry PI , Ubuntu and Debian
54 stars 4 forks source link

'Connecting...' Loop #11

Closed NellyWhads closed 4 years ago

NellyWhads commented 4 years ago

Hello there,

It seems I'm running into an infinite "connecting..." loop when attempting to use lovspotify.

Below is the journalctl output; the device shows up on my local spotify "control" devices (laptop and phone) but upon selecting it, goes into the aforementioned loop before giving up and timing out.

This occurs both when using both the ZEROCONF and USER_PASS auth methods.

I've blocked out the device ids/username from the log, for privacy.

-- Logs begin at Fri 2020-08-21 03:40:01 UTC. --
Aug 21 03:44:26 Khadas java[3883]: SLF4J: Found binding in [jar:file:/opt/lovspotify/lovspotify-1.5.0.jar!/BOOT-INF/lib/log4j-slf4j-impl-2.13.3.jar!/org/slf4j/impl/StaticLoggerBinder.class]
Aug 21 03:44:26 Khadas java[3883]: SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
Aug 21 03:44:26 Khadas java[3883]: SLF4J: Actual binding is of type [org.apache.logging.slf4j.Log4jLoggerFactory]
Aug 21 03:44:28 Khadas java[3883]: 2020-08-21 03:44:28,074 INFO  Zeroconf:473 - Announced Service{alias='Lovspotify', service='spotify-connect', port=12637, text={VERSION=1.0, CPath=/, Stack=SP}, addresses=[/192.168.4.59], domain='.local', protocol='tcp', host='Khadas'}.
Aug 21 03:44:28 Khadas java[3883]: 2020-08-21 03:44:28,453 INFO  ThreadPoolTaskExecutor:181 - Initializing ExecutorService 'applicationTaskExecutor'
Aug 21 03:44:28 Khadas java[3883]: 2020-08-21 03:44:28,710 INFO  WelcomePageHandlerMapping:54 - Adding welcome page: class path resource [static/index.html]
Aug 21 03:44:29 Khadas java[3883]: Aug 21, 2020 3:44:29 AM org.apache.coyote.AbstractProtocol start
Aug 21 03:44:29 Khadas java[3883]: INFO: Starting ProtocolHandler ["http-nio-8080"]
Aug 21 03:44:29 Khadas java[3883]: 2020-08-21 03:44:29,064 INFO  TomcatWebServer:220 - Tomcat started on port(s): 8080 (http) with context path ''
Aug 21 03:44:29 Khadas java[3883]: 2020-08-21 03:44:29,095 INFO  SpotifiApplication:61 - Started SpotifiApplication in 7.929 seconds (JVM running for 11.371)
Aug 21 03:44:54 Khadas java[3883]: 2020-08-21 03:44:54,059 INFO  ZeroconfServer:327 - Accepted new user from OnePlus 5. {deviceId: #####}
Aug 21 03:44:54 Khadas java[3883]: 2020-08-21 03:44:54,373 INFO  ApResolver:68 - Loaded aps into pool: {accesspoint=[guc3-accesspoint-b-hlk6.ap.spotify.com:4070, guc3-accesspoint-b-tmq5.ap.spotify.com:443, guc3-accesspoint-b-51gl.ap.spotify.com:80, guc3-accesspoint-b-9k33.ap.spotify.com:4070, guc3-accesspoint-b-mgp2.ap.spotify.com:443, guc3-accesspoint-b-dqm4.ap.spotify.com:80, gae2-accesspoint-b-08xp.ap.spotify.com:4070, gew1-accesspoint-b-8rjm.ap.spotify.com:443, gew1-accesspoint-b-p7sv.ap.spotify.com:80], dealer=[guc-dealer.spotify.com:443, gew-dealer.spotify.com:443, gae-dealer.spotify.com:443], spclient=[guc-spclient.spotify.com:443, gew-spclient.spotify.com:443, gae-spclient.spotify.com:443]}
Aug 21 03:44:54 Khadas java[3883]: 2020-08-21 03:44:54,997 INFO  Session:122 - Created new session! {deviceId: #####, ap: guc3-accesspoint-b-tmq5.ap.spotify.com:443, proxy: false}
Aug 21 03:44:55 Khadas java[3883]: 2020-08-21 03:44:55,578 INFO  Session:313 - Connected successfully!
Aug 21 03:44:55 Khadas java[3883]: 2020-08-21 03:44:55,773 INFO  CacheManager:73 - There are 0 cached entries.
Aug 21 03:44:55 Khadas java[3883]: 2020-08-21 03:44:55,785 INFO  Session:1375 - Skipping SecretBlock
Aug 21 03:44:55 Khadas java[3883]: 2020-08-21 03:44:55,786 INFO  Session:1347 - Received LicenseVersion: 0
Aug 21 03:44:55 Khadas java[3883]: 2020-08-21 03:44:55,789 INFO  Session:1337 - Received CountryCode: CA
Aug 21 03:44:55 Khadas java[3883]: 2020-08-21 03:44:55,817 INFO  Session:1375 - Skipping LegacyWelcome
Aug 21 03:44:55 Khadas java[3883]: 2020-08-21 03:44:55,818 INFO  Session:1375 - Skipping UnknownData_AllZeros
Aug 21 03:44:55 Khadas java[3883]: 2020-08-21 03:44:55,880 INFO  Session:1302 - Skipping unknown command {cmd: 0x75, payload: 000000}
Aug 21 03:44:55 Khadas java[3883]: 2020-08-21 03:44:55,963 INFO  Session:344 - Authenticated as #####!
Aug 21 03:45:16 Khadas java[3883]: 2020-08-21 03:45:16,188 INFO  Session:419 - Closing session. {deviceId: #####}
Aug 21 03:45:16 Khadas java[3883]: 2020-08-21 03:45:16,192 INFO  Session:481 - Closed session. {deviceId: #####}
Aug 21 03:45:16 Khadas java[3883]: 2020-08-21 03:45:16,193 INFO  ZeroconfServer:327 - Accepted new user from OnePlus 5. {deviceId: #####}
Aug 21 03:45:16 Khadas java[3883]: 2020-08-21 03:45:16,390 INFO  Session:122 - Created new session! {deviceId: #####, ap: gew1-accesspoint-b-8rjm.ap.spotify.com:443, proxy: false}
Aug 21 03:45:16 Khadas java[3883]: 2020-08-21 03:45:16,924 INFO  Session:313 - Connected successfully!
Aug 21 03:45:17 Khadas java[3883]: 2020-08-21 03:45:17,145 INFO  CacheManager:73 - There are 0 cached entries.
Aug 21 03:45:17 Khadas java[3883]: 2020-08-21 03:45:17,163 INFO  Session:1375 - Skipping SecretBlock
Aug 21 03:45:17 Khadas java[3883]: 2020-08-21 03:45:17,163 INFO  Session:1347 - Received LicenseVersion: 0
Aug 21 03:45:17 Khadas java[3883]: 2020-08-21 03:45:17,164 INFO  Session:1337 - Received CountryCode: CA
Aug 21 03:45:17 Khadas java[3883]: 2020-08-21 03:45:17,188 INFO  Session:1375 - Skipping LegacyWelcome
Aug 21 03:45:17 Khadas java[3883]: 2020-08-21 03:45:17,290 INFO  Session:1375 - Skipping UnknownData_AllZeros
Aug 21 03:45:17 Khadas java[3883]: 2020-08-21 03:45:17,544 INFO  Session:1302 - Skipping unknown command {cmd: 0x75, payload: 000000}
Aug 21 03:45:17 Khadas java[3883]: 2020-08-21 03:45:17,551 INFO  Session:344 - Authenticated as #####!
Aug 21 03:46:22 Khadas java[3883]: 2020-08-21 03:46:22,443 INFO  Session:419 - Closing session. {deviceId: #####}
Aug 21 03:46:22 Khadas java[3883]: 2020-08-21 03:46:22,445 INFO  Session:481 - Closed session. {deviceId: #####}
Aug 21 03:46:22 Khadas java[3883]: 2020-08-21 03:46:22,445 INFO  ZeroconfServer:327 - Accepted new user from CYCLONE. {deviceId: #####}
Aug 21 03:46:22 Khadas java[3883]: 2020-08-21 03:46:22,606 INFO  Session:122 - Created new session! {deviceId: #####, ap: guc3-accesspoint-b-tmq5.ap.spotify.com:443, proxy: false}
Aug 21 03:46:23 Khadas java[3883]: 2020-08-21 03:46:23,021 INFO  Session:313 - Connected successfully!
Aug 21 03:46:23 Khadas java[3883]: 2020-08-21 03:46:23,138 INFO  CacheManager:73 - There are 0 cached entries.
Aug 21 03:46:23 Khadas java[3883]: 2020-08-21 03:46:23,152 INFO  Session:1375 - Skipping SecretBlock
Aug 21 03:46:23 Khadas java[3883]: 2020-08-21 03:46:23,153 INFO  Session:1347 - Received LicenseVersion: 0
Aug 21 03:46:23 Khadas java[3883]: 2020-08-21 03:46:23,154 INFO  Session:1337 - Received CountryCode: CA
Aug 21 03:46:23 Khadas java[3883]: 2020-08-21 03:46:23,183 INFO  Session:1375 - Skipping LegacyWelcome
Aug 21 03:46:23 Khadas java[3883]: 2020-08-21 03:46:23,183 INFO  Session:1375 - Skipping UnknownData_AllZeros
Aug 21 03:46:23 Khadas java[3883]: 2020-08-21 03:46:23,278 INFO  Session:344 - Authenticated as #####!
Aug 21 03:46:23 Khadas java[3883]: 2020-08-21 03:46:23,319 INFO  Session:1302 - Skipping unknown command {cmd: 0x75, payload: 000000}
Aug 21 03:46:44 Khadas java[3883]: 2020-08-21 03:46:44,237 INFO  Session:419 - Closing session. {deviceId: #####}
Aug 21 03:46:44 Khadas java[3883]: 2020-08-21 03:46:44,251 INFO  Session:481 - Closed session. {deviceId: #####}
Aug 21 03:46:44 Khadas java[3883]: 2020-08-21 03:46:44,253 INFO  ZeroconfServer:327 - Accepted new user from CYCLONE. {deviceId: #####}
Aug 21 03:46:44 Khadas java[3883]: 2020-08-21 03:46:44,393 INFO  Session:122 - Created new session! {deviceId: #####, ap: guc3-accesspoint-b-mgp2.ap.spotify.com:443, proxy: false}
Aug 21 03:46:44 Khadas java[3883]: 2020-08-21 03:46:44,779 INFO  Session:313 - Connected successfully!
Aug 21 03:46:44 Khadas java[3883]: 2020-08-21 03:46:44,869 INFO  CacheManager:73 - There are 0 cached entries.
Aug 21 03:46:44 Khadas java[3883]: 2020-08-21 03:46:44,881 INFO  Session:1375 - Skipping SecretBlock
Aug 21 03:46:44 Khadas java[3883]: 2020-08-21 03:46:44,882 INFO  Session:1347 - Received LicenseVersion: 0
Aug 21 03:46:44 Khadas java[3883]: 2020-08-21 03:46:44,883 INFO  Session:1337 - Received CountryCode: CA
Aug 21 03:46:44 Khadas java[3883]: 2020-08-21 03:46:44,905 INFO  Session:1375 - Skipping LegacyWelcome
Aug 21 03:46:44 Khadas java[3883]: 2020-08-21 03:46:44,906 INFO  Session:1375 - Skipping UnknownData_AllZeros
Aug 21 03:46:45 Khadas java[3883]: 2020-08-21 03:46:45,266 INFO  Session:1302 - Skipping unknown command {cmd: 0x75, payload: 000000}
Aug 21 03:46:45 Khadas java[3883]: 2020-08-21 03:46:45,273 INFO  Session:344 - Authenticated as #####!
spocon commented 4 years ago

There seems to be a bug since 1.5.0 , ill look into it

NellyWhads commented 4 years ago

Thank you - if there's any way I can assist, do reach out.

spocon commented 4 years ago

Release 1.5.1 should fix your problem. its currently deploying , but it should be reachable in approx. 30 min There are some changes , please see the release notes for more informations https://github.com/spocon/lovspotify/releases/tag/1.5.1

NellyWhads commented 4 years ago

One of the fastest fixes I've seen for open source packages.

Many thank, good stranger - all works well

spocon commented 4 years ago

Hej, No problem 🙂👍