snapcast icon indicating copy to clipboard operation
snapcast copied to clipboard

Can't get Airplay to work

Open axelcypher opened this issue 2 years ago • 5 comments

Describe the bug Airplay isn't working for me. I'm trying to stream my Windows Audio to snapcast (running on docker) via TuneBlade, which supports shairport-sync. If i try to stream it to my AVR it works. Spotify also works fine.

I've tried to install shairport-sync from the repo and also build it by myself, neither worked.

Steps to Reproduce

  1. build shairport-sync with ./configure --sysconfdir=/etc --with-alsa --with-soxr --with-avahi --with-ssl=openssl --with-metadata --with-stdout
  2. added source = airplay:///shairport-sync?name=Airplay&devicename=Audiovisualizer to my config
  3. restarted the docker container

Environment details

  • OS: docker-image
  • Snapcast version 0.24.0
  • Installed Dockerhub. I think the base image was strm/snapcast, which i modified with librespot

Attach logfile if applicable Generate logs with snapclient --logfilter debug or snapserver --logging.filter debug if possible and paste them in the following codeblock

2022-06-23 01-45-13.457 [Info] (Snapserver) Version 0.24.0, revision 7eff45fd
2022-06-23 01-45-13.457 [Info] (Snapserver) Adding source: airplay:///shairport-sync?name=Airplay&devicename=Audiovisualizer
2022-06-23 01-45-13.457 [Info] (Snapserver) Adding source: spotify:///librespot?name=Spotify&username=xxx&password=xxx&devicename=Audiovisualizer&bitrate=160
2022-06-23 01-45-13.457 [Notice] (init) Settings file: "/root/.config/snapserver/server.json"
2022-06-23 01-45-13.457 [Error] (Avahi) Failed to create client: Daemon not running
2022-06-23 01-45-13.457 [Info] (PcmStream) PcmStream: Airplay, sampleFormat: 44100:16:2
2022-06-23 01-45-13.457 [Info] (PcmStream) Stream: Airplay, metadata={
2022-06-23 01-45-13.457 [Info] (PcmStream)     "STREAM": "Airplay"
2022-06-23 01-45-13.457 [Info] (PcmStream) }
2022-06-23 01-45-13.457 [Info] (Server) onMetaChanged (Airplay)
2022-06-23 01-45-13.458 [Info] (Server) Stream: {"fragment":"","host":"","path":"/shairport-sync","query":{"chunk_ms":"20","codec":"flac","devicename":"Audiovisualizer","name":"Airplay","sampleformat":"44100:16:2"},"raw":"airplay:////shairport-sync?chunk_ms=20&codec=flac&devicename=Audiovisualizer&name=Airplay&sampleformat=44100:16:2","scheme":"airplay"}
2022-06-23 01-45-13.458 [Info] (PcmStream) PcmStream: Spotify, sampleFormat: 44100:16:2
2022-06-23 01-45-13.458 [Info] (PcmStream) Stream: Spotify, metadata={
2022-06-23 01-45-13.458 [Info] (PcmStream)     "STREAM": "Spotify"
2022-06-23 01-45-13.458 [Info] (PcmStream) }
2022-06-23 01-45-13.458 [Info] (Server) onMetaChanged (Spotify)
2022-06-23 01-45-13.458 [Info] (Server) Stream: {"fragment":"","host":"","path":"/librespot","query":{"bitrate":"160","chunk_ms":"20","codec":"flac","devicename":"Audiovisualizer","name":"Spotify","password":"xxx","sampleformat":"44100:16:2","username":"xxx"},"raw":"spotify:////librespot?bitrate=160&chunk_ms=20&codec=flac&devicename=Audiovisualizer&name=Spotify&password=xxx&sampleformat=44100:16:2&username=xxx","scheme":"spotify"}
2022-06-23 01-45-13.459 [Error] (PosixStream) Connect exception: execve failed: Permission denied
2022-06-23 01-45-13.467 [Info] (Watchdog) Starting watchdog, timeout: 7800s
2022-06-23 01-45-13.468 [Info] (ControlServer) Creating TCP acceptor for address: 0.0.0.0, port: 1705
2022-06-23 01-45-13.468 [Info] (ControlServer) Creating HTTP acceptor for address: 0.0.0.0, port: 1780
2022-06-23 01-45-13.468 [Info] (StreamServer) Creating stream acceptor for address: 0.0.0.0, port: 1704
2022-06-23 01-45-13.468 [Info] (Snapserver) Number of threads: 4, hw threads: 4
2022-06-23 01-45-13.473 [Info] (LibrespotStream) (Spotify) [2022-06-23T01:45:13Z INFO  librespot] librespot 0.3.1 UNKNOWN (Built on 2022-01-14, Build ID: 4PvUVFyy, Profile: release)
2022-06-23 01-45-13.473 [Info] (LibrespotStream) (Spotify) [2022-06-23T01:45:13Z DEBUG librespot_playback::mixer::mappings] Volume control is now Log(60.0)
2022-06-23 01-45-13.475 [Info] (LibrespotStream) (Spotify) [2022-06-23T01:45:13Z DEBUG librespot_discovery::server] Zeroconf server listening on 0.0.0.0:40603
2022-06-23 01-45-13.546 [Info] (LibrespotStream) (Spotify) [2022-06-23T01:45:13Z INFO  librespot_core::session] Connecting to AP "ap-gew1.spotify.com:4070"
2022-06-23 01-45-13.559 [Error] (PosixStream) Connect exception: execve failed: Permission denied
2022-06-23 01-45-13.660 [Error] (PosixStream) Connect exception: execve failed: Permission denied

