[BUG] Spotify integration stopped working

[jappish84]

Is there an existing issue for this?

• I have searched the existing issues

Current Behavior

I noticed the spotify integration stopped working after an update.

I'm currently on latest version 28.10

In the WebUI, under "Settings" -> "Online Services" status is "Access granted for my_username"

I have tried:

1. logging out
2. restarting the container
3. Granting new access

The 3rd step generates the following log in the console, see below

The browser displays a "500 could not connect to access point". However, the owntone webui still shows that access has been granted for the user, although, no tracks from spotify are playable.

Expected Behavior

Tracks should be playable after auth

Steps To Reproduce

See above under current behaviour

Environment

- OS: Dietpi 9.8 x86 running as a VM under proxmox
- How docker service was installed: Via dietpi menu

CPU architecture

x86-64

Docker creation

---
version: "2.1"
services:
  daapd:
    image: linuxserver/daapd:latest
    container_name: daapd
    network_mode: host
    environment:
      - PUID=1000
      - PGID=1000
      - TZ=Europe/Stockholm
    volumes:
      - /mnt/dietpi_userdata/docker-data/volumes/daapdConf/_data:/config
      - /mnt/dietpi_userdata/docker-data/volumes/nfsMusic_235/_data:/owntone
      - /mnt/dietpi_userdata/docker-data/volumes/spotifyPipe/_data:/music
    restart: unless-stopped

Container logs

`[2024-10-27 13:51:05] [ INFO]     http: Making request for https://accounts.spotify.com/api/token

[2024-10-27 13:51:05] [ INFO]     http: Making request for https://api.spotify.com/v1/me

[2024-10-27 13:51:05] [ INFO]     http: Making request for https://APResolve.spotify.com/

[2024-10-27T12:53:13Z WARN  libmdns::fsm] dropping truncated packet from 192.168.1.171:5353

[2024-10-27T12:53:13Z WARN  libmdns::fsm] dropping truncated packet from 192.168.1.171:5353

[2024-10-27T12:53:13Z WARN  libmdns::fsm] dropping truncated packet from 192.168.1.171:5353

[2024-10-27 13:53:15] [  LOG]     misc: Could not connect to 'spotify' at ap-gew4.spotify.com (port 4070): Operation timed out

[2024-10-27 13:53:15] [  LOG]      web: Could not parse Spotify OAuth callback '/oauth/spotify?code=LONG_CODE_REDACTED': Could not connect to access point

[2024-10-27 13:54:12] [ INFO]     http: Making request for https://api.spotify.com/v1/albums/4SpOELLHyGJCAvRJsMYvuT

[2024-10-27 13:54:12] [ INFO]     http: Making request for https://api.spotify.com/v1/albums/4SpOELLHyGJCAvRJsMYvuT/tracks?market=SE

[2024-10-27 13:54:12] [  LOG]  spotify: Error opening source: Cannot open media, session is invalid

[2024-10-27 13:54:12] [ WARN]   player: Error starting input read loop (now 0, item_id 72485, now item_id 0)

[2024-10-27 13:54:12] [  LOG]  spotify: Error opening source: Cannot open media, session is invalid

[2024-10-27 13:54:12] [ WARN]   player: Error starting input read loop (now 0, item_id 72486, now item_id 0)

[2024-10-27 13:54:12] [  LOG]  spotify: Error opening source: Cannot open media, session is invalid

[2024-10-27 13:54:12] [ WARN]   player: Error starting input read loop (now 0, item_id 72487, now item_id 0)

[2024-10-27 13:54:12] [  LOG]  spotify: Error opening source: Cannot open media, session is invalid

[2024-10-27 13:54:12] [ WARN]   player: Error starting input read loop (now 0, item_id 72488, now item_id 0)

[2024-10-27 13:54:12] [  LOG]   player: Input start was called with an item id that has disappeared (id=72488)

[2024-10-27 13:54:12] [ WARN]   player: Error starting input read loop (now 0, item_id 72488, now item_id 0)

[2024-10-27 13:54:12] [ INFO]       db: No matching row found for query: SELECT pos FROM queue WHERE id = 72488;

[2024-10-27 13:54:12] [  LOG]       db: Error fetching queue item by pos relative to item id

[2024-10-27 13:54:12] [  LOG]   player: Error fetching next item from queue (item-id=72488, repeat=2)

[2024-10-27 13:54:12] [  LOG]      web: Failed to start playback from position '0'

[2024-10-27 13:54:12] [  LOG]      web: JSON api request failed with error code 500 (/api/queue/items/add?clear=true&playback=start&playback_from_position=0&shuffle=false&uris=spotify:album:4SpOELLHyGJCAvRJsMYvuT)`

[github-actions]

Thanks for opening your first issue here! Be sure to follow the relevant issue templates, or risk having this issue marked as invalid.

[LinuxServer-CI]

This issue has been automatically marked as stale because it has not had recent activity. This might be due to missing feedback from OP. It will be closed if no further activity occurs. Thank you for your contributions.

[jappish84]

I actually discovered that the server during start tries another spotify AP at some point:
Still - trying to authorize via WebUI results in failure as described above

[2024-12-07 21:06:41] [ LOG] scan: Done processing playlist, added/modified 134 items

[2024-12-07 21:06:41] [ LOG] scan: Bulk library scan completed in 12 sec

[2024-12-07 21:06:41] [ LOG] lib: Library init scan completed in 12 sec (337 changes)

[2024-12-07T20:06:45Z WARN librespot_core::session] Try another access point...

[2024-12-07T20:06:45Z INFO librespot_core::session] Connecting to AP "ap-guc3.spotify.com:4070"

[2024-12-07T20:06:46Z INFO librespot_core::session] Authenticated as 'REDACTED' !

[2024-12-07T20:06:46Z INFO librespot_core::session] Country: "SE"

[LinuxServer-CI]

This issue has been automatically marked as stale because it has not had recent activity. This might be due to missing feedback from OP. It will be closed if no further activity occurs. Thank you for your contributions.