[OwnTone]: ShairPort-Sync as an output – owntone.conf advisory.

[spbkaizo]

What happened?

I'm struggling to get Owntone to output to a shairplay-sync reciever (airplay2). This seems to be the same as issue #1407, and I was hoping for a steer on how best to proceed.

Shairport-sync is running on the same machine, in case that plays a part. It's been built from the latest git sources, and with the following configure arguments:

./configure --sysconfdir=/etc --with-alsa --with-soxr --with-avahi --with-ssl=openssl --with-systemd --enable-airplay2

Likewise, owntone is following the git sources, and is built with the following configure arguments:

./configure --prefix=/usr --sysconfdir=/etc --localstatedir=/var --enable-install-user --disable-spotify --enable-lastfm

Likewise, nqptp is installed from git and is up and running.

Relevant log output

(From Owntone)

[2023-07-15 11:52:58] [DEBUG]      web: JSON API request '/api/outputs/251096694378153/toggle' in worker thread 18316
[2023-07-15 11:52:58] [DEBUG]   player: Speaker enable: 'MainHiFi' (id=251096694378153)
[2023-07-15 11:52:58] [DEBUG]   player: Registered callback to device_activate_cb with id 2 (device 0xaaab0d0630d0, MainHiFi)
[2023-07-15 11:52:58] [DEBUG]   player: Number of active callbacks: 3
[2023-07-15 11:52:58] [DEBUG]  airplay: device_start: Sending GET /info to 'MainHiFi'
[2023-07-15 11:52:58] [DEBUG]  airplay: Local address: 127.0.0.1 (LL: no) port 41382
[2023-07-15 11:52:58] [DEBUG]  airplay: Status flags from 'MainHiFi' was 4: cable attached 1, one time pairing 0, password 0, PIN 0
[2023-07-15 11:52:58] [DEBUG]  airplay: device_start: Sending pair setup 1 to 'MainHiFi'
[2023-07-15 11:52:58] [DEBUG]  airplay: device_start: Sending pair setup 2 to 'MainHiFi'
[2023-07-15 11:52:58] [ WARN]   player: Output delay detected: player is 4 ticks behind, catching up
[2023-07-15 11:52:58] [DEBUG]  airplay: Ciphering setup of 'MainHiFi' completed succesfully, now using encrypted mode
[2023-07-15 11:52:58] [DEBUG]  airplay: pair_success: Sending SETUP (session) to 'MainHiFi'
[2023-07-15 11:52:58] [ WARN]  airplay: Response to SETUP (session) from 'MainHiFi' was negative, proceeding anyway (400 Bad Request)
[2023-07-15 11:52:58] [ WARN]  airplay: Unexpected reply to SETUP (session) from 'MainHiFi'
[2023-07-15 11:52:58] [DEBUG]   player: Callback request received, id is 2
[2023-07-15 11:52:58] [DEBUG]   player: Making deferred callback to device_activate_cb, id was 2
[2023-07-15 11:52:58] [DEBUG]   player: Callback from AirPlay 2 device MainHiFi to device_activate_cb (status -1)
[2023-07-15 11:52:58] [  LOG]   player: The AirPlay 2 device 'MainHiFi' failed to activate
[2023-07-15 11:52:58] [DEBUG]     main: Command has 0 pending events
[2023-07-15 11:52:58] [DEBUG]   player: Status update - status: 4, events: 12, caller: speaker_generic_bh
[2023-07-15 11:52:58] [DEBUG]      mpd: Asynchronous listener callback called with event type 12.
[2023-07-15 11:52:58] [DEBUG]   player: 0. Active callback: device_streaming_cb
[2023-07-15 11:52:58] [DEBUG]   player: 1. Active callback: device_streaming_cb
[2023-07-15 11:52:58] [DEBUG]      web: notify callback reason: 71
[2023-07-15 11:52:58] [DEBUG]      web: notify callback reason: 11
[2023-07-15 11:52:58] [DEBUG]      web: notify callback reply: 12
[2023-07-15 11:52:58] [DEBUG]      mpd: Notify clients waiting for idle results: 12
[2023-07-15 11:52:58] [  LOG]      web: JSON api request failed with error code 500 (/api/outputs/251096694378153/toggle)
[2023-07-15 11:52:58] [DEBUG]      web: JSON API request '/api/player' in worker thread 18316
[2023-07-15 11:52:58] [DEBUG]   player: Player status: playing
[2023-07-15 11:52:58] [DEBUG]      web: JSON API request '/api/outputs' in worker thread 18316

and, from shairport-sync:

2023-07-15T11:01:44.241228+00:00 myhyfy shairport-sync: warning: Shairport Sync can not handle NTP streams.
2023-07-15T11:52:52.508538+00:00 myhyfy shairport-sync: warning: Shairport Sync can not handle NTP streams.
2023-07-15T11:52:58.824445+00:00 myhyfy shairport-sync: warning: Shairport Sync can not handle NTP streams.