axelcypher avatar Jun 23 '22 01:06 axelcypher

This looks a lot like a Docker permission problem rather than something wrong with snapcast.

kingosticks avatar Jun 23 '22 07:06 kingosticks

Alright. I created my own image with librespot and shairport-sync. Now i'm getting this error:

2022-06-23 16-42-58.166 [Error] (ProcessStream) Error while reading from stderr: End of file
2022-06-23 16-42-58.282 [Error] (AirplayStream) Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor
2022-06-23 16-42-58.282 [Error] (AsioStream) Error during async wait: Operation canceled
2022-06-23 16-42-58.286 [Info] (AirplayStream) (Airplay) warning: couldn't create avahi client: Daemon not running!
2022-06-23 16-42-58.286 [Info] (AirplayStream) (Airplay) fatal error: Could not establish mDNS advertisement!

But it seems like the avahi daemon is running

root         9  0.0  0.0   7992  2744 ?        S    16:42   0:00 avahi-daemon: running [snapcastfx.local]

axelcypher avatar Jun 23 '22 16:06 axelcypher

Some debugging hints:

  1. try to start the airplay binary manually (within your container) and check if it terminates with the same error
  2. use a non-virtualized bare metal environment

badaix avatar Jun 24 '22 08:06 badaix

Some debugging hints:

  1. try to start the airplay binary manually (within your container) and check if it terminates with the same error
  2. use a non-virtualized bare metal environment

Thanks so far. I've tried to start it manually, with the same result.

root@snapcastfx:/app# shairport-sync -v -u
         0.000366025 "shairport.c:1729" Started!
         0.000061635 "shairport.c:1756" software version: "3.3.9-OpenSSL-Avahi-ALSA-pa-stdout-soxr-metadata-sysconfdir:/etc"
         0.000004388 "shairport.c:1762" log verbosity is 1.
         0.000021350 "audio_alsa.c:1015" alsa: alsa_maximum_stall_time of 0.200000 sec.
         0.000009177 "audio_alsa.c:1164" *warning: Invalid output rate "44100". It should be "auto", 44100, 88200, 176400 or 352800. It remains set to "auto". Note: numbers should not be placed in quotes.
         0.000006532 "audio_alsa.c:1312" alsa: disable_standby_mode is "never".
         0.000001643 "audio_alsa.c:1314" alsa: disable_standby_mode_silence_threshold is 0.040000 seconds.
         0.000033142 "audio_alsa.c:1316" alsa: disable_standby_mode_silence_scan_interval is 0.004000 seconds.
         0.000008717 "audio_alsa.c:1355" alsa: output device name is "default".
         0.000078286 "shairport.c:1810" disable resend requests is off.
         0.000021440 "shairport.c:1814" diagnostic_drop_packet_fraction is 0.000000. A value of 0.0 means no packets will be dropped deliberately.
         0.000004488 "shairport.c:1815" statistics_requester status is 0.
         0.000001503 "shairport.c:1820" rtsp listening port is 5000.
         0.000001463 "shairport.c:1821" udp base port is 6001.
         0.000001302 "shairport.c:1822" udp port range is 10.
         0.000001253 "shairport.c:1823" player name is "Audiovisualizer".
         0.000001302 "shairport.c:1824" backend is "alsa".
         0.000019116 "shairport.c:1825" run_this_before_play_begins action is "(null)".
         0.000022312 "shairport.c:1826" run_this_after_play_ends action is "(null)".
         0.000021690 "shairport.c:1827" wait-cmd status is 0.
         0.000004248 "shairport.c:1828" run_this_before_play_begins may return output is 0.
         0.000001573 "shairport.c:1829" run_this_if_an_unfixable_error_is_detected action is "(null)".
         0.000001363 "shairport.c:1830" run_this_before_entering_active_state action is  "(null)".
         0.000001382 "shairport.c:1831" run_this_after_exiting_active_state action is  "(null)".
         0.000001293 "shairport.c:1832" active_state_timeout is  10.000000 seconds.
         0.000002344 "shairport.c:1833" mdns backend "avahi".
         0.000001352 "shairport.c:1837" interpolation setting is "auto".
         0.000002345 "shairport.c:1838" interpolation soxr_delay_threshold is 30.
         0.000002605 "shairport.c:1839" resync time is 0.050000 seconds.
         0.000018584 "shairport.c:1840" allow a session to be interrupted: 0.
         0.000021701 "shairport.c:1841" busy timeout time is 120.
         0.000004659 "shairport.c:1842" drift tolerance is 0.001995 seconds.
         0.000001613 "shairport.c:1843" password is "(null)".
         0.000001312 "shairport.c:1844" ignore_volume_control is 1.
         0.000001423 "shairport.c:1848" volume_max_db is not set
         0.000001312 "shairport.c:1850" volume range in dB (zero means use the range specified by the mixer): 0.
         0.000001493 "shairport.c:1854" volume_range_combined_hardware_priority (1 means hardware mixer attenuation is used first) is 0.
         0.000001603 "shairport.c:1856" playback_mode is 0 (0-stereo, 1-mono, 1-reverse_stereo, 2-both_left, 3-both_right).
         0.000001523 "shairport.c:1857" disable_synchronization is 0.
         0.000001212 "shairport.c:1858" use_mmap_if_available is 1.
         0.000001233 "shairport.c:1860" output_format automatic selection is disabled.
         0.000001292 "shairport.c:1862" output_format is "S16".
         0.000001623 "shairport.c:1864" output_rate automatic selection is enabled.
         0.000001633 "shairport.c:1868" audio backend desired buffer length is 0.200000 seconds.
         0.000001453 "shairport.c:1870" audio_backend_buffer_interpolation_threshold_in_seconds is 0.120000 seconds.
         0.000001593 "shairport.c:1871" audio backend latency offset is 0.000000 seconds.
         0.000001472 "shairport.c:1873" audio backend silence lead-in time is "auto".
         0.000001383 "shairport.c:1877" zeroconf regtype is "_raop._tcp".
         0.000001272 "shairport.c:1878" decoders_supported field is 1.
         0.000001213 "shairport.c:1879" use_apple_decoder is 0.
         0.000001212 "shairport.c:1880" alsa_use_hardware_mute is 0.
         0.000001212 "shairport.c:1884" no special mdns service interface was requested.
         0.000010961 "shairport.c:1888" configuration file name "/etc/shairport-sync.conf" resolves to "/app/shairport-sync.conf".
         0.000020889 "shairport.c:1894" metadata enabled is 1.
         0.000003917 "shairport.c:1895" metadata pipename is "/tmp/shairport-sync-metadata".
         0.000020218 "shairport.c:1897" metadata socket address is "(null)" port 0.
         0.000021831 "shairport.c:1898" metadata socket packet size is "500".
         0.000004488 "shairport.c:1899" get-coverart is 1.
         0.000001543 "shairport.c:1917" loudness is 0.
         0.000001353 "shairport.c:1918" loudness reference level is -20.000000
         0.000069910 "rtsp.c:1665" metadata pipe name is "/tmp/shairport-sync-metadata".
         0.000928516 "mdns_avahi.c:332" *warning: couldn't create avahi client: Daemon not running!
         0.000031399 "mdns.c:103" *fatal error: Could not establish mDNS advertisement!
         0.000006752 "shairport.c:1424" emergency exit
