Can't connect from Mojave (10.14.6) to Airplay 2, but can with Airplay 1

[NeutralKaon]

First off, thank you so much for making and excellent bit of kit and clearly for the love you've put into this project. It's very nice to see and it is clearly both well-developed and widely used. Please forgive this plea for advice.

The Airplay 1 version of shairport sync works flawlessly for my x86-64 linux host (running Ubuntu 22.04) and OS X 10.14.6 guest (I have 32 bit apps I still use, unfortunately!). The latency is, as you predicted in the documentation, about 2 s, but this is well corrected for by the NTP techniques in Airplay 1.

I've just tried connecting to the development branch using Airplay 2 with the following configuration options:

$ shairport-sync -V
4.1-dev-505-g5f92164c-AirPlay2-alac-OpenSSL-Avahi-ALSA-jack-pa-pw-soxr-convolution-metadata-dbus-sysconfdir:/etc

I have likewise installed the latest version of NQPTP from git, and it is running. If I nmap myself, I do not see the port as open, however – I presume that is by design?

hilb@Peyton:~/Downloads/nqptp$ ps auxw|grep -i nqptp
root      925634  0.1  0.0   2812  1004 ?        SLs  17:03   0:02 /usr/local/bin/nqptp
hilb+  929630  0.0  0.0   9536  2352 pts/24   S+   17:34   0:00 grep --color=auto -i nqptp
hilb@Peyton:~/Downloads/nqptp$ sudo nmap -sS localhost -p 319
Starting Nmap 7.80 ( https://nmap.org ) at 2022-08-19 17:34 BST
Nmap scan report for localhost (127.0.0.1)
Host is up (0.0025s latency).

PORT    STATE  SERVICE
319/tcp closed ptp-event

Nmap done: 1 IP address (1 host up) scanned in 0.09 seconds

Trying to make a connection mostly works – aside from the actual playing music business as unfortunately I get the dreaded "unable to open connection" error on the mac:

Here's the log from Shairport's point of view – scroll down for that of the mac:

$ shairport-sync -vv --statistics
         0.000231474 "shairport.c:594" looking for configuration file at full path "/etc/shairport-sync.conf"
         0.000255259 "shairport.c:2026" startup in Airplay 2 mode with features 0x405fca00,0x1c340 on device "04:d9:f5:05:bd:ae".
         0.000005871 "shairport.c:2069" software version: "4.1-dev-505-g5f92164c-AirPlay2-alac-OpenSSL-Avahi-ALSA-jack-pa-pw-soxr-convolution-metadata-dbus-sysconfdir:/etc"
         0.000002284 "shairport.c:2075" log verbosity is 2.
         0.000004819 "audio_alsa.c:1010" alsa: init() -- alsa_backend_state => abm_disconnected.
         0.000002004 "audio_alsa.c:1027" alsa: alsa_maximum_stall_time of 0.200000 sec.
         0.000005370 "audio_alsa.c:1316" alsa: disable_standby_mode is "never".
         0.000001934 "audio_alsa.c:1320" alsa: disable_standby_mode_silence_threshold is 0.040000 seconds.
         0.000001973 "audio_alsa.c:1322" alsa: disable_standby_mode_silence_scan_interval is 0.004000 seconds.
         0.000004549 "audio_alsa.c:1362" alsa: output device name is "hw:1".
         0.000037250 "shairport.c:2090" The processor is running little-endian.
         0.000006662 "shairport.c:2104" libsodium initialised.
         0.000019296 "shairport.c:2154" disable resend requests is off.
         0.000001603 "shairport.c:2155" diagnostic_drop_packet_fraction is 0.000000. A value of 0.0 means no packets will be dropped deliberately.
         0.000001954 "shairport.c:2159" statistics_requester status is 1.
         0.000001693 "shairport.c:2164" rtsp listening port is 7000.
         0.000001303 "shairport.c:2165" udp base port is 6001.
         0.000001322 "shairport.c:2166" udp port range is 10.
         0.000001313 "shairport.c:2167" player name is "Peyton".
         0.000001312 "shairport.c:2168" backend is "alsa".
         0.000001322 "shairport.c:2169" run_this_before_play_begins action is "(null)".
         0.000001373 "shairport.c:2170" run_this_after_play_ends action is "(null)".
         0.000001813 "shairport.c:2171" wait-cmd status is 0.
         0.000001333 "shairport.c:2172" run_this_before_play_begins may return output is 0.
         0.000001423 "shairport.c:2173" run_this_if_an_unfixable_error_is_detected action is "(null)".
         0.000001392 "shairport.c:2175" run_this_before_entering_active_state action is  "(null)".
         0.000001353 "shairport.c:2177" run_this_after_exiting_active_state action is  "(null)".
         0.000001493 "shairport.c:2179" active_state_timeout is  10.000000 seconds.
         0.000002134 "shairport.c:2180" mdns backend "(null)".
         0.000001342 "shairport.c:2181" userSuppliedLatency is 0.
         0.000001313 "shairport.c:2182" interpolation setting is "soxr".
         0.000001302 "shairport.c:2185" interpolation soxr_delay_threshold is 30000000.
         0.000001393 "shairport.c:2186" resync time is 0.050000 seconds.
         0.000001783 "shairport.c:2187" allow a session to be interrupted: 0.
         0.000001322 "shairport.c:2188" busy timeout time is 0.
         0.000001283 "shairport.c:2189" drift tolerance is 0.001995 seconds.
         0.000001493 "shairport.c:2190" password is "(null)".
         0.000001292 "shairport.c:2191" ignore_volume_control is 0.
         0.000001282 "shairport.c:2195" volume_max_db is not set
         0.000001273 "shairport.c:2196" volume range in dB (zero means use the range specified by the mixer): 0.
         0.000001693 "shairport.c:2198" volume_range_combined_hardware_priority (1 means hardware mixer attenuation is used first) is 0.
         0.000001503 "shairport.c:2202" playback_mode is 0 (0-stereo, 1-mono, 1-reverse_stereo, 2-both_left, 3-both_right).
         0.000001443 "shairport.c:2204" disable_synchronization is 0.
         0.000001312 "shairport.c:2205" use_mmap_if_available is 1.
         0.000001513 "shairport.c:2206" output_format automatic selection is enabled.
         0.000001463 "shairport.c:2210" output_rate automatic selection is enabled.
         0.000001312 "shairport.c:2214" audio backend desired buffer length is 0.200000 seconds.
         0.000001503 "shairport.c:2216" audio_backend_buffer_interpolation_threshold_in_seconds is 0.120000 seconds.
         0.000001623 "shairport.c:2218" audio backend latency offset is 0.000000 seconds.
         0.000002194 "shairport.c:2220" audio backend silence lead-in time is "auto".
         0.000001343 "shairport.c:2224" zeroconf regtype is "_raop._tcp".
         0.000001302 "shairport.c:2225" decoders_supported field is 3.
         0.000001322 "shairport.c:2226" use_apple_decoder is 1.
         0.000001263 "shairport.c:2227" alsa_use_hardware_mute is 0.
         0.000001292 "shairport.c:2231" no special mdns service interface was requested.
         0.000002956 "shairport.c:2234" configuration file name "/etc/shairport-sync.conf" resolves to "/etc/shairport-sync.conf".
         0.000001683 "shairport.c:2241" metadata enabled is 1.
         0.000001302 "shairport.c:2242" metadata pipename is "/tmp/shairport-sync-metadata".
         0.000001353 "shairport.c:2243" metadata socket address is "(null)" port 0.
         0.000001473 "shairport.c:2245" metadata socket packet size is "500".
         0.000001643 "shairport.c:2246" get-coverart is 1.
         0.000001282 "shairport.c:2259" convolution is 0.
         0.000001283 "shairport.c:2260" convolution IR file is "(null)"
         0.000001282 "shairport.c:2261" convolution max length 8192
         0.000001323 "shairport.c:2262" convolution gain is 0.000000
         0.000001432 "shairport.c:2264" loudness is 0.
         0.000001293 "shairport.c:2265" loudness reference level is -20.000000
         0.000032791 "rtsp.c:3984" metadata pipe name is "/tmp/shairport-sync-metadata".
         0.000033753 "audio_alsa.c:2063" keep_dac_busy is now "no"
         0.000062187 "rtsp.c:361" Creating metadata queue "pipe".
         0.000005741 "rtsp.c:361" Creating metadata queue "multicast".
         0.000017974 "rtsp.c:361" Creating metadata queue "hub".
         0.000451647 "ptp-utilities.c:178" Send control message to NQPTP: "/shairport-sync-4d9f505bdae T"
         0.000047539 "ptp-utilities.c:178" Send control message to NQPTP: "/shairport-sync-4d9f505bdae T"
         0.001899633 "dbus-service.c:1096" *warning: could not acquire a Shairport Sync native D-Bus interface "org.gnome.ShairportSync.i927554" on the system bus.
         0.003165186 "ptp-utilities.c:118" ptp_shm_interface_open with mapped_addr = 0
         0.000014017 "ptp-utilities.c:149" ptp_shm_interface_open -- success!
         0.000001893 "ptp-utilities.c:118" ptp_shm_interface_open with mapped_addr = 140549167665152
         0.000001673 "ptp-utilities.c:153" ptp_shm_interface_open -- already open!
         0.000001463 "shairport.c:2347" NQPTP is online.
         0.000043692 "activity_monitor.c:172" am_state: am_inactive
         0.002347322 "mdns_avahi.c:221" avahi: service '04D9F505BDAE@Peyton' group is not yet committed.
         0.001455961 "mdns_avahi.c:269" avahi: avahi_entry_group_commit 0
         0.000055424 "mdns_avahi.c:464" avahi_dacp_monitor_start Avahi DACP monitor successfully started
         0.000057157 "mdns_avahi.c:225" avahi: service '04D9F505BDAE@Peyton' group is registering.
         0.763432403 "mdns_avahi.c:192" avahi: service '04D9F505BDAE@Peyton' successfully added.
         0.727390533 "shairport.c:243" soxr_delay: 500478 nanoseconds, soxr_delay_threshold: 30 milliseconds.
         4.425426043 "rtsp.c:5361" Connection 1: new connection from 10.244.30.1:54126 to self at 10.244.30.16:7000.
         0.001429792 "rtsp.c:1931" Connection 1: GET /info :: Content-Length 70
         0.000022412 "rtsp.c:1933" GET request
         0.000003426 "rtsp.c:1933"   Type: "X-Apple-ProtocolVersion", content: "1"
         0.000005591 "rtsp.c:1933"   Type: "Content-Length", content: "70"
         0.000004037 "rtsp.c:1933"   Type: "Content-Type", content: "application/x-apple-binary-plist"
         0.000002896 "rtsp.c:1933"   Type: "CSeq", content: "0"
         0.000003857 "rtsp.c:1933"   Type: "DACP-ID", content: "4B437B6B944DA7BE"
         0.000002775 "rtsp.c:1933"   Type: "Active-Remote", content: "3946459262"
         0.000003677 "rtsp.c:1933"   Type: "User-Agent", content: "AirPlay/387.2"
         0.000015640 "rtsp.c:1933"   Content Plist (as XML):
--
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
	<key>qualifier</key>
	<array>
		<string>txtAirPlay</string>
	</array>
</dict>
</plist>
--
         0.000013805 "rtsp.c:1592" GET /info:
         0.000003567 "rtsp.c:1592"   Type: "X-Apple-ProtocolVersion", content: "1"
         0.000004769 "rtsp.c:1592"   Type: "Content-Length", content: "70"
         0.000004448 "rtsp.c:1592"   Type: "Content-Type", content: "application/x-apple-binary-plist"
         0.000005531 "rtsp.c:1592"   Type: "CSeq", content: "0"
         0.000004568 "rtsp.c:1592"   Type: "DACP-ID", content: "4B437B6B944DA7BE"
         0.000005050 "rtsp.c:1592"   Type: "Active-Remote", content: "3946459262"
         0.000005721 "rtsp.c:1592"   Type: "User-Agent", content: "AirPlay/387.2"
         0.000009337 "rtsp.c:1592"   Content Plist (as XML):
--
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
	<key>qualifier</key>
	<array>
		<string>txtAirPlay</string>
	</array>
</dict>
</plist>
--
         0.000016812 "rtsp.c:1601" Connection 1: GET_INFO: Source AirPlay Version is: 387.2.
         0.000008225 "rtsp.c:1624" GET /info Stage 1: qualifier: txtAirPlay
         0.000126958 "rtsp.c:1706" GET /info Stage 1 Response:
         0.000005350 "rtsp.c:1706"   Response Code: 501.
         0.000004108 "rtsp.c:1706"   Type: "CSeq", content: "0"
         0.000004378 "rtsp.c:1706"   Type: "Server", content: "AirTunes/366.0"
         0.000005250 "rtsp.c:1706"   Type: "Content-Type", content: "application/x-apple-binary-plist"
         0.000036388 "rtsp.c:1706"   Content Plist (as XML):
--
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
	<key>audioLatencies</key>
	<array>
		<dict>
			<key>inputLatencyMicros</key>
			<integer>0</integer>
			<key>outputLatencyMicros</key>
			<integer>400000</integer>
			<key>type</key>
			<integer>100</integer>
		</dict>
		<dict>
			<key>audioType</key>
			<string>default</string>
			<key>inputLatencyMicros</key>
			<integer>0</integer>
			<key>outputLatencyMicros</key>
			<integer>400000</integer>
			<key>type</key>
			<integer>100</integer>
		</dict>
		<dict>
			<key>audioType</key>
			<string>media</string>
			<key>inputLatencyMicros</key>
			<integer>0</integer>
			<key>outputLatencyMicros</key>
			<integer>400000</integer>
			<key>type</key>
			<integer>100</integer>
		</dict>
		<dict>
			<key>audioType</key>
			<string>media</string>
			<key>inputLatencyMicros</key>
			<integer>0</integer>
			<key>outputLatencyMicros</key>
			<integer>400000</integer>
			<key>type</key>
			<integer>102</integer>
		</dict>
	</array>
	<key>keepAliveLowPower</key>
	<true/>
	<key>keepAliveSendStatsAsBody</key>
	<true/>
	<key>manufacturer</key>
	<string>Shairport Sync</string>
	<key>nameIsFactoryDefault</key>
	<false/>
	<key>protocolVersion</key>
	<string>1.1</string>
	<key>sdk</key>
	<string>AirPlay;2.0.2</string>
	<key>sourceVersion</key>
	<string>366.0</string>
	<key>statusFlags</key>
	<integer>4</integer>
	<key>txtAirPlay</key>
	<data>
	BWFjbD0wGmRldmljZWlkPTA0OmQ5OmY1OjA1OmJkOmFlG2ZlYXR1cmVzPTB4NDA1RkNB
	MDAsMHgxQzM0MAdyc2Y9MHgwCWZsYWdzPTB4NBRtb2RlbD1TaGFpcnBvcnQgU3luYw1t
	YW51ZmFjdHVyZXI9DXNlcmlhbE51bWJlcj0NcHJvdG92ZXJzPTEuMQ1zcmN2ZXJzPTM2
	Ni4wJ3BpPWFkZDcyM2YwLWQ0N2MtNDFmZC1iMTVhLTg5ZTYzZTU3MzI2YyhnaWQ9YWRk
	NzIzZjAtZDQ3Yy00MWZkLWIxNWEtODllNjNlNTczMjZjBmdjZ2w9MENwaz1hZDEwMjA1
	MzZhZTQ1MmVkZjFiNDY5YTVjNTgwMGVhMGJlNTY3YjRhMjI0ODk1ZjJjM2Y5Yzc2M2Zm
	ODhjOTky
	</data>
	<key>features</key>
	<integer>496155702053376</integer>
	<key>deviceID</key>
	<string>04:d9:f5:05:bd:ae</string>
	<key>pi</key>
	<string>add723f0-d47c-41fd-b15a-89e63e57326c</string>
	<key>name</key>
	<string>Peyton</string>
	<key>model</key>
	<string>Shairport Sync</string>
</dict>
</plist>
--
         0.000140935 "rtsp.c:1455" Responding with content of length 904
         0.345447130 "rtsp.c:2135" Connection 1: pair-setup Content-Length 9
         0.006285760 "rtsp.c:2173" pair-setup response
         0.000006632 "rtsp.c:2173"   Response Code: 200.
         0.000003196 "rtsp.c:2173"   Type: "CSeq", content: "1"
         0.000004529 "rtsp.c:2173"   Type: "Server", content: "AirTunes/366.0"
         0.000004678 "rtsp.c:2173"   Type: "Content-Type", content: "application/octet-stream"
         0.000003367 "rtsp.c:2173"   No Content Plist. Content length: 409.
         0.000004669 "rtsp.c:1455" Responding with content of length 409
         0.075944429 "rtsp.c:2135" Connection 1: pair-setup Content-Length 457
         0.006957549 "rtsp.c:2173" pair-setup response
         0.000006542 "rtsp.c:2173"   Response Code: 200.
         0.000002936 "rtsp.c:2173"   Type: "CSeq", content: "2"
         0.000003927 "rtsp.c:2173"   Type: "Server", content: "AirTunes/366.0"
         0.000003918 "rtsp.c:2173"   Type: "Content-Type", content: "application/octet-stream"
         0.000003085 "rtsp.c:2173"   No Content Plist. Content length: 69.
         0.000005100 "rtsp.c:1455" Responding with content of length 69
         0.222827990 "rtsp.c:1455" Responding with content of length 142
         0.002197942 "rtsp.c:1455" Responding with content of length 32
         0.006177607 "rtsp.c:2733" Connection 1: SETUP (AirPlay 2)
         0.000026199 "rtsp.c:2744" Connection 1 SETUP: No "streams" array has been found -- create an event thread and open a TCP port.
         0.000006061 "rtsp.c:2756" Connection 1: AP2 PTP connection from 10.244.30.1:54126 to self at 10.244.30.16:7000.
         0.000013566 "rtsp.c:564" Connection 1: request play lock.
         0.000004238 "rtsp.c:631" Connection 1: Got player lock.
         0.000004228 "ptp-utilities.c:118" ptp_shm_interface_open with mapped_addr = 140549167665152
         0.000004488 "ptp-utilities.c:153" ptp_shm_interface_open -- already open!
         0.000003497 "ptp-utilities.c:178" Send control message to NQPTP: "/shairport-sync-4d9f505bdae T"
         0.000010539 "metadata_hub.c:542" MH Client IP set to: "10.244.30.1"
         0.000014988 "metadata_hub.c:559" MH Server IP set to: "10.244.30.16"
         0.000019377 "rtsp.c:2808" SETUP "PTP" message
         0.000005470 "rtsp.c:2808"   Type: "Content-Length", content: "705"
         0.000003176 "rtsp.c:2808"   Type: "Content-Type", content: "application/x-apple-binary-plist"
         0.000003016 "rtsp.c:2808"   Type: "CSeq", content: "5"
         0.000005500 "rtsp.c:2808"   Type: "DACP-ID", content: "4B437B6B944DA7BE"
         0.000005520 "rtsp.c:2808"   Type: "Active-Remote", content: "3946459262"
         0.000005531 "rtsp.c:2808"   Type: "User-Agent", content: "AirPlay/387.2"
         0.000033563 "rtsp.c:2808"   Content Plist (as XML):
--
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
	<key>timingProtocol</key>
	<string>PTP</string>
	<key>sessionUUID</key>
	<string>BBB93BF5-1E9C-4FF3-87B3-24A8668CE7C7</string>
	<key>osName</key>
	<string>Mac OS X</string>
	<key>osBuildVersion</key>
	<string>18G9216</string>
	<key>sourceVersion</key>
	<string>387.2</string>
	<key>senderSupportsRelay</key>
	<false/>
	<key>osVersion</key>
	<string>10.14.6</string>
	<key>isMultiSelectAirPlay</key>
	<false/>
	<key>timingPeerInfo</key>
	<dict>
		<key>ID</key>
		<string>5A6061B6-1AE4-46B2-BAE1-BD5134FDDC54</string>
		<key>Addresses</key>
		<array>
			<string>10.244.30.1</string>
		</array>
		<key>SupportsClockPortMatchingOverride</key>
		<true/>
	</dict>
	<key>timingPeerList</key>
	<array>
		<dict>
			<key>ID</key>
			<string>5A6061B6-1AE4-46B2-BAE1-BD5134FDDC54</string>
			<key>Addresses</key>
			<array>
				<string>10.244.30.1</string>
			</array>
			<key>SupportsClockPortMatchingOverride</key>
			<true/>
		</dict>
	</array>
	<key>groupContainsGroupLeader</key>
	<false/>
	<key>groupUUID</key>
	<string>5A6061B6-1AE4-46B2-BAE1-BD5134FDDC54</string>
	<key>deviceID</key>
	<string>38:F9:D3:90:D3:C1</string>
	<key>model</key>
	<string>MacBookPro15,3</string>
	<key>name</key>
	<string>MacBook Pro - Vega</string>
	<key>macAddress</key>
	<string>32:10:1E:FE:FD:D7</string>
</dict>
</plist>
--
         0.000087283 "rtsp.c:2831" Updated groupContainsGroupLeader to 0
         0.000248597 "ptp-utilities.c:178" Send control message to NQPTP: "/shairport-sync-4d9f505bdae T 10.244.30.1 10.244.30.1"
         0.000033803 "rtsp.c:2934" Connection 1: TCP PTP event port opened: 42971.
         0.000013155 "rtsp.c:2953" Connection 1: SETUP mdns_update on PTP stream.
         0.000112471 "rtp.c:1579" Connection 1: AP2 Event Receiver started
         0.000618650 "rtsp.c:3257"  SETUP response
         0.000010359 "rtsp.c:3257"   Response Code: 200.
         0.000004689 "rtsp.c:3257"   Type: "CSeq", content: "5"
         0.000003888 "rtsp.c:3257"   Type: "Server", content: "AirTunes/366.0"
         0.000003837 "rtsp.c:3257"   Type: "Content-Type", content: "application/x-apple-binary-plist"
         0.000020047 "rtsp.c:3257"   Content Plist (as XML):
--
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
	<key>timingPeerInfo</key>
	<dict>
		<key>Addresses</key>
		<array>
			<string>10.244.30.16</string>
			<string>10.0.0.105</string>
			<string>10.0.0.67</string>
			<string>192.168.122.1</string>
			<string>10.244.30.16</string>
			<string>172.17.0.1</string>
			<string>fe80::6230:14ed:be34:765c</string>
			<string>fe80::d5b5:ac45:4dfe:f532</string>
			<string>fe80::30ff:aff:fe36:44fd</string>
		</array>
		<key>ID</key>
		<string>10.244.30.16</string>
	</dict>
	<key>eventPort</key>
	<integer>42971</integer>
	<key>timingPort</key>
	<integer>0</integer>
</dict>
</plist>
--
         0.000050134 "rtsp.c:1455" Responding with content of length 276
         0.009760327 "rtsp.c:4825" Connection 1: rtsp_conversation_thread_func_cleanup_function called.
         0.000013735 "rtsp.c:2545" Connection 1: TEARDOWN a PTP stream connection.
         0.000006192 "rtsp.c:2563" Connection 1: TEARDOWN Delete Event Thread.
         0.000047329 "rtp.c:1571" Connection 1: AP2 Event Receiver Cleanup.
         0.000037630 "rtsp.c:2569" Connection 1: TEARDOWN Close Event Socket.
         0.000062327 "rtsp.c:2589" Connection 1: TEARDOWN mdns_update on PTP stream.
         0.002345249 "rtsp.c:546" Connection 1: release play lock.
         0.000006402 "rtsp.c:552" Connection 1: play lock released.
         0.000020799 "rtsp.c:4856" Connection 1: terminating connection from 10.244.30.1:54126 to self at 10.244.30.16:7000.
         0.000076784 "rtsp.c:4915" Connection 1: Closed.
^C         3.216688880 "shairport.c:1696" exit on SIGINT
         0.000073689 "rtsp.c:5146" rtsp_listen_loop_cleanup_handler called.
         0.000022031 "rtsp.c:5152" closing socket 7.
         0.000017012 "rtsp.c:5152" closing socket 8.
         0.000054111 "shairport.c:1553" exit function called...
         0.000007134 "shairport.c:1571" Stopping D-Bus service
         0.000003677 "dbus-service.c:1132" stopping dbus service
         0.000017172 "shairport.c:1575" Stopping D-Bus Loop Thread
         0.000024616 "shairport.c:1521" g_main_loop thread exit
         0.000081533 "shairport.c:1587" Stopping DACP Monitor
         0.000005069 "dacp.c:989" dacp_monitor_stop
         0.000086523 "shairport.c:1592" Stopping metadata hub
         0.000004899 "shairport.c:1597" Stopping metadata
         0.000002785 "rtsp.c:4020" metadata_stop called.
         0.000050244 "rtsp.c:381" Deleting metadata queue "hub".
         0.000112952 "rtsp.c:381" Deleting metadata queue "multicast".
         0.000094798 "rtsp.c:381" Deleting metadata queue "pipe".
         0.000044113 "shairport.c:1600" Stopping the activity monitor.
         0.000060072 "activity_monitor.c:255" activity_monitor_stop complete
         0.000002946 "shairport.c:1604" Deinitialise the audio backend.
         0.000002925 "audio_alsa.c:1379" Cancel buffer monitor thread.
         0.000057228 "shairport.c:1610" Waiting for SoXr timecheck to terminate...
         0.000008135 "ptp-utilities.c:161" ptp_shm_interface_close
         0.000011061 "mdns_avahi.c:518" avahi_dacp_monitor_stop Avahi DACP monitor successfully stopped
         0.000002805 "mdns_avahi.c:415" avahi_unregister.
         0.000001783 "mdns_avahi.c:417" avahi: stop the threaded poll.
         0.000060494 "mdns_avahi.c:421" avahi: free the client.
         0.000022542 "mdns_avahi.c:427" avahi: free the threaded poll.
         0.000006512 "mdns_avahi.c:435" avahi: free the service name.
         0.000003507 "mdns_avahi.c:442" avahi: free the ap2 service_name.
         0.000002314 "mdns_avahi.c:448" avahi free text_record_string_list
         0.000001874 "mdns_avahi.c:455" avahi free ap_2text_record_string_list
         0.000004188 "shairport.c:1676" normal exit

And the output from Console.app:

default	17:24:44.604797 +0100	SystemUIServer	AirPlayMenu: AirPlay device list changed
default	17:24:44.603347 +0100	AirPlayXPCHelper	[0xD146] APSenderSessionAirPlay publishEncryptionKeyDiagnosticModeEnabled is off.
default	17:24:44.603891 +0100	AirPlayXPCHelper	[0xD146] Activating endpoint 'Peyton' (Shairport Sync v366) with seed 1...
default	17:24:44.607408 +0100	AirPlayXPCHelper	Successfully started LE device discovery
default	17:24:44.606900 +0100	sharingd	DeviceDiscoveryActivate: SFDeviceDiscovery (AirPlayXPCHelper), legacy, 0x2 < Prox >, cflags 0x1 < AdvData >, ScanRate Normal, FastScan Start, RSSI >= -75, from AirPlayXPCHelper:134
default	17:24:44.609979 +0100	AirPlayXPCHelper	[0xF432] Connect over Infra with "Peyton" ( senderSession->preferP2P = 0, isInfraAvailable = 1, isP2PAvailable = 0 )
default	17:24:44.611207 +0100	AirPlayXPCHelper	[0xF432] created a new transport session [0x85BA]
default	17:24:44.611348 +0100	AirPlayXPCHelper	APTransportConnectionHTTP 0x6FFB with name Peyton-ctrl created. Connection QoS: 0
default	17:24:44.611501 +0100	AirPlayXPCHelper	APTransportConnectionHTTP 0xAF3C with name Peyton-rctl created. Connection QoS: 0
default	17:24:44.611603 +0100	AirPlayXPCHelper	[0x85BA] APTransportSession with stream [0x5DAE] holds connection [0x6FFB]
default	17:24:44.611761 +0100	AirPlayXPCHelper	Connect start: '04D9F505BDAE@Peyton._raop._tcp.local.%13'
default	17:24:44.620772 +0100	AirPlayXPCHelper	Connecting to [fe80::30ff:aff:fe36:44fd%feth1889]:7000, interface 0
default	17:24:44.620966 +0100	AirPlayXPCHelper	[0x6FFB] httpconnection_asyncConnectionProgressed: Connecting to address: [fe80::30ff:aff:fe36:44fd%feth1889]:7000
default	17:24:44.621037 +0100	AirPlayXPCHelper	APTransportTrafficRegistrar: MAC 00:00:00:00:00:00 has 0 connections, 1 require infrastructure
default	17:24:44.623843 +0100	AirPlayXPCHelper	
Interface en0 Peer 00:00:00:00:00:00: RSSI value = 0 , 
Interface en0: Expected Peak Latency = 64 ms, LQM RSSI value = -52 , Effective Data Transfer Rate = 147 Mi, Interface Open Percent = 49 , Interface Avgerage CCA = 1 , LQM SNR value = 35 , 
Interface awdl0: Expected Peak Latency = 1024 ms, Interface Open Percent = 30 , Interface Avgerage CCA = 9 , 
Interface en0 Peer FF:FF:FF:FF:FF:FF: RSSI value = 0 ,
default	17:24:44.624487 +0100	kernel	com.apple.p2p: setAwdlPeerTrafficRegistration(): Clear traffic registration for airplay peer(00:00:00:00:00:00) hint=2
default	17:24:44.624893 +0100	AirPlayXPCHelper	APTransportTrafficRegistrar: Register AirPlay traffic for AWDL at MAC 00:00:00:00:00:00 with target infra critical PeerIndication=2 err=0
default	17:24:44.624502 +0100	kernel	com.apple.p2p: setAwdlPeerTrafficRegistration Airplaying on infra (149) has started
default	17:24:44.625184 +0100	AirPlayXPCHelper	### Connect failed immediate: [fe80::30ff:aff:fe36:44fd%feth1889]:7000, 65/0x41 EHOSTUNREACH
default	17:24:44.732575 +0100	AirPlayXPCHelper	Connecting to 10.244.30.16:7000, interface 0
default	17:24:44.732662 +0100	AirPlayXPCHelper	[0x6FFB] httpconnection_asyncConnectionProgressed: Connecting to address: 10.244.30.16:7000
default	17:24:44.764227 +0100	AirPlayXPCHelper	Connected to  10.244.30.16:7000 (Reach=0.00 ms, SRV=0.95 ms, DNS=12.41 ms, Connect=31.80 ms, Total=152.45 ms)
default	17:24:44.764462 +0100	AirPlayXPCHelper	[0x6FFB] httpConnection_setupHTTPClient: HTTPClient connected to 10.244.30.16:7000 (from 10.244.30.1:54200)
default	17:24:44.773492 +0100	AirPlayXPCHelper	APPairingClientCoreUtils created.
default	17:24:44.991386 +0100	SystemUIServer	AirPlayMenu: AirPlay device list changed
error	17:24:45.030783 +0100	AirPlayXPCHelper	coreUtilsPairing_XPCFindPeer:1256: got error -6727/0xFFFFE5B9 kNotFoundErr
default	17:24:45.030919 +0100	AirPlayXPCHelper	[0xF432] Pair-setup over Infra with "Peyton"
default	17:24:45.031408 +0100	AirPlayXPCHelper	APPairingClientCoreUtils created.
default	17:24:45.031491 +0100	AirPlayXPCHelper	Control pair-setup CU, type 4
default	17:24:45.031605 +0100	AirPlayXPCHelper	PairingFlags 16
default	17:24:45.031663 +0100	AirPlayXPCHelper	PairStart, PairSetupClient, 0x10 < Transient >
default	17:24:45.031771 +0100	AirPlayXPCHelper	Pair-setup client M1 -- start request
    0x00 (Method), 1 bytes, 00 |^|
    0x06 (State),  1 bytes, 01 |^|
    0x13 (Flags),  1 bytes, 10 |^|
default	17:24:45.032668 +0100	AirPlayXPCHelper	Error: Daemon connection invalidated
error	17:24:45.032494 +0100	kernel	Sandbox: AirPlayXPCHelper(134) deny(1) mach-lookup com.apple.timed.xpc
default	17:24:45.072034 +0100	AirPlayXPCHelper	Pair-setup client M2 -- start response
    0x06 (State),        1 bytes, 02 |^|
    0x02 (Salt),        16 bytes, cf 8b 30 40 ca 61 8a 44 91 79 5f 2f 94 7c f4 9d |^^0@^a^D^y_/^|^^|
    0x03 (Public Key)
        +0000: 7e2f8323 2d388f30 b3daf96a b276da50 |~/^#-8^0^^^j^v^P| (255 bytes)
        +0010: 097c7169 9a685129 1f750da3 d2924e59 |^|qi^hQ)^u^^^^NY|
        +0020: 50b81e0e fb851a83 b52cd74d e80e5b98 |P^^^^^^^^,^M^^[^|
        +0030: d8543796 a036870d dfde5a15 bc5c25fb |^T7^^6^^^^Z^^\%^|
        +0040: d8e281db dc40732e aa641b71 96104dcc |^^^^^@s.^d^q^^M^|
        +0050: 3ef43d73 e8895561 82d11751 2dc613d9 |>^=s^^Ua^^^Q-^^^|
        +0060: 264da139 3bbe2f04 f87827d8 3d8517f7 |&M^9;^/^^x'^=^^^|
        +0070: 86716db2 f2910ae1 c98fb71e f5260647 |^qm^^^^^^^^^^&^G|
        +0080: 2ccefe5b dccd04b7 6fb31eeb 71bd7bd1 |,^^[^^^^o^^^q^{^|
        +0090: 1353c59d 1435d27e da622582 21bfe48c |^S^^^5^~^b%^!^^^|
        +00A0: 901bc264 38373f8f 7ca4950a 1a2ebb4c |^^^d87?^|^^^^.^L|
        +00B0: 29cd4b72 ec46cd<…>
default	17:24:45.121466 +0100	AirPlayXPCHelper	Pair-setup  client M3 -- verify request
    0x06 (State),        1 bytes, 03 |^|
    0x03 (Public Key)
        +0000: 0dbcf7b4 41e6c8e6 407dfcfa 17855e1e |^^^^A^^^@}^^^^^^| (255 bytes)
        +0010: 42a687aa 14b72872 595f79a8 a5ebfbaf |B^^^^^(rY_y^^^^^|
        +0020: c02e7735 f5a541b2 6c832b31 5d5843c5 |^.w5^^A^l^+1]XC^|
        +0030: af6ab3f4 742b1be9 7754dbec f521fde4 |^j^^t+^^wT^^^!^^|
        +0040: ed334456 d5fda657 65633df8 734cacdd |^3DV^^^Wec=^sL^^|
        +0050: 45f05f88 6cd6bd70 d62cfa32 1cff25d6 |E^_^l^^p^,^2^^%^|
        +0060: 2fe16d36 4d218621 76bd3a41 4fe0d58f |/^m6M!^!v^:AO^^^|
        +0070: e68e41c5 7b99b626 df1f8816 89abaf02 |^^A^{^^&^^^^^^^^|
        +0080: 1005c5c4 edc8dfac 5889c941 3cea1f94 |^^^^^^^^X^^A<^^^|
        +0090: 88590b1e 5f5bc0a9 2b47f349 e44f10ca |^Y^^_[^^+G^I^O^^|
        +00A0: 786d428b f3df5ade cc5c97bd cb237324 |xmB^^^Z^^\^^^#s$|
        +00B0: 3964138d ced34867 565d2290 b909c920 |9d^^^^HgV]"^^^^ |
        +00C0: 719ba805 e4828c34 30cf0ea5 160023cc |q^^^^^^4<…>
default	17:24:45.121527 +0100	AirPlayXPCHelper	 |^V^^W^^^h^^^^^^^|
        +0020: f60c398a 504b86b4 32716234 9589df48 |^^9^PK^^2qb4^^^H|
        +0030: 15ab7acd 2abef7a8 7ddebc01 8c457d80 |^^z^*^^^}^^^^E}^|
default	17:24:45.122198 +0100	AirPlayXPCHelper	Error: Daemon connection invalidated
default	17:24:45.204699 +0100	AirPlayXPCHelper	Pair-setup client M4 -- verify response
    0x06 (State),  1 bytes, 04 |^|
    0x04 (Proof)
        +0000: 58eafb93 09755667 fbab951c ae4529b1 |X^^^^uVg^^^^^E)^| (64 bytes)
        +0010: bd6ee2f4 5dc66ff5 2775a125 6a155ec2 |^n^^]^o^'u^%j^^^|
        +0020: 4a187954 28543b74 7a7ba2de 97255352 |J^yT(T;tz{^^^%SR|
        +0030: f9596949 a72118c9 8bd7b19a ef9407a5 |^YiI^!^^^^^^^^^^|
default	17:24:45.204861 +0100	AirPlayXPCHelper	Pair-setup transient client done -- server authenticated
default	17:24:45.204971 +0100	AirPlayXPCHelper	Control pair-setup coreUtils success
default	17:24:45.212284 +0100	AirPlayXPCHelper	BootUUID 5A6061B6-1AE4-46B2-BAE1-BD5134FDDC54
default	17:24:45.212912 +0100	AirPlayXPCHelper	Setting local peer info to {
    "ID" : "5A6061B6-1AE4-46B2-BAE1-BD5134FDDC54",
    "Addresses" : 
    [
        <APSNetworkAddress 0x7fc72c70bda0 '10.244.30.1'>
    ],
    "InterfaceName" : "feth1889",
    "SupportsClockPortMatchingOverride" : true,
}
default	17:24:45.214309 +0100	AirPlayXPCHelper	BootUUID 5A6061B6-1AE4-46B2-BAE1-BD5134FDDC54
default	17:24:45.216522 +0100	kernel	Sandbox: 1 duplicate report for AirPlayXPCHelper deny(1) mach-lookup com.apple.timed.xpc
error	17:24:45.216550 +0100	kernel	Sandbox: AirPlayXPCHelper(134) deny(1) file-read-data /Library/Application Support/CrashReporter/DiagnosticMessagesHistory.plist
default	17:24:45.216411 +0100	AirPlayXPCHelper	reading _CRCopyDiagnosticMessagesHistoryValue key AutoSubmit-#12 (stat 0: 704, mode: 100664)
default	17:24:45.216859 +0100	AirPlayXPCHelper	AutoSubmitPreference is (null)
default	17:24:45.223531 +0100	AirPlayXPCHelper	Adding peer {
    "ID" : "10.244.30.16",
    "PreferredAddress" : <APSNetworkAddress 0x7fc72de3bdd0 '10.244.30.16'>,
    "InterfaceName" : "feth1889",
    "Addresses" : 
    [
        <APSNetworkAddress 0x7fc72de3dfb0 '10.244.30.16'>,
        <APSNetworkAddress 0x7fc72de2eee0 '10.0.0.105'>,
        <APSNetworkAddress 0x7fc72de39900 '10.0.0.67'>,
        <APSNetworkAddress 0x7fc72de3e180 '192.168.122.1'>,
        <APSNetworkAddress 0x7fc72de3e1b0 '10.244.30.16'>,
        <APSNetworkAddress 0x7fc72de3da20 '172.17.0.1'>,
        <APSNetworkAddress 0x7fc72de3bda0 'fe80::6230:14ed:be34:765c'>,
        <APSNetworkAddress 0x7fc72de3d9f0 'fe80::d5b5:ac45:4dfe:f532'>,
        <APSNetworkAddress 0x7fc72de2f0a0 'fe80::30ff:aff:fe36:44fd'>
    ],
}
 to PTP clock...
error	17:24:45.223778 +0100	AirPlayXPCHelper	ptpClock_openClockPortsForPeer:690: got error -536870206/0xE00002C2 kIOReturnBadArgument
default	17:24:45.223840 +0100	AirPlayXPCHelper	### Adding peer to PTP clock failed, err -536870206/0xE00002C2 kIOReturnBadArgument
error	17:24:45.224054 +0100	AirPlayXPCHelper	ptpClock_addOrUpdatePeerInternal:588: got error -536870206/0xE00002C2 kIOReturnBadArgument
error	17:24:45.224121 +0100	AirPlayXPCHelper	ptpClock_AddOrUpdatePeer:538: got error -536870206/0xE00002C2 kIOReturnBadArgument
error	17:24:45.224167 +0100	AirPlayXPCHelper	APSNetworkClockAddOrUpdatePeerFromSerializablePeerDictionary:508: got error -536870206/0xE00002C2 kIOReturnBadArgument
error	17:24:45.224217 +0100	AirPlayXPCHelper	apsession_addPeerToNetworkClock:3787: got error -536870206/0xE00002C2 kIOReturnBadArgument
error	17:24:45.224319 +0100	AirPlayXPCHelper	apsession_ensureStartedInternal:1809: got error -536870206/0xE00002C2 kIOReturnBadArgument
default	17:24:45.224396 +0100	AirPlayXPCHelper	[0xF432] Disconnecting from 'Peyton-AP'
error	17:24:45.224513 +0100	AirPlayXPCHelper	### [0xD146] Received sender session failed notification.
error	17:24:45.224631 +0100	AirPlayXPCHelper	ptpClock_removePeerInternal:957: false condition
default	17:24:45.224867 +0100	AirPlayXPCHelper	### Removing peer from PTP clock failed, err -72291/0xFFFEE59D
default	17:24:45.226995 +0100	AirPlayUIAgent	Prompt complete[0xD80C] {
    "finishedWithPromptInfo" : 
    {
        "ATVName" : "Peyton",
        "savePassword" : false,
        "uniqueID" : "04:d9:f5:05:bd:ae",
        "MACAddress" : 04d9f505 bdae                       |^^^^^^          | (6 bytes),
    },
}
error	17:24:45.224975 +0100	AirPlayXPCHelper	### [0xF432] Failed to remove peer 10.244.30.16 from sender network clock
error	17:24:45.225428 +0100	AirPlayXPCHelper	endpoint_activateInternal:2676: got error -536870206/0xE00002C2 kIOReturnBadArgument
error	17:24:45.225523 +0100	AirPlayXPCHelper	[0xD146] Endpoint activation (seed 1) failed with error -536870206/0xE00002C2 kIOReturnBadArgument.
default	17:24:45.225808 +0100	AirPlayXPCHelper	APTransportTrafficRegistrar: MAC 00:00:00:00:00:00 has 0 connections, 0 require infrastructure
default	17:24:45.228485 +0100	SystemUIServer	AirPlayMenu: AirPlay device list changed
default	17:24:45.225905 +0100	AirPlayXPCHelper	<<<< FigRoutingManager >>>> routingManager_macOSEndpointActivateCompletionCallback_block_invoke: CMSession: routingManager_macOSEndpointHelpers: endpointName = Peyton, inActivationSeed=1, err = -536870206, inFeatures=2
default	17:24:45.228655 +0100	AirPlayUIAgent	Cannot connect error for Peyton

I feel obliged to note that I can't receive audio from openairplay2 and get a crypto error with them using the same setup (c.f. openairplay/airplay2-receiver#78 – the error is RTP ChaCha20_Poly1305 decrypt: ValueError('MAC check failed'))

[mikebrady]

Thanks for the post. Just to be clear, can you clarify that you are running Shairport Sync in AirPlay 2 mode on Ubuntu on a separate machine (i.e. not on a VM on the Mac) please?

On the Ubuntu machine, you should check that a firewall is not blocking ports 319 and 320 -- could that be an issue?

(BTW, a log_verbosity of 1 is generally plenty!)

[NeutralKaon]

Thanks Mike. Can confirm, it is bare metal on Ubuntu on a separate machine and not in a container or VM.

There is no firewall in the way – I have just checked both ports with netcat and text flows both ways :-)

[mikebrady]

Thanks for the update. BTW, the nmap commands would be

$ sudo nmap -sU localhost -p 319

... because it's UDP and not TCP that's needed for NQPTP.

But anyway, this tickled my memory, so it looks like you're out of luck, I'm afraid. My guess is that this is the OpenAirPlay issue too.

[NeutralKaon]

That's really useful and helpful. Thank you. I fear you are probably right – it would be interesting to know if Apple devices "seamlessly downgrade" to airplay 1 or have a different implementation (perhaps deriving the session key algorithmically?).

[mikebrady]

Thanks. My guess is that either the session is somehow unencrypted or there is a fixed session key, but TBH I haven’t looked. But I should update the requirements documentation while I think of it!

[github-actions]

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