and lastly, from the -vv flags on the command line:

         0.000460834 "shairport.c:578" looking for configuration file at full path "/etc/shairport-sync.conf"
         0.000915092 "shairport.c:2248" Startup in AirPlay 2 mode, with features 0x405c4a00,0x1c340 on device "e4:5f:01:45:ce:a9".
         0.000073000 "shairport.c:2287" Version String: "4.2-AirPlay2-smi9-OpenSSL-Avahi-ALSA-soxr-sysconfdir:/etc"
         0.000020260 "shairport.c:2306" Command Line: "shairport-sync -vv".
         0.000041185 "shairport.c:2313" libsodium initialised.
         0.000292629 "shairport.c:2338" libgcrypt initialised.
         0.000022538 "shairport.c:2342" Log Verbosity is 2.
         0.000046722 "audio_alsa.c:1003" alsa: init() -- alsa_backend_state => abm_disconnected.
         0.000017463 "audio_alsa.c:1020" alsa: alsa_maximum_stall_time of 0.200000 sec.
         0.000027129 "audio_alsa.c:1309" alsa: disable_standby_mode is "never".
         0.000015926 "audio_alsa.c:1313" alsa: disable_standby_mode_silence_threshold is 0.040000 seconds.
         0.000015815 "audio_alsa.c:1315" alsa: disable_standby_mode_silence_scan_interval is 0.004000 seconds.
         0.000027759 "audio_alsa.c:1355" alsa: output device name is "default".
         0.000242130 "shairport.c:2357" The processor is running little-endian.
         0.000024204 "shairport.c:2390" disable_resend_requests is off.
         0.000015852 "shairport.c:2391" diagnostic_drop_packet_fraction is 0.000000. A value of 0.0 means no packets will be dropped deliberately.
         0.000021556 "shairport.c:2395" statistics_requester status is 0.
         0.000015870 "shairport.c:2400" rtsp listening port is 7000.
         0.000015463 "shairport.c:2401" udp base port is 6001.
         0.000014944 "shairport.c:2402" udp port range is 10.
         0.000014704 "shairport.c:2403" player name is "MainHiFi".
         0.000014741 "shairport.c:2404" backend is "alsa".
         0.000014889 "shairport.c:2405" run_this_before_play_begins action is "(null)".
         0.000015444 "shairport.c:2406" run_this_after_play_ends action is "(null)".
         0.000015371 "shairport.c:2407" wait-cmd status is 0.
         0.000015000 "shairport.c:2408" run_this_before_play_begins may return output is 0.
         0.000015166 "shairport.c:2409" run_this_if_an_unfixable_error_is_detected action is "(null)".
         0.000028519 "shairport.c:2411" run_this_before_entering_active_state action is  "(null)".
         0.000006018 "audio_alsa.c:2038" keep_dac_busy is now "no"
         0.000015333 "shairport.c:2413" run_this_after_exiting_active_state action is  "(null)".
         0.000081741 "shairport.c:2415" active_state_timeout is  10.000000 seconds.
         0.000019944 "shairport.c:2416" mdns backend "(null)".
         0.000015037 "shairport.c:2417" userSuppliedLatency is 0.
         0.000015130 "shairport.c:2418" interpolation setting is "auto".
         0.000015111 "shairport.c:2422" interpolation soxr_delay_threshold is 30000000.
         0.000014759 "shairport.c:2423" resync time is 0.050000 seconds.
         0.000015222 "shairport.c:2424" resync recovery time is 0.100000 seconds.
         0.000015408 "shairport.c:2425" allow a session to be interrupted: 0.
         0.000014963 "shairport.c:2426" busy timeout time is 0.
         0.000014741 "shairport.c:2427" drift tolerance is 0.002000 seconds.
         0.000015537 "shairport.c:2428" password is "(null)".
         0.000014851 "shairport.c:2429" default airplay volume is: -24.000000.
         0.000016112 "shairport.c:2430" high threshold airplay volume is: -16.000000.
         0.000015963 "shairport.c:2432" check for higher-than-threshold volume for new play session is disabled.
         0.000015314 "shairport.c:2438" ignore_volume_control is 1.
         0.000015019 "shairport.c:2442" volume_max_db is not set
         0.000014907 "shairport.c:2443" volume range in dB (zero means use the range specified by the mixer): 0.
         0.000015334 "shairport.c:2445" volume_range_combined_hardware_priority (1 means hardware mixer attenuation is used first) is 0.
         0.000025814 "shairport.c:2449" playback_mode is 0 (0-stereo, 1-mono, 1-reverse_stereo, 2-both_left, 3-both_right).
         0.000015352 "shairport.c:2451" disable_synchronization is 0.
         0.000014871 "shairport.c:2452" use_mmap_if_available is 1.
         0.000014703 "shairport.c:2453" output_format automatic selection is enabled.
         0.000014926 "shairport.c:2457" output_rate automatic selection is enabled.
         0.000014741 "shairport.c:2461" audio backend desired buffer length is 0.200000 seconds.
         0.000015611 "shairport.c:2463" audio_backend_buffer_interpolation_threshold_in_seconds is 0.120000 seconds.
         0.000016056 "shairport.c:2465" audio backend latency offset is 0.000000 seconds.
         0.000016185 "shairport.c:2467" audio backend silence lead-in time is "auto".
         0.000015000 "shairport.c:2471" zeroconf regtype is "_raop._tcp".
         0.000014833 "shairport.c:2472" decoders_supported field is 1.
         0.000014500 "shairport.c:2473" use_apple_decoder is 0.
         0.000014574 "shairport.c:2474" alsa_use_hardware_mute is 0.
         0.000014667 "shairport.c:2478" no special mdns service interface was requested.
         0.000041537 "shairport.c:2481" configuration file name "/etc/shairport-sync.conf" resolves to "/etc/shairport-sync.conf".
         0.000025389 "shairport.c:2511" loudness is 0.
         0.000014704 "shairport.c:2512" loudness reference level is -20.000000
         0.000191185 "ptp-utilities.c:176" Send control message to NQPTP: "/nqptp T"
         0.000182870 "ptp-utilities.c:176" Send control message to NQPTP: "/nqptp T"
         0.005178408 "ptp-utilities.c:116" ptp_shm_interface_open with mapped_addr = 0
         0.000153481 "ptp-utilities.c:147" ptp_shm_interface_open -- success!
         0.000024056 "ptp-utilities.c:116" ptp_shm_interface_open with mapped_addr = 281473387151360
         0.000016259 "ptp-utilities.c:151" ptp_shm_interface_open -- already open!
         0.000015611 "shairport.c:2610" NQPTP is online.
         0.000608630 "activity_monitor.c:163" am_state: am_inactive
         0.007332926 "mdns_avahi.c:220" avahi: service 'E45F0145CEA9@MainHiFi' group is not yet committed.
         0.002938481 "mdns_avahi.c:268" avahi: avahi_entry_group_commit 0
         0.000384852 "mdns_avahi.c:463" avahi_dacp_monitor_start Avahi DACP monitor successfully started
         0.000230037 "mdns_avahi.c:224" avahi: service 'E45F0145CEA9@MainHiFi' group is registering.
         0.872972648 "mdns_avahi.c:191" avahi: service 'E45F0145CEA9@MainHiFi' successfully added.
         0.012560870 "rtsp.c:774" No active connections.
         0.000141092 "rtsp.c:781" Airplay Volume for new connections is -24.000000.
         0.000239297 "rtsp.c:5610" Connection 1: New connection from 127.0.0.1:57956 to self at 127.0.0.1:7000.
         0.003104796 "rtsp.c:765" Airplay Volume for connection 1 is -24.000000.
         0.000044389 "rtsp.c:776" One active connection.
         0.000015056 "rtsp.c:781" Airplay Volume for new connections is -24.000000.
         0.000276703 "rtsp.c:5610" Connection 2: New connection from 127.0.0.1:57972 to self at 127.0.0.1:7000.
         0.000835537 "rtsp.c:765" Airplay Volume for connection 1 is -24.000000.
         0.000063537 "rtsp.c:765" Airplay Volume for connection 2 is -24.000000.
         0.000027389 "rtsp.c:778" 2 active connections.
         0.000018463 "rtsp.c:781" Airplay Volume for new connections is -24.000000.
         0.000258074 "rtsp.c:5610" Connection 3: New connection from 172.16.210.14:44568 to self at 172.16.210.14:7000.
         0.001055667 "rtsp.c:1376" Connection 3: Connection closed by client.
         0.000080148 "rtsp.c:5029" Connection 3: rtsp_conversation_thread_func_cleanup_function called.
         0.000052481 "rtsp.c:2688" Connection 3: TEARDOWN unspecified stream connection.
         0.000059408 "rtsp.c:5064" Connection 3: terminating -- closing RTSP connection socket 10: from 172.16.210.14:44568 to self at 172.16.210.14:7000.
         0.000793926 "rtsp.c:765" Airplay Volume for connection 1 is -24.000000.
         0.000579241 "rtsp.c:765" Airplay Volume for connection 2 is -24.000000.
         0.000037981 "rtsp.c:765" Airplay Volume for connection 3 is -24.000000.
         0.000020556 "rtsp.c:778" 3 active connections.
         0.000017185 "rtsp.c:781" Airplay Volume for new connections is -24.000000.
         0.000222907 "rtsp.c:1376" Connection 2: Connection closed by client.
         0.000066148 "rtsp.c:5029" Connection 2: rtsp_conversation_thread_func_cleanup_function called.
         0.000029223 "rtsp.c:2688" Connection 2: TEARDOWN unspecified stream connection.
         0.000019648 "rtsp.c:5064" Connection 2: terminating -- closing RTSP connection socket 9: from 127.0.0.1:57972 to self at 127.0.0.1:7000.
         0.000164426 "rtsp.c:5610" Connection 4: New connection from 172.16.210.14:44578 to self at 172.16.210.14:7000.
         0.000206148 "rtsp.c:5127" Connection 2: Closed.
         0.000218352 "rtsp.c:5127" Connection 3: Closed.
         0.000761370 "rtsp.c:1376" Connection 4: Connection closed by client.
         0.000049093 "rtsp.c:1376" Connection 1: Connection closed by client.
         0.000109797 "rtsp.c:5029" Connection 1: rtsp_conversation_thread_func_cleanup_function called.
         0.000063481 "rtsp.c:2688" Connection 1: TEARDOWN unspecified stream connection.
         0.000046556 "rtsp.c:5064" Connection 1: terminating -- closing RTSP connection socket 8: from 127.0.0.1:57956 to self at 127.0.0.1:7000.
         0.000044240 "rtsp.c:5029" Connection 4: rtsp_conversation_thread_func_cleanup_function called.
         0.000185222 "rtsp.c:2688" Connection 4: TEARDOWN unspecified stream connection.
         0.000173204 "rtsp.c:5064" Connection 4: terminating -- closing RTSP connection socket 9: from 172.16.210.14:44578 to self at 172.16.210.14:7000.
         0.000728926 "rtsp.c:5127" Connection 1: Closed.
         0.000013000 "rtsp.c:5127" Connection 4: Closed.
         0.589607721 "shairport.c:247" soxr_delay: 2935502 nanoseconds, soxr_delay_threshold: 30 milliseconds.
         0.000071112 "shairport.c:254" "soxr" interpolation has been chosen.
        12.299563863 "rtsp.c:760" Connection 1: deleted in cleanup.
         0.000722481 "rtsp.c:760" Connection 2: deleted in cleanup.
         0.000139630 "rtsp.c:760" Connection 3: deleted in cleanup.
         0.000120481 "rtsp.c:760" Connection 4: deleted in cleanup.
         0.000037204 "rtsp.c:774" No active connections.
         0.000030685 "rtsp.c:781" Airplay Volume for new connections is -24.000000.
         0.000187704 "rtsp.c:5610" Connection 5: New connection from 172.16.210.14:50212 to self at 172.16.210.14:7000.
         0.000630870 "rtsp.c:2068" Connection 5: GET /info :: Content-Length 0
         0.000062593 "rtsp.c:2070" GET request
         0.000040018 "rtsp.c:2070"   Type: "CSeq", content: "1"
         0.000037259 "rtsp.c:2070"   Type: "User-Agent", content: "owntone/28.6"
         0.000035612 "rtsp.c:2070"   Type: "Client-Instance", content: "6E82B7B4BB2B5945"
         0.000034888 "rtsp.c:2070"   Type: "DACP-ID", content: "6E82B7B4BB2B5945"
         0.000034982 "rtsp.c:2070"   Type: "Active-Remote", content: "21352105"
         0.000034018 "rtsp.c:2070"   No Content Plist. Content length: 0.
         0.000034963 "rtsp.c:1712" GET /info:
         0.000038686 "rtsp.c:1712"   Type: "CSeq", content: "1"
         0.000034574 "rtsp.c:1712"   Type: "User-Agent", content: "owntone/28.6"
         0.000034648 "rtsp.c:1712"   Type: "Client-Instance", content: "6E82B7B4BB2B5945"
         0.000034722 "rtsp.c:1712"   Type: "DACP-ID", content: "6E82B7B4BB2B5945"
         0.000034111 "rtsp.c:1712"   Type: "Active-Remote", content: "21352105"
         0.000034148 "rtsp.c:1712"   No Content Plist. Content length: 0.
         0.000328223 "rtsp.c:1851" GET /info Stage 2 Response
         0.000041777 "rtsp.c:1851"   Response Code: 501.
         0.000030704 "rtsp.c:1851"   Type: "CSeq", content: "1"
         0.000029741 "rtsp.c:1851"   Type: "Server", content: "AirTunes/366.0"
         0.000029315 "rtsp.c:1851"   Type: "Content-Type", content: "application/x-apple-binary-plist"
         0.000143222 "rtsp.c:1851"   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>features</key>
        <integer>496155701824000</integer>
        <key>deviceID</key>
        <string>e4:5f:01:45:ce:a9</string>
        <key>pi</key>
        <string>2ec3dbf7-88d1-4988-af1d-a3c2662e18db</string>
        <key>name</key>
        <string>MainHiFi</string>
        <key>model</key>
        <string>Shairport Sync</string>
