search

postlund / pyatv

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

push_updates sometimes crash with error (i'm using it in a daemon) #1790

Open NebzHB opened 2 years ago

NebzHB commented 2 years ago

Describe the bug

I have a daemon doing push_updates and waiting for new messages.

here is an error i get sometimes...

difficult to restart it with --debug as it appears sometimes after more than 6hours... but if needed i may try to do that...

Error log

[11-07-2022 19:35:51]ERROR : MSG CHAN ERR :Got response without having a request: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Mon, 11 Jul 2022 17:35:51 GMT', 'content-length': '55', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/615.12.1', 'cseq': '5064'}, 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')
[11-07-2022 19:35:56]DEBUG : msg |{"result": "failure", "datetime": "2022-07-11T19:35:55.773843+02:00", "exception": "no response to CSeq 5064 (/feedback)", "stacktrace": "Traceback (most recent call last):
File \"/usr/lib/python3.9/asyncio/locks.py\", line 226, in wait
await fut
asyncio.exceptions.CancelledError
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File \"/usr/lib/python3.9/asyncio/tasks.py\", line 492, in wait_for
fut.result()
asyncio.exceptions.CancelledError
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File \"/var/www/html/plugins/aTVremote/resources/atvremote/lib/python3.9/site-packages/pyatv/support/rtsp.py\", line 286, in exchange
await asyncio.wait_for(self.requests[cseq][0].wait(), 4)
File \"/usr/lib/python3.9/asyncio/tasks.py\", line 494, in wait_for
raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File \"/var/www/html/plugins/aTVremote/resources/atvremote/lib/python3.9/site-packages/pyatv/core/protocol.py\", line 56, in heartbeater
await sender_func(message)
File \"/var/www/html/plugins/aTVremote/resources/atvremote/lib/python3.9/site-packages/pyatv/protocols/airplay/remote_control.py\", line 75, in _send_feedback
await self.rtsp.feedback()
File \"/var/www/html/plugins/aTVremote/resources/atvremote/lib/python3.9/site-packages/pyatv/support/rtsp.py\", line 225, in feedback
return await self.exchange(\"POST\", uri=\"/feedback\", allow_error=allow_error)
File \"/var/www/html/plugins/aTVremote/resources/atvremote/lib/python3.9/site-packages/pyatv/support/rtsp.py\", line 289, in exchange
raise TimeoutError(
TimeoutError: no response to CSeq 5064 (/feedback)
", "connection": "lost"}
[11-07-2022 19:35:56]DEBUG : msg |{"result": "success", "datetime": "2022-07-11T19:35:56.024490+02:00", "push_updates": "finished"}
[11-07-2022 19:35:56]DEBUG : msg |{"result": "failure", "datetime": "2022-07-11T19:35:56.048140+02:00", "error": "Task was destroyed but it is pending!"}

How to reproduce the bug?

keep a push_updates session open a long time

What is expected behavior?

capture exception and don't crash

Operating System

Linux Debian 11

Python

3.9

pyatv

0.10.2

Device

Apple TV 4

Additional context

spawned command from a nodejs daemon.

postlund commented 2 years ago

This is tricky as it's hard to tell if it's a problem in pyatv, a network issue or a bug in tvOS. But if you can run it and give me some logs around the time it happens, that would help a lot.

NebzHB commented 2 years ago

i have more info, here is an example with an HomePod, i just go to cli, there is nothing playing (paused) then volume_up (or down) the music start playing (???) and 4sec after that i got a crash /



nebz@JeedomProd:~$ /var/www/html/plugins/aTVremote/resources/atvremote/bin/atvremote -i D4:A3:3D:61:3B:96 cli --debug
2022-07-16 16:15:26 DEBUG [pyatv.scripts]: Running with pyatv 0.10.2
2022-07-16 16:15:26 DEBUG [pyatv.support.net]: Binding on *:5353
2022-07-16 16:15:26 DEBUG [pyatv.support.net]: Binding on 127.0.0.1:0
2022-07-16 16:15:26 DEBUG [pyatv.support.net]: Binding on 192.168.1.31:0
2022-07-16 16:15:26 DEBUG [pyatv.support.net]: Binding on 10.13.11.198:0
2022-07-16 16:15:27 DEBUG [pyatv.core.scan]: Auto-discovered Chambre at 192.168.1.108:7000 via Protocol.AirPlay ({'acl': '0', 'btaddr': '6C:46:EE:D6:E4:BD', 'deviceid': 'D4:A3:3D:61:3B:96', 'fex': 'AMp/StBLNbw', 'features': '0x4A7FCA00,0xBC354BD0', 'flags': '0x98404', 'gid': 'E5BFE09B-D5CB-47D8-AE16-E15A73F09B52+0+99D3951A-ED6B-4557-B69D-B6E10D3761B7', 'igl': '1', 'gcgl': '1', 'model': 'AudioAccessory1,1', 'protovers': '1.1', 'pi': '73138a2e-86fd-4886-b887-f73a807607c6', 'psi': '4BE42F0B-42A9-4ECA-92FF-1852D84C31C9', 'pk': '05e1dd318dfc10d499eb5afc568c1fd12a259bf7959c2bdc0042c6be958c7b33', 'srcvers': '615.12.1', 'osvers': '15.5.1', 'vv': '2'})
2022-07-16 16:15:27 DEBUG [pyatv.core.scan]: Auto-discovered Chambre at 192.168.1.108:49152 via Protocol.Companion ({'rpmac': '1', 'rphn': 'a157d00b1cab', 'rpfl': '0x627B2', 'rpha': 'bc959ec3e395', 'rpmd': 'AudioAccessory1,1', 'rpvr': '350.2', 'rpad': 'e14dc53b3040', 'rphi': '7ff6ab352531', 'rpba': '56:CB:58:66:4D:A8'})
2022-07-16 16:15:27 DEBUG [pyatv.core.scan]: Auto-discovered D4A33D613B96@Chambre at 192.168.1.108:7000 via Protocol.RAOP ({'cn': '0,1,2,3', 'da': 'true', 'et': '0,3,5', 'ft': '0x4A7FCA00,0xBC354BD0', 'sf': '0x98404', 'md': '0,1,2', 'am': 'AudioAccessory1,1', 'pk': '05e1dd318dfc10d499eb5afc568c1fd12a259bf7959c2bdc0042c6be958c7b33', 'tp': 'UDP', 'vn': '65537', 'vs': '615.12.1', 'ov': '15.5.1', 'vv': '2'})
2022-07-16 16:15:27 INFO [pyatv.scripts.atvremote]: Auto-discovered Chambre at 192.168.1.108
2022-07-16 16:15:27 DEBUG [pyatv.core.facade]: Adding handler for protocol Protocol.AirPlay
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay]: Remote control channel is supported
2022-07-16 16:15:27 DEBUG [pyatv.core.facade]: Adding handler for protocol Protocol.MRP
2022-07-16 16:15:27 DEBUG [pyatv.protocols.companion]: Not adding Companion as credentials are missing
2022-07-16 16:15:27 DEBUG [pyatv.core.facade]: Adding handler for protocol Protocol.MRP
2022-07-16 16:15:27 DEBUG [pyatv.core.facade]: Adding handler for protocol Protocol.RAOP
2022-07-16 16:15:27 DEBUG [pyatv.core.facade]: Connecting to protocol: Protocol.AirPlay
2022-07-16 16:15:27 DEBUG [pyatv.core.facade]: Connected to protocol: Protocol.AirPlay
2022-07-16 16:15:27 DEBUG [pyatv.core.facade]: Connecting to protocol: Protocol.MRP
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.remote_control]: Setting up remote control connection to 192.168.1.108:7000
2022-07-16 16:15:27 DEBUG [pyatv.support.http]: Connected to 192.168.1.108
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.auth]: Setting up new AirPlay Pair-Verify procedure with type AuthenticationType.Transient
2022-07-16 16:15:27 DEBUG [pyatv.support.http]: Sending HTTP/1.1 message: b'POST /pair-pin-start HTTP/1.1\r\nUser-Agent: AirPlay/320.20\r\nConnection: keep-alive\r\nX-Apple-HKP: 4\r\nContent-Type: application/octet-stream\r\n\r\n'
2022-07-16 16:15:27 DEBUG [pyatv.support.http]: Received: b'HTTP/1.1 200 OK\r\nDate: Sat, 16 Jul 2022 14:15:24 GMT\r\nContent-Length: 0\r\nServer: AirTunes/615.12.1\r\n\r\n'
2022-07-16 16:15:27 DEBUG [pyatv.support.http]: Got HTTP response: HttpResponse(protocol='HTTP', version='1.1', code=200, message='OK', headers={'date': 'Sat, 16 Jul 2022 14:15:24 GMT', 'content-length': '0', 'server': 'AirTunes/615.12.1'}, body=''):
2022-07-16 16:15:27 DEBUG [pyatv.support.http]: Sending HTTP/1.1 message: b'POST /pair-setup HTTP/1.1\r\nContent-Length: 6\r\nUser-Agent: AirPlay/320.20\r\nConnection: keep-alive\r\nX-Apple-HKP: 4\r\nContent-Type: application/octet-stream\r\n\r\n\x00\x01\x00\x06\x01\x01'
2022-07-16 16:15:27 DEBUG [pyatv.support.http]: Received: b'HTTP/1.1 200 OK\r\nDate: Sat, 16 Jul 2022 14:15:24 GMT\r\nContent-Length: 409\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/615.12.1\r\n\r\n\x06\x01\x02\x02\x10#P\xb1!\xe1\xbb\xef\xa1\x8a\xad\xe7\xb7\x8fi\x18v\x03\xff\x1cK\xf4\xbb\x076\x9d)FxDm\xed\xb8\xafL\xa7\x0e`\xd1\xde\x81\x9c3A7q"z\xc8\xc7\x8a~\xad\xa4>1\xe7\xb0\xe4\xed\x1a\xe7p\xc5\x00\xee\x0biH;\xe3Q_\xe6\x84f\xd5\xb3\xa9\xec\x1cbQ\x83\x96M\xf7q \x7f\x8cf\x01\xda[d\xfd\x86\xc4\xf4\xda8\xb0/S\x9a\xbe5\xf4\x89\xbaL!bA\x97\xeb\xe8;Ah\xe7\xe8\xc0Jld\xafO\x0e\x11\xeb\x7f\xb4m\xfc\xfd\x8bV\xbdNY\x9c\x0eW\xff\xe1#\x8c\xb6\x17\xc1\x81_\x7f\x08\xa02\xa0C\xe3\x9a\x1af\xaa\x94\xca\xae\x96\xae\xb5\xda\x84`\xd5\xbfh\x92\xa2<5.\x0b}\x0emC!\xa5?\xad[\ti#\x8a-\xba\xd7"\xe5C=@\tI e\xae\x1e\x15Cm\xad\xf9BN1\x9a\x8e\xff7\xdcTEfs:\x12\xa0\nr\xd5<3\x7f\xd9B3\x1dZ\xbcl^\xc5AF\xde!M\\*\'/\xeaT\xfd\x88\xdc%\x13@b\x98\x974\xef\xf3\xdc\x9fP\x91\xbe\xd1\x03\x81\xa9\xf50q-\x89\n\xf6@H\xe1\x03\xd9\xb3uO\xc1\x89f\x1d\xc2\x18\x1ai\x12:\xb4\xf5\xac\x9265\xf1E\x89\x12i\'\xa6\x00\x94\xee\x03\xd3\xe2\x0f\x8c\xa7\xff\xac\xcb\xec\xe4\xce\xc0\r\x0f\xdeK\x8c\x0c\xdf\xbf\x9c\x9c\xa6\x01Xqv\xb7w\x86\xa0e4\xd8N\xf6\xe6:H\\,D\x1fV\x15\x7f\r\xb1_\xa6\xda>\x18l\xec$/l\x87\xa7\x15d\xb7<C\xe3\x8dRg)\x85\xc6o\xcb\x7f\xcd%\x98/\x84i\xc3\x1e6p\x99'
2022-07-16 16:15:27 DEBUG [pyatv.support.http]: Got HTTP response: HttpResponse(protocol='HTTP', version='1.1', code=200, message='OK', headers={'date': 'Sat, 16 Jul 2022 14:15:24 GMT', 'content-length': '409', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/615.12.1'}, body=b'\x06\x01\x02\x02\x10#P\xb1!\xe1\xbb\xef\xa1\x8a\xad\xe7\xb7\x8fi\x18v\x03\xff\x1cK\xf4\xbb\x076\x9d)FxDm\xed\xb8\xafL\xa7\x0e`\xd1\xde\x81\x9c3A7q"z\xc8\xc7\x8a~\xad\xa4>1\xe7\xb0\xe4\xed\x1a\xe7p\xc5\x00\xee\x0biH;\xe3Q_\xe6\x84f\xd5\xb3\xa9\xec\x1cbQ\x83\x96M\xf7q \x7f\x8cf\x01\xda[d\xfd\x86\xc4\xf4\xda8\xb0/S\x9a\xbe5\xf4\x89\xbaL!bA\x97\xeb\xe8;Ah\xe7\xe8\xc0Jld\xafO\x0e\x11\xeb\x7f\xb4m\xfc\xfd\x8bV\xbdNY\x9c\x0eW\xff\xe1#\x8c\xb6\x17\xc1\x81_\x7f\x08\xa02\xa0C\xe3\x9a\x1af\xaa\x94\xca\xae\x96\xae\xb5\xda\x84`\xd5\xbfh\x92\xa2<5.\x0b}\x0emC!\xa5?\xad[\ti#\x8a-\xba\xd7"\xe5C=@\tI e\xae\x1e\x15Cm\xad\xf9BN1\x9a\x8e\xff7\xdcTEfs:\x12\xa0\nr\xd5<3\x7f\xd9B3\x1dZ\xbcl^\xc5AF\xde!M\\*\'/\xeaT\xfd\x88\xdc%\x13@b\x98\x974\xef\xf3\xdc\x9fP\x91\xbe\xd1\x03\x81\xa9\xf50q-\x89\n\xf6@H\xe1\x03\xd9\xb3uO\xc1\x89f\x1d\xc2\x18\x1ai\x12:\xb4\xf5\xac\x9265\xf1E\x89\x12i\'\xa6\x00\x94\xee\x03\xd3\xe2\x0f\x8c\xa7\xff\xac\xcb\xec\xe4\xce\xc0\r\x0f\xdeK\x8c\x0c\xdf\xbf\x9c\x9c\xa6\x01Xqv\xb7w\x86\xa0e4\xd8N\xf6\xe6:H\\,D\x1fV\x15\x7f\r\xb1_\xa6\xda>\x18l\xec$/l\x87\xa7\x15d\xb7<C\xe3\x8dRg)\x85\xc6o\xcb\x7f\xcd%\x98/\x84i\xc3\x1e6p\x99'):
2022-07-16 16:15:27 DEBUG [pyatv.auth.hap_srp]: Client (Proof=6e5ed9f4d4bb971c319cd366a8a591d0a60b3b78b516effa55d4fe3f049e3a3dd293bcb4edd39b792a1ab836683178cb76e864247668289fb98a421f59a6a3e7, Public=6ed3f6ba05198d37eadc66e6c7d164cab42032fe389d905dfd0926d6eed6f8246390a2779e13f2f812e705deceddad9a958b0ad4c371579fc7632959c2fd3035accd40dbf92e68a25b1f81274815bdb2665ebaadeedde280a85a664da64d06949d93621933fb3964dc80733b5927c5e02ccb30fbde5b2b2d2a51c89f315ec65b24c618b4904982558eda44185770000290a332775a03e547d02f7a0eaf2772365105933abb2bb270cecdb70127fbdc2e54fac22b8cbeaea009103ff10c2e7fd13411600da5005b2e2440ede3f919577d4b4c81f8a369ca5d746c5fa88c19fa609353950d87d2a5c466ad8ec59231ea21ffe4b8a4675d82ff392ab0fbc860b...)
2022-07-16 16:15:27 DEBUG [pyatv.support.http]: Sending HTTP/1.1 message: b'POST /pair-setup HTTP/1.1\r\nContent-Length: 457\r\nUser-Agent: AirPlay/320.20\r\nConnection: keep-alive\r\nX-Apple-HKP: 4\r\nContent-Type: application/octet-stream\r\n\r\n\x06\x01\x03\x03\xffn\xd3\xf6\xba\x05\x19\x8d7\xea\xdcf\xe6\xc7\xd1d\xca\xb4 2\xfe8\x9d\x90]\xfd\t&\xd6\xee\xd6\xf8$c\x90\xa2w\x9e\x13\xf2\xf8\x12\xe7\x05\xde\xce\xdd\xad\x9a\x95\x8b\n\xd4\xc3qW\x9f\xc7c)Y\xc2\xfd05\xac\xcd@\xdb\xf9.h\xa2[\x1f\x81\'H\x15\xbd\xb2f^\xba\xad\xee\xdd\xe2\x80\xa8ZfM\xa6M\x06\x94\x9d\x93b\x193\xfb9d\xdc\x80s;Y\'\xc5\xe0,\xcb0\xfb\xde[+-*Q\xc8\x9f1^\xc6[$\xc6\x18\xb4\x90I\x82U\x8e\xdaD\x18Wp\x00\x02\x90\xa32wZ\x03\xe5G\xd0/z\x0e\xaf\'r6Q\x05\x93:\xbb+\xb2p\xce\xcd\xb7\x01\'\xfb\xdc.T\xfa\xc2+\x8c\xbe\xae\xa0\t\x10?\xf1\x0c.\x7f\xd14\x11`\r\xa5\x00[.$@\xed\xe3\xf9\x19W}KL\x81\xf8\xa3i\xca]tl_\xa8\x8c\x19\xfa`\x93S\x95\r\x87\xd2\xa5\xc4f\xad\x8e\xc5\x921\xea!\xff\xe4\xb8\xa4g]\x82\xff9*\xb0\xfb\xc8`\xb3\x03\x81\xbd\xeaZC0N\xbb\x7fWZ\x00\xb6\x95\x11\x15\xb8h\x1d\xca\x9e\x13\xee\x10x\xb8\xe8F\x01\xe6&\xa8\x14\x86-\x80<\xbc\x90>;\x1b\x1d\x10g\x11\x92\xcc\n\x19\x13\x18:\xed\x9a"\x7fG\x99\xee\xcc\xebh6=u:\x9a%\x12\xc8E\x13\'\x02\xfd\xca\x96\x07%\xf5}\xff~\xb2I\xe1v\xad\x95\xa0\xd2s@\xcd\x02\xe9m\x87.\xbfD\xe55\xbd\xf2H0qX\xf1\xc9u\xdd2\xd4\xe6\xd6ycoAd\xe7\xfbY\xaafzK\x04@n^\xd9\xf4\xd4\xbb\x97\x1c1\x9c\xd3f\xa8\xa5\x91\xd0\xa6\x0b;x\xb5\x16\xef\xfaU\xd4\xfe?\x04\x9e:=\xd2\x93\xbc\xb4\xed\xd3\x9by*\x1a\xb86h1x\xcbv\xe8d$vh(\x9f\xb9\x8aB\x1fY\xa6\xa3\xe7'
2022-07-16 16:15:27 DEBUG [pyatv.support.http]: Received: b'HTTP/1.1 200 OK\r\nDate: Sat, 16 Jul 2022 14:15:24 GMT\r\nContent-Length: 69\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/615.12.1\r\n\r\n\x06\x01\x04\x04@\xc99\xc3\xf0R\x01L\xf8\x8b\x93\rh\x92E^Y9\xbeE\xbf2\xda\xfe\x94\xaf\x1e\xc8\x92JB\x86<\xb5\xcaz\xe3\xde\xaf\xe2?\xe6\x1f{\xda\x9ds\xdf\xdb\xd2\x17\x16\xd9\xdb\xe9u\xa5n\x86p\x9c>\xa5\xedE'
2022-07-16 16:15:27 DEBUG [pyatv.support.http]: Got HTTP response: HttpResponse(protocol='HTTP', version='1.1', code=200, message='OK', headers={'date': 'Sat, 16 Jul 2022 14:15:24 GMT', 'content-length': '69', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/615.12.1'}, body=b'\x06\x01\x04\x04@\xc99\xc3\xf0R\x01L\xf8\x8b\x93\rh\x92E^Y9\xbeE\xbf2\xda\xfe\x94\xaf\x1e\xc8\x92JB\x86<\xb5\xcaz\xe3\xde\xaf\xe2?\xe6\x1f{\xda\x9ds\xdf\xdb\xd2\x17\x16\xd9\xdb\xe9u\xa5n\x86p\x9c>\xa5\xedE'):
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.auth.hap_transient]: Keys (Input=0b7bad836501863a5ed3f761bc1e50f54ba16f9fc89281be43d3fc2389651bd0, Output=02a3abebfb3e4a7a04f0383856c033a6be640f1f5beceaa95e70f805d41e4dd8)
2022-07-16 16:15:27 DEBUG [pyatv.support.http]: Sending RTSP/1.0 message: b'SETUP rtsp://192.168.1.31/3008076940 RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nContent-Length: 367\r\nCSeq: 0\r\nDACP-ID: DF9A1CAE7566DEC8\r\nActive-Remote: 1281514640\r\nClient-Instance: DF9A1CAE7566DEC8\r\nContent-Type: application/x-apple-binary-plist\r\n\r\nbplist00\xdb\x01\x02\x03\x04\x05\x06\x07\x08\t\n\x0b\x0c\r\x0e\x0f\x10\x11\x12\x13\x14\x15\x16XdeviceID_\x10\x13isRemoteControlOnlyZmacAddressUmodelTname^osBuildVersionVosNameYosVersion[sessionUUID]sourceVersion^timingProtocol_\x10\x11FF:EE:DD:CC:BB:AA\t_\x10\x11AA:BB:CC:DD:EE:FFZiPhone10,6UpyatvU18G82YiPhone OSV14.7.1_\x10$AC5324E1-AB94-40C3-97EE-668C7754AC07V550.10TNone\x00\x08\x00\x1f\x00(\x00>\x00I\x00O\x00T\x00c\x00j\x00t\x00\x80\x00\x8e\x00\x9d\x00\xb1\x00\xb2\x00\xc6\x00\xd1\x00\xd7\x00\xdd\x00\xe7\x00\xee\x01\x15\x01\x1c\x00\x00\x00\x00\x00\x00\x02\x01\x00\x00\x00\x00\x00\x00\x00\x17\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x01!'
2022-07-16 16:15:27 DEBUG [pyatv.support.http]: Received: b'RTSP/1.0 200 OK\r\nDate: Sat, 16 Jul 2022 14:15:24 GMT\r\nContent-Length: 59\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/615.12.1\r\nCSeq: 0\r\n\r\nbplist00\xd1\x01\x02YeventPort\x11\xc3C\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'
2022-07-16 16:15:27 DEBUG [pyatv.support.http]: Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Sat, 16 Jul 2022 14:15:24 GMT', 'content-length': '59', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/615.12.1', 'cseq': '0'}, body=b'bplist00\xd1\x01\x02YeventPort\x11\xc3C\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'):
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.auth.hap_transient]: Keys (Input=021518ac0cdc200f0031f3fb221a7e339985163d07d64f0536ca927d332ef653, Output=13468375f86710d5ce8c1ec447155c49b832b94737561b9a88d62d37c183e29e)
2022-07-16 16:15:27 DEBUG [pyatv.auth.hap_channel]: Connected to 192.168.1.108:49987
2022-07-16 16:15:27 DEBUG [pyatv.support.http]: Sending RTSP/1.0 message: b'RECORD rtsp://192.168.1.31/3008076940 RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nCSeq: 1\r\nDACP-ID: DF9A1CAE7566DEC8\r\nActive-Remote: 1281514640\r\nClient-Instance: DF9A1CAE7566DEC8\r\n\r\n'
2022-07-16 16:15:27 DEBUG [pyatv.support.http]: Received: b'RTSP/1.0 200 OK\r\nDate: Sat, 16 Jul 2022 14:15:24 GMT\r\nContent-Length: 0\r\nAudio-Latency: 0\r\nServer: AirTunes/615.12.1\r\nCSeq: 1\r\n\r\n'
2022-07-16 16:15:27 DEBUG [pyatv.auth.hap_channel]: Received data (Data=0004f4d06cf29117f7a8231b3e2b9384166c3754ff9ddf79be7aecfb5ff7aa447b620a98ec450a812a799d5ff5cd1261938eefc2def0203d16412338125d7354c32394c0fcbf11f78c4503d8d7326d9111b605a9ec81a1126681ce4f401859e86e4442e15fb18a56e5a6340544da70450b2b62d79445924ba5a0b5ac2ef01ab235f4b251c283d124ba5c306e935c1cff0cff3e588dbcc7d790563657e734c1f8c6903d0a157ad5e0746fddcf9e6a9300087f8209b020bc6a7655c49d3ce1bb0305c711638ac8c4226873d0ac4ff8ee5e0d5960aa130891917a838dc62020f516cd5fe8ddf4f04ea533a3caf99ea19df6a6ec8ccacf322872a978affe2bb59...)
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.channels]: Got message on event channel: HttpRequest(method='POST', path='/command', protocol='RTSP', version='1.0', headers={'cseq': '0', 'content-length': '1428', 'content-type': 'application/x-apple-binary-plist'}, body=b'bplist00\xd2\x01\x02\x03\x04TtypeUvalueZupdateInfo\xdf\x10\x17\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"&\'()*+,-"/012:;<=>?SpsiRvv_\x10\x14playbackCapabilities_\x10\x15canRecordScreenStream[statusFlags_\x10\x18keepAliveSendStatsAsBody_\x10\x0fprotocolVersion_\x10\x11volumeControlTypeTname]senderAddressXdeviceIDRpi^screenDemoMode]initialVolumeZfeaturesExZtxtAirPlay_\x10\x10supportedFormats]sourceVersionUmodelRpkZmacAddress_\x10\x15receiverHDRCapabilityXfeatures_\x10$4BE42F0B-42A9-4ECA-92FF-1852D84C31C9\x10\x02\xd3\x1f !"""_\x10\x15supportsInterstitials_\x10\x15supportsFPSSecureStop_\x10\x1dsupportsUIForAudioOnlyContent\x08\x08\x08\x08\x12\x00\t\x84\x04\tS1.1\x10\x03WChambre_\x10\x12192.168.1.31:40774_\x10\x11D4:A3:3D:61:3B:96_\x10$73138a2e-86fd-4886-b887-f73a807607c6\x08#\xc06\x7f\xff\xe0\x00\x00\x00[AMp/StBLNbwO\x11\x01\xb3\x05acl=0\x18btaddr=6C:46:EE:D6:E4:BD\x1adeviceid=D4:A3:3D:61:3B:96\x0ffex=AMp/StBLNbw\x1efeatures=0x4A7FCA00,0xBC354BD0\rflags=0x98404Ogid=E5BFE09B-D5CB-47D8-AE16-E15A73F09B52+0+99D3951A-ED6B-4557-B69D-B6E10D3761B7\x05igl=1\x06gcgl=1\x17model=AudioAccessory1,1\rprotovers=1.1\'pi=73138a2e-86fd-4886-b887-f73a807607c6(psi=4BE42F0B-42A9-4ECA-92FF-1852D84C31C9Cpk=05e1dd318dfc10d499eb5afc568c1fd12a259bf7959c2bdc0042c6be958c7b33\x10srcvers=615.12.1\rosvers=15.5.1\x04vv=2\xd434567889_\x10\x15lowLatencyAudioStream\\screenStream[audioStream\\bufferStream\x13\x00\x00\x04\x00\x02\x00\x00\x00\x12\x01D\x08\x00\x13\x00\x00\x01\x80\x00\xe0\x00\x00X615.12.1_\x10\x11AudioAccessory1,1O\x10 \x05\xe1\xdd1\x8d\xfc\x10\xd4\x99\xebZ\xfcV\x8c\x1f\xd1*%\x9b\xf7\x95\x9c+\xdc\x00B\xc6\xbe\x95\x8c{3_\x10\x11D4:A3:3D:61:3B:94T4k60\x13\xbc5K\xd0J\x7f\xca\x00\x00\x08\x00\r\x00\x12\x00\x18\x00#\x00T\x00X\x00[\x00r\x00\x8a\x00\x96\x00\xb1\x00\xc3\x00\xd7\x00\xdc\x00\xea\x00\xf3\x00\xf6\x01\x05\x01\x13\x01\x1e\x01)\x01<\x01J\x01P\x01S\x01^\x01v\x01\x7f\x01\xa6\x01\xa8\x01\xaf\x01\xc7\x01\xdf\x01\xff\x02\x00\x02\x01\x02\x02\x02\x03\x02\x08\x02\t\x02\r\x02\x0f\x02\x17\x02,\x02@\x02g\x02h\x02q\x02}\x044\x04=\x04U\x04b\x04n\x04{\x04\x84\x04\x89\x04\x92\x04\x9b\x04\xaf\x04\xd2\x04\xe6\x04\xeb\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\x04\xf4')
2022-07-16 16:15:27 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=4f003fe76ca58761b17404b20b311408f4e64c504ee7d26b23cad303900b61ab1374def61b97985e1282f76d480b0b8e82954a32f18935cd8dcb1f751e78d185e52d3731b14e97ff6a69249c051f41431ec8c755165f558c20b60b44087f1722e3)
2022-07-16 16:15:27 DEBUG [pyatv.support.http]: Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Sat, 16 Jul 2022 14:15:24 GMT', 'content-length': '0', 'audio-latency': '0', 'server': 'AirTunes/615.12.1', 'cseq': '1'}, body=''):
2022-07-16 16:15:27 DEBUG [pyatv.support.http]: Sending RTSP/1.0 message: b'SETUP rtsp://192.168.1.31/3008076940 RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nContent-Length: 298\r\nCSeq: 2\r\nDACP-ID: DF9A1CAE7566DEC8\r\nActive-Remote: 1281514640\r\nClient-Instance: DF9A1CAE7566DEC8\r\nContent-Type: application/x-apple-binary-plist\r\n\r\nbplist00\xd1\x01\x02Wstreams\xa1\x03\xd7\x04\x05\x06\x07\x08\t\n\x0b\x0c\r\x0e\x0f\x10\x11YchannelID^clientTypeUUIDZclientUUID[controlTypeTseedTtype_\x10\x14wantsDedicatedSocket_\x10$5E1DFE92-6978-4D36-95A6-F31F9CAE8EDB_\x10$1910A70F-DBC0-4242-AF95-115DB30604E1_\x10$B0C175EF-107F-482D-9D43-888ED8A99136\x10\x02\x13?a\xc48Y\xa4\xe4d\x10\x82\t\x08\x0b\x13\x15$.=HTY^u\x9c\xc3\xea\xec\xf5\xf7\x00\x00\x00\x00\x00\x00\x01\x01\x00\x00\x00\x00\x00\x00\x00\x12\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xf8'
2022-07-16 16:15:27 DEBUG [pyatv.support.http]: Received: b'RTSP/1.0 200 OK\r\nDate: Sat, 16 Jul 2022 14:15:24 GMT\r\nContent-Length: 100\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/615.12.1\r\nCSeq: 2\r\n\r\nbplist00\xd1\x01\x02Wstreams\xa1\x03\xd3\x04\x05\x06\x07\x08\tTtypeXstreamIDXdataPort\x10\x82\x10\x01\x11\xc3D\x08\x0b\x13\x15\x1c!*357\x00\x00\x00\x00\x00\x00\x01\x01\x00\x00\x00\x00\x00\x00\x00\n\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00:'
2022-07-16 16:15:27 DEBUG [pyatv.support.http]: Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Sat, 16 Jul 2022 14:15:24 GMT', 'content-length': '100', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/615.12.1', 'cseq': '2'}, body=b'bplist00\xd1\x01\x02Wstreams\xa1\x03\xd3\x04\x05\x06\x07\x08\tTtypeXstreamIDXdataPort\x10\x82\x10\x01\x11\xc3D\x08\x0b\x13\x15\x1c!*357\x00\x00\x00\x00\x00\x00\x01\x01\x00\x00\x00\x00\x00\x00\x00\n\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00:'):
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.auth.hap_transient]: Keys (Input=2b95ee0bbae547d426ace80c149a1356b830f7d0264c0a76d593b40a50b0525e, Output=b19208efb83b9e1ae6756ff0271e4ff4560f4decb20dc3a9ed406574119708a8)
2022-07-16 16:15:27 DEBUG [pyatv.auth.hap_channel]: Connected to 192.168.1.108:49988
2022-07-16 16:15:27 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=3c01b572244cdeb50b84d99b5196b1f637afd84dbbe71670846732e9f920258a5c329ef3a05b4503f8a864514c3c67232df231125a1a9abafa502e0e1b557928179aaec6c692cb37a6f7119aff608e55336be330ca14ef4a8822913d57cbd87b702152636361c965dad6bdfe69aad322b83d6df842422edb4d619d81ebe74bf1fc8e97f1076f81c55368e4d5af79ec8c5da4c03634738b9cbd606648d8858f51636736cf52e71758783a581f8edef5d5d1ab0094dbcd08700a07c9b63d66993110c593852628434027456acaf1090f0feeb756141a6c755cb9cfe1d5206e0afaa15d36ee7467e7f977736fe2ccf859be30d4db093264f0f73cb6b776cd77a...)
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: >> Send: Protobuf: type: DEVICE_INFO_MESSAGE
identifier: "3214FBB6-110C-48AA-B709-B6AFFFEC8554"
errorCode: NoError
[deviceInfoMessage] {
  uniqueIdentifier: "82c2196b-7606-419d-b6c8-02be0f9e5732"
  name: "pyatv"
  localizedModelName: "iPhone"
  systemBuildVersion: "18A393"
  applicationBundleIdentifier: "com.apple.TVRemote"
  applicationBundleVersion: "344.28"
  protocolVersion: 1
  lastSupportedMessageType: 108
  supportsSystemPairing: true
  allowsPairing: true
  systemMediaApplication: "com.apple.TVMusic"
  supportsACL: true
  supportsSharedQueue: true
  supportsExtendedMotion: true
  sharedQueueVersion: 2
  deviceClass: iPhone
  logicalDeviceCount: 1
}
uniqueIdentifier: "136B5ECE-C167-4BD0-B216-36A733D1813D"
2022-07-16 16:15:27 DEBUG [pyatv.core.protocol]: Starting heartbeat loop (AirPlay:192.168.1.108)
2022-07-16 16:15:27 DEBUG [pyatv.auth.hap_channel]: Received data (Data=20009baa0b2416038511776d675f169ff18f041a5422505d7f9696acf0e35dfe169413cfb0be5440cf099807448069b96b752a006eea3ff1dbac6a558d1490a4fbdc225bb3d80d0699526907bfe27ce6bbadb8ee368b0cdc2bae0a8d4c1e9666557c49a689f3e629cdb10ff9d18a)
2022-07-16 16:15:27 DEBUG [pyatv.auth.hap_channel]: Received data (Data=20007cc8c7aa69cd5213ff5390d9ebc509d015d47758b8c63bf527ebbff8dc659742d78e1110d71cb3f435218eba63075d0c9c0220ab65bdc505d12a99c0f67fd6584a993a2309af02b84f1df6e2349a1aa1de267c8c72e0c23a9da9298f2eab446763fc1aec0f564b3032c05cea827965121509cc4f109324f6ff42d5d4a3d9d7d617b751ed85ecb7cf33f1d4c0aa0f719dd3d1ae31271213289f81259bbbc1d5f49f5915efd3511fc4721082fc73c28a982606c077cc25eb2bdf155a74bf5b635edaadfd04dab47f03fa44ba02861e6b49e9bd28ec4f2e69674d4c0375b7c944cc9c0c19ee28f5944b2fd8082d2d3d3bfaf364c78e3cd11158d9b73aaf1...)
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: DEVICE_INFO_MESSAGE
identifier: "3214FBB6-110C-48AA-B709-B6AFFFEC8554"
[deviceInfoMessage] {
  uniqueIdentifier: "4BE42F0B-42A9-4ECA-92FF-1852D84C31C9"
  name: "Chambre"
  localizedModelName: "HomePod"
  systemBuildVersion: "19L580"
  applicationBundleIdentifier: "com.apple.mediaremoted"
  protocolVersion: 1
  lastSupportedMessageType: 123
  supportsSystemPairing: true
  allowsPairing: true
  systemMediaApplication: "com.apple.Music"
  supportsACL: true
  supportsSharedQueue: true
  sharedQueueVersion: 3
  deviceUID: "4BE42F0B-42A9-4ECA-92FF-1852D84C31C9"
  managedConfigDeviceID: "d4:a3:3d:61:3b:94"
  deviceClass: Accessory
  logicalDeviceCount: 1
  isProxyGroupPlayer: false
  groupUID: "E5BFE09B-D5CB-47D8-AE16-E15A73F09B52+0+99D3951A-ED6B-4557-B69D-B6E10D3761B7"
  isGroupLeader: true
  isAirplayActive: false
  systemPodcastApplication: "com.apple.podcasts"
  senderDefaultGroupUID: "E5BFE09B-D5CB-47D8-AE16-E15A73F09B52"
  airplayReceivers: "tvairplayd"
  clusterType: 0
  isClusterAware: true
  modelID: "AudioAccessory1,1"
  supportsMultiplayer: true
  routingContextID: "99D3951A-ED6B-4557-B69D-B6E10D3761B7"
  airPlayGroupID: "E5BFE09B-D5CB-47D8-AE16-E15A73F09B52+0+99D3951A-ED6B-4557-B69D-B6E10D3761B7"
  systemBooksApplication: "com.apple.TVBooks"
}
uniqueIdentifier: "C1F1A107-B61D-4C89-A4CC-72B660649916"
2022-07-16 16:15:27 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=2000845cbb3b6a0c938a54ff02bfd1c9f0ee4bb8fc8dcd80372842a09d65e0c362bdf88768fb7fda0a133d15561610972cd2)
2022-07-16 16:15:27 DEBUG [pyatv.core.protocol]: Dispatching message with type 15 to <bound method MrpPower._update_power_state of <pyatv.protocols.mrp.MrpPower object at 0x7f03ff057d60>>
2022-07-16 16:15:27 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=93004d4e91178ebf913f0102617c4d55e6b1d13ac69313eabcd60f8c2c8b2f96388f1dde4075211d4389dc5eb07beac1309c2982dc3d1bdd62effc68c3020fda10fe7411441724ec12896caf29952aac53fcf6a936e63e1997b31c55118dc2515d36db9b55e51df9946161f16fd1c3d232734787913a2d7504ca75912a915195136a1019492df1a214e44906a16c573254fcc16be106e810af06467a8f5480325089207800)
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: >> Send: Protobuf: type: SET_CONNECTION_STATE_MESSAGE
errorCode: NoError
[setConnectionStateMessage] {
  state: Connected
}
uniqueIdentifier: "A05945D9-BD0C-47D7-93A5-EEB7019C1BC6"
2022-07-16 16:15:27 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=c100920872a76e81ef50fbd6010aa361e7f3246efe248c035f55971c13e1c2cd66773f94eb1bb30bf9877a899c3f5ec39db3d0409e5a21dfe80a07819766a18a181e3eb610997a09c90f881b7ba565c01e9ac32ba5854fd5898fed4cb516e08e59dd98464c1472bc97ee84aacfaa83f7caf340fcade15f19f6f26d0b0a5fb6356acc3186487134ac497231ba81213a38150bdbf13d03042a4eebbe4383cabf26a5c02a6906948a7620b903114efc6df5c7e093bc466c8cb7cbdebe99d663e8b4f40e9eda7f5d2e9cedda5c351f3981039dad81)
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: >> Send: Protobuf: type: CLIENT_UPDATES_CONFIG_MESSAGE
identifier: "96768668-9046-40B7-8598-9CDA28DFA616"
errorCode: NoError
[clientUpdatesConfigMessage] {
  artworkUpdates: true
  nowPlayingUpdates: false
  volumeUpdates: true
  keyboardUpdates: true
  outputDeviceUpdates: true
}
uniqueIdentifier: "EFF6404B-E339-424F-B3C5-EF28A6D8518E"
2022-07-16 16:15:27 DEBUG [pyatv.auth.hap_channel]: Received data (Data=200011ec175590093e12c3b4124da7d35451655db7a3742c859b56f7f53b1f21650212c584f615eaf8feb89e2b79064b6f052a000dd061ea9efff204ae7be938004aa7a6b6c7a013aaec7af82cd1e8eae163acb2e505d312e14c758182e48f00a2f79a3318c9c02be74ba3ee9e2d20003b954c3297252e901537ceb04202ef52b6f0d46f69c88e2380d3bdd33b8469299531e9a18a183f909c336ddde61000f62a00057ba889ddfb1f5b9c1700bc29578cd0a27d7d53887a9946bbbc52e1886046d749e704709fbb3eb5c6c5d0564f97edbaba217ab50895e6adeaba)
2022-07-16 16:15:27 DEBUG [pyatv.auth.hap_channel]: Received data (Data=20000c677e4936de23fa90e3d94f18af63849ca4a8ca2efeb2dcf31ab89c179e789e4a2023b28a72054e7024b23decc4ce80)
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.channels]: Not enough data on data channel (has 32, expects 11897)
2022-07-16 16:15:27 DEBUG [pyatv.auth.hap_channel]: Received data (Data=592e81a3ff06c9d09a3a1350f792085ff1bbd11e423445dba4b71d5100c9818011482f539d3e31b7dde9ac546da8d21099f62b2164125b9e7a1eb7f2ab5e5e1ef109c4a553512e7019958a388fc0c068f10d86aa315d64e3ba9a9f078a361c43c8be375522824018ae60580640ee8c542ddf41f02324aad8fc748bde88bb01d790a91275fba6e2ea3f6416719e452f734d7e07a4bf277530136944f6121ce510164e95cd6eee3ff5fbcb5378a96d330a8fbec494b2934e0e11a081a7e262aa02b1fed53e0a859e91f2fcba8e90f9f9e8d81bef9373a63713e4d9c034925e3cfe5b59be471bb4e080d1bcb4f2e0807c1dfe67e6f19a079aa80c9ef367a0f86...)
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: UPDATE_OUTPUT_DEVICE_MESSAGE
[updateOutputDeviceMessage] {
  outputDevices {
    uniqueIdentifier: "4BE42F0B-42A9-4ECA-92FF-1852D84C31C9"
    canAccessRemoteAssets: false
    isRemoteControllable: false
    isGroupLeader: false
    isGroupable: true
    deviceType: BuiltIn
    deviceSubType: Speaker
    modelSpecificInfoData: "bplist00\324\001\002\003\004\005\006\007\nX$versionY$archiverT$topX$objects\022\000\001\206\240_\020\017NSKeyedArchiver...
    isLocalDevice: true
    supportsExternalScreen: false
    requiresAuthorization: true
    sourceInfo {
      routingContextUID: "99D3951A-ED6B-4557-B69D-B6E10D3761B7"
      multipleBuiltInDevices: false
    }
    isDeviceGroupable: true
    canRelayCommunicationChannel: false
    isProxyGroupPlayer: false
    canAccessAppleMusic: false
    canAccessiCloudMusicLibrary: false
    groupContainsGroupLeader: false
    supportsBufferedAirPlay: false
    canPlayEncryptedProgressiveDownloadAssets: true
    canFetchMediaDataFromSender: true
    resentsOptimizedUserInterfaceWhenPlayingFetchedAudioOnlyAssets: true
    isAirPlayReceiverSessionActive: false
    parentGroupContainsDiscoverableLeader: false
    isAddedToHomeKit: false
    volumeCapabilities: 0
    supportsHAP: false
    usingJSONProtocol: false
    clusterType: 0
    primaryUID: "4BE42F0B-42A9-4ECA-92FF-1852D84C31C9"
    configuredClusterSize: 0
    producesLowFidelityAudio: false
    45: 0
    47: "AVOutputDeviceBluetoothListeningModeNormal"
    48: 0
    50: 18446744073709551615
    52: 1
  }
  clusterAwareOutputDevices {
    uniqueIdentifier: "4BE42F0B-42A9-4ECA-92FF-1852D84C31C9"
    canAccessRemoteAssets: false
    isRemoteControllable: false
    isGroupLeader: false
    isGroupable: true
    deviceType: BuiltIn
    deviceSubType: Speaker
    modelSpecificInfoData: "bplist00\324\001\002\003\004\005\006\007\nX$versionY$archiverT$topX$objects\022\000\001\206\240_\020\017NSKeyedArchiver...
    isLocalDevice: true
    supportsExternalScreen: false
    requiresAuthorization: true
    sourceInfo {
      routingContextUID: "99D3951A-ED6B-4557-B69D-B6E10D3761B7"
      multipleBuiltInDevices: false
    }
    isDeviceGroupable: true
    canRelayCommunicationChannel: false
    isProxyGroupPlayer: false
    canAccessAppleMusic: false
    canAccessiCloudMusicLibrary: false
    groupContainsGroupLeader: false
    supportsBufferedAirPlay: false
    canPlayEncryptedProgressiveDownloadAssets: true
    canFetchMediaDataFromSender: true
    resentsOptimizedUserInterfaceWhenPlayingFetchedAudioOnlyAssets: true
    isAirPlayReceiverSessionActive: false
    parentGroupContainsDiscoverableLeader: false
    isAddedToHomeKit: false
    volumeCapabilities: 0
    supportsHAP: false
    usingJSONProtocol: false
    clusterType: 0
    primaryUID: "4BE42F0B-42A9-4ECA-92FF-1852D84C31C9"
    configuredClusterSize: 0
    producesLowFidelityAudio: false
    45: 0
    47: "AVOutputDeviceBluetoothListeningModeNormal"
    48: 0
    50: 18446744073709551615
    52: 1
  }
}
uniqueIdentifier: "BB3B978E-FC40-4AAD-8CE6-5A539AF81A47"
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: VOLUME_CONTROL_AVAILABILITY_MESSAGE
[volumeControlAvailabilityMessage] {
  volumeControlAvailable: true
  volumeCapabilities: Absolute
}
uniqueIdentifier: "E3509083-CDC5-4A02-A200-246A45E588D8"
2022-07-16 16:15:27 DEBUG [pyatv.core.protocol]: Dispatching message with type 17 to <bound method MrpAudio._volume_control_availability of <pyatv.protocols.mrp.MrpAudio object at 0x7f03ff057c10>>
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_DEFAULT_SUPPORTED_COMMANDS_MESSAGE
[setDefaultSupportedCommandsMessage] {
  supportedCommands {
    supportedCommands {
      command: PreloadedPlaybackSession
      enabled: true
      supportedPlaybackSessionTypes: "com.apple.MediaPlaybackCore.playbackSession-v4.opack:subscription:cloudLibrary:f31bd42"
      supportedPlaybackSessionTypes: "com.apple.MediaPlaybackCore.playbackSession-v3.opack:subscription:cloudLibrary:f31bd42"
      supportedPlaybackSessionTypes: "com.apple.MediaPlaybackCore.playbackSession-v4.opack:subscription:cloudLibrary:b3deedb"
      supportedPlaybackSessionTypes: "com.apple.MediaPlaybackCore.playbackSession-v3.opack:subscription:cloudLibrary:b3deedb"
    }
    supportedCommands {
      command: SetPlaybackSession
      enabled: true
      supportedPlaybackSessionTypes: "com.apple.MediaPlaybackCore.playbackSession-v4.opack:subscription:cloudLibrary:f31bd42"
      supportedPlaybackSessionTypes: "com.apple.MediaPlaybackCore.playbackSession-v3.opack:subscription:cloudLibrary:f31bd42"
      supportedPlaybackSessionTypes: "com.apple.MediaPlaybackCore.playbackSession-v4.opack:subscription:cloudLibrary:b3deedb"
      supportedPlaybackSessionTypes: "com.apple.MediaPlaybackCore.playbackSession-v3.opack:subscription:cloudLibrary:b3deedb"
    }
    supportedCommands {
      command: PrepareForSetQueue
      enabled: true
    }
    supportedCommands {
      command: SetPlaybackQueue
      enabled: true
      supportedPlaybackQueueTypes: 7
      supportedPlaybackQueueTypes: 3
      supportedPlaybackQueueTypes: 6
      supportedPlaybackQueueTypes: 2
      supportedPlaybackQueueTypes: 5
      supportedPlaybackQueueTypes: 1
      supportedPlaybackQueueTypes: 8
      supportedCustomQueueIdentifiers: "com.apple.music.playbackqueue.radio"
      supportedCustomQueueIdentifiers: "com.apple.music.playbackqueue.tracklist"
      supportedCustomQueueIdentifiers: "com.apple.MediaPlaybackCore.playbackContextArchive-v1.opack"
      supportedCustomQueueIdentifiers: "com.apple.mediaplayer.playbackcontext"
    }
    supportedCommands {
      command: Play
      enabled: true
    }
  }
  displayID: "com.apple.Music"
  playbackQueueCapabilities {
  }
  playerPath {
    client {
      bundleIdentifier: "com.apple.Music"
    }
  }
}
uniqueIdentifier: "1F9DA6D1-CBC6-4E17-84E8-1A11B3D4D9CC"
2022-07-16 16:15:27 DEBUG [pyatv.core.protocol]: Dispatching message with type 72 to <bound method PlayerStateManager._handle_set_default_supported_commands of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x7f03fef94bb0>>
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_DEFAULT_SUPPORTED_COMMANDS_MESSAGE
[setDefaultSupportedCommandsMessage] {
  supportedCommands {
    supportedCommands {
      command: SetPlaybackSession
      enabled: true
      supportedPlaybackSessionTypes: "com.apple.podcasts.MTPlaybackQueueController.GenericQueue"
      currentPlaybackSessionTypes: "com.apple.podcasts.MTPlaybackQueueController.GenericQueue"
    }
    supportedCommands {
      command: SetPlaybackQueue
      enabled: true
      supportedPlaybackQueueTypes: 3
      supportedPlaybackQueueTypes: 6
      supportedPlaybackQueueTypes: 2
      supportedPlaybackQueueTypes: 5
      supportedPlaybackQueueTypes: 1
    }
    supportedCommands {
      command: Play
      enabled: true
    }
  }
  displayID: "com.apple.podcasts"
  playbackQueueCapabilities {
  }
  playerPath {
    client {
      bundleIdentifier: "com.apple.podcasts"
    }
  }
}
uniqueIdentifier: "8CA7D00D-521F-425C-8D06-6F4438F28957"
2022-07-16 16:15:27 DEBUG [pyatv.core.protocol]: Dispatching message with type 72 to <bound method PlayerStateManager._handle_set_default_supported_commands of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x7f03fef94bb0>>
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: ORIGIN_CLIENT_PROPERTIES_MESSAGE
uniqueIdentifier: "EF5EADF1-1812-4D9F-AC1C-AC54D33E150E"
[originClientPropertiesMessage] {
  lastPlayingTimestamp: 679673704.031012
}
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_NOW_PLAYING_CLIENT_MESSAGE
[setNowPlayingClientMessage] {
  client {
    processIdentifier: 42431
    bundleIdentifier: "com.apple.Music"
  }
}
uniqueIdentifier: "83E57552-642C-47F9-B772-D190752872A6"
2022-07-16 16:15:27 DEBUG [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 0x7f03fef94bb0>>
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: UPDATE_CLIENT_MESSAGE
[updateClientMessage] {
  client {
    processIdentifier: 74
    bundleIdentifier: "com.apple.SoundBoard"
    processUserIdentifier: 501
    displayName: "SoundBoard"
  }
}
uniqueIdentifier: "B815C1B1-B313-4071-AF18-7CC41BC3669E"
2022-07-16 16:15:27 DEBUG [pyatv.core.protocol]: Dispatching message with type 55 to <bound method PlayerStateManager._handle_update_client of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x7f03fef94bb0>>
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_STATE_MESSAGE
[setStateMessage] {
  displayName: "SoundBoard"
  playbackState: Unknown
  playbackQueueCapabilities {
  }
  playerPath {
    origin {
      displayName: "HomePod"
      identifier: 1280262988
    }
    client {
      processIdentifier: 74
      bundleIdentifier: "com.apple.SoundBoard"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  playbackStateTimestamp: 679673724.755209
}
uniqueIdentifier: "25C0519D-A850-4862-BF8B-6606EB0694F2"
2022-07-16 16:15:27 DEBUG [pyatv.core.protocol]: Dispatching message with type 4 to <bound method PlayerStateManager._handle_set_state of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x7f03fef94bb0>>
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: PLAYER_CLIENT_PROPERTIES_MESSAGE
uniqueIdentifier: "9365C8CD-E49D-439C-B1B4-8D55D04FB4E9"
[playerClientPropertiesMessage] {
  playerPath {
    origin {
      displayName: "HomePod"
      identifier: 1280262988
      5: 1
    }
    client {
      processIdentifier: 74
      bundleIdentifier: "com.apple.SoundBoard"
      processUserIdentifier: 501
      displayName: "SoundBoard"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  lastPlayingTimestamp: -63114076800.0
}
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_STATE_MESSAGE
[setStateMessage] {
  playbackState: Unknown
  playbackQueueCapabilities {
  }
  playerPath {
    origin {
      displayName: "HomePod"
      identifier: 1280262988
    }
    client {
      processIdentifier: 79
      bundleIdentifier: "com.apple.internal.soundautoconfigservice"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  playbackStateTimestamp: 679673724.755388
}
uniqueIdentifier: "A7E46DF8-C4CE-434A-9A99-1CFF06AE6802"
2022-07-16 16:15:27 DEBUG [pyatv.core.protocol]: Dispatching message with type 4 to <bound method PlayerStateManager._handle_set_state of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x7f03fef94bb0>>
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: PLAYER_CLIENT_PROPERTIES_MESSAGE
uniqueIdentifier: "F9A81DAE-BEEC-4784-802B-4459389ADD4D"
[playerClientPropertiesMessage] {
  playerPath {
    origin {
      displayName: "HomePod"
      identifier: 1280262988
      5: 1
    }
    client {
      processIdentifier: 79
      bundleIdentifier: "com.apple.internal.soundautoconfigservice"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  lastPlayingTimestamp: -63114076800.0
}
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: UPDATE_CLIENT_MESSAGE
[updateClientMessage] {
  client {
    processIdentifier: 42430
    bundleIdentifier: "com.apple.podcasts"
    processUserIdentifier: 501
    displayName: "AirPodcasts"
  }
}
uniqueIdentifier: "1F429B3E-BEFB-40B7-89FC-8EE7A268556E"
2022-07-16 16:15:27 DEBUG [pyatv.core.protocol]: Dispatching message with type 55 to <bound method PlayerStateManager._handle_update_client of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x7f03fef94bb0>>
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_NOW_PLAYING_PLAYER_MESSAGE
[setNowPlayingPlayerMessage] {
  playerPath {
    origin {
      displayName: "HomePod"
      identifier: 1280262988
    }
    client {
      processIdentifier: 42430
      bundleIdentifier: "com.apple.podcasts"
    }
    player {
      identifier: "Podcasts"
      displayName: "Podcasts"
      6: 0
    }
  }
}
uniqueIdentifier: "5FA4BDC8-AF1B-4A0D-9803-E3E2DD706F37"
2022-07-16 16:15:27 DEBUG [pyatv.core.protocol]: Dispatching message with type 47 to <bound method PlayerStateManager._handle_set_now_playing_player of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x7f03fef94bb0>>
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_STATE_MESSAGE
[setStateMessage] {
  supportedCommands {
    supportedCommands {
      command: SetPlaybackSession
      enabled: true
      supportedPlaybackSessionTypes: "com.apple.podcasts.MTPlaybackQueueController.GenericQueue"
      currentPlaybackSessionTypes: "com.apple.podcasts.MTPlaybackQueueController.GenericQueue"
    }
    supportedCommands {
      command: PlayItemInPlaybackQueue
      enabled: true
    }
    supportedCommands {
      command: ReorderPlaybackQueue
      enabled: true
    }
    supportedCommands {
      command: RemoveFromPlaybackQueue
      enabled: true
    }
    supportedCommands {
      command: InsertIntoPlaybackQueue
      enabled: true
      supportedPlaybackQueueTypes: 3
      supportedPlaybackQueueTypes: 6
      supportedPlaybackQueueTypes: 2
      supportedPlaybackQueueTypes: 5
      supportedPlaybackQueueTypes: 1
    }
    supportedCommands {
      command: SetPlaybackQueue
      enabled: true
      supportedPlaybackQueueTypes: 3
      supportedPlaybackQueueTypes: 6
      supportedPlaybackQueueTypes: 2
      supportedPlaybackQueueTypes: 5
      supportedPlaybackQueueTypes: 1
    }
    supportedCommands {
      command: SeekToPlaybackPosition
      enabled: true
      canScrub: 1
    }
    supportedCommands {
      command: ChangePlaybackRate
      enabled: true
      supportedRates: 0.5
      supportedRates: 1.0
      supportedRates: 1.25
      supportedRates: 1.5
      supportedRates: 2.0
      preferredPlaybackRate: 1.0
    }
    supportedCommands {
      command: SkipBackward
      enabled: true
      preferredIntervals: 15.0
      preferredIntervals: 10.0
      preferredIntervals: 30.0
      preferredIntervals: 45.0
      preferredIntervals: 60.0
    }
    supportedCommands {
      command: SkipForward
      enabled: true
      preferredIntervals: 30.0
      preferredIntervals: 10.0
      preferredIntervals: 15.0
      preferredIntervals: 45.0
      preferredIntervals: 60.0
    }
    supportedCommands {
      command: BeginRewind
      enabled: true
    }
    supportedCommands {
      command: EndRewind
      enabled: true
    }
    supportedCommands {
      command: BeginFastForward
      enabled: true
    }
    supportedCommands {
      command: EndFastForward
      enabled: true
    }
    supportedCommands {
      command: PreviousTrack
      enabled: true
    }
    supportedCommands {
      command: NextTrack
      enabled: true
    }
    supportedCommands {
      command: Stop
      enabled: true
    }
    supportedCommands {
      command: TogglePlayPause
      enabled: true
    }
    supportedCommands {
      command: Pause
      enabled: true
    }
    supportedCommands {
      command: Play
      enabled: true
    }
  }
  displayName: "AirPodcasts"
  playbackState: Paused
  playbackQueueCapabilities {
    requestByRange: true
    requestByIdentifiers: true
  }
  playerPath {
    origin {
      displayName: "HomePod"
      identifier: 1280262988
    }
    client {
      processIdentifier: 42430
      bundleIdentifier: "com.apple.podcasts"
    }
    player {
      identifier: "Podcasts"
      displayName: "Podcasts"
      6: 0
    }
  }
  playbackStateTimestamp: 678635633.031522
}
uniqueIdentifier: "B7203BF9-CF31-4F7D-9851-B151009D3DF4"
2022-07-16 16:15:27 DEBUG [pyatv.core.protocol]: Dispatching message with type 4 to <bound method PlayerStateManager._handle_set_state of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x7f03fef94bb0>>
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: PLAYER_CLIENT_PROPERTIES_MESSAGE
uniqueIdentifier: "F5AE4581-1B5F-476E-866B-21A00737AC75"
[playerClientPropertiesMessage] {
  playerPath {
    origin {
      displayName: "HomePod"
      identifier: 1280262988
      5: 1
    }
    client {
      processIdentifier: 42430
      bundleIdentifier: "com.apple.podcasts"
      processUserIdentifier: 501
      displayName: "AirPodcasts"
    }
    player {
      identifier: "Podcasts"
      displayName: "Podcasts"
      6: 0
    }
  }
  lastPlayingTimestamp: -63114076800.0
}
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_STATE_MESSAGE
[setStateMessage] {
  supportedCommands {
    supportedCommands {
      command: SetPlaybackQueue
      enabled: true
      supportedPlaybackQueueTypes: 3
      supportedPlaybackQueueTypes: 6
      supportedPlaybackQueueTypes: 2
      supportedPlaybackQueueTypes: 5
      supportedPlaybackQueueTypes: 1
    }
  }
  displayName: "AirPodcasts"
  playbackState: Unknown
  playbackQueueCapabilities {
    requestByRange: true
    requestByIdentifiers: true
  }
  playerPath {
    origin {
      displayName: "HomePod"
      identifier: 1280262988
    }
    client {
      processIdentifier: 42430
      bundleIdentifier: "com.apple.podcasts"
    }
    player {
      identifier: "PodcastsMagicMoments"
      displayName: "PodcastsMagicMoments"
      6: 0
    }
  }
  playbackStateTimestamp: 679673724.755765
}
uniqueIdentifier: "EBD6CF16-2170-4025-B247-8DBEDDF896CD"
2022-07-16 16:15:27 DEBUG [pyatv.core.protocol]: Dispatching message with type 4 to <bound method PlayerStateManager._handle_set_state of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x7f03fef94bb0>>
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: PLAYER_CLIENT_PROPERTIES_MESSAGE
uniqueIdentifier: "BE94A389-2E64-4AA8-A8C0-855D08F42F69"
[playerClientPropertiesMessage] {
  playerPath {
    origin {
      displayName: "HomePod"
      identifier: 1280262988
      5: 1
    }
    client {
      processIdentifier: 42430
      bundleIdentifier: "com.apple.podcasts"
      processUserIdentifier: 501
      displayName: "AirPodcasts"
    }
    player {
      identifier: "PodcastsMagicMoments"
      displayName: "PodcastsMagicMoments"
      6: 0
    }
  }
  lastPlayingTimestamp: -63114076800.0
}
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_STATE_MESSAGE
[setStateMessage] {
  displayName: "AirPodcasts"
  playbackState: Unknown
  playbackQueueCapabilities {
  }
  playerPath {
    origin {
      displayName: "HomePod"
      identifier: 1280262988
    }
    client {
      processIdentifier: 42430
      bundleIdentifier: "com.apple.podcasts"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  playbackStateTimestamp: 679673724.755897
}
uniqueIdentifier: "485949F1-D9C2-407C-A014-A5FEA5453586"
2022-07-16 16:15:27 DEBUG [pyatv.core.protocol]: Dispatching message with type 4 to <bound method PlayerStateManager._handle_set_state of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x7f03fef94bb0>>
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: PLAYER_CLIENT_PROPERTIES_MESSAGE
uniqueIdentifier: "BB69464D-8DC0-44BF-95D9-5E4C82EA56EE"
[playerClientPropertiesMessage] {
  playerPath {
    origin {
      displayName: "HomePod"
      identifier: 1280262988
      5: 1
    }
    client {
      processIdentifier: 42430
      bundleIdentifier: "com.apple.podcasts"
      processUserIdentifier: 501
      displayName: "AirPodcasts"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  lastPlayingTimestamp: -63114076800.0
}
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: UPDATE_CLIENT_MESSAGE
[updateClientMessage] {
  client {
    processIdentifier: 42431
    bundleIdentifier: "com.apple.Music"
    processUserIdentifier: 501
    displayName: "AirMusic"
  }
}
uniqueIdentifier: "FF93ED36-8678-4BC9-9D55-838005ED8CAA"
2022-07-16 16:15:27 DEBUG [pyatv.core.protocol]: Dispatching message with type 55 to <bound method PlayerStateManager._handle_update_client of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x7f03fef94bb0>>
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_NOW_PLAYING_PLAYER_MESSAGE
[setNowPlayingPlayerMessage] {
  playerPath {
    origin {
      displayName: "HomePod"
      identifier: 1280262988
    }
    client {
      processIdentifier: 42431
      bundleIdentifier: "com.apple.Music"
    }
    player {
      identifier: "Music"
      displayName: "Music"
      6: 0
    }
  }
}
uniqueIdentifier: "D4D68EED-4296-41C4-B53C-0426798D0B22"
2022-07-16 16:15:27 DEBUG [pyatv.core.protocol]: Dispatching message with type 47 to <bound method PlayerStateManager._handle_set_now_playing_player of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x7f03fef94bb0>>
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_STATE_MESSAGE
[setStateMessage] {
  displayName: "AirMusic"
  playbackState: Unknown
  playbackQueueCapabilities {
  }
  playerPath {
    origin {
      displayName: "HomePod"
      identifier: 1280262988
    }
    client {
      processIdentifier: 42431
      bundleIdentifier: "com.apple.Music"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  playbackStateTimestamp: 679673724.75606
}
uniqueIdentifier: "0B6F1B52-E57D-4B36-90A8-35DB961A6481"
2022-07-16 16:15:27 DEBUG [pyatv.core.protocol]: Dispatching message with type 4 to <bound method PlayerStateManager._handle_set_state of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x7f03fef94bb0>>
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: PLAYER_CLIENT_PROPERTIES_MESSAGE
uniqueIdentifier: "3B729205-478B-4B39-8B4C-F10EB9E4D854"
[playerClientPropertiesMessage] {
  playerPath {
    origin {
      displayName: "HomePod"
      identifier: 1280262988
      5: 1
    }
    client {
      processIdentifier: 42431
      bundleIdentifier: "com.apple.Music"
      processUserIdentifier: 501
      displayName: "AirMusic"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  lastPlayingTimestamp: -63114076800.0
}
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_STATE_MESSAGE
[setStateMessage] {
  supportedCommands {
    supportedCommands {
      enabled: true
      1: 25020
    }
    supportedCommands {
      enabled: true
      1: 25010
    }
    supportedCommands {
      enabled: true
      1: 25001
    }
    supportedCommands {
      command: PreloadedPlaybackSession
      enabled: true
      supportedPlaybackSessionTypes: "com.apple.MediaPlaybackCore.playbackSession-v4.opack:subscription:cloudLibrary:f31bd42"
      supportedPlaybackSessionTypes: "com.apple.MediaPlaybackCore.playbackSession-v3.opack:subscription:cloudLibrary:f31bd42"
      supportedPlaybackSessionTypes: "com.apple.MediaPlaybackCore.playbackSession-v4.opack:subscription:cloudLibrary:b3deedb"
      supportedPlaybackSessionTypes: "com.apple.MediaPlaybackCore.playbackSession-v3.opack:subscription:cloudLibrary:b3deedb"
    }
    supportedCommands {
      command: ChangeQueueEndAction
      enabled: true
      currentQueueEndAction: AutoPlay
      supportedEndQueueActions: Reset
      supportedEndQueueActions: AutoPlay
    }
    supportedCommands {
      command: Reshuffle
      enabled: true
    }
    supportedCommands {
      command: SetPlaybackSession
      enabled: true
      supportedPlaybackSessionTypes: "com.apple.MediaPlaybackCore.playbackSession-v4.opack:subscription:cloudLibrary:f31bd42"
      supportedPlaybackSessionTypes: "com.apple.MediaPlaybackCore.playbackSession-v3.opack:subscription:cloudLibrary:f31bd42"
      supportedPlaybackSessionTypes: "com.apple.MediaPlaybackCore.playbackSession-v4.opack:subscription:cloudLibrary:b3deedb"
      supportedPlaybackSessionTypes: "com.apple.MediaPlaybackCore.playbackSession-v3.opack:subscription:cloudLibrary:b3deedb"
      currentPlaybackSessionTypes: "com.apple.MediaPlaybackCore.playbackSession-v3.opack:subscription:cloudLibrary:b3deedb"
      currentPlaybackSessionTypes: "com.apple.MediaPlaybackCore.playbackSession-v3.opack:subscription:storeFront:143446"
      playbackSessionIdentifier: "C32C222E-693B-4AD7-B6D0-7292F47E7B2F"
    }
    supportedCommands {
      command: PrepareForSetQueue
      enabled: true
    }
    supportedCommands {
      command: PlayItemInPlaybackQueue
      enabled: true
    }
    supportedCommands {
      command: ReorderPlaybackQueue
      enabled: true
    }
    supportedCommands {
      command: RemoveFromPlaybackQueue
      enabled: true
    }
    supportedCommands {
      command: InsertIntoPlaybackQueue
      enabled: true
      supportedPlaybackQueueTypes: 7
      supportedPlaybackQueueTypes: 3
      supportedPlaybackQueueTypes: 6
      supportedPlaybackQueueTypes: 2
      supportedPlaybackQueueTypes: 5
      supportedPlaybackQueueTypes: 1
      supportedCustomQueueIdentifiers: "com.apple.music.playbackqueue.tracklist"
      supportedCustomQueueIdentifiers: "com.apple.music.playbackqueue.radio"
      supportedCustomQueueIdentifiers: "com.apple.mediaplayer.playbackcontext"
      supportedInsertionPositions: 0
      supportedInsertionPositions: 2
      supportedInsertionPositions: 3
    }
    supportedCommands {
      command: SetPlaybackQueue
      enabled: true
      supportedPlaybackQueueTypes: 7
      supportedPlaybackQueueTypes: 3
      supportedPlaybackQueueTypes: 6
      supportedPlaybackQueueTypes: 2
      supportedPlaybackQueueTypes: 5
      supportedPlaybackQueueTypes: 1
      supportedPlaybackQueueTypes: 8
      supportedCustomQueueIdentifiers: "com.apple.music.playbackqueue.sharedlistening"
      supportedCustomQueueIdentifiers: "com.apple.music.playbackqueue.radio"
      supportedCustomQueueIdentifiers: "com.apple.music.playbackqueue.tracklist"
      supportedCustomQueueIdentifiers: "com.apple.MediaPlaybackCore.playbackContextArchive-v1.opack"
      supportedCustomQueueIdentifiers: "com.apple.mediaplayer.playbackcontext"
    }
    supportedCommands {
      command: CreateRadioStation
      enabled: true
    }
    supportedCommands {
      command: ChangeShuffleMode
      enabled: true
      shuffleMode: Songs
    }
    supportedCommands {
      command: ChangeRepeatMode
      enabled: true
      repeatMode: Off
    }
    supportedCommands {
      command: SeekToPlaybackPosition
      enabled: true
      canScrub: 1
    }
    supportedCommands {
      command: DislikeTrack
      enabled: true
      active: false
      localizedShortTitle: "REMOTE_CONTROL_DISLIKE_TRACK_SHORT"
      presentationStyle: 2
    }
    supportedCommands {
      command: LikeTrack
      enabled: true
      active: false
      localizedShortTitle: "REMOTE_CONTROL_LIKE_TRACK_SHORT"
      presentationStyle: 2
    }
    supportedCommands {
      command: ChangePlaybackRate
    }
    supportedCommands {
      command: SkipBackward
      preferredIntervals: 30.0
    }
    supportedCommands {
      command: SkipForward
      preferredIntervals: 30.0
    }
    supportedCommands {
      command: AdvanceRepeatMode
      enabled: true
      repeatMode: Off
    }
    supportedCommands {
      command: AdvanceShuffleMode
      enabled: true
      shuffleMode: Songs
    }
    supportedCommands {
      command: PreviousTrack
      enabled: true
    }
    supportedCommands {
      command: NextTrack
      enabled: true
    }
    supportedCommands {
      command: Stop
      enabled: true
    }
    supportedCommands {
      command: TogglePlayPause
      enabled: true
    }
    supportedCommands {
      command: Pause
      enabled: true
    }
    supportedCommands {
      command: Play
      enabled: true
    }
  }
  playbackQueue {
    location: 0
    contentItems {
      identifier: "N86egpl46\342\210\206wX6g8gSN8"
      metadata {
        title: "U Don\'t Know Me (feat. Duane Harden)"
        isPlayable: true
        albumName: "2 Future 4 U"
        trackArtistName: "Armand Van Helden"
        duration: 484.6
        artworkAvailable: true
        lyricsAvailable: true
        editingStyleFlags: 3
        elapsedTime: 432.390359699
        genre: "Electronic"
        isAlwaysLive: false
        playbackRate: 0.0
        trackNumber: 6
        iTunesStoreIdentifier: 1320963076
        iTunesStoreSubscriptionIdentifier: 1320963076
        iTunesStoreArtistIdentifier: 7431216
        iTunesStoreAlbumIdentifier: 1320962648
        defaultPlaybackRate: 1.0
        mediaType: Audio
        mediaSubType: Music
        nowPlayingInfoData: "bplist00\324\001\002\003\004\005\006\007\nX$versionY$archiverT$topX$objects\022\000\001\206\240_\020\017NSKeyedArchive...
        userInfoData: "bplist00\324\001\002\003\004\005\006\007\nX$versionY$archiverT$topX$objects\022\000\001\206\240_\020\017NSKeyedArchiver\321\...
        artworkURL: "https://is1-ssl.mzstatic.com/image/thumb/Music124/v4/2c/54/a1/2c54a128-34f7-54a5-b492-68066be1ea50/639842964326.jpg/1200x1200b...
        deviceSpecificUserInfoData: "bplist00\324\001\002\003\004\005\006\007\nX$versionY$archiverT$topX$objects\022\000\001\206\240_\020\017NSKeye...
        collectionInfoData: "bplist00\324\001\002\003\004\005\006\007\nX$versionY$archiverT$topX$objects\022\000\001\206\240_\020\017NSKeyedArchive...
        elapsedTimeTimestamp: 679673703.877575
        inferredTimestamp: 679673104.135016
        artworkIdentifier: "https://is1-ssl.mzstatic.com/image/thumb/Music124/v4/2c/54/a1/2c54a128-34f7-54a5-b492-68066be1ea50/639842964326.jpg/{w}...
        isLoading: false
        artworkURLTemplatesData: "bplist00\324\001\002\003\004\005\006\007\nX$versionY$archiverT$topX$objects\022\000\001\206\240_\020\017NSKeyedAr...
        legacyUniqueIdentifier: 6763242101845442338
        albumYear: "1997"
        songTraits: Lossless
        preferredFormat {
          tier: HighQualityStereo
          bitrate: 0
          sampleRate: 44100
          bitDepth: 16
          codec: 1634492771
          spatialized: false
          multiChannel: false
          channelLayout: 6619138
          audioChannelLayoutDescription: "Stereo"
          groupID: "audio-alac-stereo-44100-16"
          stableVariantID: "9b0ccf95cd966f41ee2b0a7ffb783baf86f1de3f4e6ecd4190ad523b8d1e8005"
        }
        activeFormat {
          tier: HighQualityStereo
          bitrate: 0
          sampleRate: 44100
          bitDepth: 16
          codec: 1634492771
          spatialized: false
          multiChannel: false
          channelLayout: 6619138
          audioChannelLayoutDescription: "Stereo"
          groupID: "audio-alac-stereo-44100-16"
          stableVariantID: "9b0ccf95cd966f41ee2b0a7ffb783baf86f1de3f4e6ecd4190ad523b8d1e8005"
        }
        activeFormatJustification: UserPreference
        audioRoute {
          name: "HomePod"
          supportsSpatialization: true
          1: 1
          4: 1
        }
        alternativeFormats {
          tier: HighQualityStereo
          bitrate: 0
          sampleRate: 44100
          bitDepth: 16
          codec: 1634492771
          spatialized: false
          multiChannel: false
          channelLayout: 6619138
          audioChannelLayoutDescription: "Stereo"
          groupID: "audio-alac-stereo-44100-16"
          stableVariantID: "9b0ccf95cd966f41ee2b0a7ffb783baf86f1de3f4e6ecd4190ad523b8d1e8005"
        }
        alternativeFormats {
          tier: LowBandwidthStereo
          bitrate: 256000
          sampleRate: 0
          bitDepth: 0
          codec: 1633772320
          spatialized: false
          multiChannel: false
          channelLayout: 6619138
          audioChannelLayoutDescription: "Stereo"
          groupID: "audio-stereo-256"
          stableVariantID: "3c1e0420f0b3913d64d3ea3b1b428806afff374af90a7ed3d8d307f352b5d152"
        }
        alternativeFormats {
          bitrate: 128000
          sampleRate: 0
          bitDepth: 0
          codec: 1633772320
          spatialized: false
          multiChannel: false
          channelLayout: 6619138
          audioChannelLayoutDescription: "Stereo"
          groupID: "audio-stereo-128"
          stableVariantID: "dcb77ff7607bcda5be58ef6808abfc2c09e8654faeeec56e7cba10374e787390"
          1: 0
        }
        alternativeFormats {
          bitrate: 64000
          sampleRate: 0
          bitDepth: 0
          codec: 1633772392
          spatialized: false
          multiChannel: false
          channelLayout: 6619138
          audioChannelLayoutDescription: "Stereo"
          groupID: "audio-HE-stereo-64"
          stableVariantID: "23506dc72aa3d7db5f4b9c8832c51909ded9820fcbc66472b4866a5cf85574b3"
          1: 0
        }
        95: 20
        99: 1
      }
    }
  }
  displayName: "AirMusic"
  playbackState: Paused
  playbackQueueCapabilities {
    requestByRange: true
    requestByIdentifiers: true
  }
  playerPath {
    origin {
      displayName: "HomePod"
      identifier: 1280262988
    }
    client {
      processIdentifier: 42431
      bundleIdentifier: "com.apple.Music"
    }
    player {
      identifier: "Music"
      displayName: "Music"
      6: 0
    }
  }
  playbackStateTimestamp: 679673703.900079
}
uniqueIdentifier: "4CE75B0D-38BC-4D39-BDC8-6B993237DCAE"
2022-07-16 16:15:27 DEBUG [pyatv.core.protocol]: Dispatching message with type 4 to <bound method PlayerStateManager._handle_set_state of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x7f03fef94bb0>>
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: PLAYER_CLIENT_PROPERTIES_MESSAGE
uniqueIdentifier: "A9F2591D-E3BC-4C4C-921F-5C51D56C1219"
[playerClientPropertiesMessage] {
  playerPath {
    origin {
      displayName: "HomePod"
      identifier: 1280262988
      5: 1
    }
    client {
      processIdentifier: 42431
      bundleIdentifier: "com.apple.Music"
      processUserIdentifier: 501
      displayName: "AirMusic"
    }
    player {
      identifier: "Music"
      displayName: "Music"
      6: 127810
    }
  }
  lastPlayingTimestamp: 679673703.91703
}
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: UPDATE_PLAYER_MESSAGE
uniqueIdentifier: "B0B4EBDC-D45B-4139-BD2C-305A968A3969"
62 {
  1 {
    1 {
      2 {
        9: 111
        13: 1685016677
      }
      3: 1280262988
    }
    2 {
      1: 42431
      2: "com.apple.Music"
    }
    3 {
      1 {
        9: 1667855221
      }
      2 {
        9: 1667855221
      }
      6: 127810
    }
  }
}
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: VOLUME_CONTROL_CAPABILITIES_DID_CHANGE_MESSAGE
[volumeControlCapabilitiesDidChangeMessage] {
  capabilities {
    volumeControlAvailable: true
    volumeCapabilities: Absolute
  }
  outputDeviceUID: "4BE42F0B-42A9-4ECA-92FF-1852D84C31C9"
}
uniqueIdentifier: "513DB0DE-87D3-4EFC-A60D-7BF04819A3BC"
2022-07-16 16:15:27 DEBUG [pyatv.core.protocol]: Dispatching message with type 64 to <bound method MrpAudio._volume_control_changed of <pyatv.protocols.mrp.MrpAudio object at 0x7f03ff057c10>>
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: VOLUME_DID_CHANGE_MESSAGE
[volumeDidChangeMessage] {
  volume: 0.25000006
  outputDeviceUID: "4BE42F0B-42A9-4ECA-92FF-1852D84C31C9"
}
uniqueIdentifier: "DAA5E84C-817D-4680-B6C4-357CF0C100FE"
2022-07-16 16:15:27 DEBUG [pyatv.core.protocol]: Dispatching message with type 52 to <bound method MrpAudio._volume_did_change of <pyatv.protocols.mrp.MrpAudio object at 0x7f03ff057c10>>
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: UNKNOWN_MESSAGE
identifier: "96768668-9046-40B7-8598-9CDA28DFA616"
uniqueIdentifier: "57C1D600-FAFA-4AF7-9321-CC3ED986F95A"
2022-07-16 16:15:27 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=20000a62cd3b2d5ec68bdc6410eb1ef6db7d3cc92b3fbf68541aef8b0a5b24572188445359aeb064c330d164e9d5e4c5838d)
2022-07-16 16:15:27 DEBUG [pyatv.protocols.mrp]: Volume control availability changed to True
2022-07-16 16:15:27 DEBUG [pyatv.protocols.mrp.player_state]: Active client is now com.apple.Music
2022-07-16 16:15:27 DEBUG [pyatv.protocols.mrp.player_state]: Active player is now Podcasts (Podcasts)
2022-07-16 16:15:27 DEBUG [pyatv.protocols.mrp.player_state]: Active player is now Music (Music)
2022-07-16 16:15:27 DEBUG [pyatv.protocols.mrp]: Volume control availability changed to True
2022-07-16 16:15:27 DEBUG [pyatv.protocols.mrp]: Volume changed to 25.0
2022-07-16 16:15:27 DEBUG [pyatv.core.protocol]: Dispatching message with type UpdatedState.Volume to <bound method RaopAudio._volume_changed of <pyatv.protocols.raop.RaopAudio object at 0x7f03fefd13d0>>
2022-07-16 16:15:27 DEBUG [pyatv.protocols.raop]: Protocol MRP changed volume to 25.000000
2022-07-16 16:15:27 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=b40086e40a60f51f3e5bcc31c28605bf1f5f2c235d5dbb34ffc21808d2a749dc477879e42c0031b7fc0ab786f6ef092c51b17c385a75f85d478325010783af8b9ffa0ff3cede65001f8db232bc02e1f323bcdab652dc401a1573a30f05fed427cf99e81ad6ede3ed5f7ae26a28ca71d30b583e33b3f72696fc98e66784a0131685e0abf3c33524adefc8abb04a99529ab9b92a46c626ab07259bd2a9349085addd5d331af05f1eaf0adc537d53b3a00d5d5d532b8eaa1be66fd6eab961ffa3ab8dcc4ae72a7e)
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: >> Send: Protobuf: type: GET_KEYBOARD_SESSION_MESSAGE
identifier: "8D3D31C8-92BF-4419-BB13-14F06604CFA4"
errorCode: NoError
uniqueIdentifier: "733A86CC-8E39-43CC-B4D3-21A8956C46EA"
2022-07-16 16:15:27 DEBUG [pyatv.auth.hap_channel]: Received data (Data=200031ef7598fd9e69154b29d478fcad05ab16eb031b6aa960a50e9d70b8edb2cfa8dcc58e6546ccf8a46355bc623b83de872a0054015c608e6a9f6aa5a8453c2b956db7497a7dc53e3bd5826643eee2858f3d74b0b899b2f48984ee124d26c8975f19bb5713e024fad63f9a1dac)
2022-07-16 16:15:27 DEBUG [pyatv.auth.hap_channel]: Received data (Data=20008afaf492fab70c3ff9e444d50865527dab9bed2f32df30a57c666e273b5f91e0cef9f02e29b30e379127fce860a6659ba9009a26b26d2eed5ecfb1c4f3167c0792ff8caada412cf79cd8e5b0a31b24bffea0bec604756602cc93b4f4d62da2898d8fd4d1ac707c4ac5639c5d039b425a756588ea4b5c2bc23b0a2658be7eeebc4f6b5cad0062d51867cc4817c55a8e9597d8cb556b4ea5254c145278f59e23bcfe89d0add3516b3fd5b943335f53ff5016ae997fc5852f94cfc242499ced4d915fb14dddb80248ed9413cdf1bdbf8b6e8da80a7f31f22eec307c67307a0af1f357d034ab0d1aad45032905)
2022-07-16 16:15:27 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: KEYBOARD_MESSAGE
identifier: "8D3D31C8-92BF-4419-BB13-14F06604CFA4"
[keyboardMessage] {
  state: Unknown
  attributes {
    inputTraits {
      autocapitalizationType: None
      keyboardType: Default
      returnKeyType: Default
      enablesReturnKeyAutomatically: false
      secureTextEntry: false
      validTextRangeLocation: 0
      validTextRangeLength: 0
    }
  }
}
uniqueIdentifier: "404F06F0-19BB-46C6-B041-B25FE28EE6E5"
2022-07-16 16:15:27 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=20005792189ae534a49f0f61d4a9ca4b3a22bc615f767a7801f243453c6440b9fcbcaf065aa235ad9ae7d6631be2522f9108)
2022-07-16 16:15:27 DEBUG [pyatv.core.facade]: Connected to protocol: Protocol.MRP
2022-07-16 16:15:27 DEBUG [pyatv.core.facade]: Protocol Protocol.MRP already set up, ignoring
2022-07-16 16:15:27 DEBUG [pyatv.core.facade]: Connecting to protocol: Protocol.RAOP
2022-07-16 16:15:27 DEBUG [pyatv.core.facade]: Connected to protocol: Protocol.RAOP
Enter commands and press enter
Type help for help and exit to quit
pyatv> volume_2022-07-16 16:15:29 DEBUG [pyatv.core.protocol]: Sending periodic heartbeat 0 (AirPlay:192.168.1.108)
2022-07-16 16:15:29 DEBUG [pyatv.support.http]: Sending RTSP/1.0 message: b'POST /feedback RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nCSeq: 3\r\nDACP-ID: DF9A1CAE7566DEC8\r\nActive-Remote: 1281514640\r\nClient-Instance: DF9A1CAE7566DEC8\r\n\r\n'
2022-07-16 16:15:29 DEBUG [pyatv.support.http]: Received: b'RTSP/1.0 200 OK\r\nDate: Sat, 16 Jul 2022 14:15:26 GMT\r\nContent-Length: 55\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/615.12.1\r\nCSeq: 3\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'
2022-07-16 16:15:29 DEBUG [pyatv.support.http]: Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Sat, 16 Jul 2022 14:15:26 GMT', 'content-length': '55', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/615.12.1', 'cseq': '3'}, 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'):
2022-07-16 16:15:29 DEBUG [pyatv.core.protocol]: Got heartbeat 0 (AirPlay:192.168.1.108)
up
2022-07-16 16:15:29 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=ce00a940e5badb8f366e9da0775a88f95875fc9b46cf6605766f96ddc3576d10cc5ee062477ad2de3fa7cac186eda1d5ca2ba837aab3f516cf0de71f8adbb4b91c4680bfbec0e0de8092c1bb4e864e2ba700c5e83611a222f35ce120d908b5da20e4704cec809e550caaf24cfd9e7b2cca9b69be3aa58cd330c5b93ef7ab771de41dc295045b345b0a50b8b0b4c2d8f3923716b046df768b3d604d18765d028ab7bb7eaba77ee6858818a319d30b76d1c1fb67fd7f3ca20428bcca7dfc7fdee444299a1069739e02de1e31897457a7ac43a79b192521c98b5aaed397881712df)
2022-07-16 16:15:29 DEBUG [pyatv.protocols.airplay.mrp_connection]: >> Send: Protobuf: type: SEND_HID_EVENT_MESSAGE
errorCode: NoError
[sendHIDEventMessage] {
  hidEventData: "C\211\"\317\010\002\000\000\000\000\000\000\000\000\000\000\001\000\000\000\000\000\000\000\002\000\000\000 \000\000\000\003\000\0...
}
uniqueIdentifier: "E635F5CB-3F78-4317-8329-47CB6A23148C"
2022-07-16 16:15:29 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=ce00e00a806ac3da7a1900d2b00b1f4fc966f25f505a1c5fe93de8d20fb773ece84966e0acf972a162b4515731d25977c4c288229977debbfe627ef6c24fe484008a78c314d9387b97d12a85ae0051f0e327b5fec7861688328f71bf16eef53e3e04c9a747909f7e688908f7f2005f4b90236af900c760583ef423d9ce0e9733a8711442e02e6c1a7d2ee259de2f9e27a8f554fda44c1b405ffe2ef1e8173f587f58ae74876a8ed271cf81aa1ec8aa28d63978cfd2c958473185b7ada86409b45a26a0b3eb1a648ec09553f6f19a8b05e36804bc825ea828803e3767a805baf0)
2022-07-16 16:15:29 DEBUG [pyatv.protocols.airplay.mrp_connection]: >> Send: Protobuf: type: SEND_HID_EVENT_MESSAGE
errorCode: NoError
[sendHIDEventMessage] {
  hidEventData: "C\211\"\317\010\002\000\000\000\000\000\000\000\000\000\000\001\000\000\000\000\000\000\000\002\000\000\000 \000\000\000\003\000\0...
}
uniqueIdentifier: "04D28610-8284-4A33-B0FC-522B0D18765E"
2022-07-16 16:15:29 DEBUG [pyatv.auth.hap_channel]: Received data (Data=20007756efdd4b441c3da886d5eca0a5059b85741a9681fb0ca2254edc5368a1a5c97ce3749078eb2c6e78a1553f3f7f296f2a0053a8379991a1ae6c459545e245f9546a617ac79aac5135cd468f4b5d5f3f09e978be96a23acfc00ac68e69793e911343ef4d223a2dcb92f94e2620009726760aeaa40f1dc3d189cd336112655319ca1852519049cb90efed24d4d3909e52e2b475e3374d1b3533cd020427e5)
2022-07-16 16:15:29 DEBUG [pyatv.protocols.airplay.channels]: Not enough data on data channel (has 32, expects 74)
2022-07-16 16:15:29 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2a0044c692467779a193e7ec72392611e99bae2c6f080e81a8a25ad7e59b90b2935dc6ad28fd14683cfe7e91bd4981700f6ba34108b5e549b07b8203)
2022-07-16 16:15:30 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2000af05ac5d69449f696561f5f19bdf480145ed7dc69ec787a5b30dadda1ac62c5874eb5235161f3ecdc7adc81886757709)
2022-07-16 16:15:30 DEBUG [pyatv.protocols.airplay.channels]: Not enough data on data channel (has 32, expects 215)
2022-07-16 16:15:30 DEBUG [pyatv.auth.hap_channel]: Received data (Data=b700a4e188ccb2c587c79518d9c60a17aa15c70c1b2e7a0532249db0e65d78600f9b9d2f059f6fa343146629401e15b580d1a0d1d9a8c4acd6ec7d24e1a7c7b0864e336efdcc6e5b65a428f5bf95d198cb2c9b4cfef7c73757704726b1cb7988b2c86964cce6269604a89de6d3c29adf3edde45ee8056e104944b73329f5046026c58d451425d02afdbf2f9706e333787378c288ddd4000a5a4578280e9bf8bc56142f302b542d4caf3640889e21c6ca37aa43b890696c9a9d29d4eb3e45acf54f46b7cf3d526303b1)
2022-07-16 16:15:30 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_STATE_MESSAGE
[setStateMessage] {
  playbackState: Playing
  playbackQueueCapabilities {
  }
  playerPath {
    origin {
      displayName: "HomePod"
      identifier: 1280262988
    }
    client {
      processIdentifier: 42431
      bundleIdentifier: "com.apple.Music"
    }
    player {
      identifier: "Music"
      displayName: "Music"
      6: 0
    }
  }
  playbackStateTimestamp: 679673727.762983
}
uniqueIdentifier: "E01F99C5-806E-420A-B2ED-07F26642F10E"
2022-07-16 16:15:30 DEBUG [pyatv.core.protocol]: Dispatching message with type 4 to <bound method PlayerStateManager._handle_set_state of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x7f03fef94bb0>>
2022-07-16 16:15:30 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=20009b0e02ddff6b8949d349302cd948e152962393d8ae863d0086253e384b13ed82a82ac0a907c16a9f33a6d3e7917f33a9)
2022-07-16 16:15:31 DEBUG [pyatv.auth.hap_channel]: Received data (Data=20005d51da604716673956cb345bdf0a8812efef5f7f845738278a46b7e5786bce9def85286bc3992506c515ad09dfccadf0)
2022-07-16 16:15:31 DEBUG [pyatv.protocols.airplay.channels]: Not enough data on data channel (has 32, expects 247)
2022-07-16 16:15:31 DEBUG [pyatv.auth.hap_channel]: Received data (Data=d7007da34cbcb729ee86ea8643dab6d98aef13e57b6726ed535d1fda3d59effa074b2f6440148a71f2aa5e9101dfb0d2b7d79d8919f41dc4107f6a58139ca56f5a5b0daae32a9b2da6f7445a95010222d942363171114f94db34ecadf58bf69457a277c23d0072dd9a18aa0df9063b071bc489a9192a39e39c9f8b8556d49f7b987b39aabaf4ddcfa216d6ee3c971a797ad505c919b608baacce66bab8bd6936ef274c11aebb8008383695485b1b7dc160358d341805eb85fcbbacf8ab0a7fcbd42d7214254b4dcec9a17da49f5ec4eb6b8484498f28030ca19c9f6ba46a1eea991cbd9a00e76afa87)
2022-07-16 16:15:31 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: UPDATE_CONTENT_ITEM_MESSAGE
[updateContentItemMessage] {
  contentItems {
    identifier: "N86egpl46\342\210\206wX6g8gSN8"
    metadata {
      playbackRate: 1.0
      elapsedTimeTimestamp: 679673727.694988
    }
  }
  playerPath {
    origin {
      displayName: "HomePod"
      identifier: 1280262988
    }
    client {
      processIdentifier: 42431
      bundleIdentifier: "com.apple.Music"
    }
    player {
      identifier: "Music"
      displayName: "Music"
      6: 0
    }
  }
}
uniqueIdentifier: "FF2B744D-C2F4-4568-A132-7DB2C2360453"
2022-07-16 16:15:31 DEBUG [pyatv.core.protocol]: Dispatching message with type 56 to <bound method PlayerStateManager._handle_content_item_update of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x7f03fef94bb0>>
2022-07-16 16:15:31 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=20006bdb72f2300e4d6254dd71076709a9a1b9de65ad7a6379f8d49b7220f9bc111b605806c27277b5893c57195171709203)
2022-07-16 16:15:31 DEBUG [pyatv.core.protocol]: Sending periodic heartbeat 1 (AirPlay:192.168.1.108)
2022-07-16 16:15:31 DEBUG [pyatv.support.http]: Sending RTSP/1.0 message: b'POST /feedback RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nCSeq: 4\r\nDACP-ID: DF9A1CAE7566DEC8\r\nActive-Remote: 1281514640\r\nClient-Instance: DF9A1CAE7566DEC8\r\n\r\n'
2022-07-16 16:15:31 DEBUG [pyatv.support.http]: Received: b'RTSP/1.0 200 OK\r\nDate: Sat, 16 Jul 2022 14:15:28 GMT\r\nContent-Length: 55\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/615.12.1\r\nCSeq: 4\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'
2022-07-16 16:15:31 DEBUG [pyatv.support.http]: Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Sat, 16 Jul 2022 14:15:28 GMT', 'content-length': '55', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/615.12.1', 'cseq': '4'}, 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'):
2022-07-16 16:15:31 DEBUG [pyatv.core.protocol]: Got heartbeat 1 (AirPlay:192.168.1.108)
2022-07-16 16:15:33 DEBUG [pyatv.core.protocol]: Sending periodic heartbeat 2 (AirPlay:192.168.1.108)
2022-07-16 16:15:33 DEBUG [pyatv.support.http]: Sending RTSP/1.0 message: b'POST /feedback RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nCSeq: 5\r\nDACP-ID: DF9A1CAE7566DEC8\r\nActive-Remote: 1281514640\r\nClient-Instance: DF9A1CAE7566DEC8\r\n\r\n'
2022-07-16 16:15:33 DEBUG [pyatv.support.http]: Received: b'RTSP/1.0 200 OK\r\nDate: Sat, 16 Jul 2022 14:15:30 GMT\r\nContent-Length: 55\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/615.12.1\r\nCSeq: 5\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'
2022-07-16 16:15:33 DEBUG [pyatv.support.http]: Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Sat, 16 Jul 2022 14:15:30 GMT', 'content-length': '55', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/615.12.1', 'cseq': '5'}, 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'):
2022-07-16 16:15:33 DEBUG [pyatv.core.protocol]: Got heartbeat 2 (AirPlay:192.168.1.108)
2022-07-16 16:15:34 DEBUG [pyatv.protocols.airplay.mrp_connection]: Closing connection
2022-07-16 16:15:34 DEBUG [pyatv.scripts.atvremote]: Waiting for 1 remaining tasks
2022-07-16 16:15:34 DEBUG [pyatv.protocols.airplay.mrp_connection]: Disconnected from device: None
2022-07-16 16:15:34 DEBUG [pyatv.scripts.atvremote]: Connection was closed properly
2022-07-16 16:15:34 DEBUG [pyatv.core.protocol]: Stopping heartbeat loop at 4 (AirPlay:192.168.1.108)
2022-07-16 16:15:34 DEBUG [pyatv.support.http]: Connection closed
2022-07-16 16:15:34 DEBUG [pyatv.auth.hap_channel]: Connection was lost to remote
Traceback (most recent call last):
  File "/usr/lib/python3.9/asyncio/locks.py", line 226, in wait
    await fut
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.9/asyncio/tasks.py", line 492, in wait_for
    fut.result()
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/var/www/html/plugins/aTVremote/resources/atvremote/lib/python3.9/site-packages/pyatv/scripts/atvremote.py", line 717, in _run_application
    return await cli_handler(loop)
  File "/var/www/html/plugins/aTVremote/resources/atvremote/lib/python3.9/site-packages/pyatv/scripts/atvremote.py", line 511, in cli_handler
    return await _handle_commands(args, config, loop)
  File "/var/www/html/plugins/aTVremote/resources/atvremote/lib/python3.9/site-packages/pyatv/scripts/atvremote.py", line 612, in _handle_commands
    ret = await _handle_device_command(args, cmd, atv, loop)
  File "/var/www/html/plugins/aTVremote/resources/atvremote/lib/python3.9/site-packages/pyatv/scripts/atvremote.py", line 637, in _handle_device_command
    return await _exec_command(
  File "/var/www/html/plugins/aTVremote/resources/atvremote/lib/python3.9/site-packages/pyatv/scripts/atvremote.py", line 683, in _exec_command
    value = await tmp(*args)
  File "/var/www/html/plugins/aTVremote/resources/atvremote/lib/python3.9/site-packages/pyatv/scripts/atvremote.py", line 248, in cli
    await _handle_device_command(self.args, command, self.atv, self.loop)
  File "/var/www/html/plugins/aTVremote/resources/atvremote/lib/python3.9/site-packages/pyatv/scripts/atvremote.py", line 644, in _handle_device_command
    return await _exec_command(atv.audio, cmd, True, *cmd_args)
  File "/var/www/html/plugins/aTVremote/resources/atvremote/lib/python3.9/site-packages/pyatv/scripts/atvremote.py", line 683, in _exec_command
    value = await tmp(*args)
  File "/var/www/html/plugins/aTVremote/resources/atvremote/lib/python3.9/site-packages/pyatv/core/facade.py", line 423, in volume_up
    return await self.relay("volume_up")()
  File "/var/www/html/plugins/aTVremote/resources/atvremote/lib/python3.9/site-packages/pyatv/protocols/mrp/__init__.py", line 757, in volume_up
    await asyncio.wait_for(self._volume_event.wait(), timeout=5.0)
  File "/usr/lib/python3.9/asyncio/tasks.py", line 494, in wait_for
    raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError

>>> An error occurred, full stack trace above
postlund commented 2 years ago

That is a different error unfortunately. That happens because volume_up waits for a volume update that never comes (for some reason), so I can't really draw any conclusions from that log.

NebzHB commented 2 years ago

what would you need ?

datawrangler commented 1 year ago

I too have been trying to develop a daemon which writes the output of _atvremote pushupdates to a websocket. Everything is working pretty well, but when the Apple Music application on my iMac shuts down, pyatv crashes and I need to restart the daemon manually. I can't figure out how to catch this error gracefully.