Playback starts only after ~160 seconds

[s256]

Hi, I stumbled across your project as I have a very similar setup. Installation was straight forward, as was the configuration. Now that I see the Airplay2 device on my iPhone, the playback wont start right away but with a delay of ~120-180 seconds. First I thought it doesn't start at all, but after 2 minutes there was music.

Attached are some logs:

2024-05-12 15:07:05,789 WARN received SIGTERM indicating exit request
2024-05-12 15:07:05,816 INFO waiting for nqptp, dbus, avahidaemon, shairport to die
2024-05-12 15:07:06,542 INFO stopped: shairport (exit status 0)
2024-05-12 15:07:06,607 INFO stopped: avahidaemon (exit status 0)
2024-05-12 15:07:06,607 INFO reaped unknown pid 65 (exit status 0)
2024-05-12 15:07:07,612 WARN stopped: dbus (terminated by SIGTERM)
2024-05-12 15:07:08,184 INFO stopped: nqptp (exit status 0)
2024-05-12 15:07:08,184 INFO reaped unknown pid 1781 (exit status 0)
/usr/lib/python3/dist-packages/supervisor/options.py:474: UserWarning: Supervisord is running as root and it is searching for its configuration file in default locations (including its current working directory); you probably want to specify a "-c" argument specifying an absolute path to a configuration file for improved security.
  self.warnings.warn(
2024-05-12 15:07:10,968 CRIT Supervisor is running as root.  Privileges were not dropped because no user is specified in the config file.  If you intend to run as root, you can set user=root in the config file to avoid this message.
2024-05-12 15:07:10,969 INFO Included extra file "/etc/supervisor/conf.d/supervisord.conf" during parsing
2024-05-12 15:07:10,999 INFO RPC interface 'supervisor' initialized
2024-05-12 15:07:11,000 CRIT Server 'unix_http_server' running without any HTTP authentication checking
2024-05-12 15:07:11,001 INFO supervisord started with pid 1
2024-05-12 15:07:12,006 INFO spawned: 'apply-config' with pid 7
2024-05-12 15:07:12,013 INFO spawned: 'nqptp' with pid 8
2024-05-12 15:07:12,021 INFO spawned: 'dbus' with pid 9
2024-05-12 15:07:12,036 INFO spawned: 'avahidaemon' with pid 10
2024-05-12 15:07:12,052 INFO spawned: 'shairport' with pid 11
2024-05-12 15:07:12,057 INFO success: apply-config entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
2024-05-12 15:07:13,240 INFO success: nqptp entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-05-12 15:07:13,240 INFO success: dbus entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-05-12 15:07:13,240 INFO success: avahidaemon entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-05-12 15:07:13,240 INFO success: shairport entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-05-12 15:07:13,240 INFO exited: apply-config (exit status 0; expected)

I restarted the plugin at 15:07. Playback started around 15:11, while connecting airplay and start playback was around 15:09.

Not sure if there is a debug mode, at least I didn't find it.

I'm using a rpi4 with the official HassOS, so nothing special.

 Core 2024.5.3
Supervisor 2024.05.1
Operating System 12.3
Frontend 20240501.1

Maybe you have had similar situations or any idea on where to look.

[s256]

Target picture for me is to use MusicAssistant , and use a group of airplay devices via shortcut. Irrelevant for this case I assume, but it might help troubleshooting, as MusicAssistant throws another error when trying to connect/play on home-assistant using the airplay plugin:

2024-05-12 15:37:13.269 INFO (MainThread) [music_assistant.providers.airplay] Unknown DACP request for DCA63215972C@HassLiving._raop._tcp.local.: /ctrl-int/1/getproperty?properties=dmcp.volume

Same delay in playback start here as well.

[JohannVR]

Hey! I've experienced the same weird behavior on my Pi 4, have you tested the Debian version? The Alpine image also takes a while to start on my Pi 4, that's why I made the Debian version, you should check and see if that one works better for you.  As for the delay, I've read that it's normal for Airplay to do that, so that it can buffer a little. You can try to set the Playback offset in the configuration to a negative value, but that might lead to instability.

Thanks for sending me the error! I only used the Shairport Sync implementation made by mikebrady, so I'm not sure how to fix that, you could check his Repo to see if that leads to any possible fixes though. Maybe MusicAssistant just doesn't play nice with anything that isn't real airplay :/

[s256]

I'm using the Debian version. Did you manage to fix it in your setup? I get that it takes a couple of seconds but 2-3 minutes to buffer is excessive.

[JohannVR]

Ohh okay, I didn't think the audio delay was that bad, mine is around 1-2 seconds. The only problem I had with the Alpine version is that the initial startup took around 8 minutes. It works pretty well in my setup, using the Debian image and leaving the rest as the default config.  I'm not really sure what your issue could be caused by. If you don't mind using airplay 1, you could give this other Shairplay-addon for HA a try: https://github.com/v3rm0n/addon-shairport-sync

[s256]

I think I might have described it badly. The audio is in sync, once it started. The container start is also not what I mean. But when I select the device in iOS , it takes 2-3 minutes until the music starts. But then it is in sync.

[JohannVR]

Hmm, that is really weird, I'm not sure what to do about that. My only advice would be to check the Shairport Sync Repo :/ Sorry