search

postlund / pyatv

A client library for Apple TV and AirPlay devices
https://pyatv.dev
MIT License
824 stars 87 forks source link

encryption keys not supported by legacy auth #2124

Open TechShift007 opened 9 months ago

TechShift007 commented 9 months ago

Describe the bug

When I try and "Browse Media" from HA in order to Airplay to the Apple TV from HA I get the following error within HA "encryption keys not supported by legacy auth". I am currently running HA 2023.8.0 and Supervisor 2023.07.1. I have tried removing the Apple TV and repairing it with all the codes and it pairs 100%. If I change the source to an app that is on the Apple TV it works. It seems that the Airplay authentication is stuck on legacy. I have an Apple TV 4K and it also wont Airplay with the same legacy auth error.

Error log

uniqueIdentifier: "DB91C0CD-A1FC-4BD2-97C9-910AA2C7504C"
2023-08-04 11:55:18.002 DEBUG (MainThread) [pyatv.core.protocol] Dispatching message with type 37 to <bound method MrpPower._update_power_state of <pyatv.protocols.mrp.MrpPower object at 0x7f51f40ecbd0>>
2023-08-04 11:55:18.002 DEBUG (MainThread) [pyatv.core.protocol] Dispatching message with type 37 to <bound method MrpAudio._update_output_devices of <pyatv.protocols.mrp.MrpAudio object at 0x7f51f40ed9d0>>
2023-08-04 11:55:18.002 DEBUG (MainThread) [pyatv.auth.hap_channel] Sending data (Encrypted=2000ebb6c3a40d9c29971a3fd0f797196a2429fb9a9f4dc1aa57a28b064c90959c7d002441577926492f313d981c1dd95af8)
2023-08-04 11:55:18.003 DEBUG (MainThread) [pyatv.core.protocol] Dispatching message with type UpdatedState.OutputDevices to <bound method FacadeAudio._output_devices_changed of <pyatv.core.facade.FacadeAudio object at 0x7f520696cad0>>
2023-08-04 11:55:19.104 DEBUG (MainThread) [pyatv.core.protocol] Sending periodic heartbeat 1998 (AirPlay:192.168.1.127)
2023-08-04 11:55:19.104 DEBUG (MainThread) [pyatv.support.http] Sending RTSP/1.0 message: b'POST /feedback RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nCSeq: 2001\r\nDACP-ID: C192FE7B5CE535FA\r\nActive-Remote: 1715454294\r\nClient-Instance: C192FE7B5CE535FA\r\n\r\n'
2023-08-04 11:55:19.115 DEBUG (MainThread) [pyatv.support.http] Received: b'RTSP/1.0 200 OK\r\nDate: Fri, 04 Aug 2023 09:55:19 GMT\r\nContent-Length: 55\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/695.5.1\r\nCSeq: 2001\r\n\r\nbplist00\xd1\x01\x02Wstreams\xa0\x08\x0b\x13\x00\x00\x00\x00\x00\x00\x01\x01\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x14'
2023-08-04 11:55:19.120 DEBUG (MainThread) [pyatv.support.http] Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'Date': 'Fri, 04 Aug 2023 09:55:19 GMT', 'Content-Length': '55', 'Content-Type': 'application/x-apple-binary-plist', 'Server': 'AirTunes/695.5.1', 'CSeq': '2001'}, body=b'bplist00\xd1\x01\x02Wstreams\xa0\x08\x0b\x13\x00\x00\x00\x00\x00\x00\x01\x01\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x14'):
2023-08-04 11:55:19.121 DEBUG (MainThread) [pyatv.core.protocol] Got heartbeat 1998 (AirPlay:192.168.1.127)
2023-08-04 11:55:21.122 DEBUG (MainThread) [pyatv.core.protocol] Sending periodic heartbeat 1999 (AirPlay:192.168.1.127)
2023-08-04 11:55:21.122 DEBUG (MainThread) [pyatv.support.http] Sending RTSP/1.0 message: b'POST /feedback RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nCSeq: 2002\r\nDACP-ID: C192FE7B5CE535FA\r\nActive-Remote: 1715454294\r\nClient-Instance: C192FE7B5CE535FA\r\n\r\n'
2023-08-04 11:55:21.126 DEBUG (MainThread) [pyatv.support.http] Received: b'RTSP/1.0 200 OK\r\nDate: Fri, 04 Aug 2023 09:55:21 GMT\r\nContent-Length: 55\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/695.5.1\r\nCSeq: 2002\r\n\r\nbplist00\xd1\x01\x02Wstreams\xa0\x08\x0b\x13\x00\x00\x00\x00\x00\x00\x01\x01\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x14'
2023-08-04 11:55:21.127 DEBUG (MainThread) [pyatv.support.http] Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'Date': 'Fri, 04 Aug 2023 09:55:21 GMT', 'Content-Length': '55', 'Content-Type': 'application/x-apple-binary-plist', 'Server': 'AirTunes/695.5.1', 'CSeq': '2002'}, body=b'bplist00\xd1\x01\x02Wstreams\xa0\x08\x0b\x13\x00\x00\x00\x00\x00\x00\x01\x01\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x14'):
2023-08-04 11:55:21.127 DEBUG (MainThread) [pyatv.core.protocol] Got heartbeat 1999 (AirPlay:192.168.1.127)
2023-08-04 11:55:23.128 DEBUG (MainThread) [pyatv.core.protocol] Sending periodic heartbeat 2000 (AirPlay:192.168.1.127)
2023-08-04 11:55:23.128 DEBUG (MainThread) [pyatv.support.http] Sending RTSP/1.0 message: b'POST /feedback RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nCSeq: 2003\r\nDACP-ID: C192FE7B5CE535FA\r\nActive-Remote: 1715454294\r\nClient-Instance: C192FE7B5CE535FA\r\n\r\n'
2023-08-04 11:55:23.134 DEBUG (MainThread) [pyatv.support.http] Received: b'RTSP/1.0 200 OK\r\nDate: Fri, 04 Aug 2023 09:55:23 GMT\r\nContent-Length: 55\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/695.5.1\r\nCSeq: 2003\r\n\r\nbplist00\xd1\x01\x02Wstreams\xa0\x08\x0b\x13\x00\x00\x00\x00\x00\x00\x01\x01\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x14'
2023-08-04 11:55:23.135 DEBUG (MainThread) [pyatv.support.http] Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'Date': 'Fri, 04 Aug 2023 09:55:23 GMT', 'Content-Length': '55', 'Content-Type': 'application/x-apple-binary-plist', 'Server': 'AirTunes/695.5.1', 'CSeq': '2003'}, body=b'bplist00\xd1\x01\x02Wstreams\xa0\x08\x0b\x13\x00\x00\x00\x00\x00\x00\x01\x01\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x14'):
2023-08-04 11:55:23.135 DEBUG (MainThread) [pyatv.core.protocol] Got heartbeat 2000 (AirPlay:192.168.1.127)
2023-08-04 11:55:25.136 DEBUG (MainThread) [pyatv.core.protocol] Sending periodic heartbeat 2001 (AirPlay:192.168.1.127)
2023-08-04 11:55:25.136 DEBUG (MainThread) [pyatv.support.http] Sending RTSP/1.0 message: b'POST /feedback RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nCSeq: 2004\r\nDACP-ID: C192FE7B5CE535FA\r\nActive-Remote: 1715454294\r\nClient-Instance: C192FE7B5CE535FA\r\n\r\n'
2023-08-04 11:55:25.141 DEBUG (MainThread) [pyatv.support.http] Received: b'RTSP/1.0 200 OK\r\nDate: Fri, 04 Aug 2023 09:55:25 GMT\r\nContent-Length: 55\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/695.5.1\r\nCSeq: 2004\r\n\r\nbplist00\xd1\x01\x02Wstreams\xa0\x08\x0b\x13\x00\x00\x00\x00\x00\x00\x01\x01\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x14'
2023-08-04 11:55:25.142 DEBUG (MainThread) [pyatv.support.http] Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'Date': 'Fri, 04 Aug 2023 09:55:25 GMT', 'Content-Length': '55', 'Content-Type': 'application/x-apple-binary-plist', 'Server': 'AirTunes/695.5.1', 'CSeq': '2004'}, body=b'bplist00\xd1\x01\x02Wstreams\xa0\x08\x0b\x13\x00\x00\x00\x00\x00\x00\x01\x01\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x14'):
2023-08-04 11:55:25.142 DEBUG (MainThread) [pyatv.core.protocol] Got heartbeat 2001 (AirPlay:192.168.1.127)
2023-08-04 11:55:25.417 DEBUG (MainThread) [homeassistant.components.apple_tv.media_player] Streaming https://edge.iono.fm/xice/ecr_live_medium.aac via RAOP
2023-08-04 11:55:25.417 DEBUG (MainThread) [pyatv.core.facade] Takeover (<class 'pyatv.interface.Audio'>, <class 'pyatv.interface.Metadata'>, <class 'pyatv.interface.PushUpdater'>, <class 'pyatv.interface.RemoteControl'>) by Protocol.RAOP
2023-08-04 11:55:25.422 DEBUG (MainThread) [pyatv.support.http] Connected to 192.168.1.127
2023-08-04 11:55:25.423 DEBUG (MainThread) [pyatv.protocols.raop] Using AirPlay version AirPlayMajorVersion.AirPlayV2
2023-08-04 11:55:25.424 DEBUG (MainThread) [pyatv.protocols.raop.stream_client] Initializing RTSP with encryption=21, metadata=7
2023-08-04 11:55:25.424 DEBUG (MainThread) [pyatv.protocols.raop.stream_client] Update play settings to 44100/2/16bit
2023-08-04 11:55:25.429 DEBUG (MainThread) [pyatv.protocols.raop.stream_client] Local ports: control=53161, timing=43579
2023-08-04 11:55:25.429 DEBUG (MainThread) [pyatv.support.http] Sending RTSP/1.0 message: b'GET /info RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nCSeq: 0\r\nDACP-ID: EE217CAA6E4969E7\r\nActive-Remote: 2605865061\r\nClient-Instance: EE217CAA6E4969E7\r\n\r\n'
2023-08-04 11:55:25.446 DEBUG (MainThread) [pyatv.support.http] Received: b"RTSP/1.0 200 OK\r\nDate: Fri, 04 Aug 2023 09:55:25 GMT\r\nContent-Length: 1039\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/695.5.1\r\nCSeq: 0\r\n\r\nbplist00\xdf\x10\x17\x01\x02\x03\x04\x05\x06\x07\x08\t\n\x0b\x0c\r\x0e\x0f\x10\x11\x12\x13\x14\x15\x16\x17\x18\x19\x1a &!()*+,- /019:;<=>?SpsiRvv_\x10\x14playbackCapabilities_\x10\x15canRecordScreenStream[statusFlags_\x10\x18keepAliveSendStatsAsBody_\x10\x0fprotocolVersion_\x10\x11volumeControlTypeTname]senderAddressXdeviceIDRpi^screenDemoMode]initialVolumeZfeaturesEx_\x10\x10supportedFormats]sourceVersionUmodelRpkZmacAddress^osBuildVersion_\x10\x15receiverHDRCapabilityXfeatures_\x10$C0E9C116-1F15-4A0A-8603-FA617376A047\x10\x02\xd5\x1b\x1c\x1d\x1e\x1f !!!!_\x10\x12supportsOfflineHLS_\x10\x1dsupportsUIForAudioOnlyContent_\x10\x15supportsInterstitials_\x10\x15supportsFPSSecureStop_\x10!supportsAirPlayVideoWithSharePlay\x08\t\t\t\t\x08\x12\x00\x01\x86D\tS1.1\x10\x04_\x10\x10Bedroom Apple TV_\x10\x13192.168.1.120:51496_\x10\x11C8:69:CD:53:14:FB_\x10$2b5256c7-0cf3-4099-af75-8f6de03d3c0e\x08#\x00\x00\x00\x00\x00\x00\x00\x00_\x10\x0f1d9/Wt5fFbwooQQ\xd423456778_\x10\x15lowLatencyAudioStream\\screenStream[audioStream\\bufferStream\x10\x00\x12\x01D\x08\x00\x137\xc0\x01\x80\x00\xe0\x00\x00W695.5.1ZAppleTV5,3O\x10 xRJ\x9a\xd7~\xe7\xbf\x18\tm@]\xf7\xb7tU\xc4(\x1f\xe4\\i}\xa1a\x03\x10\x1fc\x06r_\x10\x11C8:69:CD:53:14:F9U20M73W1080p60\x13\xbc\x15_\xdeZ\x7f\xdf\xd5\x00\x08\x009\x00=\x00@\x00W\x00o\x00{\x00\x96\x00\xa8\x00\xbc\x00\xc1\x00\xcf\x00\xd8\x00\xdb\x00\xea\x00\xf8\x01\x03\x01\x16\x01$\x01*\x01-\x018\x01G\x01_\x01h\x01\x8f\x01\x91\x01\x9c\x01\xb1\x01\xd1\x01\xe9\x02\x01\x02%\x02&\x02'\x02(\x02)\x02*\x02+\x020\x021\x025\x027\x02J\x02`\x02t\x02\x9b\x02\x9c\x02\xa5\x02\xb7\x02\xc0\x02\xd8\x02\xe5\x02\xf1\x02\xfe\x03\x00\x03\x05\x03\x0e\x03\x16\x03!\x03D\x03X\x03^\x03f\x00\x00\x00\x00\x00\x00\x02\x01\x00\x00\x00\x00\x00\x00\x00@\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x03o"
2023-08-04 11:55:25.447 DEBUG (MainThread) [pyatv.support.http] Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'Date': 'Fri, 04 Aug 2023 09:55:25 GMT', 'Content-Length': '1039', 'Content-Type': 'application/x-apple-binary-plist', 'Server': 'AirTunes/695.5.1', 'CSeq': '0'}, body=b"bplist00\xdf\x10\x17\x01\x02\x03\x04\x05\x06\x07\x08\t\n\x0b\x0c\r\x0e\x0f\x10\x11\x12\x13\x14\x15\x16\x17\x18\x19\x1a &!()*+,- /019:;<=>?SpsiRvv_\x10\x14playbackCapabilities_\x10\x15canRecordScreenStream[statusFlags_\x10\x18keepAliveSendStatsAsBody_\x10\x0fprotocolVersion_\x10\x11volumeControlTypeTname]senderAddressXdeviceIDRpi^screenDemoMode]initialVolumeZfeaturesEx_\x10\x10supportedFormats]sourceVersionUmodelRpkZmacAddress^osBuildVersion_\x10\x15receiverHDRCapabilityXfeatures_\x10$C0E9C116-1F15-4A0A-8603-FA617376A047\x10\x02\xd5\x1b\x1c\x1d\x1e\x1f !!!!_\x10\x12supportsOfflineHLS_\x10\x1dsupportsUIForAudioOnlyContent_\x10\x15supportsInterstitials_\x10\x15supportsFPSSecureStop_\x10!supportsAirPlayVideoWithSharePlay\x08\t\t\t\t\x08\x12\x00\x01\x86D\tS1.1\x10\x04_\x10\x10Bedroom Apple TV_\x10\x13192.168.1.120:51496_\x10\x11C8:69:CD:53:14:FB_\x10$2b5256c7-0cf3-4099-af75-8f6de03d3c0e\x08#\x00\x00\x00\x00\x00\x00\x00\x00_\x10\x0f1d9/Wt5fFbwooQQ\xd423456778_\x10\x15lowLatencyAudioStream\\screenStream[audioStream\\bufferStream\x10\x00\x12\x01D\x08\x00\x137\xc0\x01\x80\x00\xe0\x00\x00W695.5.1ZAppleTV5,3O\x10 xRJ\x9a\xd7~\xe7\xbf\x18\tm@]\xf7\xb7tU\xc4(\x1f\xe4\\i}\xa1a\x03\x10\x1fc\x06r_\x10\x11C8:69:CD:53:14:F9U20M73W1080p60\x13\xbc\x15_\xdeZ\x7f\xdf\xd5\x00\x08\x009\x00=\x00@\x00W\x00o\x00{\x00\x96\x00\xa8\x00\xbc\x00\xc1\x00\xcf\x00\xd8\x00\xdb\x00\xea\x00\xf8\x01\x03\x01\x16\x01$\x01*\x01-\x018\x01G\x01_\x01h\x01\x8f\x01\x91\x01\x9c\x01\xb1\x01\xd1\x01\xe9\x02\x01\x02%\x02&\x02'\x02(\x02)\x02*\x02+\x020\x021\x025\x027\x02J\x02`\x02t\x02\x9b\x02\x9c\x02\xa5\x02\xb7\x02\xc0\x02\xd8\x02\xe5\x02\xf1\x02\xfe\x03\x00\x03\x05\x03\x0e\x03\x16\x03!\x03D\x03X\x03^\x03f\x00\x00\x00\x00\x00\x00\x02\x01\x00\x00\x00\x00\x00\x00\x00@\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x03o"):
2023-08-04 11:55:25.448 DEBUG (MainThread) [pyatv.protocols.raop.stream_client] Updated info parameters to: {'psi': 'C0E9C116-1F15-4A0A-8603-FA617376A047', 'vv': 2, 'playbackCapabilities': {'supportsOfflineHLS': False, 'supportsUIForAudioOnlyContent': True, 'supportsInterstitials': True, 'supportsFPSSecureStop': True, 'supportsAirPlayVideoWithSharePlay': True}, 'canRecordScreenStream': False, 'statusFlags': 99908, 'keepAliveSendStatsAsBody': True, 'protocolVersion': '1.1', 'volumeControlType': 4, 'name': 'Bedroom Apple TV', 'senderAddress': '192.168.1.120:51496', 'deviceID': 'C8:69:CD:53:14:FB', 'pi': '2b5256c7-0cf3-4099-af75-8f6de03d3c0e', 'screenDemoMode': False, 'initialVolume': 0.0, 'featuresEx': '1d9/Wt5fFbwooQQ', 'supportedFormats': {'lowLatencyAudioStream': 0, 'screenStream': 21235712, 'audioStream': 21235712, 'bufferStream': 4017212516896604160}, 'sourceVersion': '695.5.1', 'model': 'AppleTV5,3', 'pk': b'xRJ\x9a\xd7~\xe7\xbf\x18\tm@]\xf7\xb7tU\xc4(\x1f\xe4\\i}\xa1a\x03\x10\x1fc\x06r', 'macAddress': 'C8:69:CD:53:14:F9', 'osBuildVersion': '20M73', 'receiverHDRCapability': '1080p60', 'features': -4893900011462467627}
2023-08-04 11:55:25.448 DEBUG (MainThread) [pyatv.protocols.airplay.auth] Setting up new AirPlay Pair-Verify procedure with type AuthenticationType.Legacy
2023-08-04 11:55:25.448 DEBUG (MainThread) [pyatv.protocols.airplay.srp] Authentication keys (Private=302ce6b6e630d4886646373cab9148412e4914ec0370fd5c5e8688d71de043f5, Public=c1cdad643e02207104efab938d0fb18bba137523a6c58e471121ae393d32b150)
2023-08-04 11:55:25.449 DEBUG (MainThread) [pyatv.protocols.airplay.srp] Verification keys (Private=302ce6b6e630d4886646373cab9148412e4914ec0370fd5c5e8688d71de043f5, Public=c3b0d76d02f6cd5627d3c8e1d7e6bb9350deccad87f14b7dc07800c501c8ae0e)
2023-08-04 11:55:25.449 DEBUG (MainThread) [pyatv.support.http] Sending HTTP/1.1 message: b"POST /pair-verify HTTP/1.1\r\nContent-Length: 68\r\nUser-Agent: AirPlay/320.20\r\nConnection: keep-alive\r\nContent-Type: application/octet-stream\r\n\r\n\x01\x00\x00\x00\xc3\xb0\xd7m\x02\xf6\xcdV'\xd3\xc8\xe1\xd7\xe6\xbb\x93P\xde\xcc\xad\x87\xf1K}\xc0x\x00\xc5\x01\xc8\xae\x0e\xc1\xcd\xadd>\x02 q\x04\xef\xab\x93\x8d\x0f\xb1\x8b\xba\x13u#\xa6\xc5\x8eG\x11!\xae9=2\xb1P"
2023-08-04 11:55:25.476 DEBUG (MainThread) [pyatv.support.http] Received: b"HTTP/1.1 200 OK\r\nDate: Fri, 04 Aug 2023 09:55:25 GMT\r\nContent-Length: 96\r\nContent-Type: application/octet-stream\r\nServer: AirTunes/695.5.1\r\n\r\n+U#q=P\x81BM\xbd\xb8\x07\xfd\x88\xb7\xea\x06\xc5\xb8\xb0\xb0\xb3\xeaM\x16$}\xba\xb7\xdd\xc8\x12\x97\xa9\xa1\x16\x12\xa3^\xaaE \x8b5\xb3\xf7'\x94\xb1(\xf9\x12\x98C\xd9`\xb6,\xd9\x10;\xf8T4\x7f\x8ery\xd3Y\x9c\x19\xed\x1a\xbb\xb1`\xae5\xb9\xbc7\xfc4>M\x00\xe8\xab\xaa\xe8H\xf8=\x10:"
2023-08-04 11:55:25.476 DEBUG (MainThread) [pyatv.support.http] Got HTTP response: HttpResponse(protocol='HTTP', version='1.1', code=200, message='OK', headers={'Date': 'Fri, 04 Aug 2023 09:55:25 GMT', 'Content-Length': '96', 'Content-Type': 'application/octet-stream', 'Server': 'AirTunes/695.5.1'}, body=b"+U#q=P\x81BM\xbd\xb8\x07\xfd\x88\xb7\xea\x06\xc5\xb8\xb0\xb0\xb3\xeaM\x16$}\xba\xb7\xdd\xc8\x12\x97\xa9\xa1\x16\x12\xa3^\xaaE \x8b5\xb3\xf7'\x94\xb1(\xf9\x12\x98C\xd9`\xb6,\xd9\x10;\xf8T4\x7f\x8ery\xd3Y\x9c\x19\xed\x1a\xbb\xb1`\xae5\xb9\xbc7\xfc4>M\x00\xe8\xab\xaa\xe8H\xf8=\x10:"):
2023-08-04 11:55:25.476 DEBUG (MainThread) [pyatv.protocols.airplay.srp] Verify (Data=97a9a11612a35eaa45208b35b3f72794b128f9129843d960b62cd9103bf854347f8e7279d3599c19ed1abbb160ae35b9bc37fc343e4d00e8abaae848f83d103a, PublicSecret=2b5523713d5081424dbdb807fd88b7ea06c5b8b0b0b3ea4d16247dbab7ddc812)
2023-08-04 11:55:25.477 DEBUG (MainThread) [pyatv.protocols.airplay.srp] Shared secret (Secret=9cfbc17201738d718ebc2a3e9c48d66027976d34cd719cd9a54459b848b09153)
2023-08-04 11:55:25.477 DEBUG (MainThread) [pyatv.protocols.airplay.srp] Pair-Verify-AES (IV=f96be91204488eeb37ba90129782c823, Key=a60ec9793750b3f17630b09cccc23ab7)
2023-08-04 11:55:25.480 DEBUG (MainThread) [pyatv.protocols.airplay.srp] Signature (Signature=cf9d7a9ff5c3372043ed2de9ddef318e41b51f2e45eb78cbed58834c51df98eef5c65d366165c14a15724fcfcda76c94822832fd63ae0663f65e111e1508d6a7)
2023-08-04 11:55:25.480 DEBUG (MainThread) [pyatv.support.http] Sending HTTP/1.1 message: b'POST /pair-verify HTTP/1.1\r\nContent-Length: 68\r\nUser-Agent: AirPlay/320.20\r\nConnection: keep-alive\r\nContent-Type: application/octet-stream\r\n\r\n\x00\x00\x00\x00\xcf\x9dz\x9f\xf5\xc37 C\xed-\xe9\xdd\xef1\x8eA\xb5\x1f.E\xebx\xcb\xedX\x83LQ\xdf\x98\xee\xf5\xc6]6ae\xc1J\x15rO\xcf\xcd\xa7l\x94\x82(2\xfdc\xae\x06c\xf6^\x11\x1e\x15\x08\xd6\xa7'
2023-08-04 11:55:25.486 DEBUG (MainThread) [pyatv.support.http] Received: b'HTTP/1.1 200 OK\r\nDate: Fri, 04 Aug 2023 09:55:25 GMT\r\nContent-Length: 0\r\nContent-Type: application/octet-stream\r\nServer: AirTunes/695.5.1\r\n\r\n'
2023-08-04 11:55:25.486 DEBUG (MainThread) [pyatv.support.http] Got HTTP response: HttpResponse(protocol='HTTP', version='1.1', code=200, message='OK', headers={'Date': 'Fri, 04 Aug 2023 09:55:25 GMT', 'Content-Length': '0', 'Content-Type': 'application/octet-stream', 'Server': 'AirTunes/695.5.1'}, body=b''):
2023-08-04 11:55:25.487 DEBUG (MainThread) [pyatv.support.http] Sending RTSP/1.0 message: b'SETUP rtsp://192.168.1.120/1246107179 RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nContent-Length: 455\r\nCSeq: 1\r\nDACP-ID: EE217CAA6E4969E7\r\nActive-Remote: 2605865061\r\nClient-Instance: EE217CAA6E4969E7\r\nContent-Type: application/x-apple-binary-plist\r\n\r\nbplist00\xdf\x10\x0f\x01\x02\x03\x04\x05\x06\x07\x08\t\n\x0b\x0c\r\x0e\x0f\x10\x11\x12\x10\x13\x14\x15\x16\x17\x11\x18\x19\x11\x1a\x1bXdeviceID_\x10\x18groupContainsGroupLeader_\x10\x14isMultiSelectAirPlayZmacAddressUmodelTname^osBuildVersionVosNameYosVersion_\x10\x13senderSupportsRelay[sessionUUID]sourceVersion_\x10\x16statsCollectionEnabledZtimingPort^timingProtocol_\x10\x11AA:BB:CC:DD:EE:FF\x08\tZiPhone14,3UpyatvU20F66YiPhone OST16.5_\x10$95AE3DF5-A47A-4371-8D74-4FBF95D92F8AW690.7.1\x11\xaa;SNTP\x00\x08\x00)\x002\x00M\x00d\x00o\x00u\x00z\x00\x89\x00\x90\x00\x9a\x00\xb0\x00\xbc\x00\xca\x00\xe3\x00\xee\x00\xfd\x01\x11\x01\x12\x01\x13\x01\x1e\x01$\x01*\x014\x019\x01`\x01h\x01k\x00\x00\x00\x00\x00\x00\x02\x01\x00\x00\x00\x00\x00\x00\x00\x1c\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x01o'
2023-08-04 11:55:25.628 DEBUG (MainThread) [pyatv.protocols.companion.connection] Received data (Data=08000035a865d1c62495d348c07728147426365cc4d4d340c89fbb47c97dc02551d7b9e2a24acf6d0bdf1d799f9abbd351206c3725ce037ebd)
2023-08-04 11:55:25.628 DEBUG (MainThread) [pyatv.protocols.companion.protocol] Received frame FrameType.E_OPACK: b'\xe4B_iD_iMCB_x3;\x13\xa2\xc4\x00\x00\x00\x00B_c\xe1D_mcF1?\x01B_t\t'
2023-08-04 11:55:25.628 DEBUG (MainThread) [pyatv.protocols.companion.protocol] Process incoming OPACK frame (FrameType.E_OPACK): {'_i': '_iMC', '_x': 3298956091, '_c': {'_mcF': 319}, '_t': 1}
2023-08-04 11:55:25.628 DEBUG (MainThread) [pyatv.protocols.companion.protocol] Received event: {'_i': '_iMC', '_x': 3298956091, '_c': {'_mcF': 319}, '_t': 1}
2023-08-04 11:55:25.628 DEBUG (MainThread) [pyatv.protocols.companion.api] Got event _iMC from device: {'_mcF': 319}
2023-08-04 11:55:25.628 DEBUG (MainThread) [pyatv.core.protocol] Dispatching message with type _iMC to <bound method CompanionFeatures._handle_control_flag_update of <pyatv.protocols.companion.CompanionFeatures object at 0x7f51f422c4d0>>
2023-08-04 11:55:25.629 DEBUG (MainThread) [pyatv.core.protocol] Dispatching message with type _iMC to <bound method CompanionAudio._handle_control_flag_update of <pyatv.protocols.companion.CompanionAudio object at 0x7f51f422ebd0>>
2023-08-04 11:55:25.629 DEBUG (MainThread) [pyatv.protocols.companion] Updated media control flags to 319
2023-08-04 11:55:25.629 DEBUG (MainThread) [pyatv.protocols.companion] Volume control changed, updating volume
2023-08-04 11:55:25.629 DEBUG (MainThread) [pyatv.protocols.companion.protocol] Exchange OPACK: {'_i': '_mcc', '_t': 2, '_c': {'_mcc': 5}, '_x': 18723}
2023-08-04 11:55:25.629 DEBUG (MainThread) [pyatv.protocols.companion.protocol] Send OPACK: {'_i': '_mcc', '_t': 2, '_c': {'_mcc': 5}, '_x': 18723}
2023-08-04 11:55:25.629 DEBUG (MainThread) [pyatv.protocols.companion.connection] >> Send data (Data=e4425f69445f6d6363425f740a425f63e1a10d425f78312349, FrameType=08)
2023-08-04 11:55:25.629 DEBUG (MainThread) [pyatv.protocols.companion.connection] >> Send (Encrypted=045f76268090d2d16c7ce00aff9864a34a46fe65ea2173ab0d168c1d05ee011babb8f0e43d6a4f991b, Header=08000029)
2023-08-04 11:55:25.677 DEBUG (MainThread) [pyatv.protocols.companion.connection] Received data (Data=08000029766cfb5fbb5251b3dea457e3b6cf49121b84e3289108b9418b19e397312b57c2580afa120fd52b9533)
2023-08-04 11:55:25.678 DEBUG (MainThread) [pyatv.protocols.companion.protocol] Received frame FrameType.E_OPACK: b'\xe3B_c\xe1D_vol5\x00\x00\x80?B_t\x0bB_x1#I'
2023-08-04 11:55:25.678 DEBUG (MainThread) [pyatv.protocols.companion.protocol] Process incoming OPACK frame (FrameType.E_OPACK): {'_c': {'_vol': 1.0}, '_t': 3, '_x': 18723}
2023-08-04 11:55:25.678 DEBUG (MainThread) [pyatv.protocols.companion] Volume changed to 100.000000
2023-08-04 11:55:25.678 DEBUG (MainThread) [pyatv.core.protocol] Dispatching message with type UpdatedState.Volume to <bound method FacadeAudio._volume_changed of <pyatv.core.facade.FacadeAudio object at 0x7f520696cad0>>
2023-08-04 11:55:25.678 DEBUG (MainThread) [pyatv.core.protocol] Dispatching message with type UpdatedState.Volume to <bound method RaopAudio._volume_changed of <pyatv.protocols.raop.RaopAudio object at 0x7f51f422e710>>
2023-08-04 11:55:25.679 DEBUG (MainThread) [pyatv.protocols.raop] Protocol Companion changed volume to 100.000000
2023-08-04 11:55:25.702 DEBUG (MainThread) [pyatv.auth.hap_channel] Received data (Data=2000cd8406f7627723ec9c57476b9a165abfd97ccf5d311ecb6a42f9f4fa47cbba9978e688f52c0b06af337245644b1c28278900f348feb77efaa7e5cc34628c15181a93ee5a5b67828027876888d7302284a09ba4f3e2f7f0f65377d15c22541d1ce5e9d8279a730df38a346c60242788cb74a52b7511a25278cd99befc1622371253bf77236d1d985ad54c74b9bce72cc18deae1fd153e4847f87760e5826793718e99b89eaf7e5decb9727f93e617b197bfb116ae6e089d887ab64908d57bcf1a363fb0381ee1317598fa32)
2023-08-04 11:55:25.703 DEBUG (MainThread) [pyatv.protocols.airplay.mrp_connection] << Receive: Protobuf: type: SET_NOW_PLAYING_CLIENT_MESSAGE
[setNowPlayingClientMessage] {
  client {
    processIdentifier: 161
    bundleIdentifier: "com.apple.TVAirPlay"
  }
}
uniqueIdentifier: "0BD6B46B-7A88-4E57-8339-EAE57E070941"
2023-08-04 11:55:25.703 DEBUG (MainThread) [pyatv.core.protocol] Dispatching message with type 46 to <bound method PlayerStateManager._handle_set_now_playing_client of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x7f51f40ecd10>>
2023-08-04 11:55:25.704 DEBUG (MainThread) [pyatv.auth.hap_channel] Sending data (Encrypted=20002cc5ab0d5b71428fd2ac440d5f3de94703ccf94e23870666b0568790a7df3c1fe9652fd53d0b1d6cabe966a2bc01968c)
2023-08-04 11:55:25.704 DEBUG (MainThread) [pyatv.protocols.mrp.player_state] Active client is now com.apple.TVAirPlay
2023-08-04 11:55:25.749 DEBUG (MainThread) [pyatv.support.http] Received: b'RTSP/1.0 200 OK\r\nDate: Fri, 04 Aug 2023 09:55:25 GMT\r\nContent-Length: 59\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/695.5.1\r\nCSeq: 1\r\n\r\nbplist00\xd1\x01\x02YeventPort\x11\xc05\x08\x0b\x15\x00\x00\x00\x00\x00\x00\x01\x01\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x18'
2023-08-04 11:55:25.749 DEBUG (MainThread) [pyatv.support.http] Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'Date': 'Fri, 04 Aug 2023 09:55:25 GMT', 'Content-Length': '59', 'Content-Type': 'application/x-apple-binary-plist', 'Server': 'AirTunes/695.5.1', 'CSeq': '1'}, body=b'bplist00\xd1\x01\x02YeventPort\x11\xc05\x08\x0b\x15\x00\x00\x00\x00\x00\x00\x01\x01\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x18'):
2023-08-04 11:55:25.750 DEBUG (MainThread) [pyatv.protocols.raop.protocols.airplayv2] Setup response body: {'eventPort': 49205}
2023-08-04 11:55:25.750 DEBUG (MainThread) [pyatv.core.facade] Release (<class 'pyatv.interface.Audio'>, <class 'pyatv.interface.Metadata'>, <class 'pyatv.interface.PushUpdater'>, <class 'pyatv.interface.RemoteControl'>) by Protocol.RAOP
2023-08-04 11:55:25.751 DEBUG (MainThread) [pyatv.protocols.raop.stream_client] Control connection lost (None)
2023-08-04 11:55:25.751 DEBUG (MainThread) [pyatv.support.http] Connection closed
2023-08-04 11:55:25.751 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [139990008383040] encryption keys not supported by legacy auth
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 226, in handle_call_service
    await hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1974, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2011, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 235, in handle_service
    return await service.entity_service_call(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 870, in entity_service_call
    response_data = await _handle_entity_call(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 942, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/apple_tv/media_player.py", line 300, in async_play_media
    await self.atv.stream.stream_file(media_id)
  File "/usr/local/lib/python3.11/site-packages/pyatv/core/facade.py", line 370, in stream_file
    await self.relay("stream_file")(
  File "/usr/local/lib/python3.11/site-packages/pyatv/protocols/raop/__init__.py", line 353, in stream_file
    await client.initialize(self.core.service.properties)
  File "/usr/local/lib/python3.11/site-packages/pyatv/protocols/raop/stream_client.py", line 375, in initialize
    await self._protocol.setup(self.timing_client.port, self.control_client.port)
  File "/usr/local/lib/python3.11/site-packages/pyatv/protocols/raop/protocols/airplayv2.py", line 74, in setup
    transport, _ = await setup_channel(
                   ^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/pyatv/auth/hap_channel.py", line 88, in setup_channel
    out_key, in_key = verifier.encryption_keys(salt, output_info, input_info)
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/pyatv/protocols/airplay/auth/legacy.py", line 112, in encryption_keys
    raise exceptions.NotSupportedError(
pyatv.exceptions.NotSupportedError: encryption keys not supported by legacy auth
2023-08-04 11:55:25.785 DEBUG (MainThread) [pyatv.auth.hap_channel] Received data (Data=0004418058feea149cf727053332a4ac4d3c81e53677fde19841160ebe03d9d69114f5cfcee2b35d127bc3616a9c1525f2feb3b97919198d99a58014c9d89d3d500fc90f58b459e6c16d97e64c8d20f2919bd4865b24f8205b1a74549c110882947d2c345c915b669065f508cf45a003446dc99a2621654d35f81fa92724da2e4619d5a2ec191faff5652c606b0fab16523b799d096531642b457473f29ad4491ccd6b5162f6c8ff0ad3b89bb82e6b9c96c030867d768eb6fb038ef1631b75d06fb9daef57bd018801a7486bf4a6bbac3ee874d584eea652e2f51c7168576d614d30c913d76ce8d07476412d3961447679d8998cf838159237d4c21cbceb4...)
2023-08-04 11:55:25.786 DEBUG (MainThread) [pyatv.protocols.airplay.channels] Got message on event channel: HttpRequest(method='POST', path='/command', protocol='RTSP', version='1.0', headers={'CSeq': '17', 'Content-Length': '1485', 'Content-Type': 'application/x-apple-binary-plist'}, body=b'bplist00\xd2\x01\x02\x03\x04TtypeUvalueZupdateInfo\xdf\x10\x18\x05\x06\x07\x08\t\n\x0b\x0c\r\x0e\x0f\x10\x11\x12\x13\x14\x15\x16\x17\x18\x19\x1a\x1b\x1c\x1d\x1e\x1f%+&-./012%4567?@ABCDESpsiRvv_\x10\x14playbackCapabilities_\x10\x15canRecordScreenStream[statusFlags_\x10\x18keepAliveSendStatsAsBody_\x10\x0fprotocolVersionTname_\x10\x11volumeControlType]senderAddressXdeviceIDRpi^screenDemoMode]initialVolumeZfeaturesExZtxtAirPlay_\x10\x10supportedFormats]sourceVersionUmodelRpkZmacAddress^osBuildVersion_\x10\x15receiverHDRCapabilityXfeatures_\x10$C0E9C116-1F15-4A0A-8603-FA617376A047\x10\x02\xd5 !"#$%&&&&_\x10\x12supportsOfflineHLS_\x10\x1dsupportsUIForAudioOnlyContent_\x10\x15supportsInterstitials_\x10\x15supportsFPSSecureStop_\x10!supportsAirPlayVideoWithSharePlay\x08\t\t\t\t\x08\x12\x00\x03\x86D\tS1.1_\x10\x10Bedroom Apple TV\x10\x04_\x10\x13192.168.1.120:40302_\x10\x11C8:69:CD:53:14:FB_\x10$2b5256c7-0cf3-4099-af75-8f6de03d3c0e\x08#\x00\x00\x00\x00\x00\x00\x00\x00_\x10\x0f1d9/Wt5fFbwooQQO\x11\x01\x86\x05acl=0\x18btaddr=00:00:00:00:00:00\x1adeviceid=C8:69:CD:53:14:FB\x13fex=1d9/Wt5fFbwooQQ\x1efeatures=0x5A7FDFD5,0xBC155FDE\rflags=0x38644(gid=DCD8B165-2F9C-466D-B06E-16ED42338C48\x05igl=1\x06gcgl=1\x10model=AppleTV5,3\rprotovers=1.1\'pi=2b5256c7-0cf3-4099-af75-8f6de03d3c0e(psi=C0E9C116-1F15-4A0A-8603-FA617376A047Cpk=78524a9ad77ee7bf18096d405df7b77455c4281fe45c697da16103101f630672\x0fsrcvers=695.5.1\x0bosvers=16.6\x04vv=2\xd489:;<==>_\x10\x15lowLatencyAudioStream\\screenStream[audioStream\\bufferStream\x10\x00\x12\x01D\x08\x00\x137\xc0\x01\x80\x00\xe0\x00\x00W695.5.1ZAppleTV5,3O\x10 xRJ\x9a\xd7~\xe7\xbf\x18\tm@]\xf7\xb7tU\xc4(\x1f\xe4\\i}\xa1a\x03\x10\x1fc\x06r_\x10\x11C8:69:CD:53:14:F9U20M73W1080p60\x13\xbc\x15_\xdeZ\x7f\xdf\xd5\x00\x08\x00\r\x00\x12\x00\x18\x00#\x00V\x00Z\x00]\x00t\x00\x8c\x00\x98\x00\xb3\x00\xc5\x00\xca\x00\xde\x00\xec\x00\xf5\x00\xf8\x01\x07\x01\x15\x01 \x01+\x01>\x01L\x01R\x01U\x01`\x01o\x01\x87\x01\x90\x01\xb7\x01\xb9\x01\xc4\x01\xd9\x01\xf9\x02\x11\x02)\x02M\x02N\x02O\x02P\x02Q\x02R\x02S\x02X\x02Y\x02]\x02p\x02r\x02\x88\x02\x9c\x02\xc3\x02\xc4\x02\xcd\x02\xdf\x04i\x04r\x04\x8a\x04\x97\x04\xa3\x04\xb0\x04\xb2\x04\xb7\x04\xc0\x04\xc8\x04\xd3\x04\xf6\x05\n\x05\x10\x05\x18\x00\x00\x00\x00\x00\x00\x02\x01\x00\x00\x00\x00\x00\x00\x00F\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x05!')
2023-08-04 11:55:25.786 DEBUG (MainThread) [pyatv.auth.hap_channel] Sending data (Encrypted=5c007f141fa51ea72f228ca319c79c956da4f7c4f1473c662738daa5dc54c41f0bdf9aefcb0f861bbdd2c41c243e40985a96edf244eefa882b6337a1849f5a9631de53b922a26eda2481ca9e971bb7e08cfb60b43e806995c8bab068d77395640a97d1ddf3ac849fdc331b944106)
2023-08-04 11:55:25.792 DEBUG (MainThread) [pyatv.auth.hap_channel] Received data (Data=0004a4bfbdcc344567c7165135677a8c344aad386f11e2ddbdb177056cde12d16b11952312c96d48f84a00297e3a901f3f8ebced7eec7dc51dab05ec5081183e0beb15de97c7ebe75d7074b815fdf409ebb6ab1b946c476497c4ac088b51a4f320d5346614a0ee93c9e4ec0a677fa5b7fbc1f8540129e235579317d42f5367557cc6ba2c2d5843c97e38d1436c19ae7acef2a7e40b76eb03bad79b373f5af9bae1a71ca34c7003fa5645402bad16f39e9a2bc1f9c7384c22f4e5e34380c7f6030131c3f1c85d40573d1036c35da27bccfd42f92dc50d3f92017f8969651b17c351d1ae29f41eff65ce630fa9d10d275679feb0c91a6b16ea3344f0f865315...)
2023-08-04 11:55:25.793 DEBUG (MainThread) [pyatv.protocols.airplay.channels] Got message on event channel: HttpRequest(method='POST', path='/command', protocol='RTSP', version='1.0', headers={'CSeq': '18', 'Content-Length': '1485', 'Content-Type': 'application/x-apple-binary-plist'}, body=b'bplist00\xd2\x01\x02\x03\x04TtypeUvalueZupdateInfo\xdf\x10\x18\x05\x06\x07\x08\t\n\x0b\x0c\r\x0e\x0f\x10\x11\x12\x13\x14\x15\x16\x17\x18\x19\x1a\x1b\x1c\x1d\x1e\x1f%+&-./012%4567?@ABCDESpsiRvv_\x10\x14playbackCapabilities_\x10\x15canRecordScreenStream[statusFlags_\x10\x18keepAliveSendStatsAsBody_\x10\x0fprotocolVersionTname_\x10\x11volumeControlType]senderAddressXdeviceIDRpi^screenDemoMode]initialVolumeZfeaturesExZtxtAirPlay_\x10\x10supportedFormats]sourceVersionUmodelRpkZmacAddress^osBuildVersion_\x10\x15receiverHDRCapabilityXfeatures_\x10$C0E9C116-1F15-4A0A-8603-FA617376A047\x10\x02\xd5 !"#$%&&&&_\x10\x12supportsOfflineHLS_\x10\x1dsupportsUIForAudioOnlyContent_\x10\x15supportsInterstitials_\x10\x15supportsFPSSecureStop_\x10!supportsAirPlayVideoWithSharePlay\x08\t\t\t\t\x08\x12\x00\x03\x86D\tS1.1_\x10\x10Bedroom Apple TV\x10\x04_\x10\x13192.168.1.120:40302_\x10\x11C8:69:CD:53:14:FB_\x10$2b5256c7-0cf3-4099-af75-8f6de03d3c0e\x08#\x00\x00\x00\x00\x00\x00\x00\x00_\x10\x0f1d9/Wt5fFbwooQQO\x11\x01\x86\x05acl=0\x18btaddr=00:00:00:00:00:00\x1adeviceid=C8:69:CD:53:14:FB\x13fex=1d9/Wt5fFbwooQQ\x1efeatures=0x5A7FDFD5,0xBC155FDE\rflags=0x38644(gid=DCD8B165-2F9C-466D-B06E-16ED42338C48\x05igl=1\x06gcgl=1\x10model=AppleTV5,3\rprotovers=1.1\'pi=2b5256c7-0cf3-4099-af75-8f6de03d3c0e(psi=C0E9C116-1F15-4A0A-8603-FA617376A047Cpk=78524a9ad77ee7bf18096d405df7b77455c4281fe45c697da16103101f630672\x0fsrcvers=695.5.1\x0bosvers=16.6\x04vv=2\xd489:;<==>_\x10\x15lowLatencyAudioStream\\screenStream[audioStream\\bufferStream\x10\x00\x12\x01D\x08\x00\x137\xc0\x01\x80\x00\xe0\x00\x00W695.5.1ZAppleTV5,3O\x10 xRJ\x9a\xd7~\xe7\xbf\x18\tm@]\xf7\xb7tU\xc4(\x1f\xe4\\i}\xa1a\x03\x10\x1fc\x06r_\x10\x11C8:69:CD:53:14:F9U20M73W1080p60\x13\xbc\x15_\xdeZ\x7f\xdf\xd5\x00\x08\x00\r\x00\x12\x00\x18\x00#\x00V\x00Z\x00]\x00t\x00\x8c\x00\x98\x00\xb3\x00\xc5\x00\xca\x00\xde\x00\xec\x00\xf5\x00\xf8\x01\x07\x01\x15\x01 \x01+\x01>\x01L\x01R\x01U\x01`\x01o\x01\x87\x01\x90\x01\xb7\x01\xb9\x01\xc4\x01\xd9\x01\xf9\x02\x11\x02)\x02M\x02N\x02O\x02P\x02Q\x02R\x02S\x02X\x02Y\x02]\x02p\x02r\x02\x88\x02\x9c\x02\xc3\x02\xc4\x02\xcd\x02\xdf\x04i\x04r\x04\x8a\x04\x97\x04\xa3\x04\xb0\x04\xb2\x04\xb7\x04\xc0\x04\xc8\x04\xd3\x04\xf6\x05\n\x05\x10\x05\x18\x00\x00\x00\x00\x00\x00\x02\x01\x00\x00\x00\x00\x00\x00\x00F\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x05!')
2023-08-04 11:55:25.794 DEBUG (MainThread) [pyatv.auth.hap_channel] Sending data (Encrypted=5c0022a6a563b06feb4bd8627d8d62d749e80af4e3ffccff7b5e17406e24913092452dbf0091350a6b4dec09a7862f637052b4d00e16c6aa52812b126e16c23adb35c0e54b51ca50d9ade2675b07a608d003e9208af707614c93f0fd8706df7ca7234366cf990c1383e774e74eb2)
2023-08-04 11:55:25.930 DEBUG (MainThread) [pyatv.protocols.companion.connection] Received data (Data=0800003543ed1541c2eeb6e3adc50d137c1f2d3914d9055f573806d28c55a4d11747afadc0ab660a591e3324737150e0145df7740ebf9114b4)
2023-08-04 11:55:25.930 DEBUG (MainThread) [pyatv.protocols.companion.protocol] Received frame FrameType.E_OPACK: b'\xe4B_iD_iMCB_x3<\x13\xa2\xc4\x00\x00\x00\x00B_c\xe1D_mcF1\x00\x01B_t\t'
2023-08-04 11:55:25.930 DEBUG (MainThread) [pyatv.protocols.companion.protocol] Process incoming OPACK frame (FrameType.E_OPACK): {'_i': '_iMC', '_x': 3298956092, '_c': {'_mcF': 256}, '_t': 1}
2023-08-04 11:55:25.930 DEBUG (MainThread) [pyatv.protocols.companion.protocol] Received event: {'_i': '_iMC', '_x': 3298956092, '_c': {'_mcF': 256}, '_t': 1}
2023-08-04 11:55:25.931 DEBUG (MainThread) [pyatv.protocols.companion.api] Got event _iMC from device: {'_mcF': 256}
2023-08-04 11:55:25.931 DEBUG (MainThread) [pyatv.core.protocol] Dispatching message with type _iMC to <bound method CompanionFeatures._handle_control_flag_update of <pyatv.protocols.companion.CompanionFeatures object at 0x7f51f422c4d0>>
2023-08-04 11:55:25.931 DEBUG (MainThread) [pyatv.core.protocol] Dispatching message with type _iMC to <bound method CompanionAudio._handle_control_flag_update of <pyatv.protocols.companion.CompanionAudio object at 0x7f51f422ebd0>>
2023-08-04 11:55:25.931 DEBUG (MainThread) [pyatv.protocols.companion] Updated media control flags to 256
2023-08-04 11:55:25.931 DEBUG (MainThread) [pyatv.protocols.companion] Volume control changed, updating volume
2023-08-04 11:55:25.931 DEBUG (MainThread) [pyatv.protocols.companion.protocol] Exchange OPACK: {'_i': '_mcc', '_t': 2, '_c': {'_mcc': 5}, '_x': 18724}
2023-08-04 11:55:25.931 DEBUG (MainThread) [pyatv.protocols.companion.protocol] Send OPACK: {'_i': '_mcc', '_t': 2, '_c': {'_mcc': 5}, '_x': 18724}
2023-08-04 11:55:25.932 DEBUG (MainThread) [pyatv.protocols.companion.connection] >> Send data (Data=e4425f69445f6d6363425f740a425f63e1a10d425f78312449, FrameType=08)
2023-08-04 11:55:25.932 DEBUG (MainThread) [pyatv.protocols.companion.connection] >> Send (Encrypted=ac0bff507d68db3c69e15f1989717d90b5223b8568f70c5027ab9457f8b6206a49809e74b8e2cd6184, Header=08000029)
2023-08-04 11:55:25.932 DEBUG (MainThread) [pyatv.auth.hap_channel] Received data (Data=2000e9a327aa4dbd46fd43879457f3ee8adfef0f5760dc3caddd9892a6c7d09d7cd0d87a758c7334f543d69e35f8093adb716f00e2f32a7069ef9003a014ef6703821dc265165f6574d36c9f15766f10ed3cf19021ad5780ff42da09c2fda84e44a9fa65fa1880c15bb19950c8ec05a1335cfd6c41b3f7a7771bcd5aa71eb3eab0e46856769e60fddd9250ae429bd15155312dac76936461a8f3a5615a810a072da466809383aac9511c0dc97ee3c2a57ef25d)
2023-08-04 11:55:25.933 DEBUG (MainThread) [pyatv.protocols.airplay.mrp_connection] << Receive: Protobuf: type: SET_NOW_PLAYING_CLIENT_MESSAGE

How to reproduce the bug?

Try Airplay media from HA to Apple TV.

What is expected behavior?

The audio or video should airplay to the Apple TV from HA.

Operating System

HA

Python

Other

pyatv

0.8.2

Device

Apple TV 4th Gen TVOS 16.6

Additional context

I am running the built in HA version of pyatv. I have searched the web and read numerous HA forums but with no solution on how to forcefully change the legacy auth to the new auth.

postlund commented 9 months ago

This is obviously a mismatch where pairing RAOP yields legacy credentials (like it did before I added AirPlay 2 support), but AirPlay 2 is used for streaming. This should not happen if you remove and add the device again, so something strange is happening there. Can you remove the device and enable additional logging when adding it again?

TechShift007 commented 9 months ago

Hi @postlund. I think I managed to enable the additional logger. Here as attached are the latest logs while re-adding the device.

home-assistant.log

postlund commented 9 months ago

Yeah, those are the logs I need. For some reason pyatv thinks RAOP should be paired with legacy authentication instead of HAP. The feature flags are used to decide this, but they look correct. I have tried to reproduce this myself and it seems to work as expected. Would it be possible for you to test this with atvremote as well and check if the same thing happens? You would need to install pyatv and run atvremote --debug -s 192.168.1.127 --protocol raop pair.

TechShift007 commented 9 months ago

Hi, I will gladly test atvremote, excuse my stupidity, but how do you run the requested test in HA and install pyatv?

postlund commented 9 months ago

It depends on the operating system you run a bit (I suggest you run it on another computer than they over you use for Home Assistant, assuming you are running HAOS). Basically you need python and then you can follow the instructions here:

https://pyatv.dev/documentation/#installing-pyatv

ronluna commented 1 week ago

Having the same problem. @postlund any way I could help debugging this ?