spocon / spocon

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

SpoCon Does Not Work Any Longer With librespot-java v1.6.2 #59

Closed smolinde closed 1 year ago

smolinde commented 1 year ago

Describe the bug As of now, SpoCon does not allow the phone to connect. The device is visible in Spotify client app, can be selected, but after a while connection times out.

To Reproduce Steps to reproduce the behavior:

  1. Open Spotify client on any device
  2. Open device selection
  3. Select "SpoCon-Spotify" if not renamed
  4. See timeout behavior

Expected behavior After tapping the device, connection to SpoCon server should be established within five seconds.

Screenshots N/A

Logs Logs for 24.06.2023:
Jun 24 21:19:37 duscloud java[30591]: 2023-06-24 21:19:37,901 DEBUG CrossfadeController:58 - Loaded crossfade intervals {id: 01e5872d965284d170c26ec6ee1474e1, in: {}, out: {}} Jun 24 21:19:37 duscloud java[30591]: 2023-06-24 21:19:37,918 TRACE PlayerQueueEntry:149 - Loaded VORBIS decoder: VorbisDecoder {of: {fileId: 1C3599AAC8D4412E102FCBF8CA744244C46399D6}, for> Jun 24 21:19:37 duscloud java[30591]: 2023-06-24 21:19:37,919 TRACE PlayerSession:194 - PlayerQueueEntry{01e5872d965284d170c26ec6ee1474e1} finished loading. Jun 24 21:19:37 duscloud java[30591]: 2023-06-24 21:19:37,948 TRACE MixingLine:184 - Toggle first channel: true Jun 24 21:19:37 duscloud java[30591]: 2023-06-24 21:19:37,960 TRACE CdnManager:277 - Chunk 1/23 completed, cached: false, stream: {fileId: 1C3599AAC8D4412E102FCBF8CA744244C46399D6} Jun 24 21:19:38 duscloud java[30591]: 2023-06-24 21:19:38,012 TRACE CdnManager:277 - Chunk 3/23 completed, cached: false, stream: {fileId: 1C3599AAC8D4412E102FCBF8CA744244C46399D6} Jun 24 21:19:38 duscloud java[30591]: 2023-06-24 21:19:38,066 TRACE CdnManager:277 - Chunk 2/23 completed, cached: false, stream: {fileId: 1C3599AAC8D4412E102FCBF8CA744244C46399D6} Jun 24 21:19:38 duscloud java[30591]: 2023-06-24 21:19:38,569 INFO DeviceStateHandler:273 - Put state. {ts: 1687634377930, connId: NDRlN...2NkEx, reason: PLAYER_STATE_CHANGED, request: de> Jun 24 21:19:45 duscloud java[30591]: 2023-06-24 21:19:45,206 TRACE CdnManager:277 - Chunk 4/23 completed, cached: false, stream: {fileId: 1C3599AAC8D4412E102FCBF8CA744244C46399D6} Jun 24 21:19:52 duscloud java[30591]: 2023-06-24 21:19:52,980 TRACE DealerClient:113 - Received request. {mid: hm://connect-state/v1/player/command, key: 83062d1c-ad51-41a6-ae9c-2b9f990aca> Jun 24 21:19:52 duscloud java[30591]: 2023-06-24 21:19:52,981 DEBUG Player:107 - Received command: SkipNext Jun 24 21:19:52 duscloud java[30591]: 2023-06-24 21:19:52,993 TRACE MercuryClient:148 - Send Mercury request, seq: 9, uri: hm://event-service/v1/events, method: POST Jun 24 21:19:52 duscloud java[30591]: 2023-06-24 21:19:52,995 DEBUG Player:492 - Loading track, id: TrackId{spotify:track:3ZffCQKLFLUvYM59XKLbVm}, session: iznL/nuy44FlA55kEuOSXw, playback> Jun 24 21:19:52 duscloud java[30591]: 2023-06-24 21:19:52,996 TRACE PlayerQueueEntry:92 - Created new PlayerQueueEntry{019ff3fd035c52d0b1deacb232b235e6}. Jun 24 21:19:52 duscloud java[30591]: 2023-06-24 21:19:52,996 TRACE PlayerQueue:82 - PlayerQueueEntry{019ff3fd035c52d0b1deacb232b235e6} added to queue. Jun 24 21:19:53 duscloud java[30591]: 2023-06-24 21:19:52,996 TRACE PlayerSession:162 - PlayerQueueEntry{019ff3fd035c52d0b1deacb232b235e6} started loading. Jun 24 21:19:53 duscloud java[30591]: 2023-06-24 21:19:52,997 DEBUG CrossfadeController:192 - Changed fade out. {curr: null, custom: false, why: TRACK_DONE, id: 01e5872d965284d170c26ec6ee1> Jun 24 21:19:53 duscloud java[30591]: 2023-06-24 21:19:52,998 DEBUG CrossfadeController:192 - Changed fade out. {curr: null, custom: false, why: FORWARD_BTN, id: 01e5872d965284d170c26ec6ee> Jun 24 21:19:53 duscloud java[30591]: 2023-06-24 21:19:52,998 TRACE MixingLine:184 - Toggle first channel: false Jun 24 21:19:53 duscloud java[30591]: 2023-06-24 21:19:53,000 DEBUG PlayerQueueEntry:234 - PlayerQueueEntry{01e5872d965284d170c26ec6ee1474e1} has been removed from output. Jun 24 21:19:53 duscloud java[30591]: 2023-06-24 21:19:53,001 TRACE PlayerQueueEntry:350 - PlayerQueueEntry{01e5872d965284d170c26ec6ee1474e1} terminated. Jun 24 21:19:53 duscloud java[30591]: 2023-06-24 21:19:53,006 DEBUG PlayerSession:283 - PlayerQueueEntry{019ff3fd035c52d0b1deacb232b235e6} has been added to the output. {sessionId: iznL/nu> Jun 24 21:19:53 duscloud java[30591]: 2023-06-24 21:19:53,009 DEBUG DealerClient:125 - Handled request. {key: 83062d1c-ad51-41a6-ae9c-2b9f990acad5, result: SUCCESS} Jun 24 21:19:53 duscloud java[30591]: 2023-06-24 21:19:53,089 TRACE MercuryClient:191 - Handling packet, cmd: MercuryReq, seq: 9, flags: 1, parts: 1 Jun 24 21:19:53 duscloud java[30591]: 2023-06-24 21:19:53,089 DEBUG EventService:51 - Event sent. {body: 12|38|2|44e43de551f9d5b6e850fec9928c4685b6366eed|01e5872d965284d170c26ec6ee1474e1|0> Jun 24 21:19:53 duscloud java[30591]: 2023-06-24 21:19:53,091 TRACE MercuryClient:148 - Send Mercury request, seq: 10, uri: hm://event-service/v1/events, method: POST Jun 24 21:19:53 duscloud java[30591]: 2023-06-24 21:19:53,178 TRACE MercuryClient:191 - Handling packet, cmd: MercuryReq, seq: 10, flags: 1, parts: 1 Jun 24 21:19:53 duscloud java[30591]: 2023-06-24 21:19:53,179 DEBUG EventService:51 - Event sent. {body: 558|1|019ff3fd035c52d0b1deacb232b235e6|iznL/nuy44FlA55kEuOSXw|1687634393006, result> Jun 24 21:19:53 duscloud java[30591]: 2023-06-24 21:19:53,664 INFO DeviceStateHandler:273 - Put state. {ts: 1687634393007, connId: NDRlN...2NkEx, reason: PLAYER_STATE_CHANGED, request: de> Jun 24 21:19:53 duscloud java[30591]: 2023-06-24 21:19:53,854 TRACE CdnManager:277 - Chunk 0/44 completed, cached: false, stream: {fileId: 405D2C4F23DE788267EABDF0BC7F23E85C2253DA} Jun 24 21:19:53 duscloud java[30591]: 2023-06-24 21:19:53,862 TRACE NormalizationData:46 - Loaded normalization data, track_gain: -9.68, track_peak: 1.1598752, album_gain: -10.370003, albu> Jun 24 21:19:53 duscloud java[30591]: 2023-06-24 21:19:53,863 INFO PlayerQueueEntry:125 - Loaded track. {name: 'Wake Me up When September Ends', artists: 'Green Day', duration: 285653, ur> Jun 24 21:19:53 duscloud java[30591]: 2023-06-24 21:19:53,864 DEBUG CrossfadeController:58 - Loaded crossfade intervals {id: 019ff3fd035c52d0b1deacb232b235e6, in: {}, out: {}} Jun 24 21:19:53 duscloud java[30591]: 2023-06-24 21:19:53,876 TRACE PlayerQueueEntry:149 - Loaded VORBIS decoder: VorbisDecoder {of: {fileId: 405D2C4F23DE788267EABDF0BC7F23E85C2253DA}, for> Jun 24 21:19:53 duscloud java[30591]: 2023-06-24 21:19:53,877 TRACE PlayerSession:194 - PlayerQueueEntry{019ff3fd035c52d0b1deacb232b235e6} finished loading. Jun 24 21:19:53 duscloud java[30591]: 2023-06-24 21:19:53,889 TRACE MixingLine:184 - Toggle first channel: true Jun 24 21:19:54 duscloud java[30591]: 2023-06-24 21:19:54,085 TRACE CdnManager:277 - Chunk 1/44 completed, cached: false, stream: {fileId: 405D2C4F23DE788267EABDF0BC7F23E85C2253DA} Jun 24 21:19:54 duscloud java[30591]: 2023-06-24 21:19:54,121 TRACE CdnManager:277 - Chunk 3/44 completed, cached: false, stream: {fileId: 405D2C4F23DE788267EABDF0BC7F23E85C2253DA} Jun 24 21:19:54 duscloud java[30591]: 2023-06-24 21:19:54,162 TRACE CdnManager:277 - Chunk 2/44 completed, cached: false, stream: {fileId: 405D2C4F23DE788267EABDF0BC7F23E85C2253DA} Jun 24 21:19:54 duscloud java[30591]: 2023-06-24 21:19:54,502 INFO DeviceStateHandler:273 - Put state. {ts: 1687634393883, connId: NDRlN...2NkEx, reason: PLAYER_STATE_CHANGED, request: de> Jun 24 21:19:58 duscloud java[30591]: 2023-06-24 21:19:58,866 TRACE CdnManager:277 - Chunk 4/44 completed, cached: false, stream: {fileId: 405D2C4F23DE788267EABDF0BC7F23E85C2253DA} Jun 24 21:20:04 duscloud java[30591]: 2023-06-24 21:20:04,800 TRACE CdnManager:277 - Chunk 5/44 completed, cached: false, stream: {fileId: 405D2C4F23DE788267EABDF0BC7F23E85C2253DA} Jun 24 21:20:11 duscloud java[30591]: 2023-06-24 21:20:11,862 TRACE CdnManager:277 - Chunk 6/44 completed, cached: false, stream: {fileId: 405D2C4F23DE788267EABDF0BC7F23E85C2253DA} Jun 24 21:20:18 duscloud java[30591]: 2023-06-24 21:20:18,398 TRACE CdnManager:277 - Chunk 7/44 completed, cached: false, stream: {fileId: 405D2C4F23DE788267EABDF0BC7F23E85C2253DA} Jun 24 21:20:19 duscloud java[30591]: 2023-06-24 21:20:19,872 TRACE DealerClient:113 - Received request. {mid: hm://connect-state/v1/player/command, key: a543ad2a-9d9a-4d2b-9683-ba74913aa9> Jun 24 21:20:19 duscloud java[30591]: 2023-06-24 21:20:19,873 DEBUG Player:107 - Received command: Pause Jun 24 21:20:19 duscloud java[30591]: 2023-06-24 21:20:19,879 DEBUG DealerClient:125 - Handled request. {key: a543ad2a-9d9a-4d2b-9683-ba74913aa983, result: SUCCESS} Jun 24 21:20:20 duscloud java[30591]: 2023-06-24 21:20:20,513 INFO DeviceStateHandler:273 - Put state. {ts: 1687634419875, connId: NDRlN...2NkEx, reason: PLAYER_STATE_CHANGED, request: de> Jun 24 21:20:52 duscloud java[30591]: 2023-06-24 21:20:52,604 TRACE DeviceStateHandler:172 - Received cluster update at 1687634452594: cluster { timestamp: 1687634452141 active_device_id: > Jun 24 21:23:39 duscloud java[30591]: 2023-06-24 21:23:39,139 TRACE DeviceStateHandler:172 - Received cluster update at 1687634619132: cluster { timestamp: 1687634618670 active_device_id: > Jun 24 21:23:40 duscloud java[30591]: 2023-06-24 21:23:40,986 TRACE DeviceStateHandler:172 - Received cluster update at 1687634620976: cluster { timestamp: 1687634620553 active_device_id: >

Server (please complete the following information):

Smartphone (please complete the following information):

Hotfix I already managed to completely fix the issue by doing following steps:

  1. Download latest librespot-java v1.6.3 here
  2. Rename file to: librespot-java-api-v1.6.2.jar
  3. SSH into your system and run: sudo rm /opt/spocon/librespot-java-api-v1.6.2.jar
  4. With FileZilla or something else, upload the downloaded and renamed file to your home directory
  5. Move the file with: sudo mv librespot-java-api-v1.6.2.jar /opt/spocon/
  6. Reload SpoCon by executing: sudo systemctl restart spocon

For the developers, thank you very much for the amazing project, please consider updating the librespot-java API :)

spocon commented 1 year ago

upgraded to 1.6.3