search

mikebrady / shairport-sync

AirPlay and AirPlay 2 audio player
Other
7.27k stars 573 forks source link

[Problem]: Large sync issues when running from systemctl, but not when run directly. #1841

Closed michaelshumshum closed 7 months ago

michaelshumshum commented 7 months ago

What happened?

Running shairport-sync -v --statistics straight does not show any issues. Only very infrequent stutters. When running as a systemctl service, constant stuttering where audio is essentially inaudible.

Relevant log output

Apr 09 01:28:42 theshumpc shairport-sync[4726]:          1.337034300 "rtsp.c:2902" Connection 1: AP2 PTP connection from ****** ("******") to self>
Apr 09 01:28:46 theshumpc shairport-sync[4726]: Failed to load cookie file from cookie: No such file or directory
Apr 09 01:28:46 theshumpc shairport-sync[4726]: Failed to load cookie file from cookie: No such file or directory
Apr 09 01:28:47 theshumpc shairport-sync[4726]:          4.853569600 "player.c:2835" Connection 1: Playback started at frame 1817367315 -- AirPlay 2 Buffered.
Apr 09 01:28:47 theshumpc shairport-sync[4726]:          0.081104300 "player.c:2881" Large positive (i.e. late) sync error of 2459 frames (0.055760 seconds), at frame: 1817370483.
Apr 09 01:28:47 theshumpc shairport-sync[4726]:          0.200737400 "audio_alsa.c:1754" alsa: underrun while writing 352 samples to alsa device.
Apr 09 01:28:47 theshumpc shairport-sync[4726]:          0.043147200 "player.c:2906" Large negative (i.e. early) sync error of -6682 frames (-0.151519 seconds), at frame: 1817381395.
Apr 09 01:28:47 theshumpc shairport-sync[4726]:          0.126271600 "player.c:2881" Large positive (i.e. late) sync error of 3568 frames (0.080907 seconds), at frame: 1817386675.
Apr 09 01:28:48 theshumpc shairport-sync[4726]:          0.280828000 "player.c:2906" Large negative (i.e. early) sync error of -7693 frames (-0.174444 seconds), at frame: 1817398643.
Apr 09 01:28:48 theshumpc shairport-sync[4726]:          0.210007400 "player.c:2881" Large positive (i.e. late) sync error of 3327 frames (0.075442 seconds), at frame: 1817408499.
Apr 09 01:28:48 theshumpc shairport-sync[4726]:          0.281648600 "player.c:2906" Large negative (i.e. early) sync error of -7482 frames (-0.169660 seconds), at frame: 1817420115.
Apr 09 01:28:48 theshumpc shairport-sync[4726]:          0.169587100 "player.c:2881" Large positive (i.e. late) sync error of 3343 frames (0.075805 seconds), at frame: 1817428563.
Apr 09 01:28:49 theshumpc shairport-sync[4726]:          0.236028400 "audio_alsa.c:1754" alsa: underrun while writing 352 samples to alsa device.
Apr 09 01:28:49 theshumpc shairport-sync[4726]:          0.033848300 "player.c:2906" Large negative (i.e. early) sync error of -7173 frames (-0.162653 seconds), at frame: 1817440531.
Apr 09 01:28:49 theshumpc shairport-sync[4726]:          0.128770800 "player.c:2881" Large positive (i.e. late) sync error of 2854 frames (0.064717 seconds), at frame: 1817446163.
Apr 09 01:28:49 theshumpc shairport-sync[4726]:          0.276989800 "player.c:2906" Large negative (i.e. early) sync error of -7520 frames (-0.170522 seconds), at frame: 1817457427.
Apr 09 01:28:49 theshumpc shairport-sync[4726]:          0.209666400 "player.c:2881" Large positive (i.e. late) sync error of 3709 frames (0.084104 seconds), at frame: 1817467283.
Apr 09 01:28:50 theshumpc shairport-sync[4726]:          0.284204400 "audio_alsa.c:1752" alsa: recovering from a previous underrun.
Apr 09 01:28:50 theshumpc shairport-sync[4726]:          0.023213100 "player.c:2906" Large negative (i.e. early) sync error of -6894 frames (-0.156327 seconds), at frame: 1817479603.
Apr 09 01:28:50 theshumpc shairport-sync[4726]:          0.138051000 "player.c:2881" Large positive (i.e. late) sync error of 3205 frames (0.072676 seconds), at frame: 1817487347.
Apr 09 01:28:50 theshumpc shairport-sync[4726]:          0.269661200 "player.c:2906" Large negative (i.e. early) sync error of -8274 frames (-0.187619 seconds), at frame: 1817498963.
Apr 09 01:28:50 theshumpc shairport-sync[4726]:          0.161036500 "player.c:2881" Large positive (i.e. late) sync error of 3001 frames (0.068050 seconds), at frame: 1817506355.
Apr 09 01:28:50 theshumpc shairport-sync[4726]:          0.273284300 "player.c:2906" Large negative (i.e. early) sync error of -8130 frames (-0.184354 seconds), at frame: 1817517971.
Apr 09 01:28:51 theshumpc shairport-sync[4726]:          0.153129700 "player.c:2881" Large positive (i.e. late) sync error of 2634 frames (0.059728 seconds), at frame: 1817525363.
Apr 09 01:28:51 theshumpc shairport-sync[4726]:          0.263556900 "player.c:2906" Large negative (i.e. early) sync error of -8410 frames (-0.190703 seconds), at frame: 1817536627.
Apr 09 01:28:51 theshumpc shairport-sync[4726]:          0.181464100 "player.c:2881" Large positive (i.e. late) sync error of 3841 frames (0.087098 seconds), at frame: 1817544371.
Apr 09 01:28:51 theshumpc shairport-sync[4726]:          0.277356800 "player.c:2906" Large negative (i.e. early) sync error of -8240 frames (-0.186848 seconds), at frame: 1817556691.
Apr 09 01:28:52 theshumpc shairport-sync[4726]:          0.201480000 "player.c:2881" Large positive (i.e. late) sync error of 3857 frames (0.087460 seconds), at frame: 1817565491.
Apr 09 01:28:52 theshumpc shairport-sync[4726]:          0.235992400 "audio_alsa.c:1754" alsa: underrun while writing 352 samples to alsa device.
Apr 09 01:28:52 theshumpc shairport-sync[4726]:          0.034139200 "player.c:2906" Large negative (i.e. early) sync error of -7191 frames (-0.163061 seconds), at frame: 1817577811.
Apr 09 01:28:52 theshumpc shairport-sync[4726]:          0.135535200 "player.c:2881" Large positive (i.e. late) sync error of 3207 frames (0.072721 seconds), at frame: 1817583443.
Apr 09 01:28:52 theshumpc shairport-sync[4726]:          0.271368500 "player.c:2906" Large negative (i.e. early) sync error of -7866 frames (-0.178367 seconds), at frame: 1817595059.
Apr 09 01:28:52 theshumpc shairport-sync[4726]:          0.162326300 "player.c:2881" Large positive (i.e. late) sync error of 3013 frames (0.068322 seconds), at frame: 1817602803.
Apr 09 01:28:53 theshumpc shairport-sync[4726]:          0.283225100 "player.c:2906" Large negative (i.e. early) sync error of -7577 frames (-0.171814 seconds), at frame: 1817614419.
Apr 09 01:28:53 theshumpc shairport-sync[4726]:          0.162286700 "player.c:2881" Large positive (i.e. late) sync error of 3025 frames (0.068594 seconds), at frame: 1817622515.
Apr 09 01:28:53 theshumpc shairport-sync[4726]:          0.283273800 "player.c:2906" Large negative (i.e. early) sync error of -7639 frames (-0.173220 seconds), at frame: 1817634131.
Apr 09 01:28:53 theshumpc shairport-sync[4726]:          0.202240200 "player.c:2881" Large positive (i.e. late) sync error of 3357 frames (0.076122 seconds), at frame: 1817643987.
Apr 09 01:28:54 theshumpc shairport-sync[4726]:          0.224390200 "audio_alsa.c:1754" alsa: underrun while writing 352 samples to alsa device.
Apr 09 01:28:54 theshumpc shairport-sync[4726]:          0.044723500 "player.c:2906" Large negative (i.e. early) sync error of -7318 frames (-0.165941 seconds), at frame: 1817655955.
Apr 09 01:28:54 theshumpc shairport-sync[4726]:          0.129116000 "player.c:2881" Large positive (i.e. late) sync error of 2871 frames (0.065102 seconds), at frame: 1817661587.
Apr 09 01:28:54 theshumpc shairport-sync[4726]:          0.277347900 "player.c:2906" Large negative (i.e. early) sync error of -7646 frames (-0.173379 seconds), at frame: 1817672851.
Apr 09 01:28:54 theshumpc shairport-sync[4726]:          0.202530400 "player.c:2881" Large positive (i.e. late) sync error of 3380 frames (0.076644 seconds), at frame: 1817682707.
Apr 09 01:28:54 theshumpc shairport-sync[4726]:          0.223094500 "audio_alsa.c:1754" alsa: underrun while writing 352 samples to alsa device.
Apr 09 01:28:54 theshumpc shairport-sync[4726]:          0.045613200 "player.c:2906" Large negative (i.e. early) sync error of -7321 frames (-0.166009 seconds), at frame: 1817694675.
...

