[GH-ISSUE #1058] librespot cannot play user playlists (including daily mixes) #496

Closed
opened 2026-02-27 19:30:59 +03:00 by kerem · 6 comments
Owner

Originally created by @jonotargett on GitHub (Sep 13, 2022).
Original GitHub issue: https://github.com/librespot-org/librespot/issues/1058

Describe the bug
Librespot (as called via snapcast) is unable to play any user playlists. It appears that anything that would require permissions to access the private user is failing, as any publicly accessible playlists are still working correctly. Playing a track directly from an artist/album page also works with no issues. This affects my curated playlists, daily mixes, and ' Mix' playlists that spotify generates.

I have already found some workaround to this, but I feel like this is a hack which just sidesteps the actual bug. I have followed the discussion here and used the same resolution of manually remapping the domain to point to a different endpoint, which restores the functionality.

My hack/fix
Manually forcing librespot to use a different spotify endpoint resolves the issue. As per the method in the link above, my response from apresolve.spotify.com is:

{"ap_list":["ap-gae2.spotify.com:4070","ap-gae2.spotify.com:443","ap-gae2.spotify.com:80","ap-gue1.spotify.com:4070","ap-gew4.spotify.com:443","ap-guc3.spotify.com:80"]}

My librespot seems to be defaulting to use the ap-gae2.spotify.com endpoint, and according to the logs the alternative endpoint ap-gew4.spotify.com is blacklisted. However I can restore correct functionality by creating a local DNS record remapping ap-gae2 to 34.158.253.218, which is the current IP address that ap-gew4.spotify.com points to.
Not sure why this endpoint blacklisted, or what blacklisting means, but redirecting my traffic to that means that my setup is working again. The non-blacklisted endpoint has been failing consistently - I can reproduce this issue every single attempt.
The other endpoints listed by apresolve don't seem to actually be available. If I remap to point to those, I get an error about connection issues and all playback fails.

To reproduce failure

  1. Launch librespot as part of the snapclient service.
  2. In the spotify desktop or mobile app, start playing music from a spotify created playlist, ie created by user 'Spotify', or by playing an artist/album directly.
  3. Choose 'Connect to Device' -> device.
  4. Spotify connects to the librespot device correctly. Playback works as expected (everything working until this point)
  5. In the desktop/mobile app, change playback to a user playlist. The librespot device will be immediately disconnected and playback will stop.
  6. Restart the snapcast/librespot service.
  7. In the spotify desktop or mobile app, start playing music from a user playlist, or a daily mix, etc.
  8. Choose 'Connect to Device' -> device. Spotify will attempt to connect but will fail.
  9. The spotify desktop/mobile app with now show the current playing track as "Playing from playlist " but with a blank playlist name. Before trying to connect to the librespot device it would have said "Daily Mix 4" for example.

Host
I'm running librespot as part of my snapcast service in a docker container. Dockerfile is pretty basic:

FROM alpine:latest

RUN apk add --no-cache snapcast-server
RUN apk add --no-cache -X http://dl-cdn.alpinelinux.org/alpine/edge/testing librespot
RUN apk add --no-cache mpv

CMD ["snapserver"]

Log
Note that this is a truncated log; I'm not going to share the full details as it exposes a lot of my home network information. This is the log from the docker container (snapcast-server process), without the hack DNS fix, limited to just the librespot output. The process crashes after the last line in this log.

2022-09-13 08-30-40.358 [Info] (librespot) librespot 0.4.2 1c364e3eec (Built on 2022-07-30, Build ID: 1659203265, Profile: release)
2022-09-13 08-30-42.195 [Warn] (librespot_core::apresolve) Ignoring blacklisted access point ap-gew4.spotify.com:80
2022-09-13 08-30-42.195 [Info] (librespot_core::session) Connecting to AP "ap-gae2.spotify.com:4070"
2022-09-13 08-30-42.882 [Info] (librespot_core::session) Authenticated as "uquhcy53zuk19hf72mm4sl4d6" !
2022-09-13 08-30-42.882 [Info] (librespot_playback::mixer::softmixer) Mixing with softvol and volume control: Log(60.0)
2022-09-13 08-30-42.883 [Info] (librespot_playback::convert) Converting with ditherer: tpdf
2022-09-13 08-30-42.883 [Info] (librespot_playback::audio_backend::pipe) Using StdoutSink (pipe) with format: S16
2022-09-13 08-30-42.884 [Info] (librespot_core::session) Country: "AU"
Originally created by @jonotargett on GitHub (Sep 13, 2022). Original GitHub issue: https://github.com/librespot-org/librespot/issues/1058 **Describe the bug** Librespot (as called via snapcast) is unable to play any user playlists. It appears that anything that would require permissions to access the private user is failing, as any publicly accessible playlists are still working correctly. Playing a track directly from an artist/album page also works with no issues. This affects my curated playlists, daily mixes, and '<genre> Mix' playlists that spotify generates. I have already found some workaround to this, but I feel like this is a hack which just sidesteps the actual bug. I have followed the discussion [here](https://github.com/librespot-org/librespot/issues/972) and used the same resolution of manually remapping the domain to point to a different endpoint, which restores the functionality. **My hack/fix** Manually forcing librespot to use a different spotify endpoint resolves the issue. As per the method in the link above, my response from `apresolve.spotify.com` is: ``` {"ap_list":["ap-gae2.spotify.com:4070","ap-gae2.spotify.com:443","ap-gae2.spotify.com:80","ap-gue1.spotify.com:4070","ap-gew4.spotify.com:443","ap-guc3.spotify.com:80"]} ``` My librespot seems to be defaulting to use the `ap-gae2.spotify.com` endpoint, and according to the logs the alternative endpoint `ap-gew4.spotify.com` is blacklisted. However I can restore correct functionality by creating a local DNS record remapping `ap-gae2` to `34.158.253.218`, which is the current IP address that `ap-gew4.spotify.com` points to. Not sure why this endpoint blacklisted, or what blacklisting means, but redirecting my traffic to that means that my setup is working again. The non-blacklisted endpoint has been failing consistently - I can reproduce this issue every single attempt. The other endpoints listed by apresolve don't seem to actually be available. If I remap to point to those, I get an error about connection issues and all playback fails. **To reproduce failure** 1. Launch `librespot` as part of the snapclient service. 2. In the spotify desktop or mobile app, start playing music from a spotify created playlist, ie created by user 'Spotify', or by playing an artist/album directly. 3. Choose 'Connect to Device' -> *device*. 4. Spotify connects to the librespot device correctly. Playback works as expected (everything working until this point) 5. In the desktop/mobile app, change playback to a user playlist. The librespot device will be immediately disconnected and playback will stop. 6. Restart the snapcast/librespot service. 7. In the spotify desktop or mobile app, start playing music from a user playlist, or a daily mix, etc. 8. Choose 'Connect to Device' -> *device*. Spotify will attempt to connect but will fail. 9. The spotify desktop/mobile app with now show the current playing track as "Playing from playlist " but with a blank playlist name. Before trying to connect to the librespot device it would have said "Daily Mix 4" for example. **Host** I'm running librespot as part of my snapcast service in a docker container. Dockerfile is pretty basic: ``` FROM alpine:latest RUN apk add --no-cache snapcast-server RUN apk add --no-cache -X http://dl-cdn.alpinelinux.org/alpine/edge/testing librespot RUN apk add --no-cache mpv CMD ["snapserver"] ``` **Log** Note that this is a truncated log; I'm not going to share the full details as it exposes a lot of my home network information. This is the log from the docker container (snapcast-server process), without the hack DNS fix, limited to just the librespot output. The process crashes after the last line in this log. ``` 2022-09-13 08-30-40.358 [Info] (librespot) librespot 0.4.2 1c364e3eec (Built on 2022-07-30, Build ID: 1659203265, Profile: release) 2022-09-13 08-30-42.195 [Warn] (librespot_core::apresolve) Ignoring blacklisted access point ap-gew4.spotify.com:80 2022-09-13 08-30-42.195 [Info] (librespot_core::session) Connecting to AP "ap-gae2.spotify.com:4070" 2022-09-13 08-30-42.882 [Info] (librespot_core::session) Authenticated as "uquhcy53zuk19hf72mm4sl4d6" ! 2022-09-13 08-30-42.882 [Info] (librespot_playback::mixer::softmixer) Mixing with softvol and volume control: Log(60.0) 2022-09-13 08-30-42.883 [Info] (librespot_playback::convert) Converting with ditherer: tpdf 2022-09-13 08-30-42.883 [Info] (librespot_playback::audio_backend::pipe) Using StdoutSink (pipe) with format: S16 2022-09-13 08-30-42.884 [Info] (librespot_core::session) Country: "AU" ```
kerem 2026-02-27 19:30:59 +03:00
  • closed this issue
  • added the
    bug
    label
Author
Owner

@roderickvd commented on GitHub (Sep 13, 2022):

Thanks for the report. This is really strange, never heard of it before. Would you please recompile from the current dev and post the verbose logs. I don't mind at all if you anonymise it but we really need the extra log lines to understand what's happening here.

Coincidentally dev no longer blacklists that access point, so your issues may just fade away.

Still if you could be of service to also run vanilla librespot v0.4.2 with verbose logs then we could actually have a throw at analysing and fixing the issue instead of just working around it. I don't mind if you anonymise the logs at all but I really need the extra log lines or I just can't debug.

<!-- gh-comment-id:1245534256 --> @roderickvd commented on GitHub (Sep 13, 2022): Thanks for the report. This is really strange, never heard of it before. Would you please recompile from the current `dev` and post the verbose logs. I don't mind at all if you anonymise it but we really need the extra log lines to understand what's happening here. Coincidentally `dev` no longer blacklists that access point, so your issues may just fade away. Still if you could be of service to also run vanilla `librespot` v0.4.2 with verbose logs then we could actually have a throw at analysing and fixing the issue instead of just working around it. I don't mind if you anonymise the logs at all but I really need the extra log lines or I just can't debug.
Author
Owner

@jonotargett commented on GitHub (Sep 14, 2022):

Have flushed my DNS cache and gone back to using the original endpoint - and the issue doesn't seem to be present when librespot is called as a standalone process, instead of when using snapcast's stream = ///librespot:/<etc> manner. I'm reproducing the same issue I had before using the snapcast container, but everything appears to be working fine with the following setup:

Dockerfile
Note that this is the identical version/package that I'm using in the failing setup.

FROM alpine:latest
RUN apk add --no-cache -X http://dl-cdn.alpinelinux.org/alpine/edge/testing librespot
RUN mkfifo /tmp/emptysink
CMD ["/usr/bin/librespot", "--verbose", "--backend", "pipe", "--device", "/tmp/emptysink"]

docker-compose.yml

version: "3"

services:
  librespot:
    container_name: librespot
    build:
      context: .
      dockerfile: Dockerfile    
    network_mode: host

Logs

librespot  | [2022-09-14T05:23:31Z INFO  librespot] librespot 0.4.2 1c364e3eec (Built on 2022-07-30, Build ID: 1659203265, Profile: release)
librespot  | [2022-09-14T05:23:31Z TRACE librespot] Command line argument(s):
librespot  | [2022-09-14T05:23:31Z TRACE librespot] 		verbose
librespot  | [2022-09-14T05:23:31Z TRACE librespot] 		backend "pipe"
librespot  | [2022-09-14T05:23:31Z TRACE librespot] 		device "/tmp/emptysink"
librespot  | [2022-09-14T05:23:31Z DEBUG librespot_discovery::server] Zeroconf server listening on 0.0.0.0:43895
librespot  | [2022-09-14T05:23:36Z DEBUG librespot_discovery::server] POST "/" {}
librespot  | [2022-09-14T05:23:36Z WARN  librespot_core::apresolve] Ignoring blacklisted access point ap-gue1.spotify.com:4070
librespot  | [2022-09-14T05:23:36Z INFO  librespot_core::session] Connecting to AP "ap-gae2.spotify.com:4070"
librespot  | [2022-09-14T05:23:37Z INFO  librespot_core::session] Authenticated as "uquhcy53zuk19hf72mm4sl4d6" !
librespot  | [2022-09-14T05:23:37Z DEBUG librespot_core::session] new Session[0]
librespot  | [2022-09-14T05:23:37Z INFO  librespot_playback::mixer::softmixer] Mixing with softvol and volume control: Log(60.0)
librespot  | [2022-09-14T05:23:37Z DEBUG librespot_connect::spirc] new Spirc[0]
librespot  | [2022-09-14T05:23:37Z DEBUG librespot_connect::spirc] canonical_username: uquhcy53zuk19hf72mm4sl4d6
librespot  | [2022-09-14T05:23:37Z DEBUG librespot::component] new MercuryManager
librespot  | [2022-09-14T05:23:37Z DEBUG librespot_playback::player] new Player[0]
librespot  | [2022-09-14T05:23:37Z INFO  librespot_playback::convert] Converting with ditherer: tpdf
librespot  | [2022-09-14T05:23:37Z INFO  librespot_playback::audio_backend::pipe] Using StdoutSink (pipe) with format: S16
librespot  | [2022-09-14T05:23:37Z DEBUG librespot_playback::mixer::mappings] Input volume 58958 mapped to: 49.99%
librespot  | [2022-09-14T05:23:37Z DEBUG librespot_playback::player] command=AddEventSender
librespot  | [2022-09-14T05:23:37Z DEBUG librespot_playback::player] command=VolumeSet(58958)
librespot  | [2022-09-14T05:23:37Z DEBUG librespot_core::session] Session[0] strong=3 weak=2
librespot  | [2022-09-14T05:23:37Z INFO  librespot_core::session] Country: "AU"
librespot  | [2022-09-14T05:23:37Z DEBUG librespot_core::mercury] subscribed uri=hm://remote/user/uquhcy53zuk19hf72mm4sl4d6/ count=0
librespot  | [2022-09-14T05:23:37Z DEBUG librespot_connect::spirc] kMessageTypeNotify "vulcan" 314f28608ee3d8ef85db71a241a511bc5e8e713c 980674917 1663133017695 kPlayStatusPlay
librespot  | [2022-09-14T05:23:38Z DEBUG librespot_connect::spirc] kMessageTypeLoad "vulcan" 314f28608ee3d8ef85db71a241a511bc5e8e713c 980675156 1663133017695 kPlayStatusPlay
librespot  | [2022-09-14T05:23:38Z DEBUG librespot_connect::spirc] State: context_uri: "spotify:playlist:37i9dQZF1E39dznvv93rL1" index: 4 position_ms: 266559 status: kPlayStatusPlay position_measured_at: 1663133017990 context_description: "" shuffle: false repeat: false playing_from_fallback: true row: 0 playing_track_index: 4 track {gid: "\371-\013\327\240xKn\270]s+\273S{\225"} track {gid: "\301\245\235\215\226\005C\'\276\342\313\\\361\266\210C"} track {gid: "\306\200#\026\r\366F\363\224lJ\230\371@L\311"} track {gid: "\310\00315J\213Oo\2631\263r\\\024\202\232"} track {gid: "\327\210x\363\237\362H\255\225\246\254\207(\225\212\202"} track {gid: "\035%{\252\371\022@\236\2307(\376\266\372\250\356"} track {gid: "|\366\326\252\343\027B\250\275\025g_fMnI"} track {gid: "\r{\252u\206{F\305\220\0003 \232\252\236\304"} track {gid: "\360\034\327[\333\304H\013\245\305\362\357J\333\365\014"} track {gid: "\274\325\266|zpB\302\224\344\177\026V6p\352"} track {gid: "\362\244\036\205\335\024B\221\273\372\373\027BH\251\014"} track {gid: "g\335\004\372\035\264N\240\243q?\227\310\352\271\334"} track {gid: "\037\317\256\346\243\226L\007\231SgQ\272\302X\306"} track {gid: "\006oo\270\347k@.\251J\033m\321:\300E"} track {gid: "\365\2614\213\251\237L;\274\tMnH\347\202\026"} track {gid: "\270\322M~\\\300A\313\271@\215\372y<\313\'"} track {gid: "\014\313\334\336\205\215K\t\225\217\323I\010l!s"} track {gid: "\332\021\236\027U\300M!\237v+(\373MGF"} track {gid: "6\316\363\000\013\274I\324\277\004\030}\264}\347\014"} track {gid: "\275}\306#\214;I\001\230\272b\305\233\243`\377"} track {gid: "\025W!\014\240\223Ac\235K\357\332\337\036\215F"} track {gid: "T6\321\010\351\264L\320\2009v\374q&\030\033"} track {gid: "\362\340S \'\366J\274\273\353\206bVW\030 "} track {gid: "\361]\345\335*\302Hg\274\371\352\364\2741\263\330"} track {gid: "\256p\225\350\322~@\361\247\323\200\336Q+\204P"} track {gid: "+\313\262\034I\177B\265\250\270\216d\026\220\260\223"} track {gid: "\005b\320\210C)Ff\251\312`\201\367 \007\327"} track {gid: "Z\000\314\266\332\377B\025\216\312\344}\247\027\244\253"} track {gid: "hIT\224^\255A\006\266A\322\024Tz\037\211"} track {gid: "\274\017\361\347\352\340L\351\2169\205\351\322kK\006"} track {gid: "\321\265\302\013k\020F\301\236d\311\036\273/\334>"} track {gid: "\265ci\376\271HM\240\275o\250\0003j\025\262"} track {gid: "\001\000\013\020\037\320O9\275Sp\322Nf\227\010"} track {gid: "6\3138\236\242mHC\2453\217\226\3218\232\001"} track {gid: "1\302\251P\352\227Ip\261\270j\357\350\026\366\035"} track {gid: "\204]\004\013x\323KX\256\366\313J8.\221H"} track {gid: "\351_PzLEG\351\212\320#\363k\027\221\330"} track {gid: "\244\260i$\274LD~\273\343\376\243GZ\323\263"} track {gid: "^\371]Y;\276LI\244d\303\277\177{\021\372"} track {gid: "\206iqd\226\016K\365\267)\302~\345\257\016\033"} track {gid: "`aQ.\353mK\205\223n\353\243U\202$]"} track {gid: "\n\202+ HfBJ\200\\\222\331\253\016 L"} track {gid: "bm\376\241\250sM\222\2147\215\227\177?\027\305"} track {gid: "\253\202^\006\036\026L\210\245L#*\2321M\274"} track {gid: "\025\231K\232\3610H\037\273c\245\034\370\245q\350"} track {gid: "[\035\010\206\343\237Ie\216\234c\331\274\377\375p"} track {gid: "\307^h\014;c@\010\217\247\000\237\305\321\025p"} track {gid: "<q\242\033Q-D,\222\026\307c>\371\256\272"} track {gid: "p\225\231\206\002XNR\232{)D\004!|\250"} track {gid: "\014P\204\014\330IL$\250\337\240d\241k\243\303"}
librespot  | [2022-09-14T05:23:38Z DEBUG librespot_connect::spirc] Frame has 50 tracks
librespot  | [2022-09-14T05:23:38Z TRACE librespot_connect::spirc] Sending status to server: [kPlayStatusPlay]
librespot  | [2022-09-14T05:23:38Z DEBUG librespot_playback::player] command=SetAutoNormaliseAsAlbum(false)
librespot  | [2022-09-14T05:23:38Z DEBUG librespot_playback::player] command=Load(SpotifyId { id: 286492624657614598220881167970395851394, audio_type: Track }, true, 266559)
librespot  | [2022-09-14T05:23:38Z TRACE librespot_connect::spirc] Sending status to server: [kPlayStatusPlay]
librespot  | [2022-09-14T05:23:38Z INFO  librespot_playback::player] Loading <I Don't Do Drugs, I Just Sweat a Lot> with Spotify URI <spotify:track:6yHIxvq0z3KIQevkjaTf10>
librespot  | [2022-09-14T05:23:38Z DEBUG librespot_audio::fetch] Downloading file 9b4cc8b5cbae8d60429d3d43db99a8670af561dc
librespot  | [2022-09-14T05:23:38Z DEBUG librespot::component] new ChannelManager
librespot  | [2022-09-14T05:23:38Z DEBUG librespot::component] new AudioKeyManager
librespot  | [2022-09-14T05:23:38Z DEBUG librespot_connect::spirc] kMessageTypeNotify "vulcan" 314f28608ee3d8ef85db71a241a511bc5e8e713c 980675675 1663133018453 kPlayStatusStop
librespot  | [2022-09-14T05:23:40Z INFO  librespot_playback::player] <I Don't Do Drugs, I Just Sweat a Lot> (371280 ms) loaded
librespot  | [2022-09-14T05:23:40Z TRACE librespot_playback::player] == Starting sink ==

I've tried and it doesn't look like I can pass through the --verbose flag to librespot when called by snapcast easily. Looks like from now on I'll be running librespot in a separate container and piping the audio into snapcast that way. For any future readers: my hack fix ended up not being a good solution, the alternate endpoint worked for some playlists/tracks but failed again on others.

If you don't mind, could you explain the meaning/reason behind blacklisting an access point? I'm curious why ap-gae2 would have been blacklisted in the first place.

<!-- gh-comment-id:1246260279 --> @jonotargett commented on GitHub (Sep 14, 2022): Have flushed my DNS cache and gone back to using the original endpoint - and the issue doesn't seem to be present when librespot is called as a standalone process, instead of when using snapcast's `stream = ///librespot:/<etc>` manner. I'm reproducing the same issue I had before using the snapcast container, but everything appears to be working fine with the following setup: **Dockerfile** Note that this is the identical version/package that I'm using in the failing setup. ``` FROM alpine:latest RUN apk add --no-cache -X http://dl-cdn.alpinelinux.org/alpine/edge/testing librespot RUN mkfifo /tmp/emptysink CMD ["/usr/bin/librespot", "--verbose", "--backend", "pipe", "--device", "/tmp/emptysink"] ``` **docker-compose.yml** ``` version: "3" services: librespot: container_name: librespot build: context: . dockerfile: Dockerfile network_mode: host ``` **Logs** ``` librespot | [2022-09-14T05:23:31Z INFO librespot] librespot 0.4.2 1c364e3eec (Built on 2022-07-30, Build ID: 1659203265, Profile: release) librespot | [2022-09-14T05:23:31Z TRACE librespot] Command line argument(s): librespot | [2022-09-14T05:23:31Z TRACE librespot] verbose librespot | [2022-09-14T05:23:31Z TRACE librespot] backend "pipe" librespot | [2022-09-14T05:23:31Z TRACE librespot] device "/tmp/emptysink" librespot | [2022-09-14T05:23:31Z DEBUG librespot_discovery::server] Zeroconf server listening on 0.0.0.0:43895 librespot | [2022-09-14T05:23:36Z DEBUG librespot_discovery::server] POST "/" {} librespot | [2022-09-14T05:23:36Z WARN librespot_core::apresolve] Ignoring blacklisted access point ap-gue1.spotify.com:4070 librespot | [2022-09-14T05:23:36Z INFO librespot_core::session] Connecting to AP "ap-gae2.spotify.com:4070" librespot | [2022-09-14T05:23:37Z INFO librespot_core::session] Authenticated as "uquhcy53zuk19hf72mm4sl4d6" ! librespot | [2022-09-14T05:23:37Z DEBUG librespot_core::session] new Session[0] librespot | [2022-09-14T05:23:37Z INFO librespot_playback::mixer::softmixer] Mixing with softvol and volume control: Log(60.0) librespot | [2022-09-14T05:23:37Z DEBUG librespot_connect::spirc] new Spirc[0] librespot | [2022-09-14T05:23:37Z DEBUG librespot_connect::spirc] canonical_username: uquhcy53zuk19hf72mm4sl4d6 librespot | [2022-09-14T05:23:37Z DEBUG librespot::component] new MercuryManager librespot | [2022-09-14T05:23:37Z DEBUG librespot_playback::player] new Player[0] librespot | [2022-09-14T05:23:37Z INFO librespot_playback::convert] Converting with ditherer: tpdf librespot | [2022-09-14T05:23:37Z INFO librespot_playback::audio_backend::pipe] Using StdoutSink (pipe) with format: S16 librespot | [2022-09-14T05:23:37Z DEBUG librespot_playback::mixer::mappings] Input volume 58958 mapped to: 49.99% librespot | [2022-09-14T05:23:37Z DEBUG librespot_playback::player] command=AddEventSender librespot | [2022-09-14T05:23:37Z DEBUG librespot_playback::player] command=VolumeSet(58958) librespot | [2022-09-14T05:23:37Z DEBUG librespot_core::session] Session[0] strong=3 weak=2 librespot | [2022-09-14T05:23:37Z INFO librespot_core::session] Country: "AU" librespot | [2022-09-14T05:23:37Z DEBUG librespot_core::mercury] subscribed uri=hm://remote/user/uquhcy53zuk19hf72mm4sl4d6/ count=0 librespot | [2022-09-14T05:23:37Z DEBUG librespot_connect::spirc] kMessageTypeNotify "vulcan" 314f28608ee3d8ef85db71a241a511bc5e8e713c 980674917 1663133017695 kPlayStatusPlay librespot | [2022-09-14T05:23:38Z DEBUG librespot_connect::spirc] kMessageTypeLoad "vulcan" 314f28608ee3d8ef85db71a241a511bc5e8e713c 980675156 1663133017695 kPlayStatusPlay librespot | [2022-09-14T05:23:38Z DEBUG librespot_connect::spirc] State: context_uri: "spotify:playlist:37i9dQZF1E39dznvv93rL1" index: 4 position_ms: 266559 status: kPlayStatusPlay position_measured_at: 1663133017990 context_description: "" shuffle: false repeat: false playing_from_fallback: true row: 0 playing_track_index: 4 track {gid: "\371-\013\327\240xKn\270]s+\273S{\225"} track {gid: "\301\245\235\215\226\005C\'\276\342\313\\\361\266\210C"} track {gid: "\306\200#\026\r\366F\363\224lJ\230\371@L\311"} track {gid: "\310\00315J\213Oo\2631\263r\\\024\202\232"} track {gid: "\327\210x\363\237\362H\255\225\246\254\207(\225\212\202"} track {gid: "\035%{\252\371\022@\236\2307(\376\266\372\250\356"} track {gid: "|\366\326\252\343\027B\250\275\025g_fMnI"} track {gid: "\r{\252u\206{F\305\220\0003 \232\252\236\304"} track {gid: "\360\034\327[\333\304H\013\245\305\362\357J\333\365\014"} track {gid: "\274\325\266|zpB\302\224\344\177\026V6p\352"} track {gid: "\362\244\036\205\335\024B\221\273\372\373\027BH\251\014"} track {gid: "g\335\004\372\035\264N\240\243q?\227\310\352\271\334"} track {gid: "\037\317\256\346\243\226L\007\231SgQ\272\302X\306"} track {gid: "\006oo\270\347k@.\251J\033m\321:\300E"} track {gid: "\365\2614\213\251\237L;\274\tMnH\347\202\026"} track {gid: "\270\322M~\\\300A\313\271@\215\372y<\313\'"} track {gid: "\014\313\334\336\205\215K\t\225\217\323I\010l!s"} track {gid: "\332\021\236\027U\300M!\237v+(\373MGF"} track {gid: "6\316\363\000\013\274I\324\277\004\030}\264}\347\014"} track {gid: "\275}\306#\214;I\001\230\272b\305\233\243`\377"} track {gid: "\025W!\014\240\223Ac\235K\357\332\337\036\215F"} track {gid: "T6\321\010\351\264L\320\2009v\374q&\030\033"} track {gid: "\362\340S \'\366J\274\273\353\206bVW\030 "} track {gid: "\361]\345\335*\302Hg\274\371\352\364\2741\263\330"} track {gid: "\256p\225\350\322~@\361\247\323\200\336Q+\204P"} track {gid: "+\313\262\034I\177B\265\250\270\216d\026\220\260\223"} track {gid: "\005b\320\210C)Ff\251\312`\201\367 \007\327"} track {gid: "Z\000\314\266\332\377B\025\216\312\344}\247\027\244\253"} track {gid: "hIT\224^\255A\006\266A\322\024Tz\037\211"} track {gid: "\274\017\361\347\352\340L\351\2169\205\351\322kK\006"} track {gid: "\321\265\302\013k\020F\301\236d\311\036\273/\334>"} track {gid: "\265ci\376\271HM\240\275o\250\0003j\025\262"} track {gid: "\001\000\013\020\037\320O9\275Sp\322Nf\227\010"} track {gid: "6\3138\236\242mHC\2453\217\226\3218\232\001"} track {gid: "1\302\251P\352\227Ip\261\270j\357\350\026\366\035"} track {gid: "\204]\004\013x\323KX\256\366\313J8.\221H"} track {gid: "\351_PzLEG\351\212\320#\363k\027\221\330"} track {gid: "\244\260i$\274LD~\273\343\376\243GZ\323\263"} track {gid: "^\371]Y;\276LI\244d\303\277\177{\021\372"} track {gid: "\206iqd\226\016K\365\267)\302~\345\257\016\033"} track {gid: "`aQ.\353mK\205\223n\353\243U\202$]"} track {gid: "\n\202+ HfBJ\200\\\222\331\253\016 L"} track {gid: "bm\376\241\250sM\222\2147\215\227\177?\027\305"} track {gid: "\253\202^\006\036\026L\210\245L#*\2321M\274"} track {gid: "\025\231K\232\3610H\037\273c\245\034\370\245q\350"} track {gid: "[\035\010\206\343\237Ie\216\234c\331\274\377\375p"} track {gid: "\307^h\014;c@\010\217\247\000\237\305\321\025p"} track {gid: "<q\242\033Q-D,\222\026\307c>\371\256\272"} track {gid: "p\225\231\206\002XNR\232{)D\004!|\250"} track {gid: "\014P\204\014\330IL$\250\337\240d\241k\243\303"} librespot | [2022-09-14T05:23:38Z DEBUG librespot_connect::spirc] Frame has 50 tracks librespot | [2022-09-14T05:23:38Z TRACE librespot_connect::spirc] Sending status to server: [kPlayStatusPlay] librespot | [2022-09-14T05:23:38Z DEBUG librespot_playback::player] command=SetAutoNormaliseAsAlbum(false) librespot | [2022-09-14T05:23:38Z DEBUG librespot_playback::player] command=Load(SpotifyId { id: 286492624657614598220881167970395851394, audio_type: Track }, true, 266559) librespot | [2022-09-14T05:23:38Z TRACE librespot_connect::spirc] Sending status to server: [kPlayStatusPlay] librespot | [2022-09-14T05:23:38Z INFO librespot_playback::player] Loading <I Don't Do Drugs, I Just Sweat a Lot> with Spotify URI <spotify:track:6yHIxvq0z3KIQevkjaTf10> librespot | [2022-09-14T05:23:38Z DEBUG librespot_audio::fetch] Downloading file 9b4cc8b5cbae8d60429d3d43db99a8670af561dc librespot | [2022-09-14T05:23:38Z DEBUG librespot::component] new ChannelManager librespot | [2022-09-14T05:23:38Z DEBUG librespot::component] new AudioKeyManager librespot | [2022-09-14T05:23:38Z DEBUG librespot_connect::spirc] kMessageTypeNotify "vulcan" 314f28608ee3d8ef85db71a241a511bc5e8e713c 980675675 1663133018453 kPlayStatusStop librespot | [2022-09-14T05:23:40Z INFO librespot_playback::player] <I Don't Do Drugs, I Just Sweat a Lot> (371280 ms) loaded librespot | [2022-09-14T05:23:40Z TRACE librespot_playback::player] == Starting sink == ``` I've tried and it doesn't look like I can pass through the `--verbose` flag to librespot when called by snapcast easily. Looks like from now on I'll be running librespot in a separate container and piping the audio into snapcast that way. For any future readers: my hack fix ended up not being a good solution, the alternate endpoint worked for some playlists/tracks but failed again on others. If you don't mind, could you explain the meaning/reason behind blacklisting an access point? I'm curious why `ap-gae2` would have been blacklisted in the first place.
Author
Owner

@kingosticks commented on GitHub (Sep 14, 2022):

Gew4 was blacklisted as per the first log. Gew2 shouldn't have been. It's because it was found to be broken for some users. See https://github.com/librespot-org/librespot/pull/1026

<!-- gh-comment-id:1246334170 --> @kingosticks commented on GitHub (Sep 14, 2022): Gew4 was blacklisted as per the first log. Gew2 shouldn't have been. It's because it was found to be broken for some users. See https://github.com/librespot-org/librespot/pull/1026
Author
Owner

@kingosticks commented on GitHub (Sep 14, 2022):

And Gae1 is also blacklisted as per github.com/librespot-org/librespot@87ea69b457, I missed that one. Gae2 is not blacklisted, assuming that's just your typo in the above comment.

<!-- gh-comment-id:1246347956 --> @kingosticks commented on GitHub (Sep 14, 2022): And Gae1 is also blacklisted as per https://github.com/librespot-org/librespot/commit/87ea69b4573f1ec9205dbab29d997916e7218fc0, I missed that one. Gae2 is not blacklisted, assuming that's just your typo in the above comment.
Author
Owner

@jonotargett commented on GitHub (Sep 14, 2022):

Yep that was a typo, I meant ap-gew4. Thanks for the commit link.

I'll close this then, seems its not actually an issue with librespot but something do with snapcast + librespot.

<!-- gh-comment-id:1246670735 --> @jonotargett commented on GitHub (Sep 14, 2022): Yep that was a typo, I meant `ap-gew4`. Thanks for the commit link. I'll close this then, seems its not actually an issue with librespot but something do with snapcast + librespot.
Author
Owner

@kingosticks commented on GitHub (Sep 14, 2022):

I think more likely something related to the container rather than using with snapcast, snapcast just runs the binary with a few options that should have not effect on this. Containers are always the problem!

<!-- gh-comment-id:1246676928 --> @kingosticks commented on GitHub (Sep 14, 2022): I think more likely something related to the container rather than using with snapcast, snapcast just runs the binary with a few options that should have not effect on this. Containers are always the problem!
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
starred/librespot#496
No description provided.