badaix/snapcast

librespot:// source plays as noise

Opened this issue · 7 comments

Describe the bug
Since Spotify disabled the use of username/password for librespot, I tried to configure a librespot:// source without username/password parameters to use zeroconf. It works on the Spotify part, but reproduce as noise on Snapcast.

Relevant part of snapserver.conf:

source = librespot:///usr/bin/librespot?name=Spotify&devicename=Snapcast&bitrate=320&wd_timeout=3600&params=--volume-ctrl%20fixed

Everything works fine If instead I configure a new fifo on Snapcast server, and run an external librespot using pipe backend.

Steps to Reproduce

  1. create a librespot:// source without username/password parameters
  2. play on the device using Spotify
  3. Noise is reproduced on Snapcast clients

Environment details

Attach logfile if applicable

$ /usr/bin/snapserver --logfilter debug
2024-08-15 17-18-50.861 [Error] (Avahi) Failed to create client: Daemon not running
2024-08-15 17-18-50.863 [Error] (AsioStream) Error reading message: End of file, length: 0, ec: asio.misc:2
2024-08-15 17-19-11.909 [Warn] (librespot_core::apresolve) Ignoring blacklisted access point ap-gew4.spotify.com:80

Interestingly, the output from librespot is a lot more verbose when I run it outside of snapcast:

$ /usr/bin/snapserver --logfilter debug & librespot --backend pipe --device /tmp/snapspot --name Snapcast --bitrate 320 --volume-ctrl fixed
[2024-08-15T20:21:40Z INFO  librespot] librespot 0.4.2 UNKNOWN (Built on 2023-08-01, Build ID: 1690865570, Profile: release)
2024-08-15 17-21-40.748 [Error] (Avahi) Failed to create client: Daemon not running
2024-08-15 17-21-40.750 [Error] (AsioStream) Error reading message: End of file, length: 0, ec: asio.misc:2
2024-08-15 17-21-40.750 [Error] (AsioStream) Error reading message: End of file, length: 0, ec: asio.misc:2
[2024-08-15T20:21:56Z WARN  librespot_core::apresolve] Ignoring blacklisted access point ap-gue1.spotify.com:443
[2024-08-15T20:21:56Z INFO  librespot_core::session] Connecting to AP "ap-guc3.spotify.com:4070"
[2024-08-15T20:21:56Z INFO  librespot_core::session] Authenticated as "csalmeri" !
[2024-08-15T20:21:56Z INFO  librespot_playback::mixer::softmixer] Mixing with softvol and volume control: Fixed
[2024-08-15T20:21:56Z INFO  librespot_playback::convert] Converting with ditherer: tpdf
[2024-08-15T20:21:56Z INFO  librespot_playback::audio_backend::pipe] Using StdoutSink (pipe) with format: S16
[2024-08-15T20:21:56Z INFO  librespot_core::session] Country: "AR"
[2024-08-15T20:21:57Z INFO  librespot_playback::player] Loading <Habanera> with Spotify URI <spotify:track:6pUlLSkBmvHzDaPlzZsvtr>
[2024-08-15T20:22:00Z INFO  librespot_playback::player] <Habanera> (288385 ms) loaded
[2024-08-15T20:22:16Z INFO  librespot_playback::player] Loading <Other Jewels> with Spotify URI <spotify:track:43QCn1fqNpaVllvjNXx5eX>
[2024-08-15T20:22:17Z INFO  librespot_playback::player] <Other Jewels> (347377 ms) loaded
2024-08-15 17-22-33.562 [Error] (AsioStream) Error reading message: End of file, length: 2304, ec: asio.misc:2

So the issue seems that some INFO messages from librespot are consumed as sound data by snapserver, also something is changing the format of log messages for librespot

UPDATE 16/Aug/2024
Cannot reproduce this anymore. Will stick to the librespot:// source configuration to see if this happens again

Looking at the code it seems that the stream processor is consuming stderr from librespot to get track name and duration.

I made some tests and messages from librespot zeroconf negotiation are still being output to stderr, no stdout were the audio should be written. I couldn't find any extra message on stdout.

I remember that without zeroconf, messages from librespot username/password auth was written on snapserver logs. Sadly, I cannot reproduce that anymore. So somehow the stream processor is being confused by the delayed authentication that with zeroconf occurs only when the device is selected on the Spotify app.

Darn, I reverted back to the librespot:// source and cannot reproduce the noise. I'll stick to this configuration to test if I get the noise again.

Can you reproduce the noise by skipping a few songs while playing from a librespot:// source?

Hello I'm having the same problem, did someone repro and/or find a fix?

I tried skipping songs but it doesn't seem to help. This started happening when I switched to using libre-auth credentials.json file, when I used user name password it worked fine, but that doesn't work with spotify anymore

This is my configuration

source = spotify:///librespot?name=Home%20Assistant&devicename=Spotify&wd_timeout=7800&volume=100&normalize=false&autoplay=false&disable_audio_cache=true&params=--device-type%20avr&params=--volume-ctrl%20fixed&params=--format%20S32

I also tried this

source = spotify:///librespot?name=Home%20Assistant&devicename=Spotify&wd_timeout=7800&volume=100&normalize=false&autoplay=false&cache=/var/cache/librespot&cache-size-limit=2G

same :(

This is probably nothing to do with it .. but I thought I'd see if I can figure out the version of librespot that is part of the snapserver container.. so I ran this

root@8505a85afae7:/# librespot [2024-09-23T02:13:35Z INFO librespot] librespot 0.4.2 6537c44 (Built on 2024-08-08, Build ID: d77PPi6H, Profile: release)

is this old? should it be newer?

Can you reproduce the noise by skipping a few songs while playing from a librespot:// source?

Nop. No way to reproduce it now. However I noticed that the songname scrapping logic is not keeping up with the song being played if I skip forward or backward on Spotify a little too fast.

@pookieman no clue about why it is happening to you. librespot, as far as I could test it, sends all messages to stderr, and snapcast never uses stderr as sound data.

Your version of librespot is ok. It wasn't updated in a while.

Did you try setting up librespot to use a fifo sound device? Also, please send your log output.