</dict>
</plist>
--
         0.001585463 "rtsp.c:1574" Responding with content of length 571
         0.001888111 "rtsp.c:2272" Connection 5: handle_pair-setup Content-Length 9
         0.016649685 "rtsp.c:2310" pair-setup response
         0.000070759 "rtsp.c:2310"   Response Code: 200.
         0.000255741 "rtsp.c:2310"   Type: "CSeq", content: "2"
         0.000017963 "rtsp.c:2310"   Type: "Server", content: "AirTunes/366.0"
         0.000015759 "rtsp.c:2310"   Type: "Content-Type", content: "application/octet-stream"
         0.000016148 "rtsp.c:2310"   No Content Plist. Content length: 409.
         0.000020371 "rtsp.c:1574" Responding with content of length 409
         0.052366981 "rtsp.c:2272" Connection 5: handle_pair-setup Content-Length 457
         0.020108908 "rtsp.c:2310" pair-setup response
         0.000048370 "rtsp.c:2310"   Response Code: 200.
         0.000016241 "rtsp.c:2310"   Type: "CSeq", content: "3"
         0.000015370 "rtsp.c:2310"   Type: "Server", content: "AirTunes/366.0"
         0.000015408 "rtsp.c:2310"   Type: "Content-Type", content: "application/octet-stream"
         0.000015740 "rtsp.c:2310"   No Content Plist. Content length: 69.
         0.000018982 "rtsp.c:1574" Responding with content of length 69
         0.001155907 "rtsp.c:2881" Connection 5: SETUP (AirPlay 2)
         0.000058648 "rtsp.c:2901" Connection 5 SETUP: No "streams" array has been found -- create an event thread and open a TCP port.
         0.000038352 "rtsp.c:2929" Connection 5: SETUP: NTP setup from 172.16.210.14:50212 ("<unknown>") to self at 172.16.210.14:7000.
         0.000026352 "rtsp.c:3138" SETUP on Connection 5: ntp stream handling is not implemented!
         0.000015685 "rtsp.c:3140" *warning: Shairport Sync can not handle NTP streams.
         0.000018945 "rtsp.c:3439"  SETUP response
         0.000014926 "rtsp.c:3439"   Response Code: 400.
         0.000014629 "rtsp.c:3439"   Type: "CSeq", content: "4"
         0.000014704 "rtsp.c:3439"   Type: "Server", content: "AirTunes/366.0"
         0.000015055 "rtsp.c:3439"   No Content Plist. Content length: 0.
         0.000644223 "rtsp.c:1376" Connection 5: Connection closed by client.
         0.000064944 "rtsp.c:5029" Connection 5: rtsp_conversation_thread_func_cleanup_function called.
         0.000023241 "rtsp.c:2688" Connection 5: TEARDOWN NTP stream connection.
         0.000018778 "rtsp.c:5064" Connection 5: terminating -- closing RTSP connection socket 8: from 172.16.210.14:50212 to self at 172.16.210.14:7000.
         0.000704037 "rtsp.c:5127" Connection 5: Closed.
         0.957680647 "rtsp.c:760" Connection 5: deleted in cleanup.
         0.000074945 "rtsp.c:781" Airplay Volume for new connections is -24.000000.
         0.000237629 "rtsp.c:5610" Connection 6: New connection from 172.16.210.14:50224 to self at 172.16.210.14:7000.
         0.000574463 "rtsp.c:2068" Connection 6: GET /info :: Content-Length 0
         0.000061630 "rtsp.c:2070" GET request
         0.000048296 "rtsp.c:2070"   Type: "CSeq", content: "1"
         0.000041982 "rtsp.c:2070"   Type: "User-Agent", content: "owntone/28.6"
         0.000041074 "rtsp.c:2070"   Type: "Client-Instance", content: "6E82B7B4BB2B5945"
         0.000040833 "rtsp.c:2070"   Type: "DACP-ID", content: "6E82B7B4BB2B5945"
         0.000039722 "rtsp.c:2070"   Type: "Active-Remote", content: "21352105"
         0.000037019 "rtsp.c:2070"   No Content Plist. Content length: 0.
         0.000036074 "rtsp.c:1712" GET /info:
         0.000033130 "rtsp.c:1712"   Type: "CSeq", content: "1"
         0.000033722 "rtsp.c:1712"   Type: "User-Agent", content: "owntone/28.6"
         0.000033944 "rtsp.c:1712"   Type: "Client-Instance", content: "6E82B7B4BB2B5945"
         0.000033500 "rtsp.c:1712"   Type: "DACP-ID", content: "6E82B7B4BB2B5945"
         0.000033093 "rtsp.c:1712"   Type: "Active-Remote", content: "21352105"
         0.000032815 "rtsp.c:1712"   No Content Plist. Content length: 0.
         0.000343740 "rtsp.c:1851" GET /info Stage 2 Response
         0.000040204 "rtsp.c:1851"   Response Code: 501.
         0.000053907 "rtsp.c:1851"   Type: "CSeq", content: "1"
         0.000040445 "rtsp.c:1851"   Type: "Server", content: "AirTunes/366.0"
         0.000031741 "rtsp.c:1851"   Type: "Content-Type", content: "application/x-apple-binary-plist"
         0.000163463 "rtsp.c:1851"   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>features</key>
        <integer>496155701824000</integer>
        <key>deviceID</key>
        <string>e4:5f:01:45:ce:a9</string>
        <key>pi</key>
        <string>2ec3dbf7-88d1-4988-af1d-a3c2662e18db</string>
        <key>name</key>
        <string>MainHiFi</string>
        <key>model</key>
        <string>Shairport Sync</string>