(practically no sync error when not running as service)

System Information.

Personal PC: I5 10400F - 32 GB RAM ... PC spec is definitely not the problem.

Running on Ubuntu 22.04.2 on WSL2. Using Hyper-V Virtual Switch that bridges to external network. Uses a PulseAudio server running on Windows, which Ubuntu routes to.

Configuration Information.

From "uname -a":
 Linux theshumpc 5.15.146.1-microsoft-standard-WSL2 #1 SMP Thu Jan 11 04:09:03 UTC 2024 x86_64 x86_64 x86_64 GNU/Linux

From /etc/os-release:
 Ubuntu 22.04.4 LTS

Shairport Sync Version String:
 4.3.2-2-g165431a8-AirPlay2-smi10-OpenSSL-Avahi-ALSA-pa-soxr-sysconfdir:/etc

Command Line:
 shairport-sync --displayConfig

Configuration File:
 /etc/shairport-sync.conf

Configuration File Settings:
 pw :
 {
 };

PulseAudio or PipeWire installed?

How did you install Shairport Sync?

Built from source

Check previous issues

mikebrady commented 7 months ago

Thanks for the post.

Since you have not configured it otherwise, Shairport Sync is directing the output to the ALSA default device. The default device will be set up to direct audio into the sound server. The thing is, this is done for the logged-in user only, so it won't be set up for the user that Shairport Sync runs under when it's a service -- that user is called shairport-sync. The default might not be set at all, or it might be set to a hardware device that may be unsuitable (e.g. only accepts audio at 48,000 frames per second) or already in use (see below).