root@snapcastfx:/app# service avahi-daemon status
Avahi mDNS/DNS-SD Daemon is running

Do I need a specifit avahi-daemon version? Currently I'm running v0.7

Unfortunally, right now I'm not able to try it on bare metal, as my testing machine isn't working.

For some context what i'm trying to accomplish:

I want to run Snapserver alongside with LedFx. Right now it's running in 2 different container, one for LedFx and one for Snapserver configured with librespot. But i also want to be able to visualize audio from movies or games.
Currently i'm running everything in a Docker enviroment on a Intel NUC, but in the future i want to run all of this on a PI Zero W directly attached to my AVR. But for now, I'm stuck with what i have, and that is Docker and a couple of ESP's with a Pi 3 that runs my abilight and outputs the audio to my AVR.

EDIT:

when i manually start the avahi-daemon, i get a warning that another mdns service is running. After a quick search i've found out that LedFX is using zeroconf. Could that be it?

EDIT 2:

nope, didn't solve the problem to build an image without LedFx. But the avahi-error that another mdns service is running is gone. So back to the beginning.

axelcypher avatar Jun 24 '22 12:06 axelcypher

Got it. dbus was not running. New try: Now i get this error:

2022-06-24 14-54-02.836 [Info] (AirplayStream) (Airplay) warning: Audio receiver -- Unknown RTP packet of type 0x52 length 32.

I've edited my avahi config. Might be that. I'm digging deeper, will reporty my results asap. Just in case someone else runs into these problems

EDIT:

Nope, changing the config's of avahi and shairport back to default doesn't changes anything....

axelcypher avatar Jun 24 '22 14:06 axelcypher

I have the same exact problem on bare metal, running on a Raspberry Pi 3B+. Anyone come up with a solution?

mattcassini avatar Jan 05 '23 20:01 mattcassini

This is an Airplay issue, not Snapcast:

2022-06-24 14-54-02.836 [Info] (AirplayStream) (Airplay) warning: Audio receiver -- Unknown RTP packet of type 0x52 length 32.

badaix avatar Jul 14 '23 09:07 badaix