</dict>
</plist>
--
         0.001287092 "rtsp.c:1574" Responding with content of length 571
         0.002808815 "rtsp.c:2272" Connection 6: handle_pair-setup Content-Length 9
         0.017397130 "rtsp.c:2310" pair-setup response
         0.000051148 "rtsp.c:2310"   Response Code: 200.
         0.000020407 "rtsp.c:2310"   Type: "CSeq", content: "2"
         0.000016408 "rtsp.c:2310"   Type: "Server", content: "AirTunes/366.0"
         0.000016222 "rtsp.c:2310"   Type: "Content-Type", content: "application/octet-stream"
         0.000016537 "rtsp.c:2310"   No Content Plist. Content length: 409.
         0.000019685 "rtsp.c:1574" Responding with content of length 409
         0.049943889 "rtsp.c:2272" Connection 6: handle_pair-setup Content-Length 457
         0.020585537 "rtsp.c:2310" pair-setup response
         0.000047037 "rtsp.c:2310"   Response Code: 200.
         0.000016741 "rtsp.c:2310"   Type: "CSeq", content: "3"
         0.000015296 "rtsp.c:2310"   Type: "Server", content: "AirTunes/366.0"
         0.000015333 "rtsp.c:2310"   Type: "Content-Type", content: "application/octet-stream"
         0.000015834 "rtsp.c:2310"   No Content Plist. Content length: 69.
         0.000019333 "rtsp.c:1574" Responding with content of length 69
         0.001107019 "rtsp.c:2881" Connection 6: SETUP (AirPlay 2)
         0.000062518 "rtsp.c:2901" Connection 6 SETUP: No "streams" array has been found -- create an event thread and open a TCP port.
         0.000122907 "rtsp.c:2929" Connection 6: SETUP: NTP setup from 172.16.210.14:50224 ("<unknown>") to self at 172.16.210.14:7000.
         0.000029797 "rtsp.c:3138" SETUP on Connection 6: ntp stream handling is not implemented!
         0.000017092 "rtsp.c:3140" *warning: Shairport Sync can not handle NTP streams.
         0.000019056 "rtsp.c:3439"  SETUP response
         0.000015722 "rtsp.c:3439"   Response Code: 400.
         0.000015389 "rtsp.c:3439"   Type: "CSeq", content: "4"
         0.000013759 "rtsp.c:3439"   Type: "Server", content: "AirTunes/366.0"
         0.000013426 "rtsp.c:3439"   No Content Plist. Content length: 0.
         0.000597834 "rtsp.c:1376" Connection 6: Connection closed by client.
         0.000083259 "rtsp.c:5029" Connection 6: rtsp_conversation_thread_func_cleanup_function called.
         0.000050241 "rtsp.c:2688" Connection 6: TEARDOWN NTP stream connection.
         0.000050666 "rtsp.c:5064" Connection 6: terminating -- closing RTSP connection socket 8: from 172.16.210.14:50224 to self at 172.16.210.14:7000.
         0.000658278 "rtsp.c:5127" Connection 6: Closed.

Configuration Information.

>> Display Config Start.

From "uname -a":
 Linux myhyfy 6.2.0-1008-raspi #10-Ubuntu SMP PREEMPT Fri Jun 30 12:20:13 UTC 2023 aarch64 aarch64 aarch64 GNU/Linux

From /etc/os-release:
 Ubuntu 23.04

From /sys/firmware/devicetree/base/model:
 Raspberry Pi 4 Model B Rev 1.4

Shairport Sync Version String:
 4.2-AirPlay2-smi9-OpenSSL-Avahi-ALSA-soxr-sysconfdir:/etc

Command Line:
 shairport-sync --displayConfig

Configuration File:
 /etc/shairport-sync.conf

Configuration File Settings:
 general : 
 {
   name = "MainHiFi";
   ignore_volume_control = "yes";
 };

>> Display Config End.
>> Goodbye!

How did you install Shairport Sync?

Built from source

Check previous issues

• [X] Confirm

[mikebrady]

Thanks for the report. You should switch to the development branch of Shairport Sync – that fix is not yet in the master branch. Then let’s see how it’s going…

[spbkaizo]

