mikebrady / shairport-sync

AirPlay and AirPlay 2 audio player
Other
7.2k stars 571 forks source link

AirPlay through VLANs #1192

Closed DenisKevljanin closed 3 years ago

DenisKevljanin commented 3 years ago

I am really close to giving up on this, because I have a strange behavior with shairport-sync. Currently I have 4 VLANs at home with Unifi gear (UDM Pro/APs):

My situation is, that I can see all mDNS announcements on DNS-SD or with avahi-browse in any VLAN and in the logs of the multicast-relay. This is the expected and wanted behavior. All my devices in the IoT network announce _raop_.tcp and I can read it in my internal network. Now to the things, that are odd. I can connect to any shairport-sync instance and play music without getting any error on the client or log messages in any of my services/devices, but there is no sound output. It gets even stranger considering I can play music and cast video just fine to my Apple TV, but that might be because it uses AirPlay 2 instead of a RAOP/AirTunes. My Apple TV can cast to shairport also without a problem and I can play music from Spotify to a Spotify connect client running on the same Pi from my phone. AirPrint works also just fine. However when I connect to the shairport instance and disconnect, my connection doesn't seem to be closed. I get an error that the device is already in use when I want to reconnect. It seems it does not receive the information of my phone disconnecting.

I was 100% sure that this is a firewall issue, because the rules I have in place are:

To make sure, that one of the rules is blocking me streaming to the shairport instance I shutdown the firewall and allowed all traffic between any network. To my surprise I still do not have any output when streaming from my phone. This brings me here.

Setup Information:

Appreciate any help!

mikebrady commented 3 years ago

Thanks for the post. It's not clear, but did you ever get audio out of a Shairport Sync instance? (If not, the problem might have nothing to do with VLANS, but instead be something more mundane.)

It might be worth turning on the first level of verbosity (in the configuration file) and also turn on statistics to see if Shairport Sync seems to be outputting audio.

Staying with network matters, the audio and control signals are all via UDP, not TCP, so it's important to ensure they are getting through. Another thing is that some users have reported issues with Unifi gear, though it seemed to be more related to mDNS than anything else, so may not be relevant.

DenisKevljanin commented 3 years ago

I actually did before I segmented the network, but also do now. Apple TV to Shairport in the same VLAN works just fine.

I will check statistics later and report back.

I have been running into some issues with mDNS on the UDM Pro, but installed the multicast-relay container and didn't have trouble besides shairport since. Means AirPrint and HomeKit as well as AirPlay to the Apple TV work flawlessly. As mentioned I have allowed related/established traffic for any protocol and they are getting through.

DenisKevljanin commented 3 years ago

Okay so I have checked the logs once again and it looks like shairport receives everything it needs, but has a syncing problem. Especially this message is only given when streaming across VLANs: May 17 13:52:35 raspberrypi shairport-sync[9118]: Sync packet received before we got a timing packet back.

