search

owntone / owntone-server

Linux/FreeBSD DAAP (iTunes) and MPD audio server with support for AirPlay 1 and 2 speakers (multiroom), Apple Remote (and compatibles), Chromecast, Spotify and internet radio.
https://owntone.github.io/owntone-server
GNU General Public License v2.0
2.09k stars 235 forks source link

Issues broadcasting pipe to HomePod #1183

Closed paperparrot closed 3 years ago

paperparrot commented 3 years ago

I am trying to use a Raspberry Pi to play audio from a turntable to my HomePods. I am using a raspberry pi on raspian, and AudioInjector's stereo card to get audio from the turntable. I'd like to use record to write to a pipe, then have forked-daapd send it to my HomePods but I am having some issue.

Currently I am able to record audio to a wav just fine, and play that file on a HomePod. However if I try to set up a pipe on a fifo file, I get some errors, and forked-daapd is unable to connect to any of my HomePods. Here is the command I am using to set up the pipe: sudo arecord -f S16_LE -r 44100 -c 2 -B 150000 -t wav > /srv/music/pipe

I am running forked-daapd as root (it is having issues accessing the logs and the playlist db if not), and I have changed the conf file to have audio at 16bit 44.1kHz (cd).

On the arecord side I get these errors: overrun!!! (at least 27396.841 ms long) from the forked-daapd log: [2021-01-31 19:17:42] [ LOG] player: Output delay detected (behind=198, max=150), resetting all outputs' '[2021-01-31 19:17:45] [ LOG] player: Source is not providing sufficient data, temporarily suspending playback (deficit=264608/264600 bytes)' '[2021-01-31 19:17:58] [ LOG] cache: Beginning DAAP cache update' '[2021-01-31 19:17:58] [ LOG] cache: DAAP cache updated' [2021-01-31 19:18:23] [ LOG] mdns: Avahi Resolver failure: service 'Kitchen HomePod' type '_airplay._tcp' proto 0: Timeout reached [2021-01-31 19:19:33] [ LOG] cache: Beginning DAAP cache update [2021-01-31 19:19:34] [ LOG] cache: DAAP cache updated [2021-01-31 19:21:14] [ LOG] player: The AirPlay 1 device 'Kitchen' failed to activate [2021-01-31 19:22:20] [ LOG] player: The AirPlay 1 device 'Kitchen' failed to activate

Any insights would help! I had to disable ipv6 for airplay to work, and if I try to force airplay 2 by setting "raop_disable = true" I get an error saying "config: [root:316] no such option 'raop_disable'"

Any help and insights would help, thanks!

Porco-Rosso commented 3 years ago

Hi @paperparrot perhaps you are not running the latest version of forked-daapd? config: [root:316] no such option 'raop_disable' sounds like you might not be. Did you build from master, or install from an apt deb package? Not sure this has to do with the PIPE problem though.

ejurgensen commented 3 years ago

What RPi is this? From the log it looks like what is happening is that producing the Airplay packets is delaying forked-daapd so much that it resets, and while it does this arecord overruns and stops, and thus forked-daapd ends up stopping too.

The arecord warning doesn't have a timestamp, my theory would be confirmed if its timestamp was between 19:17:42 and 19:17:45.

ejurgensen commented 3 years ago

I just gave it try myself, but I notice arecord does not stop writing when there is an overrun. So that is good, but it also means that my theory was wrong. I can't explain why forked-daapd is saying that the source is not providing enough data, there should be plenty. I will test a bit more and see if I can reproduce somehow.

paperparrot commented 3 years ago

Thanks for the response! I am using a Raspberry Pi 3B (rev 1.2) on Linux raspberry 5.10.11-v7+. I built forked-daapd from source from cloning the guy, -v returns 27.2 I don’t think the airplay 1 is what’s causing the issue, but just calling out something else I had an issue with in case it ends up being helpful.

ejurgensen commented 3 years ago

Ok, a RPi 3B should have plenty of horsepower for this, so that's not the cause then. I looked into it some more, and now it looks to me that there are two different issues at play, and I am not sure how they are connected. One is too little data in the pipe for forked-daapd, the other is the Airplay packet issue I mentioned. A few more questions for you:

  1. When the issue occurs, do you always see the "Output delay.." message followed by the "Source is not providing..." message? Are they always a few seconds apart?
  2. Can you try running this command bundle and share the output: (if arecord only works as root then switch to root - don't use sudo) date; timeout 20s arecord -f S16_LE -r 44100 -c 2 -t wav test.wav ; date; ls -l test.wav; ffprobe -hide_banner test.wav

On my machine I notice that arecord produces a file that does in fact not contain 20 seconds, which is odd. It is like arecord writes about 3-4% slower than 44100. Will google around for an explanation for that.

ejurgensen commented 3 years ago

You can also test with this (avoid any writing to the disk, ruling out that factor): date; arecord -f S16_LE -r 44100 -c 2 -t wav -d 60 > /dev/null; date It should complete after exactly 60 seconds, but on my system it runs for 63 seconds.

paperparrot commented 3 years ago

From the first one: Mon 01 Feb 2021 01:53:10 PM PST XDG_RUNTIME_DIR (/run/user/1000) is not owned by us (uid 0), but by uid 1000! (This could e g happen if you try to connect to a non-root PulseAudio as a root user, over the native protocol. Don't do that.) Recording WAVE 'test.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo Aborted by signal Terminated... Mon 01 Feb 2021 01:53:31 PM PST -rw-r--r-- 1 root root 3528364 Feb 1 13:53 test.wav Input #0, wav, from 'test.wav': Duration: 00:00:20.00, bitrate: 1411 kb/s Stream #0:0: Audio: pcm_s16le ([1][0][0][0] / 0x0001), 44100 Hz, 2 channels, s16, 1411 kb/s

From the 2nd one Mon 01 Feb 2021 01:55:05 PM PST XDG_RUNTIME_DIR (/run/user/1000) is not owned by us (uid 0), but by uid 1000! (This could e g happen if you try to connect to a non-root PulseAudio as a root user, over the native protocol. Don't do that.) Recording WAVE 'stdin' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo Mon 01 Feb 2021 01:56:05 PM PST

Somehow the timings match on my end?

ejurgensen commented 3 years ago

Yes, looks like the audio is being written perfectly. Now some more questions/suggestions:

  1. Does the error occur right away or after a while?
  2. Does any error occur start this pipe playback with all speakers unselected?
  3. Edit src/input.c and uncomment line 53 (DEBUG_INPUT), rebuild, set the log level to debug (in /etc/forked-daapd.conf), run and try to get some logging of when the error happens. Don’t cut and paste lengthy log outtakes here on github. Instead, attach the log file.
paperparrot commented 3 years ago
  1. error occurs right away
  2. No errors whatsoever with all speakers unselected (and starts back up immediately as soon as any homepods are selected)
  3. File attached! forked-daapd.log
ejurgensen commented 3 years ago

That's a very weird log. forked-daapd is starting and stopping many times, and it somewhat looks like you have two instances of forked-daapd running at once? There is also no debug level logging of the Airplay session being set up, nor of the pipe reading starting. Based on that log I cannot help you.

paperparrot commented 3 years ago

Let me try to get a more helpful log. The starting and stopping was because i changed the conf file to have debug logging.

ejurgensen commented 3 years ago

Closing, no feedback