Switched to the development branch - still no joy.

         0.000492667 "shairport.c:579" looking for configuration file at full path "/etc/shairport-sync.conf"
         0.000898666 "shairport.c:2251" Startup in AirPlay 2 mode, with features 0x405c4a00,0x1c340 on device "e4:5f:01:45:ce:a9".
         0.000077889 "shairport.c:2290" Version String: "4.2.1-dev-AirPlay2-smi9-alac-OpenSSL-Avahi-ALSA-soxr-sysconfdir:/etc"
         0.000019000 "shairport.c:2309" Command Line: "shairport-sync -vvv".
         0.000040889 "shairport.c:2316" libsodium initialised.
         0.000344074 "shairport.c:2341" libgcrypt initialised.
         0.000024056 "shairport.c:2345" Log Verbosity is 3.
         0.000038944 "audio_alsa.c:1003" alsa: init() -- alsa_backend_state => abm_disconnected.
         0.000017445 "audio_alsa.c:1020" alsa: alsa_maximum_stall_time of 0.200000 sec.
         0.000028185 "audio_alsa.c:1309" alsa: disable_standby_mode is "never".
         0.000015611 "audio_alsa.c:1313" alsa: disable_standby_mode_silence_threshold is 0.040000 seconds.
         0.000015426 "audio_alsa.c:1315" alsa: disable_standby_mode_silence_scan_interval is 0.004000 seconds.
         0.000026944 "audio_alsa.c:1355" alsa: output device name is "default".
         0.000290037 "shairport.c:2360" The processor is running little-endian.
         0.000025426 "shairport.c:2393" disable_resend_requests is off.
         0.000016297 "shairport.c:2394" diagnostic_drop_packet_fraction is 0.000000. A value of 0.0 means no packets will be dropped deliberately.
         0.000052260 "shairport.c:2398" statistics_requester status is 0.
         0.000017666 "shairport.c:2403" rtsp listening port is 7000.
         0.000015260 "shairport.c:2404" udp base port is 6001.
         0.000015351 "shairport.c:2405" udp port range is 10.
         0.000015112 "shairport.c:2406" player name is "MainHiFi".
         0.000015833 "shairport.c:2407" backend is "alsa".
         0.000013981 "shairport.c:2408" run_this_before_play_begins action is "(null)".
         0.000006814 "audio_alsa.c:2038" keep_dac_busy is now "no"
         0.000013574 "shairport.c:2409" run_this_after_play_ends action is "(null)".
         0.000082963 "shairport.c:2410" wait-cmd status is 0.
         0.000017426 "shairport.c:2411" run_this_before_play_begins may return output is 0.
         0.000015741 "shairport.c:2412" run_this_if_an_unfixable_error_is_detected action is "(null)".
         0.000033833 "shairport.c:2414" run_this_before_entering_active_state action is  "(null)".
         0.000016500 "shairport.c:2416" run_this_after_exiting_active_state action is  "(null)".
         0.000028074 "shairport.c:2418" active_state_timeout is  10.000000 seconds.
         0.000026575 "shairport.c:2419" mdns backend "(null)".
         0.000016092 "shairport.c:2420" userSuppliedLatency is 0.
         0.000015056 "shairport.c:2421" interpolation setting is "auto".
         0.000024333 "shairport.c:2425" interpolation soxr_delay_threshold is 30000000.
         0.000022759 "shairport.c:2426" resync time is 0.050000 seconds.
         0.000016426 "shairport.c:2427" resync recovery time is 0.100000 seconds.
         0.000015445 "shairport.c:2428" allow a session to be interrupted: 0.
         0.000015185 "shairport.c:2429" busy timeout time is 0.
         0.000014907 "shairport.c:2430" drift tolerance is 0.002000 seconds.
         0.000015593 "shairport.c:2431" password is "(null)".
         0.000014685 "shairport.c:2432" default airplay volume is: -24.000000.
         0.000016333 "shairport.c:2433" high threshold airplay volume is: -16.000000.
         0.000016167 "shairport.c:2435" check for higher-than-threshold volume for new play session is disabled.
         0.000015630 "shairport.c:2441" ignore_volume_control is 1.
         0.000015740 "shairport.c:2445" volume_max_db is not set
         0.000015093 "shairport.c:2446" volume range in dB (zero means use the range specified by the mixer): 0.
         0.000015537 "shairport.c:2448" volume_range_combined_hardware_priority (1 means hardware mixer attenuation is used first) is 0.
         0.000024241 "shairport.c:2452" playback_mode is 0 (0-stereo, 1-mono, 1-reverse_stereo, 2-both_left, 3-both_right).
         0.000015500 "shairport.c:2454" disable_synchronization is 0.
         0.000014870 "shairport.c:2455" use_mmap_if_available is 1.
         0.000014889 "shairport.c:2456" output_format automatic selection is enabled.
         0.000015148 "shairport.c:2460" output_rate automatic selection is enabled.
         0.000015296 "shairport.c:2464" audio backend desired buffer length is 0.200000 seconds.
         0.000015741 "shairport.c:2466" audio_backend_buffer_interpolation_threshold_in_seconds is 0.120000 seconds.
         0.000015778 "shairport.c:2468" audio backend latency offset is 0.000000 seconds.
         0.000015796 "shairport.c:2470" audio backend silence lead-in time is "auto".
         0.000015037 "shairport.c:2474" zeroconf regtype is "_raop._tcp".
         0.000015130 "shairport.c:2475" decoders_supported field is 3.
         0.000014944 "shairport.c:2476" use_apple_decoder is 1.
         0.000014871 "shairport.c:2477" alsa_use_hardware_mute is 0.
         0.000014815 "shairport.c:2481" no special mdns service interface was requested.
         0.000042611 "shairport.c:2484" configuration file name "/etc/shairport-sync.conf" resolves to "/etc/shairport-sync.conf".
         0.000025629 "shairport.c:2514" loudness is 0.
         0.000014889 "shairport.c:2515" loudness reference level is -20.000000
         0.000173315 "ptp-utilities.c:176" Send control message to NQPTP: "/nqptp T"
         0.000174185 "ptp-utilities.c:176" Send control message to NQPTP: "/nqptp T"
         0.005180741 "ptp-utilities.c:116" ptp_shm_interface_open with mapped_addr = 0
         0.000050407 "ptp-utilities.c:120" ptp_shm_interface_open is NULL
         0.000102241 "ptp-utilities.c:147" ptp_shm_interface_open -- success!
         0.000021408 "ptp-utilities.c:116" ptp_shm_interface_open with mapped_addr = 281473791553536
         0.000016962 "ptp-utilities.c:151" ptp_shm_interface_open -- already open!
         0.000015723 "shairport.c:2616" NQPTP is online.
         0.000375333 "activity_monitor.c:164" am_state: am_inactive
         0.007124148 "mdns_avahi.c:220" avahi: service 'E45F0145CEA9@MainHiFi' group is not yet committed.
         0.003199722 "mdns_avahi.c:268" avahi: avahi_entry_group_commit 0
         0.000468019 "mdns_avahi.c:463" avahi_dacp_monitor_start Avahi DACP monitor successfully started
         0.000464481 "mdns_avahi.c:224" avahi: service 'E45F0145CEA9@MainHiFi' group is registering.
         0.765113759 "mdns_avahi.c:191" avahi: service 'E45F0145CEA9@MainHiFi' successfully added.
         0.010430704 "rtsp.c:759" mutex_lock "&conns_lock".
         0.000057852 "common.c:1612" mutex_unlock "&conns_lock" at "rtsp.c:775".
         0.000023352 "rtsp.c:779" No active connections.
         0.000019814 "rtsp.c:786" Airplay Volume for new connections is -24.000000.
         0.000246315 "rtsp.c:5629" Connection 1: New connection from 127.0.0.1:43132 to self at 127.0.0.1:7000.
         0.000409685 "rtsp.c:5645" Successfully created RTSP receiver thread 1.
         0.000044649 "rtsp.c:696" mutex_lock "&conns_lock".
         0.000025074 "common.c:1612" mutex_unlock "&conns_lock" at "rtsp.c:718".
         0.000712240 "rtsp.c:1381" Connection 1: Connection closed by client.
         0.000065019 "rtsp.c:5345" Connection 1: Terminate RTSP connection.
         0.000029426 "rtsp.c:5048" Connection 1: rtsp_conversation_thread_func_cleanup_function called.
         0.000019833 "rtsp.c:2693" Connection 1: TEARDOWN unspecified stream connection.
         0.000019167 "rtsp.c:5062" Connection 1: terminating  -- closing timing, control and audio sockets...
         0.000018167 "rtsp.c:5083" Connection 1: terminating -- closing RTSP connection socket 8: from 127.0.0.1:43132 to self at 127.0.0.1:7000.
         0.000930259 "rtsp.c:5136" Cancel watchdog thread.
         0.000625778 "rtsp.c:5138" Join watchdog thread.
         0.001280129 "rtsp.c:644" Connection 1: Watchdog Exit.
         0.000672463 "rtsp.c:5140" Delete watchdog mutex.
         0.000057074 "rtsp.c:5146" Connection 1: Closed.
         0.001633111 "rtsp.c:759" mutex_lock "&conns_lock".
         0.000057463 "rtsp.c:762" found RTSP connection thread 1 in a non-running state.
         0.000025426 "rtsp.c:765" Connection 1: deleted in cleanup.
         0.000022759 "common.c:1612" mutex_unlock "&conns_lock" at "rtsp.c:775".
         0.000018982 "rtsp.c:786" Airplay Volume for new connections is -24.000000.
         0.000950222 "rtsp.c:5629" Connection 2: New connection from 127.0.0.1:43144 to self at 127.0.0.1:7000.
         0.000304334 "rtsp.c:5645" Successfully created RTSP receiver thread 2.
         0.000042000 "rtsp.c:696" mutex_lock "&conns_lock".
         0.000022462 "common.c:1612" mutex_unlock "&conns_lock" at "rtsp.c:718".
         0.000351630 "rtsp.c:1381" Connection 2: Connection closed by client.
         0.000038204 "rtsp.c:5345" Connection 2: Terminate RTSP connection.
         0.000020389 "rtsp.c:5048" Connection 2: rtsp_conversation_thread_func_cleanup_function called.
         0.000020000 "rtsp.c:2693" Connection 2: TEARDOWN unspecified stream connection.
         0.000020592 "rtsp.c:5062" Connection 2: terminating  -- closing timing, control and audio sockets...
         0.000015093 "rtsp.c:5083" Connection 2: terminating -- closing RTSP connection socket 8: from 127.0.0.1:43144 to self at 127.0.0.1:7000.
         0.000816315 "rtsp.c:5136" Cancel watchdog thread.
         0.000054481 "rtsp.c:5138" Join watchdog thread.
         0.000090037 "rtsp.c:644" Connection 2: Watchdog Exit.
         0.000409296 "rtsp.c:5140" Delete watchdog mutex.
         0.000060352 "rtsp.c:5146" Connection 2: Closed.
         0.000032241 "rtsp.c:759" mutex_lock "&conns_lock".
         0.002392259 "rtsp.c:762" found RTSP connection thread 2 in a non-running state.
         0.000040408 "rtsp.c:765" Connection 2: deleted in cleanup.
         0.000017778 "common.c:1612" mutex_unlock "&conns_lock" at "rtsp.c:775".
         0.000015833 "rtsp.c:786" Airplay Volume for new connections is -24.000000.
         0.000124667 "rtsp.c:5629" Connection 3: New connection from 172.16.210.14:51688 to self at 172.16.210.14:7000.
         0.000173388 "rtsp.c:5645" Successfully created RTSP receiver thread 3.
         0.000025371 "rtsp.c:696" mutex_lock "&conns_lock".
         0.000016407 "common.c:1612" mutex_unlock "&conns_lock" at "rtsp.c:718".
         0.000031574 "rtsp.c:759" mutex_lock "&conns_lock".
         0.000014685 "rtsp.c:770" Airplay Volume for connection 3 is -24.000000.
         0.000017482 "common.c:1612" mutex_unlock "&conns_lock" at "rtsp.c:775".
         0.000014111 "rtsp.c:781" One active connection.
         0.000013611 "rtsp.c:786" Airplay Volume for new connections is -24.000000.
         0.000248722 "rtsp.c:5629" Connection 4: New connection from 172.16.210.14:51698 to self at 172.16.210.14:7000.
         0.000150649 "rtsp.c:5645" Successfully created RTSP receiver thread 4.
         0.000022444 "rtsp.c:696" mutex_lock "&conns_lock".
         0.000016593 "common.c:1612" mutex_unlock "&conns_lock" at "rtsp.c:718".
         0.000742611 "rtsp.c:1381" Connection 3: Connection closed by client.
         0.000633463 "rtsp.c:5345" Connection 3: Terminate RTSP connection.
         0.000258981 "rtsp.c:5048" Connection 3: rtsp_conversation_thread_func_cleanup_function called.
         0.000152797 "rtsp.c:2693" Connection 3: TEARDOWN unspecified stream connection.
         0.000455907 "rtsp.c:5062" Connection 3: terminating  -- closing timing, control and audio sockets...
         0.000256926 "rtsp.c:5083" Connection 3: terminating -- closing RTSP connection socket 8: from 172.16.210.14:51688 to self at 172.16.210.14:7000.
         0.000297648 "rtsp.c:1381" Connection 4: Connection closed by client.
         0.000476648 "rtsp.c:5345" Connection 4: Terminate RTSP connection.
         0.000042296 "rtsp.c:5048" Connection 4: rtsp_conversation_thread_func_cleanup_function called.
         0.000021389 "rtsp.c:2693" Connection 4: TEARDOWN unspecified stream connection.
         0.000019130 "rtsp.c:5062" Connection 4: terminating  -- closing timing, control and audio sockets...
         0.000018185 "rtsp.c:5083" Connection 4: terminating -- closing RTSP connection socket 9: from 172.16.210.14:51698 to self at 172.16.210.14:7000.
         0.000148148 "rtsp.c:5136" Cancel watchdog thread.
         0.000145852 "rtsp.c:5136" Cancel watchdog thread.
         0.000027963 "rtsp.c:644" Connection 4: Watchdog Exit.
         0.000263055 "rtsp.c:5138" Join watchdog thread.
         0.000142056 "rtsp.c:5138" Join watchdog thread.
         0.000170759 "rtsp.c:5140" Delete watchdog mutex.
         0.000046019 "rtsp.c:5146" Connection 4: Closed.
         0.000178111 "rtsp.c:644" Connection 3: Watchdog Exit.
         0.000480815 "rtsp.c:5140" Delete watchdog mutex.
         0.000054481 "rtsp.c:5146" Connection 3: Closed.
         0.689324981 "shairport.c:248" soxr_delay: 2896998 nanoseconds, soxr_delay_threshold: 30 milliseconds.
         0.000074852 "shairport.c:255" "soxr" interpolation has been chosen.
         3.514474369 "rtsp.c:759" mutex_lock "&conns_lock".
         0.000060259 "rtsp.c:762" found RTSP connection thread 3 in a non-running state.
         0.000028185 "rtsp.c:765" Connection 3: deleted in cleanup.
         0.000021148 "rtsp.c:762" found RTSP connection thread 4 in a non-running state.
         0.000020222 "rtsp.c:765" Connection 4: deleted in cleanup.
         0.000021704 "common.c:1612" mutex_unlock "&conns_lock" at "rtsp.c:775".
         0.000029352 "rtsp.c:779" No active connections.
         0.000022018 "rtsp.c:786" Airplay Volume for new connections is -24.000000.
         0.000165130 "rtsp.c:5629" Connection 5: New connection from 172.16.210.14:51712 to self at 172.16.210.14:7000.
         0.000166444 "rtsp.c:5645" Successfully created RTSP receiver thread 5.
         0.000034704 "rtsp.c:696" mutex_lock "&conns_lock".
         0.000022815 "common.c:1612" mutex_unlock "&conns_lock" at "rtsp.c:718".
         0.000186444 "rtsp.c:836" msg_init message 1
         0.000049686 "rtsp.c:945" RTSP Message Received: "GET /info RTSP/1.0".
         0.000039944 "rtsp.c:976"     CSeq: 1.
         0.000046648 "rtsp.c:976"     User-Agent: owntone/28.6.
         0.000024334 "rtsp.c:976"     Client-Instance: 6E82B7B4BB2B5945.
         0.000022740 "rtsp.c:976"     DACP-ID: 6E82B7B4BB2B5945.
         0.000022463 "rtsp.c:976"     Active-Remote: 21352105.
         0.000041519 "rtsp.c:836" msg_init message 2
         0.000024000 "rtsp.c:5212" Connection 5: Received an RTSP Packet of type "GET":
         0.000022852 "rtsp.c:5214"   Type: "CSeq", content: "1"
         0.000021444 "rtsp.c:5214"   Type: "User-Agent", content: "owntone/28.6"
         0.000032445 "rtsp.c:5214"   Type: "Client-Instance", content: "6E82B7B4BB2B5945"
         0.000032759 "rtsp.c:5214"   Type: "DACP-ID", content: "6E82B7B4BB2B5945"
         0.000021778 "rtsp.c:5214"   Type: "Active-Remote", content: "21352105"
         0.000021777 "rtsp.c:5214"   No Content Plist. Content length: 0.
         0.000025537 "rtsp.c:2073" Connection 5: GET /info :: Content-Length 0
         0.000077167 "rtsp.c:2075" GET request
         0.000025315 "rtsp.c:2075"   Type: "CSeq", content: "1"
         0.000021315 "rtsp.c:2075"   Type: "User-Agent", content: "owntone/28.6"
         0.000019074 "rtsp.c:2075"   Type: "Client-Instance", content: "6E82B7B4BB2B5945"
         0.000036963 "rtsp.c:2075"   Type: "DACP-ID", content: "6E82B7B4BB2B5945"
         0.000032703 "rtsp.c:2075"   Type: "Active-Remote", content: "21352105"
         0.000036778 "rtsp.c:2075"   No Content Plist. Content length: 0.
         0.000022537 "rtsp.c:1717" GET /info:
         0.000020982 "rtsp.c:1717"   Type: "CSeq", content: "1"
         0.000035500 "rtsp.c:1717"   Type: "User-Agent", content: "owntone/28.6"
         0.000031111 "rtsp.c:1717"   Type: "Client-Instance", content: "6E82B7B4BB2B5945"
         0.000021907 "rtsp.c:1717"   Type: "DACP-ID", content: "6E82B7B4BB2B5945"
         0.000021019 "rtsp.c:1717"   Type: "Active-Remote", content: "21352105"
         0.000050148 "rtsp.c:1717"   No Content Plist. Content length: 0.
         0.000266370 "rtsp.c:1856" GET /info Stage 2 Response
         0.000031926 "rtsp.c:1856"   Response Code: 501.
         0.000025389 "rtsp.c:1856"   Type: "CSeq", content: "1"
         0.000024741 "rtsp.c:1856"   Type: "Server", content: "AirTunes/366.0"
         0.000024889 "rtsp.c:1856"   Type: "Content-Type", content: "application/x-apple-binary-plist"
         0.000111666 "rtsp.c:1856"   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>features</key>
        <integer>496155701824000</integer>
        <key>deviceID</key>
        <string>e4:5f:01:45:ce:a9</string>
        <key>pi</key>
        <string>69744b03-94ae-47ec-9e01-7c1e2c6a53ad</string>
        <key>name</key>
        <string>MainHiFi</string>
        <key>model</key>
        <string>Shairport Sync</string>