May 17 13:51:56 raspberrypi shairport-sync[9118]: New RTSP connection from 192.168.0.167:63530 to self at 192.168.20.114:5000 on conversation thread 2.
May 17 13:52:33 raspberrypi shairport-sync[9118]: RTSP thread 2 received an RTSP Packet of type "ANNOUNCE":
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "Content-Length", content: "652"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "Content-Type", content: "application/sdp"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "CSeq", content: "4"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "DACP-ID", content: "506659DE0573F4FA"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "Active-Remote", content: "3361043355"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "User-Agent", content: "AirPlay/540.31"
May 17 13:52:33 raspberrypi shairport-sync[9118]: Connection 2: ANNOUNCE
May 17 13:52:33 raspberrypi shairport-sync[9118]: Play connection from user agent "AirPlay/540.31" on RTSP conversation thread 2.
May 17 13:52:33 raspberrypi shairport-sync[9118]: AirPlay version 540 detected.
May 17 13:52:33 raspberrypi shairport-sync[9118]: RTSP thread 2: RTSP Response:
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "CSeq", content: "4"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "Server", content: "AirTunes/105.1"
May 17 13:52:33 raspberrypi shairport-sync[9118]: RTSP thread 2 received an RTSP Packet of type "SETUP":
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "Transport", content: "RTP/AVP/UDP;unicast;mode=record;timing_port=56438;control_port=64145"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "CSeq", content: "5"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "DACP-ID", content: "506659DE0573F4FA"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "Active-Remote", content: "3361043355"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "User-Agent", content: "AirPlay/540.31"
May 17 13:52:33 raspberrypi shairport-sync[9118]: Connection 2: SETUP -- Active-Remote string seen: "3361043355".
May 17 13:52:33 raspberrypi shairport-sync[9118]: Connection 2: SETUP -- DACP-ID string seen: "506659DE0573F4FA".
May 17 13:52:33 raspberrypi shairport-sync[9118]: Connection 2: SETUP -- Connection from 192.168.0.167 to self at 192.168.20.114.
May 17 13:52:33 raspberrypi shairport-sync[9118]: RTSP thread 2: RTSP Response:
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "CSeq", content: "5"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "Server", content: "AirTunes/105.1"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "Transport", content: "RTP/AVP/UDP;unicast;interleaved=0-1;mode=record;control_port=6001;timing_port=6002;server_port=6003"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "Session", content: "1"
May 17 13:52:33 raspberrypi shairport-sync[9118]: RTSP thread 2 received an RTSP Packet of type "RECORD":
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "CSeq", content: "6"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "DACP-ID", content: "506659DE0573F4FA"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "Active-Remote", content: "3361043355"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "User-Agent", content: "AirPlay/540.31"
May 17 13:52:33 raspberrypi shairport-sync[9118]: Connection 2: RECORD
May 17 13:52:33 raspberrypi shairport-sync[9118]: pbeg
May 17 13:52:33 raspberrypi shairport-sync[9118]: RTSP thread 2: RTSP Response:
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "CSeq", content: "6"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "Server", content: "AirTunes/105.1"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "Audio-Latency", content: "11025"
May 17 13:52:33 raspberrypi shairport-sync[9118]: RTSP thread 2 received an RTSP Packet of type "SET_PARAMETER":
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "Content-Length", content: "20"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "Content-Type", content: "text/parameters"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "CSeq", content: "7"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "DACP-ID", content: "506659DE0573F4FA"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "Active-Remote", content: "3361043355"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "User-Agent", content: "AirPlay/540.31"
May 17 13:52:33 raspberrypi shairport-sync[9118]: RTSP thread 2: RTSP Response:
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "CSeq", content: "7"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "Server", content: "AirTunes/105.1"
May 17 13:52:33 raspberrypi shairport-sync[9118]: sync error in milliseconds, net correction in ppm, corrections in ppm, total packets, missing packets, late packets, too late packets, resend requests, min DAC queue size, min buffer occupancy, max buffer occupancy
May 17 13:52:33 raspberrypi shairport-sync[9118]: Sync packet received before we got a timing packet back.
May 17 13:52:33 raspberrypi shairport-sync[9118]: RTSP thread 2 received an RTSP Packet of type "FLUSH":
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "RTP-Info", content: "seq=10021;rtptime=3832114019"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "CSeq", content: "8"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "DACP-ID", content: "506659DE0573F4FA"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "Active-Remote", content: "3361043355"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "User-Agent", content: "AirPlay/540.31"
May 17 13:52:33 raspberrypi shairport-sync[9118]: RTSP thread 2: RTSP Response:
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "CSeq", content: "8"
May 17 13:52:33 raspberrypi shairport-sync[9118]:   Type: "Server", content: "AirTunes/105.1"
May 17 13:52:33 raspberrypi shairport-sync[9118]: Resend interval for latency of 88200 frames is 31 frames.
May 17 13:52:33 raspberrypi shairport-sync[9118]: Hammerton Decoder used on encrypted audio.
May 17 13:52:35 raspberrypi shairport-sync[9118]: Sync packet received before we got a timing packet back.
May 17 13:52:36 raspberrypi shairport-sync[9118]: Sync packet received before we got a timing packet back.
May 17 13:52:37 raspberrypi shairport-sync[9118]: Sync packet received before we got a timing packet back.
May 17 13:52:39 raspberrypi shairport-sync[9118]: Sync packet received before we got a timing packet back.
May 17 13:52:41 raspberrypi shairport-sync[9118]: Sync packet received before we got a timing packet back.
May 17 13:52:42 raspberrypi shairport-sync[9118]: Aliasing of buffer index -- reset.
May 17 13:52:42 raspberrypi shairport-sync[9118]: Sync packet received before we got a timing packet back.
May 17 13:52:44 raspberrypi shairport-sync[9118]: Sync packet received before we got a timing packet back.
May 17 13:52:46 raspberrypi shairport-sync[9118]: Sync packet received before we got a timing packet back.
May 17 13:52:48 raspberrypi shairport-sync[9118]: Sync packet received before we got a timing packet back.
May 17 13:52:49 raspberrypi shairport-sync[9118]: Sync packet received before we got a timing packet back.
May 17 13:52:50 raspberrypi shairport-sync[9118]: Aliasing of buffer index -- reset.
May 17 13:52:51 raspberrypi shairport-sync[9118]: RTSP thread 2 received an RTSP Packet of type "TEARDOWN":
May 17 13:52:51 raspberrypi shairport-sync[9118]:   Type: "CSeq", content: "17"
May 17 13:52:51 raspberrypi shairport-sync[9118]:   Type: "DACP-ID", content: "506659DE0573F4FA"
May 17 13:52:51 raspberrypi shairport-sync[9118]:   Type: "Active-Remote", content: "3361043355"
May 17 13:52:51 raspberrypi shairport-sync[9118]:   Type: "User-Agent", content: "AirPlay/540.31"
May 17 13:52:51 raspberrypi shairport-sync[9118]: Connection 2: TEARDOWN
May 17 13:52:51 raspberrypi shairport-sync[9118]: Playback Stopped. Total playing time 00:00:18.
May 17 13:52:51 raspberrypi shairport-sync[9118]: Cancelling timing, control and audio threads...
May 17 13:52:51 raspberrypi shairport-sync[9118]: Cancel timing thread.
May 17 13:52:51 raspberrypi shairport-sync[9118]: Join timing thread.
May 17 13:52:51 raspberrypi shairport-sync[9118]: shutdown timing socket.
May 17 13:52:51 raspberrypi shairport-sync[9118]: close timing socket.
May 17 13:52:51 raspberrypi shairport-sync[9118]: Timing thread terminated.
May 17 13:52:51 raspberrypi shairport-sync[9118]: Cancel control thread.
May 17 13:52:51 raspberrypi shairport-sync[9118]: Join control thread.
May 17 13:52:51 raspberrypi shairport-sync[9118]: shutdown control socket.
May 17 13:52:51 raspberrypi shairport-sync[9118]: close control socket.
May 17 13:52:51 raspberrypi shairport-sync[9118]: Control thread terminated.
May 17 13:52:51 raspberrypi shairport-sync[9118]: Cancel audio thread.
May 17 13:52:51 raspberrypi shairport-sync[9118]: Join audio thread.
May 17 13:52:51 raspberrypi shairport-sync[9118]: shutdown audio socket.
May 17 13:52:51 raspberrypi shairport-sync[9118]: close audio socket.
May 17 13:52:51 raspberrypi shairport-sync[9118]: Audio thread terminated.
May 17 13:52:51 raspberrypi shairport-sync[9118]: Freeing audio buffers and decoders.
May 17 13:52:51 raspberrypi shairport-sync[9118]: Connection 2: player thread terminated.
May 17 13:52:51 raspberrypi shairport-sync[9118]: pend
May 17 13:52:51 raspberrypi shairport-sync[9118]: RTSP thread 2: RTSP Response:
May 17 13:52:51 raspberrypi shairport-sync[9118]:   Type: "CSeq", content: "17"
May 17 13:52:51 raspberrypi shairport-sync[9118]:   Type: "Server", content: "AirTunes/105.1"
May 17 13:52:51 raspberrypi shairport-sync[9118]:   Type: "Connection", content: "close"
May 17 13:52:51 raspberrypi shairport-sync[9118]: Connection 2: RTSP thread terminated.
mikebrady commented 3 years ago

