Cannot connect to shairport-sync AirPlay 2
gearhead opened this issue · 1 comments
gearhead commented
Please try to provide the following:
- steps to reproduce and/or logging of the error
- version of owntone 28.9
- platform Rpi 64 bit Bookworm
Trying to connect via AirPlay 2 to shairport-sync
shairport-sync version
4.3.3-AirPlay2-smi10-alac-OpenSSL-Avahi-ALSA-jack-pa-pw-stdout-pipe-soxr-metadata-mqtt-dbus-sysconfdir:/etc
Add 3 lines to /etc/shairport-sync to enable AirPlay 2:
port = 7000;
airplay_device_id_offset = 2;
regtype = "_airplay._tcp";
Select the output in Settings -> Remotes and Outputs
The slider returns and the UI shows:
Request failed (status: 500 Internal Server Error http://192.168.2.200:3689/api/outputs/237747341274684/toggle)
The debug log shows:
Jun 27 14:07:58 kitchenrune owntone[39884]: [2024-06-27 14:07:58] [DEBUG] player: Speaker enable: 'Pi5' (id=237747341274684)
Jun 27 14:07:58 kitchenrune owntone[39884]: [2024-06-27 14:07:58] [DEBUG] player: Registered callback to device_activate_cb with id 0 (device 0x5594e06c30, Pi5)
Jun 27 14:07:58 kitchenrune owntone[39884]: [2024-06-27 14:07:58] [DEBUG] player: Number of active callbacks: 1
Jun 27 14:07:58 kitchenrune owntone[39884]: [2024-06-27 14:07:58] [DEBUG] player: Subscription request for quality 44100/16/2 (now 1 subscribers)
Jun 27 14:07:58 kitchenrune owntone[39884]: [2024-06-27 14:07:58] [DEBUG] xcode: Selected encoder 'ALAC (Apple Lossless Audio Codec)'
Jun 27 14:07:58 kitchenrune owntone[39884]: [2024-06-27 14:07:58] [DEBUG] ffmpeg: tb:1/44100 samplefmt:s16 samplerate:44100 chlayout:stereo
Jun 27 14:07:58 kitchenrune owntone[39884]: [2024-06-27 14:07:58] [DEBUG] xcode: Created 'abuffer' filter: 'time_base=1/44100:sample_rate=44100:sample_fmt=s16:channel_layout=stereo'
Jun 27 14:07:58 kitchenrune owntone[39884]: [2024-06-27 14:07:58] [DEBUG] xcode: Created 'aformat' filter: 'sample_fmts=s16p:sample_rates=44100:channel_layouts=stereo'
Jun 27 14:07:58 kitchenrune owntone[39884]: [2024-06-27 14:07:58] [DEBUG] xcode: Created 'abuffersink' filter: ''
Jun 27 14:07:58 kitchenrune owntone[39884]: [2024-06-27 14:07:58] [DEBUG] ffmpeg: auto-inserting filter 'auto_aresample_0' between the filter 'abuffer' and the filter 'aformat'
Jun 27 14:07:58 kitchenrune owntone[39884]: [2024-06-27 14:07:58] [DEBUG] ffmpeg: ch:2 chl:stereo fmt:s16 r:44100Hz -> ch:2 chl:stereo fmt:s16p r:44100Hz
Jun 27 14:07:58 kitchenrune owntone[39884]: [2024-06-27 14:07:58] [DEBUG] airplay: device_start: Sending GET /info to 'Pi5'
Jun 27 14:07:58 kitchenrune owntone[39884]: [2024-06-27 14:07:58] [DEBUG] airplay: Local address: 192.168.2.200 (LL: no) port 38272
Jun 27 14:07:58 kitchenrune owntone[39884]: [2024-06-27 14:07:58] [DEBUG] airplay: Status flags from 'Pi5' was 4: cable attached 1, one time pairing 0, password 0, PIN 0
Jun 27 14:07:58 kitchenrune owntone[39884]: [2024-06-27 14:07:58] [DEBUG] airplay: device_start: Sending pair setup 1 to 'Pi5'
Jun 27 14:07:59 kitchenrune owntone[39884]: [2024-06-27 14:07:59] [DEBUG] airplay: device_start: Sending pair setup 2 to 'Pi5'
Jun 27 14:07:59 kitchenrune owntone[39884]: [2024-06-27 14:07:59] [ WARN] player: Output delay detected: player is 14 ticks behind, catching up
Jun 27 14:07:59 kitchenrune owntone[39884]: [2024-06-27 14:07:59] [DEBUG] airplay: Ciphering setup of 'Pi5' completed succesfully, now using encrypted mode
Jun 27 14:07:59 kitchenrune owntone[39884]: [2024-06-27 14:07:59] [DEBUG] airplay: pair_success: Sending SETUP (session) to 'Pi5'
Jun 27 14:07:59 kitchenrune owntone[39884]: [2024-06-27 14:07:59] [ WARN] airplay: Response to SETUP (session) from 'Pi5' was negative, proceeding anyway (400 Bad Request)
Jun 27 14:07:59 kitchenrune owntone[39884]: [2024-06-27 14:07:59] [ WARN] airplay: Unexpected reply to SETUP (session) from 'Pi5'
Jun 27 14:07:59 kitchenrune owntone[39884]: [2024-06-27 14:07:59] [DEBUG] player: Callback request received, id is 0
Jun 27 14:07:59 kitchenrune owntone[39884]: [2024-06-27 14:07:59] [DEBUG] player: Unsubscription request for quality 44100/16/2 (now 0 subscribers)
Jun 27 14:07:59 kitchenrune owntone[39884]: [2024-06-27 14:07:59] [DEBUG] player: Making deferred callback to device_activate_cb, id was 0
Jun 27 14:07:59 kitchenrune owntone[39884]: [2024-06-27 14:07:59] [DEBUG] player: Callback from AirPlay 2 device Pi5 to device_activate_cb (status -1)
Jun 27 14:07:59 kitchenrune owntone[39884]: [2024-06-27 14:07:59] [ LOG] player: The AirPlay 2 device 'Pi5' failed to activate
Jun 27 14:07:59 kitchenrune owntone[39884]: [2024-06-27 14:07:59] [DEBUG] main: Command has 0 pending events
Jun 27 14:07:59 kitchenrune owntone[39884]: [2024-06-27 14:07:59] [DEBUG] player: Status update - status: 4, events: 12, caller: speaker_generic_bh
Jun 27 14:07:59 kitchenrune owntone[39884]: [2024-06-27 14:07:59] [DEBUG] mpd: Asynchronous listener callback called with event type 12.
Jun 27 14:07:59 kitchenrune owntone[39884]: [2024-06-27 14:07:59] [DEBUG] mpd: Notify clients waiting for idle results: 12
Jun 27 14:07:59 kitchenrune owntone[39884]: [2024-06-27 14:07:59] [ LOG] web: JSON api request failed with error code 500 (/api/outputs/237747341274684/toggle)
Jun 27 14:07:59 kitchenrune owntone[39884]: [2024-06-27 14:07:59] [DEBUG] web: notify callback reason: 71
Jun 27 14:07:59 kitchenrune owntone[39884]: [2024-06-27 14:07:59] [DEBUG] web: notify callback reason: 11
Jun 27 14:07:59 kitchenrune owntone[39884]: [2024-06-27 14:07:59] [DEBUG] web: notify callback reply: 12
Jun 27 14:07:59 kitchenrune owntone[39884]: [2024-06-27 14:07:59] [DEBUG] web: JSON API request '/api/player' in worker thread 39891
If I comment the 3 lines shairport-sync.conf and try again, it connects and plays, but as airplay 1, of course.
Jun 27 14:26:07 kitchenrune owntone[39884]: [2024-06-27 14:26:07] [DEBUG] player: Speaker enable: 'Pi5' (id=237747341274682)
Jun 27 14:26:07 kitchenrune owntone[39884]: [2024-06-27 14:26:07] [DEBUG] player: Registered callback to device_activate_cb with id 0 (device 0x5594f35da0, Pi5)
Jun 27 14:26:07 kitchenrune owntone[39884]: [2024-06-27 14:26:07] [DEBUG] player: Number of active callbacks: 1
Jun 27 14:26:07 kitchenrune owntone[39884]: [2024-06-27 14:26:07] [DEBUG] player: Subscription request for quality 44100/16/2 (now 1 subscribers)
Jun 27 14:26:07 kitchenrune owntone[39884]: [2024-06-27 14:26:07] [DEBUG] xcode: Selected encoder 'ALAC (Apple Lossless Audio Codec)'
Jun 27 14:26:07 kitchenrune owntone[39884]: [2024-06-27 14:26:07] [DEBUG] ffmpeg: tb:1/44100 samplefmt:s16 samplerate:44100 chlayout:stereo
Jun 27 14:26:07 kitchenrune owntone[39884]: [2024-06-27 14:26:07] [DEBUG] xcode: Created 'abuffer' filter: 'time_base=1/44100:sample_rate=44100:sample_fmt=s16:channel_layout=stereo'
Jun 27 14:26:07 kitchenrune owntone[39884]: [2024-06-27 14:26:07] [DEBUG] xcode: Created 'aformat' filter: 'sample_fmts=s16p:sample_rates=44100:channel_layouts=stereo'
Jun 27 14:26:07 kitchenrune owntone[39884]: [2024-06-27 14:26:07] [DEBUG] xcode: Created 'abuffersink' filter: ''
Jun 27 14:26:07 kitchenrune owntone[39884]: [2024-06-27 14:26:07] [DEBUG] ffmpeg: auto-inserting filter 'auto_aresample_0' between the filter 'abuffer' and the filter 'aformat'
Jun 27 14:26:07 kitchenrune owntone[39884]: [2024-06-27 14:26:07] [DEBUG] ffmpeg: ch:2 chl:stereo fmt:s16 r:44100Hz -> ch:2 chl:stereo fmt:s16p r:44100Hz
Jun 27 14:26:07 kitchenrune owntone[39884]: [2024-06-27 14:26:07] [DEBUG] raop: device_start: Sending OPTIONS to 'Pi5'
Jun 27 14:26:07 kitchenrune owntone[39884]: [2024-06-27 14:26:07] [DEBUG] raop: startup_options: Sending ANNOUNCE to 'Pi5'
Jun 27 14:26:07 kitchenrune owntone[39884]: [2024-06-27 14:26:07] [DEBUG] raop: Local address: 192.168.2.200 (LL: no) port 58872
Jun 27 14:26:07 kitchenrune owntone[39884]: [2024-06-27 14:26:07] [ INFO] raop: Setting up AirPlay session 4172357229 (192.168.2.200 -> 192.168.2.201)
Jun 27 14:26:07 kitchenrune owntone[39884]: [2024-06-27 14:26:07] [DEBUG] raop: startup_announce: Sending SETUP to 'Pi5'
Jun 27 14:26:07 kitchenrune owntone[39884]: [2024-06-27 14:26:07] [DEBUG] raop: Negotiated AirTunes v2 UDP streaming session 1; ports s=6003 c=6001 t=6002
Jun 27 14:26:07 kitchenrune owntone[39884]: [2024-06-27 14:26:07] [DEBUG] raop: startup_setup: Sending RECORD to 'Pi5'
Jun 27 14:26:07 kitchenrune owntone[39884]: [2024-06-27 14:26:07] [DEBUG] raop: RTP-Info is seq=57392;rtptime=1376423351
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] raop: RAOP audio latency is 11025
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] raop: volume_internal: Sending SET_PARAMETER to 'Pi5'
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] raop: send_progress: Sending SET_PARAMETER to 'Pi5'
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] raop: send_text: Sending SET_PARAMETER to 'Pi5'
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] misc: Connecting to 'RAOP data' at 192.168.2.201 (port 6003)
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] player: Callback request received, id is 0
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] player: Making deferred callback to device_activate_cb, id was 0
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] player: Callback from AirPlay 1 device Pi5 to device_activate_cb (status 2)
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] player: Registered callback to device_streaming_cb with id 0 (device 0x5594f35da0, Pi5)
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] player: Number of active callbacks: 1
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] main: Command has 0 pending events
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] player: Status update - status: 4, events: 12, caller: speaker_generic_bh
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] mpd: Asynchronous listener callback called with event type 12.
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] player: 0. Active callback: device_streaming_cb
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] mpd: Notify clients waiting for idle results: 12
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] web: notify callback reason: 71
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] web: notify callback reason: 11
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] web: notify callback reply: 12
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] raop: Start sync packet sent to 'Pi5': cur_pos=1376420001, cur_ts=1942.195906740, clock=1942.206395488, rtptime=1376508183
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] web: JSON API request '/api/player' in worker thread 39891
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] web: JSON API request '/api/outputs' in worker thread 39890
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] player: Player status: playing
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] web: JSON API request '/api/library/tracks/1' in worker thread 39891
Jun 27 14:26:09 kitchenrune owntone[39884]: [2024-06-27 14:26:09] [DEBUG] db: Running query 'SELECT value FROM admin a WHERE a.key = 'db_modified';'
Jun 27 14:26:10 kitchenrune owntone[39884]: [2024-06-27 14:26:10] [DEBUG] mdns: Avahi Resolver: resolved service 'Pi5' type '_airplay._tcp' proto 0/0, host pi5.local, address 192.168.2.201
Jun 27 14:26:10 kitchenrune owntone[39884]: [2024-06-27 14:26:10] [DEBUG] mdns: Connection test to 192.168.2.201:7000 completed successfully
Jun 27 14:26:10 kitchenrune owntone[39884]: [2024-06-27 14:26:10] [DEBUG] airplay: Event for AirPlay device 'Pi5' (port 7000, id d83addd2ae3a, Active-Remote 3721571898)
Jun 27 14:26:10 kitchenrune owntone[39884]: [2024-06-27 14:26:10] [ INFO] airplay: Adding AirPlay device 'Pi5': features 0x405FCA00,0x1C340, type Other, address 192.168.2.201:7000
Jun 27 14:26:10 kitchenrune owntone[39884]: [2024-06-27 14:26:10] [DEBUG] player: Ignoring type AirPlay 2 for device 'Pi5', will use type AirPlay 1
Jun 27 14:26:11 kitchenrune owntone[39884]: [2024-06-27 14:26:11] [DEBUG] dacp: DACP request '/ctrl-int/1/getproperty?properties=dmcp.volume' in worker thread 39888
Jun 27 14:26:11 kitchenrune owntone[39884]: [2024-06-27 14:26:11] [DEBUG] player: Player status: playing
It seems that shairport-sync is not configured correctly. Is this the critical bit that Shairport-sync is not responding correctly?
Jun 27 14:07:59 kitchenrune owntone[39884]: [2024-06-27 14:07:59] [ WARN] airplay: Response to SETUP (session) from 'Pi5' was negative, proceeding anyway (400 Bad Request)
Jun 27 14:07:59 kitchenrune owntone[39884]: [2024-06-27 14:07:59] [ WARN] airplay: Unexpected reply to SETUP (session) from 'Pi5'
I verified that it will connect and play to a roku-stick running airplay2, so it is not owntone, per se, just interoperability with shairport-sync. Maybe I should put this over on that issue list instead?
ejurgensen commented
This problem arises because you are forcing shairport-sync to use Airplay 2 with that config. If you just leave it at the default it will support both Airplay 1 and 2, and then all clients should work.
OwnTone can't use Airplay 2 for shairport-sync because OwnTone only supports ntp timing, and in Airplay 2 mode shairport-sync only supports ptp. But it's not really a great loss because in this use case Airplay 1 will do fine.