</dict>
</plist>
--
         0.001381426 "rtsp.c:5273" Connection 5: RTSP Response:
         0.000028019 "rtsp.c:5274"   Response Code: 200.
         0.000024778 "rtsp.c:5274"   Type: "CSeq", content: "1"
         0.000024629 "rtsp.c:5274"   Type: "Server", content: "AirTunes/366.0"
         0.000024593 "rtsp.c:5274"   Type: "Content-Type", content: "application/x-apple-binary-plist"

                        <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>features</key>
        <integer>496155701824000</integer>
        <key>deviceID</key>
        <string>e4:5f:01:45:ce:a9</string>
        <key>pi</key>
        <string>69744b03-94ae-47ec-9e01-7c1e2c6a53ad</string>
        <key>name</key>
        <string>MainHiFi</string>
        <key>model</key>
        <string>Shairport Sync</string>
</dict>
</plist>
--
         0.001744000 "rtsp.c:1579" Responding with content of length 571
         0.000182889 "rtsp.c:921" msg_free freed message 2
         0.000074518 "rtsp.c:921" msg_free freed message 1
         0.006853408 "rtsp.c:836" msg_init message 3
         0.000049000 "rtsp.c:945" RTSP Message Received: "POST /pair-setup RTSP/1.0".
         0.000027148 "rtsp.c:976"     CSeq: 2.
         0.000017389 "rtsp.c:976"     User-Agent: owntone/28.6.
         0.000017000 "rtsp.c:976"     Client-Instance: 6E82B7B4BB2B5945.
         0.000017055 "rtsp.c:976"     DACP-ID: 6E82B7B4BB2B5945.
         0.000017408 "rtsp.c:976"     Active-Remote: 21352105.
         0.000017092 "rtsp.c:976"     Content-Type: application/octet-stream.
         0.000017482 "rtsp.c:976"     X-Apple-HKP: 4.
         0.000016815 "rtsp.c:976"     Content-Length: 9.
         0.000021240 "rtsp.c:836" msg_init message 4
         0.000017278 "rtsp.c:5212" Connection 5: Received an RTSP Packet of type "POST":
         0.000017593 "rtsp.c:5214"   Type: "CSeq", content: "2"
         0.000016166 "rtsp.c:5214"   Type: "User-Agent", content: "owntone/28.6"
         0.000016093 "rtsp.c:5214"   Type: "Client-Instance", content: "6E82B7B4BB2B5945"
         0.000016333 "rtsp.c:5214"   Type: "DACP-ID", content: "6E82B7B4BB2B5945"
         0.000015945 "rtsp.c:5214"   Type: "Active-Remote", content: "21352105"
         0.000035574 "rtsp.c:5214"   Type: "Content-Type", content: "application/octet-stream"
         0.000030315 "rtsp.c:5214"   Type: "X-Apple-HKP", content: "4"
         0.000016759 "rtsp.c:5214"   Type: "Content-Length", content: "9"
         0.000016704 "rtsp.c:5214"   No Content Plist. Content length: 9.
         0.000021000 "rtsp.c:2277" Connection 5: handle_pair-setup Content-Length 9
         0.017631111 "rtsp.c:2315" pair-setup response
         0.000049129 "rtsp.c:2315"   Response Code: 200.
         0.000017297 "rtsp.c:2315"   Type: "CSeq", content: "2"
         0.000015407 "rtsp.c:2315"   Type: "Server", content: "AirTunes/366.0"
         0.000015519 "rtsp.c:2315"   Type: "Content-Type", content: "application/octet-stream"
         0.000016648 "rtsp.c:2315"   No Content Plist. Content length: 409.
         0.000015833 "rtsp.c:5273" Connection 5: RTSP Response:
         0.000015630 "rtsp.c:5274"   Response Code: 200.
         0.000014926 "rtsp.c:5274"   Type: "CSeq", content: "2"
         0.000014722 "rtsp.c:5274"   Type: "Server", content: "AirTunes/366.0"
         0.000015055 "rtsp.c:5274"   Type: "Content-Type", content: "application/octet-stream"
         0.000015612 "rtsp.c:5274"   No Content Plist. Content length: 409.
         0.000017944 "rtsp.c:1579" Responding with content of length 409
         0.000095148 "rtsp.c:921" msg_free freed message 4
         0.000041963 "rtsp.c:921" msg_free freed message 3
         0.049920778 "rtsp.c:836" msg_init message 5
         0.000053074 "rtsp.c:945" RTSP Message Received: "POST /pair-setup RTSP/1.0".
         0.000022000 "rtsp.c:976"     CSeq: 3.
         0.000016963 "rtsp.c:976"     User-Agent: owntone/28.6.
         0.000016037 "rtsp.c:976"     Client-Instance: 6E82B7B4BB2B5945.
         0.000016352 "rtsp.c:976"     DACP-ID: 6E82B7B4BB2B5945.
         0.000015740 "rtsp.c:976"     Active-Remote: 21352105.
         0.000015667 "rtsp.c:976"     Content-Type: application/octet-stream.
         0.000017019 "rtsp.c:976"     X-Apple-HKP: 4.
         0.000015889 "rtsp.c:976"     Content-Length: 457.
         0.000020000 "rtsp.c:836" msg_init message 6
         0.000016685 "rtsp.c:5212" Connection 5: Received an RTSP Packet of type "POST":
         0.000016518 "rtsp.c:5214"   Type: "CSeq", content: "3"
         0.000015260 "rtsp.c:5214"   Type: "User-Agent", content: "owntone/28.6"
         0.000015222 "rtsp.c:5214"   Type: "Client-Instance", content: "6E82B7B4BB2B5945"
         0.000014889 "rtsp.c:5214"   Type: "DACP-ID", content: "6E82B7B4BB2B5945"
         0.000047240 "rtsp.c:5214"   Type: "Active-Remote", content: "21352105"
         0.000032260 "rtsp.c:5214"   Type: "Content-Type", content: "application/octet-stream"
         0.000016685 "rtsp.c:5214"   Type: "X-Apple-HKP", content: "4"
         0.000015204 "rtsp.c:5214"   Type: "Content-Length", content: "457"
         0.000015611 "rtsp.c:5214"   No Content Plist. Content length: 457.
         0.000019703 "rtsp.c:2277" Connection 5: handle_pair-setup Content-Length 457
         0.019022686 "rtsp.c:2315" pair-setup response
         0.000046462 "rtsp.c:2315"   Response Code: 200.
         0.000019556 "rtsp.c:2315"   Type: "CSeq", content: "3"
         0.000017482 "rtsp.c:2315"   Type: "Server", content: "AirTunes/366.0"
         0.000017574 "rtsp.c:2315"   Type: "Content-Type", content: "application/octet-stream"
         0.000017888 "rtsp.c:2315"   No Content Plist. Content length: 69.
         0.000017834 "rtsp.c:5273" Connection 5: RTSP Response:
         0.000017259 "rtsp.c:5274"   Response Code: 200.
         0.000021167 "rtsp.c:5274"   Type: "CSeq", content: "3"
         0.000029389 "rtsp.c:5274"   Type: "Server", content: "AirTunes/366.0"
         0.000023685 "rtsp.c:5274"   Type: "Content-Type", content: "application/octet-stream"
         0.000020852 "rtsp.c:5274"   No Content Plist. Content length: 69.
         0.000021518 "rtsp.c:1579" Responding with content of length 69
         0.000150685 "rtsp.c:921" msg_free freed message 6
         0.000028426 "rtsp.c:921" msg_free freed message 5
         0.000963389 "rtsp.c:836" msg_init message 7
         0.000046093 "rtsp.c:945" RTSP Message Received: "SETUP rtsp://172.16.210.14/3723604573 RTSP/1.0".
         0.000031333 "rtsp.c:976"     CSeq: 4.
         0.000021056 "rtsp.c:976"     User-Agent: owntone/28.6.
         0.000014685 "rtsp.c:976"     Client-Instance: 6E82B7B4BB2B5945.
         0.000014389 "rtsp.c:976"     DACP-ID: 6E82B7B4BB2B5945.
         0.000026185 "rtsp.c:976"     Active-Remote: 21352105.
         0.000019537 "rtsp.c:976"     Content-Type: application/x-apple-binary-plist.
         0.000015556 "rtsp.c:976"     Content-Length: 177.
         0.000018833 "rtsp.c:836" msg_init message 8
         0.000015018 "rtsp.c:5212" Connection 5: Received an RTSP Packet of type "SETUP":
         0.000015741 "rtsp.c:5214"   Type: "CSeq", content: "4"
         0.000018741 "rtsp.c:5214"   Type: "User-Agent", content: "owntone/28.6"
         0.000018000 "rtsp.c:5214"   Type: "Client-Instance", content: "6E82B7B4BB2B5945"
         0.000018518 "rtsp.c:5214"   Type: "DACP-ID", content: "6E82B7B4BB2B5945"
         0.000017760 "rtsp.c:5214"   Type: "Active-Remote", content: "21352105"
         0.000017518 "rtsp.c:5214"   Type: "Content-Type", content: "application/x-apple-binary-plist"
         0.000017371 "rtsp.c:5214"   Type: "Content-Length", content: "177"
         0.000040925 "rtsp.c:5214"   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>deviceID</key>
        <string>6E:82:B7:B4:BB:2B:59:45</string>
        <key>sessionUUID</key>
        <string>56243447-9773-4D87-96B2-E2EE9B028298</string>
        <key>timingPort</key>
        <integer>50001</integer>
        <key>timingProtocol</key>
        <string>NTP</string>
