Librespot no sound?
Streammet opened this issue · 3 comments
Describe the bug
My Snapcast Server is working perfekt exept librespot. Airplay works flawless but when I try to select librespot it seems to work but there is no sound comming out the android devices. There are no errors in the logs and I set the volume in the config to 100%
Steps to Reproduce
- Install Snapcast
- Install librespot with cargo
- setup Librespot in the config
Environment details
- OS: Debian 12 CPU: Intel N100 (4) @ 3.400GHz CPU: Intel Alder Lake-N [UHD Graphics]
- Snapcast version 0.26.0
- Installed from a package, self compiled, ...
Attach logfile if applicable
2023-12-16 19-46-55.818 [Info] (Snapserver) Version 0.26.0
2023-12-16 19-46-55.818 [Info] (Snapserver) Adding source: pipe:///tmp/snapfifo?name=default
2023-12-16 19-46-55.818 [Info] (Snapserver) Adding source: spotify:///home/nuc/.cargo/bin/librespot?name=Spotify&username=xxx&password=xxx&devicename=Snapcast&bitrate=320&volume=100
2023-12-16 19-46-55.818 [Info] (Snapserver) Adding source: airplay:///shairport-sync?name=Airplay
2023-12-16 19-46-55.818 [Notice] (init) Settings file: "/root/.config/snapserver/server.json"
2023-12-16 19-46-55.818 [Info] (Snapserver) Using HTTP host name: nucbox
2023-12-16 19-46-55.821 [Info] (Avahi) Adding service 'Snapcast'
2023-12-16 19-46-55.823 [Info] (PcmStream) PcmStream: default, sampleFormat: 48000:16:2
2023-12-16 19-46-55.823 [Info] (PipeStream) PipeStream mode: create
2023-12-16 19-46-55.823 [Info] (Server) Stream: {"fragment":"","host":"","path":"/tmp/snapfifo","query":{"chunk_ms":"20","codec":"flac","name":"default","sampleformat":"48000:16:2"},"raw":"pipe:////tmp/snapfifo?chunk_ms=20&codec=flac&name=default&sampleformat=48000:16:2","scheme":"pipe"}
2023-12-16 19-46-55.824 [Info] (PcmStream) PcmStream: Spotify, sampleFormat: 44100:16:2
2023-12-16 19-46-55.824 [Info] (Server) Stream: {"fragment":"","host":"","path":"/home/nuc/.cargo/bin/librespot","query":{"bitrate":"320","chunk_ms":"20","codec":"flac","devicename":"Snapcast","name":"Spotify","password":"xxx","sampleformat":"44100:16:2","username":"xxx","volume":"100"},"raw":"spotify:////home/nuc/.cargo/bin/librespot?bitrate=320&chunk_ms=20&codec=flac&devicename=Snapcast&name=Spotify&password=xxx&sampleformat=44100:16:2&username=xxx&volume=100","scheme":"spotify"}
2023-12-16 19-46-55.824 [Info] (PcmStream) PcmStream: Airplay, sampleFormat: 44100:16:2
2023-12-16 19-46-55.824 [Info] (Server) Stream: {"fragment":"","host":"","path":"/shairport-sync","query":{"chunk_ms":"20","codec":"flac","name":"Airplay","sampleformat":"44100:16:2"},"raw":"airplay:////shairport-sync?chunk_ms=20&codec=flac&name=Airplay&sampleformat=44100:16:2","scheme":"airplay"}
2023-12-16 19-46-55.824 [Info] (FlacEnc) Init - compression level: 2
2023-12-16 19-46-55.824 [Error] (PosixStream) Exception: end of file
2023-12-16 19-46-55.824 [Info] (FlacEnc) Init - compression level: 2
2023-12-16 19-46-55.825 [Info] (Watchdog) Starting watchdog, timeout: 7800s
2023-12-16 19-46-55.825 [Info] (FlacEnc) Init - compression level: 2
2023-12-16 19-46-55.828 [Error] (AirplayStream) Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor
2023-12-16 19-46-55.828 [Info] (ControlServer) Creating TCP acceptor for address: 0.0.0.0, port: 1705
2023-12-16 19-46-55.828 [Error] (ControlServer) error creating TCP acceptor: bind: Address already in use, code: system:98
2023-12-16 19-46-55.828 [Info] (ControlServer) Creating HTTP acceptor for address: 0.0.0.0, port: 1780
2023-12-16 19-46-55.828 [Error] (ControlServer) error creating HTTP acceptor: bind: Address already in use, code: system:98
2023-12-16 19-46-55.828 [Info] (StreamServer) Creating stream acceptor for address: 0.0.0.0, port: 1704
2023-12-16 19-46-55.828 [Error] (StreamServer) error creating TCP acceptor: bind: Address already in use, code: system:98
2023-12-16 19-46-55.828 [Info] (Snapserver) Number of threads: 4, hw threads: 4
2023-12-16 19-46-55.829 [Info] (librespot) librespot 0.4.2 UNKNOWN (Built on 2023-12-16, Build ID: a43KiNmS, Profile: release)
2023-12-16 19-46-55.845 [Info] (AirplayStream) (Airplay) fatal error: could not establish a service on port 5000 -- program terminating. Is another instance of Shairport Sync running on this device?
2023-12-16 19-46-55.845 [Error] (AirplayStream) It seems there is another Shairport Sync runnig on port 5000, switching to port 5001
2023-12-16 19-46-55.847 [Error] (ProcessStream) Error while reading from stderr: End of file
2023-12-16 19-46-55.848 [Error] (PosixStream) Exception: end of file
2023-12-16 19-46-55.878 [Warn] (librespot_core::apresolve) Ignoring blacklisted access point ap-gew4.spotify.com:4070
2023-12-16 19-46-55.878 [Warn] (librespot_core::apresolve) Ignoring blacklisted access point ap-gew4.spotify.com:443
2023-12-16 19-46-55.878 [Warn] (librespot_core::apresolve) Ignoring blacklisted access point ap-gew4.spotify.com:80
2023-12-16 19-46-55.879 [Warn] (librespot_core::apresolve) Ignoring blacklisted access point ap-gue1.spotify.com:443
2023-12-16 19-46-55.879 [Info] (librespot_core::session) Connecting to AP "ap-guc3.spotify.com:4070"
2023-12-16 19-46-55.952 [Error] (AirplayStream) Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor
2023-12-16 19-46-55.952 [Error] (AsioStream) Error during async wait: Operation canceled
2023-12-16 19-46-56.452 [Info] (AirplayStream) Metadata pipe opened: /tmp/shairmeta.113490.5001
2023-12-16 19-46-56.452 [Info] (AirplayStream) Waiting for metadata, retrying in 2500ms
2023-12-16 19-46-56.516 [Info] (librespot_core::session) Authenticated as "x" !
2023-12-16 19-46-56.517 [Info] (librespot_playback::mixer::softmixer) Mixing with softvol and volume control: Log(60.0)
2023-12-16 19-46-56.517 [Info] (librespot_playback::convert) Converting with ditherer: tpdf
2023-12-16 19-46-56.517 [Info] (librespot_playback::audio_backend::pipe) Using StdoutSink (pipe) with format: S16
2023-12-16 19-46-56.517 [Info] (librespot_core::session) Country: "DE"
2023-12-16 19-46-56.824 [Info] (Avahi) Service 'Snapcast' successfully established.
2023-12-16 19-46-58.953 [Info] (AirplayStream) Waiting for metadata, retrying in 2500ms
2023-12-16 19-47-01.453 [Info] (AirplayStream) Waiting for metadata, retrying in 2500ms
2023-12-16 19-47-03.953 [Info] (AirplayStream) Waiting for metadata, retrying in 2500ms
2023-12-16 19-47-06.453 [Info] (AirplayStream) Waiting for metadata, retrying in 2500ms
2023-12-16 19-47-06.659 [Info] (librespot_playback::player) Loading with Spotify URI spotify:track:5gLplbzXl21gdfvXi9UC0D
2023-12-16 19-47-08.773 [Info] (librespot_playback::player) (209186 ms) loaded
2023-12-16 19-47-08.773 [Info] (LibrespotStream) metadata:
2023-12-16 19-47-08.826 [Info] (PcmStream) State changed: Spotify, state: idle => playing
2023-12-16 19-47-08.826 [Info] (Server) onStateChanged (Spotify): playing
I know you've already edited this but if you have not already done so, you should change your Spotify password. The logging needs fixing to hide the password, it's not helpful as it is.
Sorry, I don't have any ideas regarding your actual problem.
Maybe you're listening to the wrong stream source on you Android device?
Please try with the latest version and provide debug logs.
2023-12-16 19-46-55.823 [Info] (PcmStream) PcmStream: default, sampleFormat: 48000:16:2
@Streammet something is triggering the wrong sample size, or your soundcard doesnt support it. You want 44100:16:2, not 48000:16:2