Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

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

Closed
1 task done
spbkaizo opened this issue Jul 15, 2023 · 4 comments
Closed
1 task done

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

spbkaizo opened this issue Jul 15, 2023 · 4 comments
Labels
information Stale

Comments

@spbkaizo
Copy link

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

  • Confirm
@mikebrady
Copy link
Owner

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
Copy link
Author

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
Copy link
Author

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.

@mikebrady mikebrady changed the title [Problem]: ShairPort-Sync as an output [OwnTone]: ShairPort-Sync as an output Jul 16, 2023
@mikebrady mikebrady changed the title [OwnTone]: ShairPort-Sync as an output [OwnTone]: ShairPort-Sync as an output – owntone.conf advisory. Jul 16, 2023
@github-actions
Copy link

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.

@github-actions github-actions bot added the Stale label Sep 15, 2023
@ralph-ralph0 ralph-ralph0 mentioned this issue Sep 26, 2023
Closed
2 tasks
@github-actions github-actions bot closed this as not planned Won't fix, can't repro, duplicate, stale Dec 23, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
information Stale
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@mikebrady @spbkaizo