</dict>
</plist>
--
         0.000127500 "rtsp.c:2886" Connection 5: SETUP (AirPlay 2)
         0.000023130 "rtsp.c:2906" Connection 5 SETUP: No "streams" array has been found -- create an event thread and open a TCP port.
         0.000026741 "rtsp.c:2934" Connection 5: SETUP: NTP setup from 172.16.210.14:51712 ("<unknown>") to self at 172.16.210.14:7000.
         0.000026129 "rtsp.c:3143" SETUP on Connection 5: ntp stream handling is not implemented!
         0.000016130 "rtsp.c:3145" *warning: Shairport Sync can not handle NTP streams.
         0.000017722 "rtsp.c:3444"  SETUP response
         0.000015500 "rtsp.c:3444"   Response Code: 400.
         0.000014667 "rtsp.c:3444"   Type: "CSeq", content: "4"
         0.000014796 "rtsp.c:3444"   Type: "Server", content: "AirTunes/366.0"
         0.000024889 "rtsp.c:3444"   No Content Plist. Content length: 0.
         0.000016463 "rtsp.c:5273" Connection 5: RTSP Response:
         0.000015278 "rtsp.c:5274"   Response Code: 400.
         0.000014796 "rtsp.c:5274"   Type: "CSeq", content: "4"
         0.000015037 "rtsp.c:5274"   Type: "Server", content: "AirTunes/366.0"
         0.000015019 "rtsp.c:5274"   No Content Plist. Content length: 0.
         0.000300500 "rtsp.c:921" msg_free freed message 8
         0.000044518 "rtsp.c:921" msg_free freed message 7
         0.001563389 "rtsp.c:1381" Connection 5: Connection closed by client.
         0.000086593 "rtsp.c:5345" Connection 5: Terminate RTSP connection.
         0.000028815 "rtsp.c:5048" Connection 5: rtsp_conversation_thread_func_cleanup_function called.
         0.000161481 "rtsp.c:2693" Connection 5: TEARDOWN NTP stream connection.
         0.000037593 "rtsp.c:5062" Connection 5: terminating  -- closing timing, control and audio sockets...
         0.000019240 "rtsp.c:5083" Connection 5: terminating -- closing RTSP connection socket 8: from 172.16.210.14:51712 to self at 172.16.210.14:7000.
         0.000506111 "rtsp.c:5136" Cancel watchdog thread.
         0.000084371 "rtsp.c:5138" Join watchdog thread.
         0.000239704 "rtsp.c:644" Connection 5: Watchdog Exit.
         0.000139055 "rtsp.c:5140" Delete watchdog mutex.
         0.000054333 "rtsp.c:5146" Connection 5: Closed.