Thanks. That:

Sync packet received before we got a timing packet back.

is almost certainly caused by something blocking UDP packets interchanged between Shairport Sync and the player. Are you allowing Shairport Sync to send UDP packets between VLANS? It needs to be able to do so for timing and for missing packet resend requests.

DenisKevljanin commented 3 years ago

All my devices can communicate across VLANs with UDP and TCP when it is a related or established connection. From my understanding it should not affect the communication as long as my iOS device initiates the traffic. For testing purposes I allowed any UDP traffic from the Pi to my internal network, but it has the same outcome.

Any other UDP traffic is able to pass the network and was able to pass it with the closed down firewall too. As mentioned I am able to stream and mirror screens to the Apple TV via AirPlay and also use Spotify connect on the very same device.

Could this be a system time issue?

mikebrady commented 3 years ago

All my devices can communicate across VLANs with UDP and TCP when it is a related or established connection. From my understanding it should not affect the communication as long as my iOS device initiates the traffic. For testing purposes I allowed any UDP traffic from the Pi to my internal network, but it has the same outcome.

Not a system time issue, no. Apple TV AirPlay may be using a different protocol. Don't know about Spotify.

But the situation is:

  1. Can play to Shairport Sync if the player is on the same VLAN.
  2. Can not play to Shairport Sync if the player is not on the same VLAN.
  3. Shairport Sync reports missing packets. Shairport Sync actually sends UDP packets to elicit a response to do timing. It may be that these are not considered "a related or established connection". That's where I would be digging.
DenisKevljanin commented 3 years ago

Okay quick update, I got it working by adding an explicit allow between VLANs for dynamic UDP ports 49152 - 65535 AND the NTP Port 123/udp. I am currently not sure how big of an attack vector I opened, but it seems to be safe except for DOS attacks and possible gathering of spoof information.

github-actions[bot] commented 3 years ago

This issue has been inactive for 60 days so will be closed 7 days from now. To prevent this, please remove the "stale" label or post a comment.