You can try to direct the output to the ALSA hardware device. Do $shairport-sync -h to get an approximate list or use sps-alsa-explore to get an accurate list. A potential problem here, of course, is that the sound server may already have taken their device over.

There's more at PulseAudioAndPipeWire.md.

michaelshumshum commented 7 months ago

Thanks fo the reply.

When using aplay -l to display the audio devices, none are detected. When using your sps-alsa-explore, it states that the /dev/snd/ directory cannot be found. I am not surprised that there are no audio devices detected since this is in a WSL environment.

I have tried changing the audio backend to PA and have also tried changing the ALSA output device to PA. I have rebuilt the shairport-sync again using different configuration and sometimes it doesn't even work in the commandline when rebuilding.

michaelshumshum commented 7 months ago

I solved it!!

Completely wasn't related to audio device issues. In the config file, I set resync_threshold_in_seconds = 0, which disabled resynchronization. I was tinkering with setting it higher and lower and saw that setting it higher decreased sync errors. Disabling it completely removed all issues.

That was kind of unintuitive in my opinion, where resyncing caused even more sync issues.

mikebrady commented 7 months ago

Good stuff. I don't have a machine capable of running the WSL environment, I'm afraid, but from your results, it seems as if the audio service is providing either very coarse synchronisation information or no information at all to Shairport Sync when it's running as a service.

What I don't understand, is why it should be different when Shairport Sync is invoked from the command line.