[spbkaizo]

So this was in fact an issue with my owntone.conf. Leaving this here for others to find.

I had defined the output in owntone.conf thusly:

airplay "MainHiFi" {
    exclude = false
    permanent = true
    reconnect = true
    raop_disable = true
}

Commenting, or marking 'raop_disable=false' allows the streams to start.

        10.536751382 "rtsp.c:2934" Connection 5: SETUP: NTP setup from 172.16.210.14:40582 ("<unknown>") to self at 172.16.210.14:7000.
         0.000103389 "rtsp.c:3143" SETUP on Connection 5: ntp stream handling is not implemented!
         0.000030815 "rtsp.c:3145" *warning: Shairport Sync can not handle NTP streams.
        13.027949529 "rtsp.c:2934" Connection 6: SETUP: NTP setup from 172.16.210.14:39860 ("<unknown>") to self at 172.16.210.14:7000.
         0.000057797 "rtsp.c:3143" SETUP on Connection 6: ntp stream handling is not implemented!
         0.000021240 "rtsp.c:3145" *warning: Shairport Sync can not handle NTP streams.
      1084.236292984 "rtsp.c:4515" Connection 11: Classic AirPlay connection from 127.0.0.1:56318 to self at 127.0.0.1:7000.
         0.007276203 "rtsp.c:1668" Connection 11: Classic AirPlay connection from 127.0.0.1:56318 to self at 127.0.0.1:7000.
         1.004980407 "audio_alsa.c:1769" alsa: SND_PCM_STATE_* 3, error -32 ("Broken pipe") writing 8820 samples to alsa device.
         0.009439185 "audio_alsa.c:1751" alsa: recovering from a previous underrun.

[github-actions[bot]]

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.