postlund / pyatv

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

Help me squash bugs before 0.9.0 is released #1298

Closed postlund closed 3 years ago

postlund commented 3 years ago

What's on your mind?

So, I'm getting very close to release v0.9.0 of pyatv, containing lots of updates. Especially under the hood. The biggest update is however the "MRP-over-AirPlay"-support, that is required to work with tvOS 15. Adding support for that also made it possible to support the HomePod with very little effort, so it is now possible to do that as well.

It would be really great to get some help testing things before shipping to iron out the last quirks (as I'm sure there are quite a few...). What mainly needs testing is tvOS 15 support and the HomePod, as mentioned. But general usage is also welcomed (other protocols, streaming, etc.) as a lot of improvements have been made that changes the general way pyatv works.

The HomePod does not require particular pairing or such, it should just work now. For instance to see what is playing:

$ atvremote -s 10.0.10.84 playing
  Media type: Unknown
Device state: Playing
       Title: Unpaid Intern
      Artist: Bo Burnham
       Album: Inside (The Songs)
    Position: 5/34s (14.7%)
      Repeat: Off
     Shuffle: Off

The Apple TV requires credentials however, so you need to pair with it first (atvremote -s <ip> --protocol airplay pair) and pass them via --airplay-credentials (atvremote -s <ip> --airplay-credentials <creds> playing). Only AirPlay credentials are really needed to test tvOS 15 support. Credentials obtained with previous versions of pyatv will not work, so you need to re-pair for this one.

This will work with tvOS 14 as well, but it's tricky to know if MRP tunneled over AirPlay or if regular MRP is used. An easy way is to look for this line in the --debug log:

2021-09-09 06:18:36 DEBUG [pyatv.protocols.airplay.remote_control]: Setting up remote control connection to 10.0.10.84:7000

It's also possible to limit to just testing AirPlay by specifying --scan-protocols:

$ atvrremote -s <ip> --scan-protocols airplay --airplay-credentials <creds> playing

One last thing: there are pre-built docker images now. So it's possible to test pyatv without having to install anything other than Docker. Version 0.9.0 will be the first proper "container release", but all commits to the master branch are automatically pushed as new images. It's as easy as this to run from master:

$ docker run  --rm --network=host ghcr.io/postlund/pyatv:master atvremote scan

I will be so thankful for all the help I can get here, to thank you!

dehness commented 3 years ago

How do I go about installing this version? I'm running the latest version of Home Assistant Core (docker) and have the latest tvOS 15 Beta and an iPhone 11 running iOS 14.3. It looks like HA has the current 0.8.2 master of pyatv, but I'm guessing I need to install some sort of dev branch in order to get tvOS 15 support as I still get the error "The configuration for this device is incomplete. Please try adding it again."

postlund commented 3 years ago

I have not made any releases to pypi yet, so it's tricky to get it into Home Assistant. In the past, it was possible to point to a commit at GitHub and have Home Assistant pull the code from there. Maybe that's still possible, I don't know. But I think that would be the only feasible way right now.

Qonstrukt commented 3 years ago

Can you also make a Docker build for the existing 0.8.2 version? Because I get inconsistent results while using the master image on my Mac, and I'm wondering if it's because of Docker or the new version:

> docker run --rm --network=host ghcr.io/postlund/pyatv:master atvremote scan
Scan Results
========================================

Because I do get results with pyatv 0.8.2 installed directly on my Mac:

> atvremote scan
Scan Results
========================================
       Name: Receiver Mancave
   Model/SW: Unknown Model Unknown OS
    Address: -
        MAC: -
 Deep Sleep: False
Identifiers:
Services:
 - Protocol: AirPlay, Port: 7000, Credentials: None
 - Protocol: RAOP, Port: 7000, Credentials: None

       Name: Sonos Veranda
   Model/SW: Unknown Model Unknown OS
    Address: -
        MAC: -
 Deep Sleep: False
Identifiers:
Services:
 - Protocol: AirPlay, Port: 7000, Credentials: None
 - Protocol: RAOP, Port: 7000, Credentials: None

       Name: Apple TV Zithoek
   Model/SW: AppleTV4KGen2 Unknown OS 15.0
    Address: -
        MAC: -
 Deep Sleep: False
Identifiers:
Services:
 - Protocol: Companion, Port: 49156, Credentials: None
 - Protocol: AirPlay, Port: 7000, Credentials: None
 - Protocol: RAOP, Port: 7000, Credentials: None

       Name: Sonos Eethoek
   Model/SW: Unknown Model Unknown OS
    Address: -
        MAC: -
 Deep Sleep: False
Identifiers:
Services:
 - Protocol: AirPlay, Port: 7000, Credentials: None
 - Protocol: RAOP, Port: 7000, Credentials: None

       Name: Apple TV Slaapkamer
   Model/SW: Gen4 tvOS 14.7 build 18M60
    Address: -
        MAC: -
 Deep Sleep: False
Identifiers:
Services:
 - Protocol: AirPlay, Port: 7000, Credentials: None
 - Protocol: Companion, Port: 49153, Credentials: None
 - Protocol: MRP, Port: 49152, Credentials: None
 - Protocol: RAOP, Port: 7000, Credentials: None

       Name: Apple TV Mancave
   Model/SW: Gen4K tvOS 14.7 build 18M60
    Address: -
        MAC: -
 Deep Sleep: False
Identifiers:
Services:
 - Protocol: Companion, Port: 49153, Credentials: None
 - Protocol: AirPlay, Port: 7000, Credentials: None
 - Protocol: MRP, Port: 49152, Credentials: None
 - Protocol: RAOP, Port: 7000, Credentials: None

Trying to pair one manually tries to initiate something, but fails while I should enter the pin:

> docker run  --rm --network=host ghcr.io/postlund/pyatv:master atvremote -s <ipaddress> --protocol airplay pair
Enter PIN on screen: 2021-09-13 13:05:44 ERROR [pyatv.scripts.atvremote]: Pairing failed
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/site-packages/pyatv/support/__init__.py", line 33, in error_handler
    return await func(*args, **kwargs)
  File "/usr/local/lib/python3.9/site-packages/pyatv/protocols/airplay/auth/hap.py", line 77, in finish_pairing
    resp = await self.http.post(
  File "/usr/local/lib/python3.9/site-packages/pyatv/support/http.py", line 360, in post
    return await self.send_and_receive(
  File "/usr/local/lib/python3.9/site-packages/pyatv/support/http.py", line 413, in send_and_receive
    raise exceptions.ProtocolError(
pyatv.exceptions.ProtocolError: HTTP/1.1 method POST failed with code 470: Connection Authorization Required

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

Traceback (most recent call last):
  File "/usr/local/lib/python3.9/site-packages/pyatv/scripts/atvremote.py", line 181, in pair
    await self._perform_pairing(pairing)
  File "/usr/local/lib/python3.9/site-packages/pyatv/scripts/atvremote.py", line 215, in _perform_pairing
    await pairing.finish()
  File "/usr/local/lib/python3.9/site-packages/pyatv/protocols/airplay/pairing.py", line 74, in finish
    await error_handler(
  File "/usr/local/lib/python3.9/site-packages/pyatv/support/__init__.py", line 41, in error_handler
    raise fallback(str(ex)) from ex
pyatv.exceptions.PairingError: HTTP/1.1 method POST failed with code 470: Connection Authorization Required

I can't enter the pin, it immediately crashes as the prompt shows up. This is tested on the ATV 4k 1st gen with tvOS 14.7.

Getting credentials locally works, but then trying to use them in the Docker image:

> docker run  --rm --network=host ghcr.io/postlund/pyatv:master atvremote -s <ipaddress> --scan-protocols airplay --airplay-credentials <credentials> playing
NOTE: Push updates are not supported in this configuration
2021-09-13 13:15:05 ERROR [pyatv.scripts.atvremote]: Command 'playing' is not supported by device
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/site-packages/pyatv/scripts/atvremote.py", line 697, in _exec_command
    value = await tmp(*args)
  File "/usr/local/lib/python3.9/site-packages/pyatv/core/facade.py", line 178, in playing
    return await self.relay("playing")()
  File "/usr/local/lib/python3.9/site-packages/pyatv/core/relayer.py", line 75, in relay
    instance = self._find_instance(target, priority or self._priorities)
  File "/usr/local/lib/python3.9/site-packages/pyatv/core/relayer.py", line 97, in _find_instance
    raise exceptions.NotSupportedError(f"{target} is not supported")
pyatv.exceptions.NotSupportedError: playing is not supported

But I'm guessing this last bit is because of how tvOS 14.7 works compared to tvOS 15.

postlund commented 3 years ago

It's a bit tricky to make a build for 0.8.2, but I'll see if I can manage that tomorrow. It's a also bit strange that scanning isn't working properly. Can you try running with additional debugging and see if you get responses at all to the multicast requests? You can add --debug --mdns-debug for that. Maybe you can also test unicast scanning with one device to see if that works, I.e. docker run --rm --network=host ghcr.io/postlund/pyatv:master atvremote -s <ip> scan. It should only show the specified host.

Regarding pairing not working is because stdin is not kept open by docker. Totally missed that. If you add -it after docker run, does it work to pair?

The last command looks to me like it should work since you don't get any other particular error messages. Can you re-run with --debug and paste the logs?

Qonstrukt commented 3 years ago

It seems multicast traffic is not passing past the Docker container:

> docker run --rm --network=host ghcr.io/postlund/pyatv:master atvremote scan --debug --mdns-debug
2021-09-13 20:58:03 DEBUG [pyatv.core.net]: Binding on *:5353
2021-09-13 20:58:03 DEBUG [pyatv.core.net]: Binding on 127.0.0.1:0
2021-09-13 20:58:03 DEBUG [pyatv.core.net]: Binding on 192.168.65.3:0
2021-09-13 20:58:03 DEBUG [pyatv.core.net]: Binding on 192.168.65.4:0
2021-09-13 20:58:03 DEBUG [pyatv.core.net]: Binding on 172.18.0.1:0
2021-09-13 20:58:03 DEBUG [pyatv.core.net]: Binding on 172.17.0.1:0
<Responses only from the subnets being bound on>

My local network sits on 192.168.144.0/24, and no responses come from that subnet. Doing a unicast scan works though and returns the correct results.

About the stdin, I should've known that, sorry! πŸ˜‚

Regarding the playing command:

docker run  --rm --network=host ghcr.io/postlund/pyatv:master atvremote -s <ipaddress> --scan-protocols airplay --airplay-credentials <credentials> playing --debug
2021-09-13 21:05:03 DEBUG [pyatv.support.knock]: Knocking at ports [3689, 7000, 49152, 32498] on <ipaddress>
2021-09-13 21:05:03 DEBUG [pyatv.core.scan]: Auto-discovered Apple TV Mancave at <ipaddress>:7000 via Protocol.AirPlay ({'acl': '0', 'btaddr': '<mac>', 'deviceid': '<mac>', 'fex': '1d9/St5/FTw', 'features': '0x4A7FDFD5,0x3C157FDE', 'flags': '0x18644', 'gid': '44FC5D3B-1D36-443F-B931-7EC446574F01', 'igl': '1', 'gcgl': '1', 'model': 'AppleTV6,2', 'protovers': '1.1', 'pi': '97b7fc08-46ca-4f7e-9461-de26214bee99', 'psi': 'E9B8499C-47B9-43D7-85C2-C43C5A629985', 'pk': '<secret>', 'srcvers': '550.10', 'osvers': '14.7', 'vv': '2'})
2021-09-13 21:05:03 INFO [pyatv.scripts.atvremote]: Auto-discovered Apple TV Mancave at <ipaddress>
2021-09-13 21:05:03 DEBUG [pyatv.core.facade]: Adding handler for protocol Protocol.AirPlay
2021-09-13 21:05:03 DEBUG [pyatv.protocols.airplay]: AuthenticationType.Legacy not supported by remote control channel
2021-09-13 21:05:03 DEBUG [pyatv.core.facade]: Connecting to protocol: Protocol.AirPlay
2021-09-13 21:05:03 DEBUG [pyatv.core.facade]: Power management not supported by any protocols
NOTE: Push updates are not supported in this configuration
2021-09-13 21:05:03 ERROR [pyatv.scripts.atvremote]: Command 'playing' is not supported by device
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/site-packages/pyatv/scripts/atvremote.py", line 697, in _exec_command
    value = await tmp(*args)
  File "/usr/local/lib/python3.9/site-packages/pyatv/core/facade.py", line 178, in playing
    return await self.relay("playing")()
  File "/usr/local/lib/python3.9/site-packages/pyatv/core/relayer.py", line 75, in relay
    instance = self._find_instance(target, priority or self._priorities)
  File "/usr/local/lib/python3.9/site-packages/pyatv/core/relayer.py", line 97, in _find_instance
    raise exceptions.NotSupportedError(f"{target} is not supported")
pyatv.exceptions.NotSupportedError: playing is not supported
2021-09-13 21:05:03 DEBUG [pyatv.scripts.atvremote]: Waiting for 0 remaining tasks

Don't waste too much time on a docker image for older versions. Might be better to focus on an pypi release for 0.9.0, that would be insightful as well. πŸ˜„

Edit: I installed straight from GH using this command: pip3 install git+https://github.com/postlund/pyatv@master#pyatv --force I think it worked, but not sure how I can check? --version still returns 0.8.2. A multicast scan now just works at least.

postlund commented 3 years ago

Looks like docker does not find an interface in the subnet you are referring to, so pyatv won't send any multicast requests there. Do you have a special network setup of some sort? I'm not an expert when it comes to host network mode in docker, but I assumed that it would see all interfaces you have on the host system.

Regarding playing... this line was what I was looking for:

2021-09-13 21:05:03 DEBUG [pyatv.protocols.airplay]: AuthenticationType.Legacy not supported by remote control channel

It means that "legacy" credentials were loaded, i.e. they were obtained using legacy pairing used in 0.8.2 and older (or when you are pairing with an older device, like Apple TV 3). You need HAP credentials and pyatv should hopefully figure out that your device supports that and create those automatically. Based on the exception in earlier posts (File "/usr/local/lib/python3.9/site-packages/pyatv/protocols/airplay/auth/hap.py", line 77, in finish_pairing) that seems to work. The format is four hex values concatenated with colons. Is that what you have? Otherwise, try re-pairing again.

You can verify which method you are getting with --debug like this:

$ atvremote -s 10.0.10.81 --debug --protocol airplay pair
...
2021-09-14 12:25:53 DEBUG [pyatv.protocols.airplay.auth]: Setting up new AirPlay Pair-Setup procedure with type AuthenticationType.HAP
...
Enter PIN on screen:

It should say AuthenticationType.HAP and not AuthenticationType.Legacy.

There's currently no way to see what version you have installed (other than testing something only existing on master), it will say that latest released version as I don't bump master to any dev version. I should probably do that at some point...

Qonstrukt commented 3 years ago

Ah that explains it, I used credentials I had from 0.8.2 on my local machine. I installed the master version on my HA container and got credentials there and was successful in retrieving the playing state of an ATV with 14.7 and on another with the latest 15.0 beta. πŸ™‚ Unfortunately Home Assistant itself doesn't let me finish paring yet, even though I installed the latest master version through pip like mentioned before. (I'm guessing that's to be expected, just wanted to let you know.)

postlund commented 3 years ago

Great, then we know the reason and also that it works πŸ‘

Once 0.9.0 is out, I will take some time and fix the Home Assistant integration. I want to add proper AirPlay support (with file streaming and all that) as well as support for Companion. But I don't see any real reason why it shouldn't work with master. If you can provide a debug log I can take look.

Qonstrukt commented 3 years ago

It just says this like before:

The configuration for this device is incomplete. Please try adding it again.

Relevant debug logging:

2021-09-14 13:27:54 DEBUG (MainThread) [pyatv.support.http] Connected to 192.168.144.53
2021-09-14 13:27:54 DEBUG (MainThread) [pyatv.protocols.airplay.auth] Setting up new AirPlay Pair-Setup procedure with type AuthenticationType.HAP
2021-09-14 13:27:54 DEBUG (MainThread) [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: 3\r\nContent-Type: application/octet-stream\r\n\r\n'
2021-09-14 13:27:54 DEBUG (MainThread) [pyatv.support.http] Received: b'HTTP/1.1 200 OK\r\nDate: Tue, 14 Sep 2021 11:27:52 GMT\r\nContent-Length: 0\r\nServer: AirTunes/566.25.43\r\n\r\n'
2021-09-14 13:27:54 DEBUG (MainThread) [pyatv.support.http] Got HTTP response: HttpResponse(protocol='HTTP', version='1.1', code=200, message='OK', headers={'date': 'Tue, 14 Sep 2021 11:27:52 GMT', 'content-length': '0', 'server': 'AirTunes/566.25.43'}, body=''):
2021-09-14 13:27:54 DEBUG (MainThread) [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: 3\r\nContent-Type: application/octet-stream\r\n\r\n\x00\x01\x00\x06\x01\x01'
2021-09-14 13:27:54 DEBUG (MainThread) [pyatv.support.http] Received: b'HTTP/1.1 200 OK\r\nDate: Tue, 14 Sep 2021 11:27:52 GMT\r\nContent-Length: 409\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/566.25.43\r\n\r\n\x06\x01\x02\x02\x10X\xcf\x1fd\x1c\xc6\x9f\x12+\xd5\x8b84v\xb1\xf9\x03\xff\xbf\x0e_\xcf\xa4\xbeJS\x04S\xa6\xc5\x8c\xf594\xb0"\x19\xf1N\n\xfc\xd1:I\xd4<\xe2\x9b\x8e\xc9,\xd2\xc1-!8\xcbB\x9e\xd1\xa8\xcf\xdf\xb4\xa87~\xb3\x97\xbe\x8c\xb7t\x87\xee\x81\x13\xd9\\\xc5\xd0\x0f\\S\\)8P\xa6b\xce\x90Wj\x941\x8b\xb7,4AW\x84\x9b\x06\xadf\xb1\xdc\xb9#E\xe5\xdd\xae4\xb3x \xdf#\xb2\x98d\xd8\xb6W\xfai\xa9\xa8\xcbX\xcc\x1d\x1d\x9e\x03`\x1d\xee\xe8\xec\x15\xdf\xcaK\xa1\xa1Af\x85bR\xb4\xa43\xb4\xbbx\x0eH\xa9\x80\xa0^w\xee\xd9\'\xb3\xec\xf5\xf0\x14M\xa6\xad\x11\xbb\x95\x86\x84R\x14-\xb6\xfa\xe6\x8a\xb1]\xf4\xa8z\x81(\xe5\xd6\x7fZP\xbe\xe0\'\xdfD\x96;\x8fm\x18\x89\xaaI\x17\x87\x97<\xec{\xecQy\xdc\xcf\xee\x9e\xc0;yh\xaecUn\xfc\tb!\xf9\xa3\xabC^L\x9fExQ\xc1<\x12\xee\x0e\xdbp\xb4\x96|\x12G\x08\x17\tU\x03\xa6\x15\xae\xca\x94\x03\x03\x81\xdc\xca\x0e\x93O\xec\x83\x03\xe7\x1d\xf7Q\x12\xebn\x97\x06\xb8aHT\xb4@\xedZ\x18\x80\xabD"\xe5Ax\x8e\x06\xf6\xac\xc9\xe5m\x93[0\x1f\x8ay?F\xfe\xe1\xa1(zh\xa3\xbb\x1d\x9c\xea\xd1\xd8\xf0\x01\xcf~4\x16\xb8\xbc4\x19\t\xda\xe4\x00y\x93U\x17\xb3\x82\x13\xc31\xebmy\xc0\x02\xcc|\xe2\xe3e}\xf1\xc2E4es\x93\xb5a\x081\xde\x95\xd3\x1bK\xa1\x07ys\x1d\x08\xafr;\x974HP\x19\xdd\x80`\x10'
2021-09-14 13:27:54 DEBUG (MainThread) [pyatv.support.http] Got HTTP response: HttpResponse(protocol='HTTP', version='1.1', code=200, message='OK', headers={'date': 'Tue, 14 Sep 2021 11:27:52 GMT', 'content-length': '409', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/566.25.43'}, body=b'\x06\x01\x02\x02\x10X\xcf\x1fd\x1c\xc6\x9f\x12+\xd5\x8b84v\xb1\xf9\x03\xff\xbf\x0e_\xcf\xa4\xbeJS\x04S\xa6\xc5\x8c\xf594\xb0"\x19\xf1N\n\xfc\xd1:I\xd4<\xe2\x9b\x8e\xc9,\xd2\xc1-!8\xcbB\x9e\xd1\xa8\xcf\xdf\xb4\xa87~\xb3\x97\xbe\x8c\xb7t\x87\xee\x81\x13\xd9\\\xc5\xd0\x0f\\S\\)8P\xa6b\xce\x90Wj\x941\x8b\xb7,4AW\x84\x9b\x06\xadf\xb1\xdc\xb9#E\xe5\xdd\xae4\xb3x \xdf#\xb2\x98d\xd8\xb6W\xfai\xa9\xa8\xcbX\xcc\x1d\x1d\x9e\x03`\x1d\xee\xe8\xec\x15\xdf\xcaK\xa1\xa1Af\x85bR\xb4\xa43\xb4\xbbx\x0eH\xa9\x80\xa0^w\xee\xd9\'\xb3\xec\xf5\xf0\x14M\xa6\xad\x11\xbb\x95\x86\x84R\x14-\xb6\xfa\xe6\x8a\xb1]\xf4\xa8z\x81(\xe5\xd6\x7fZP\xbe\xe0\'\xdfD\x96;\x8fm\x18\x89\xaaI\x17\x87\x97<\xec{\xecQy\xdc\xcf\xee\x9e\xc0;yh\xaecUn\xfc\tb!\xf9\xa3\xabC^L\x9fExQ\xc1<\x12\xee\x0e\xdbp\xb4\x96|\x12G\x08\x17\tU\x03\xa6\x15\xae\xca\x94\x03\x03\x81\xdc\xca\x0e\x93O\xec\x83\x03\xe7\x1d\xf7Q\x12\xebn\x97\x06\xb8aHT\xb4@\xedZ\x18\x80\xabD"\xe5Ax\x8e\x06\xf6\xac\xc9\xe5m\x93[0\x1f\x8ay?F\xfe\xe1\xa1(zh\xa3\xbb\x1d\x9c\xea\xd1\xd8\xf0\x01\xcf~4\x16\xb8\xbc4\x19\t\xda\xe4\x00y\x93U\x17\xb3\x82\x13\xc31\xebmy\xc0\x02\xcc|\xe2\xe3e}\xf1\xc2E4es\x93\xb5a\x081\xde\x95\xd3\x1bK\xa1\x07ys\x1d\x08\xafr;\x974HP\x19\xdd\x80`\x10'):
2021-09-14 13:28:01 DEBUG (MainThread) [pyatv.protocols.airplay.pairing] AirPlay PIN changed to 5276
2021-09-14 13:28:01 DEBUG (MainThread) [pyatv.auth.hap_srp] Client (Proof=124f8238a5a1c1f0e18da140abbf4691c912f8319d13648ffd23e572277a54634a040ed2abbe48ffb5bc44036bd733eb1a4aedbc06de661e68ad913e573c2d0a, Public=544665942bcd3dd6475435e1a865577c2435b0cb8965359fe3c7e65806c0fee810ce9e1461bce25239cd435f1344a0bd4a9c682f2c8d2894b17672c170af7d11984b1b190d8738131efb7466e061364f993685022106aa8c8b3fff32a18afb204f34ef2656bdb784135fc2132280d0a2d5bb77a87e8004a7693f22db49878bf70beaf7704ac783fa21ab79554440225ba74e26f12bf6feefb333960a289ab54c055a8bc2734f2029d00b357813098df626fcb12e86bb0a6a1796773bb0e65fcf336434692baae8739ef68f7ebb2f72bd52feeb4b597161681fef3b8a5e3f3bd50b4f6170ba9c27856c0ce7420e090a2717b317f8d6651f286697c95b7582f...)
2021-09-14 13:28:01 DEBUG (MainThread) [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: 3\r\nContent-Type: application/octet-stream\r\n\r\n\x06\x01\x03\x03\xffTFe\x94+\xcd=\xd6GT5\xe1\xa8eW|$5\xb0\xcb\x89e5\x9f\xe3\xc7\xe6X\x06\xc0\xfe\xe8\x10\xce\x9e\x14a\xbc\xe2R9\xcdC_\x13D\xa0\xbdJ\x9ch/,\x8d(\x94\xb1vr\xc1p\xaf}\x11\x98K\x1b\x19\r\x878\x13\x1e\xfbtf\xe0a6O\x996\x85\x02!\x06\xaa\x8c\x8b?\xff2\xa1\x8a\xfb O4\xef&V\xbd\xb7\x84\x13_\xc2\x13"\x80\xd0\xa2\xd5\xbbw\xa8~\x80\x04\xa7i?"\xdbI\x87\x8b\xf7\x0b\xea\xf7pJ\xc7\x83\xfa!\xabyUD@"[\xa7N&\xf1+\xf6\xfe\xef\xb33\x96\n(\x9a\xb5L\x05Z\x8b\xc2sO )\xd0\x0b5x\x13\t\x8d\xf6&\xfc\xb1.\x86\xbb\nj\x17\x96w;\xb0\xe6_\xcf3d4i+\xaa\xe8s\x9e\xf6\x8f~\xbb/r\xbdR\xfe\xebKYqah\x1f\xef;\x8a^?;\xd5\x0bOap\xba\x9c\'\x85l\x0c\xe7B\x0e\t\n\'\x17\xb3\x17\xf8\xd6e\x1f(f\x97\xc9[u\x82\xf0\x03\x81\\\xc0l\x87\xe9K\x8eF\xb4\xa4\xfd\x16x5\xa0O\xe1\x1e\x1bL#x\xd3\xcf\xe9\xdf\x9d\xac\xdd$\xea\x00\xf1\xe2$\x95N\x17\xd8euZ\xdc\xcdi\x04\x11c\x90}\xba\xe9\x86\xb4S\xc5o}\xeab\xb6\xd2\xfbp\xa8"\xc3\x1a\xde\x1f\x94\xeb\xd7\xa8\x9aK\x05t\xad\xd0\xbdk.y?gH\x8f\t>jf\xb6\x80/k\xc1\xe0\xa1\x81\xf0\xce\xa1\x1a\n\x81}\'\x99\n\xefe@\xed\xb3\xf9\xcad%\xf7\xde\x9b\x01y\x06`? \x08\x04@\x12O\x828\xa5\xa1\xc1\xf0\xe1\x8d\xa1@\xab\xbfF\x91\xc9\x12\xf81\x9d\x13d\x8f\xfd#\xe5r\'zTcJ\x04\x0e\xd2\xab\xbeH\xff\xb5\xbcD\x03k\xd73\xeb\x1aJ\xed\xbc\x06\xdef\x1eh\xad\x91>W<-\n'
2021-09-14 13:28:01 DEBUG (MainThread) [pyatv.support.http] Received: b'HTTP/1.1 200 OK\r\nDate: Tue, 14 Sep 2021 11:27:59 GMT\r\nContent-Length: 69\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/566.25.43\r\n\r\n\x06\x01\x04\x04@(tSl\xef\x96\xcd\xd2p\xd6\xb6?\xd8\xd6\x1d\x1fJ;\x8c*\xcc\x8b\xc6\x8c4\x9c\x8e\x8e\xfe\xbb\x9be\xa2\xc4\xc8.<@\x1a\x82d\xd5>\xc5&\x88\x06\xe20\xee2\xb1\xa6\x16>\xa3\x8dR\xdf\x0b\xee\x0f\x15-'
2021-09-14 13:28:01 DEBUG (MainThread) [pyatv.support.http] Got HTTP response: HttpResponse(protocol='HTTP', version='1.1', code=200, message='OK', headers={'date': 'Tue, 14 Sep 2021 11:27:59 GMT', 'content-length': '69', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/566.25.43'}, body=b'\x06\x01\x04\x04@(tSl\xef\x96\xcd\xd2p\xd6\xb6?\xd8\xd6\x1d\x1fJ;\x8c*\xcc\x8b\xc6\x8c4\x9c\x8e\x8e\xfe\xbb\x9be\xa2\xc4\xc8.<@\x1a\x82d\xd5>\xc5&\x88\x06\xe20\xee2\xb1\xa6\x16>\xa3\x8dR\xdf\x0b\xee\x0f\x15-'):
2021-09-14 13:28:01 DEBUG (MainThread) [pyatv.auth.hap_srp] Data (Encrypted=70c2080a10970b211104f0d7ffff5810e0d950c36a948dbcb9830206ee398c4e83fad545f22796ac0b872b35c6f690574358c6f87841433510e8ecaf2d7c0b7aec108bec0046e419c6966286a523f754b6c314293ac21147ac22a0f9b9aae42790e348228600af9b94b605447401d6b3324196b437ed18f63c82a8c71e0175bb95a8e08c3ca75cb4cca2d758f08470c853e1f6e05098f10dd2dd)
2021-09-14 13:28:01 DEBUG (MainThread) [pyatv.support.http] Sending HTTP/1.1 message: b'POST /pair-setup HTTP/1.1\r\nContent-Length: 159\r\nUser-Agent: AirPlay/320.20\r\nConnection: keep-alive\r\nX-Apple-HKP: 3\r\nContent-Type: application/octet-stream\r\n\r\n\x06\x01\x05\x05\x9ap\xc2\x08\n\x10\x97\x0b!\x11\x04\xf0\xd7\xff\xffX\x10\xe0\xd9P\xc3j\x94\x8d\xbc\xb9\x83\x02\x06\xee9\x8cN\x83\xfa\xd5E\xf2\'\x96\xac\x0b\x87+5\xc6\xf6\x90WCX\xc6\xf8xAC5\x10\xe8\xec\xaf-|\x0bz\xec\x10\x8b\xec\x00F\xe4\x19\xc6\x96b\x86\xa5#\xf7T\xb6\xc3\x14):\xc2\x11G\xac"\xa0\xf9\xb9\xaa\xe4\'\x90\xe3H"\x86\x00\xaf\x9b\x94\xb6\x05Dt\x01\xd6\xb32A\x96\xb47\xed\x18\xf6<\x82\xa8\xc7\x1e\x01u\xbb\x95\xa8\xe0\x8c<\xa7\\\xb4\xcc\xa2\xd7X\xf0\x84p\xc8S\xe1\xf6\xe0P\x98\xf1\r\xd2\xdd'
2021-09-14 13:28:01 DEBUG (MainThread) [pyatv.support.http] Received: b'HTTP/1.1 200 OK\r\nDate: Tue, 14 Sep 2021 11:27:59 GMT\r\nContent-Length: 327\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/566.25.43\r\n\r\n\x05\xff\xd58\xc9+\xa1\xa7<h\x08i\xe8\xdb\x98\xca\xec\x87\x1a\xef\xb3\xda,\x9d\x02\x93\x1f5Jm]\x99\x1a\x9d0\xab \x9e\x06\xdc\xe6\xaf\x87\x81\xfc2.+\x82\xccDD\xe1$\xf0o8\xc62\xc5s5\x01\xe4\r1\xf2\xfbX\x95\xfc\xbb^IW\xdd\xfffR\xd25\x02c\xed\t\xa2^\x81\xf7*\x80\xf5:G\t\xd1\xa4\xc9=\x13-\x05\xbc\x14\xf1\xa1\xc8\xea\xca\x19O\xe7\xf8\xa7\x93\xef\xef\xa0A\r\xde\x80s\xd6K>\x00\x11,\t\x99\rPcE\x83^\x84?$\xec\x8b\xeb\x97|1\xb4\xdaF\xfb\x7f:\xd0\x903\xf5n\xef\xf6\xe8\xa6Cqf\xf0!\xdb\x9c\x17mR\xd7\x9e\xd8k\x01}\x04\x86<\xb2\x89a}ut6\x92\xb5|\xcd:I\x15O Y\xb4\xb0{%\x87\xed\xbe\xd8\x17\x00\x04\xf6\xa6\x03\x042\x13\x96R\x92\x04cM\xf9\x99# F\xd6\xe5aK\xa5~>\x86\xa6\\\xb9\x9d\x8e/U\xfc\x8f1\x14I\x08\x88B\xfbf\x8eP\x9cz\xe4\xab\x84\x05A\xf2%\x80v\x16_\xeb#r\x87\xc5\x9c\xc3\x9c\xe8\x04\x84\xce\xd6\x0f1j\x13"\xb6qE\x83\x9f\x8c\xdc50\xc1\xcd\xd6Wc\'\x8f"&\x00\xc4\xeb\x97\x90\x1b0\x0f\x99w\xf0\x93\x00G\xcc\xd5l:\x8fs\x15I\x9f\x06\x01\x06'
2021-09-14 13:28:01 DEBUG (MainThread) [pyatv.support.http] Got HTTP response: HttpResponse(protocol='HTTP', version='1.1', code=200, message='OK', headers={'date': 'Tue, 14 Sep 2021 11:27:59 GMT', 'content-length': '327', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/566.25.43'}, body=b'\x05\xff\xd58\xc9+\xa1\xa7<h\x08i\xe8\xdb\x98\xca\xec\x87\x1a\xef\xb3\xda,\x9d\x02\x93\x1f5Jm]\x99\x1a\x9d0\xab \x9e\x06\xdc\xe6\xaf\x87\x81\xfc2.+\x82\xccDD\xe1$\xf0o8\xc62\xc5s5\x01\xe4\r1\xf2\xfbX\x95\xfc\xbb^IW\xdd\xfffR\xd25\x02c\xed\t\xa2^\x81\xf7*\x80\xf5:G\t\xd1\xa4\xc9=\x13-\x05\xbc\x14\xf1\xa1\xc8\xea\xca\x19O\xe7\xf8\xa7\x93\xef\xef\xa0A\r\xde\x80s\xd6K>\x00\x11,\t\x99\rPcE\x83^\x84?$\xec\x8b\xeb\x97|1\xb4\xdaF\xfb\x7f:\xd0\x903\xf5n\xef\xf6\xe8\xa6Cqf\xf0!\xdb\x9c\x17mR\xd7\x9e\xd8k\x01}\x04\x86<\xb2\x89a}ut6\x92\xb5|\xcd:I\x15O Y\xb4\xb0{%\x87\xed\xbe\xd8\x17\x00\x04\xf6\xa6\x03\x042\x13\x96R\x92\x04cM\xf9\x99# F\xd6\xe5aK\xa5~>\x86\xa6\\\xb9\x9d\x8e/U\xfc\x8f1\x14I\x08\x88B\xfbf\x8eP\x9cz\xe4\xab\x84\x05A\xf2%\x80v\x16_\xeb#r\x87\xc5\x9c\xc3\x9c\xe8\x04\x84\xce\xd6\x0f1j\x13"\xb6qE\x83\x9f\x8c\xdc50\xc1\xcd\xd6Wc\'\x8f"&\x00\xc4\xeb\x97\x90\x1b0\x0f\x99w\xf0\x93\x00G\xcc\xd5l:\x8fs\x15I\x9f\x06\x01\x06'):
2021-09-14 13:28:01 DEBUG (MainThread) [pyatv.auth.hap_srp] PS-Msg06: {1: b'DF45AFF3-7F3F-4E87-A126-9BC07E7946B9', 3: b'\xee/\xc6`W?\xb7&\xbf\xb8\x9f&\xed\xf2\x1e\x14\x97A\xa5\xbfC\xc30\xde\xa1Y\xd0I\x98^o\xcb', 10: b'\xc0t\xf2\xcb\x99HW\xd6(2;\xfcM9F\xd3r`\xef\x07\xa8&Z\x01g(\x96\xc6\x03\x8c\xcd,I\x9b\xde%!\xb0\xebT\x0cN.\xd8N\xedd\xa4\x16\xcdn\x06)\xa9\x98.\x88\xfc.V\xfc\x04}\x0c', 17: b'\xe7FaltIRK\x80Z\xa5\xb0\xd8+l\xe7>x\x95\xf3\x8f{\x1f\xd2(FbtAddrQf0:b3:ec:14:67:ffCmacv\xf0\xb3\xec\x06\x05`IaccountIDa$DF45AFF3-7F3F-4E87-A126-9BC07E7946B9EmodelKAppleTV11,1GwifiMACv\xf0\xb3\xec\x0b\x92\xc7DnamePApple TV Zithoek'}
2021-09-14 13:28:01 DEBUG (MainThread) [pyatv.auth.hap_srp] Device (Identifier=44463435414646332d374633462d344538372d413132362d394243303745373934364239, Public=ee2fc660573fb726bfb89f26edf21e149741a5bf43c330dea159d049985e6fcb, Signature=c074f2cb994857d628323bfc4d3946d37260ef07a8265a01672896c6038ccd2c499bde2521b0eb540c4e2ed84eed64a416cd6e0629a9982e88fc2e56fc047d0c)
2021-09-14 13:28:01 DEBUG (MainThread) [pyatv.support.http] Connection closed

I expect tvOS 15 GM to come out tonight, with the public release probably next week, so that will be a lot of extra nagging people... I have patience and I'm just glad you're so on to it @postlund ❀️ But be warned πŸ˜‚ I gladly try to help debug however I can. πŸ™‚

postlund commented 3 years ago

Oh, yeah, right, now I understand. Legacy-wise I required that either DMAP or MAP was paired to consider everything OK. That is no longer necessary as pyatv is a log more generic now, so I need to remove that check.

Guess I will have a busy upcoming week then πŸ˜‰ Thanks for the heads up!

Qonstrukt commented 3 years ago

Removing that check from the ATV component indeed fixes pairing! πŸ˜„ It brings other problems though, like media info getting overwritten with the app that's playing it, and probably other stuff too. But basic controls all work again, and it gives me some control over knowing whether something's playing again. (Which I use for movie lights, etc.) So that's nice. πŸ™‚

It's a bit offtopic for pyatv though, so I'll leave it at that.

postlund commented 3 years ago

That's good! I'll probably figure out the problems as I go along. But what do you mean by media info getting overwritten with the app that's playing it?

Qonstrukt commented 3 years ago

I thought the two seemed mutual exclusive, but that's not the case. It's a weird thing happening; when I start playing a song (for example) it shows all the media info and the app name and ID in the entity. But when I click on the info in a media_control card for example. It removes the media_info, and the app info stays intact. Almost like if it tries to update the data, then fails, and removes part of what was there. Or replaces the complete info with just the info of the app playing it.

postlund commented 3 years ago

That sounds more like a frontend bug or something as only the entity itself can change its state. App information, like app name, is just an attribute just like other metadata and there's nothing special or exclusive about either of them. Is the state correct if you look in the developer tools? Or do you see anything in the logs?

Qonstrukt commented 3 years ago

I'm talking about the info in developer tools, so I'm looking under the state attributes. For some reason the media_info gets cleared out sometimes.

postlund commented 3 years ago

That's strange, I guess only debug logs can tell us what's going on in that case. It shouldn't just disappear.

Qonstrukt commented 3 years ago

It seems to be related to playing through the Companion protocol. So in the Music app on my phone, I'm not AirPlaying, but I'm choosing "Control other speakers or TV's", or however it's called in English, and then I put something on. It shows all the track information for 10 seconds. And after that it gets reset. With just this info remaining:

media_position: 12
media_position_updated_at: '2021-09-15T14:04:47.732748+00:00'
app_id: com.apple.TVMusic
app_name: Muziek
shuffle: true
repeat: 'off'
friendly_name: Apple TV Zithoek
supported_features: 317363

This now keeps happening, pressing next etc. on the physical ATV remote. Until I put something new on, using said remote. Then it works correctly, even though the experience on the TV is exactly the same.

It's really hard to get relevant debug info, because the log grows so quickly that I can't make out the proper info and HA almost crashes trying to open it. I'll have to look where the actual log files are and then grep and tail it, might do that later.

I'm running the latest iOS 15 and tvOS 15 RC's.

postlund commented 3 years ago

That sounds like a potential bug in the play state management. You should definitely try to reproduce with atvremote ... push_updates. If you see the same behavior, add --debug, pipe the output to a file and send it to me. Hopefully I can see what's going on. Finding these things are what this issue is all about 😊

Qonstrukt commented 3 years ago

I can't seem to replicate it anymore in HA. And looking at push_updates I don't see any weird results passing by. I did upgrade to the latest master version, so not sure if you might've updated something. πŸ™‚

Something else I noticed, all paired pyATV instances are called Unknown device on the Apple TV. Supplying a --remote-name during pairing doesn't change that.

mschwartz commented 3 years ago

Seems like a good place for this.

tvOS 15 officially released today.

Will 0.9.0 still work with tvOS 14?

postlund commented 3 years ago

@Qonstrukt Maybe a case of "did you try turning it off and on again"? πŸ˜‰ Can't think of any changes I've made related to this, more likely a hiccup with tvOS. Seem to happen every now and then. Regarding name... that's not anything I have even thought about. I know that it did work at some point as I have seen "pyatv" there. Will have to look into that. Thanks for mentioning it!

@mschwartz Sure! It will work with both tvOS 14 and 15. As mentioned before: make sure to (re-)pair AirPlay and provide those credentials for tvOS 15. For tvOS 14 there's no difference from before.

mschwartz commented 3 years ago

To be clear, it's ready for use against tvOS 15?

I can try it out for you, if so, and report any issues.

geekofweek commented 3 years ago

Removing that check from the ATV component indeed fixes pairing! πŸ˜„ It brings other problems though, like media info getting overwritten with the app that's playing it, and probably other stuff too. But basic controls all work again, and it gives me some control over knowing whether something's playing again. (Which I use for movie lights, etc.) So that's nice. πŸ™‚

It's a bit offtopic for pyatv though, so I'll leave it at that.

What check are you removing? I'm assuming it's in config_flow.py but I haven't pinned it down what line I need to remove.

13mralex commented 3 years ago

On different note, not sure if this is related to the thread or not, but is/will there be a way to store credentials when using the Python library? Since credentials will be required to do things, how do I store them aside from the normal command line with atvremote?

postlund commented 3 years ago

@mschwartz What is on master is ready for tvOS 15, you can just install that or run one of the container versions (to test with atvremote). Once I'm done with the remaining bits, I will release the sharp version of 0.9.0 and update Home Assistant.

@geekofweek It's this check: https://github.com/home-assistant/core/blob/097fae0348b17656cab8734ad3b49f5256ad6973/homeassistant/components/apple_tv/config_flow.py#L326 (and also make sure you have pyatv corresponding to master installed).

@13mralex There is currently no built-in support for that. There's a very old issue for it, #243, and I very much intend to implement support for it. I'm thinking a generic backend API, providing implementations for "Null" (like today), "Memory" (store during runtime of application) and "File" (which stores persistently to a file). It will also be possible to write your own implementations, in case you want to store credentials anywhere else, like a cloud service for instance. But until that is implemented, you will have to deal with credentials manually I'm afraid:

https://pyatv.dev/development/scan_pair_and_connect/#storing-credentials https://pyatv.dev/development/scan_pair_and_connect/#restoring-credentials

Qonstrukt commented 3 years ago

Hey @postlund, don't you find this interesting:

Scan Results
========================================
       Name: Apple TV Slaapkamer
   Model/SW: Gen4 tvOS 15.0 build 19J346
    Address: 192.168.144.13
        MAC: bla
 Deep Sleep: True
Identifiers:
 - bla
Services:
 - Protocol: Companion, Port: 49153, Credentials: None, Requires Password: False, Password: None, Pairing: Mandatory
 - Protocol: AirPlay, Port: 7000, Credentials: None, Requires Password: False, Password: None, Pairing: Mandatory
 - Protocol: MRP, Port: 49152, Credentials: None, Requires Password: False, Password: None, Pairing: Optional
 - Protocol: RAOP, Port: 7000, Credentials: None, Requires Password: False, Password: None, Pairing: Mandatory

Protocol: MRP... πŸ™ˆ I upgraded it this morning, and I've restarted the Apple TV multiple times already. Trying to connect through MRP doesn't work, but it throws the whole paring process in HA off, because it will fail to connect MRP and then you get a non-functional (very limited) AirPlay integration instead. I'm guessing it's just zeroconf caching floating around my network. But what's even more interesting, is that it even has the build number correct. Which I think it gets through MRP currently right? The other tvOS 15 devices (with the same build installed by now) still don't show the build number in the scan.

One other thing regarding the name of pyatv on the ATV itself. When pairing before, it would show pyatv under App Remotes. But with the new pairing process it adds itself under the Devices list, and there it shows up as Unknown Device. The App Remotes list on tvOS 15 will only show old paired app remotes, but that list disappears when you remove those since they all show up as disconnected anyway.

postlund commented 3 years ago

@Qonstrukt That's interesting! Would be interesting to know if anyone else is seeing this behavior as well. Especially since the actual service disappeared a few betas ago... It's strange that you get a limited AirPlay-like integration though. The protocol should just be ignored and credentials from AirPlay used instead, which should restore functionality. It's worth looking at the logs to see what is going on.

You are right, the build number is extracted from the MRP service. In other cases it's extracted when connecting to a device, so you will not see it in the scan results but it's present after connecting, e.g. with atvremote -s ... device_info.

Ok, interesting. Maybe I need to adjust some parameter. I think I have to troubleshoot that by looking at the device logs as well. Feel free to open a new issue for this, it makes it easier to track.

I will release 0.9.0 today, soon-ish. I will focus on basic functionality in Home Assistant after today, probably by tomorrow or so.

Qonstrukt commented 3 years ago

@postlund I just can't get this ATV to integrate into HA. Unchanged, it always first comes up with a popup stating that it cannot pair over MRP, so it will be skipped. Then it will pair over AirPlay, but it's non functional. (It always shows state off.)

So I changed config_flow.py by removing MRP from the PROTOCOL_PRIORITY, which at least skips over the error message, but still gives a non-functional AirPlay integration.

All my other tvOS 15 ATV's still function correctly, but I'm a bit hesitant to re-pair them now. πŸ˜… I'm thinking that I maybe should reset the ATV in question, but I might do some atvremote tests first.

postlund commented 3 years ago

@Qonstrukt Does it work with atvremote? You can pair with atvremote -s ... --protocol airplay pair and then test with atvremote -s ... --airplay-credentials <credentials> --scan-protocols airplay playing.

postlund commented 3 years ago

And yes, it it's just this device, then I would also consider resetting it. Seems to be working a bit strange.

Qonstrukt commented 3 years ago

Using the commands you provided works correctly. Could it be possible that the HA integration still tries to use MRP for its information etc.? Since pairing is marked optional.

Edit, I'm pretty sure that must be it. My HA log is spammed with:

Failed to connect
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/asyncio/locks.py", line 413, in acquire
    await fut
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/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 "/usr/src/homeassistant/homeassistant/components/apple_tv/__init__.py", line 225, in _connect_loop
    await self._connect(conf)
  File "/usr/src/homeassistant/homeassistant/components/apple_tv/__init__.py", line 309, in _connect
    self.atv = await connect(conf, self.hass.loop, session=session)
  File "/usr/local/lib/python3.9/site-packages/pyatv/__init__.py", line 96, in connect
    await atv.connect()
  File "/usr/local/lib/python3.9/site-packages/pyatv/core/facade.py", line 425, in connect
    if await setup_data.connect():
  File "/usr/local/lib/python3.9/site-packages/pyatv/protocols/mrp/__init__.py", line 870, in _connect
    await protocol.start()
  File "/usr/local/lib/python3.9/site-packages/pyatv/protocols/mrp/protocol.py", line 134, in start
    self.device_info = await self.send_and_receive(msg)
  File "/usr/local/lib/python3.9/site-packages/pyatv/protocols/mrp/protocol.py", line 234, in send_and_receive
    return await self._receive(identifier, timeout)
  File "/usr/local/lib/python3.9/site-packages/pyatv/protocols/mrp/protocol.py", line 242, in _receive
    await asyncio.wait_for(semaphore.acquire(), timeout)
  File "/usr/local/lib/python3.9/asyncio/tasks.py", line 494, in wait_for
    raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError

It's the same Exception I get when using this command:

atvremote -s <ipaddress> --scan-protocols mrp playing

Which makes sense because I'm assuming the HA integration doesn't request a specific protocol from pyatv which causes it to use the first available I presume.

postlund commented 3 years ago

Yes, that is definitely it. The same thing seems to be reported in #1322, so we can continue there.

Qonstrukt commented 3 years ago

I just reset the ATV and now the MRP service is gone and everything's working as expected. The thing is that this ATV actually did the consumer upgrade. So it went from 14.7 to the stable release of 15.0 without any betas. So this might happen to more people...

Timing ^^

postlund commented 3 years ago

Yeah, that's a not so cool development... I need to come up with a work-around for that.

postlund commented 3 years ago

I've been thinking a bit more about the situation to find a potential workaround and I think I know now. The way it works for the time being, simplified, is like this:

  1. Scan for a devices and its services
  2. Iterate over each service and pass it to a setup method (in the protocol implementation for that service) which returns lots of stuff later used to connect
  3. Iterate over what is returned in 2 and connect all protocols, skip already set up protocols

The key part here is that in the second step, a protocol implementation may return any number of implementations for any kind of protocols. That's how MRP-over-AirPlay works: airplay returns one implementation for AirPlay and one for MRP. If the regular MRP protocol is also present, then the final list after the second step will contain two implementations for MRP. The second one will later be ignored in the connect step, as the protocol has already been set up. As I haven't implemented a connect strategy yet (#1209), there's no special error handling here. If connect to one protocol fails, it all fails.

The take here is that I iterate over the discovered services rather than the protocol implementations. The order will be based on the order protocols are discovered. So if MRP is found before AirPlay, then it will fail as connecting to MRP will fail. If AirPlay is found first on the other hand, then everything will be fine as the "regular" MRP service will implicitly get lower priority and ignored since MRP was already set up via AirPlay. If i make sure to always start setting up AirPlay before MRP, then this is solved. It's not really a generic solution, but good enough until this is smoked out naturally.

martinorob commented 3 years ago

I think that volume commands doesn't works very well..

volume_up works but exit with error

`atvremote --id C8:69:CD:6E:43:86 --companion-credentials "db120e921609b11ae66fb2ee2b4aa9f6adaf3e2e480a18e3d8356b29b7745f41:0b7048d68d80030752af99293c35df66c2611066f2afc041972c66d575c5f038:46383142303836342d453236422d343042412d424232432d313633454435463230304245:32623061303963342d363361652d343236352d393266322d333561363631653936623962" --airplay-credentials "db120e921609b11ae66fb2ee2b4aa9f6adaf3e2e480a18e3d8356b29b7745f41:5b194d29c5411690bc7f26e8dcf0ae763ed4b1249f37e4647fa9c51f8952eef9:46383142303836342d453236422d343042412d424232432d313633454435463230304245:39663439623363662d613333642d343239342d393738312d326563336235353235323961" volume_up Traceback (most recent call last): File "/usr/local/Cellar/python@3.9/3.9.7/Frameworks/Python.framework/Versions/3.9/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/local/Cellar/python@3.9/3.9.7/Frameworks/Python.framework/Versions/3.9/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 "/usr/local/lib/python3.9/site-packages/pyatv/scripts/atvremote.py", line 700, in _run_application return await cli_handler(loop) File "/usr/local/lib/python3.9/site-packages/pyatv/scripts/atvremote.py", line 494, in cli_handler return await _handle_commands(args, config, loop) File "/usr/local/lib/python3.9/site-packages/pyatv/scripts/atvremote.py", line 595, in _handle_commands ret = await _handle_device_command(args, cmd, atv, loop) File "/usr/local/lib/python3.9/site-packages/pyatv/scripts/atvremote.py", line 627, in _handle_device_command return await _exec_command(atv.audio, cmd, True, cmd_args) File "/usr/local/lib/python3.9/site-packages/pyatv/scripts/atvremote.py", line 666, in _exec_command value = await tmp(args) File "/usr/local/lib/python3.9/site-packages/pyatv/core/facade.py", line 339, in volume_up return await self.relay("volume_up")() File "/usr/local/lib/python3.9/site-packages/pyatv/protocols/mrp/init.py", line 706, in volume_up await asyncio.wait_for(self._volume_event.wait(), timeout=5.0) File "/usr/local/Cellar/python@3.9/3.9.7/Frameworks/Python.framework/Versions/3.9/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 `

volume_down exit well (no error on console) but doesn't do anything

atvremote --id C8:69:CD:6E:43:86 --companion-credentials "db120e921609b11ae66fb2ee2b4aa9f6adaf3e2e480a18e3d8356b29b7745f41:0b7048d68d80030752af99293c35df66c2611066f2afc041972c66d575c5f038:46383142303836342d453236422d343042412d424232432d313633454435463230304245:32623061303963342d363361652d343236352d393266322d333561363631653936623962" --airplay-credentials "db120e921609b11ae66fb2ee2b4aa9f6adaf3e2e480a18e3d8356b29b7745f41:5b194d29c5411690bc7f26e8dcf0ae763ed4b1249f37e4647fa9c51f8952eef9:46383142303836342d453236422d343042412d424232432d313633454435463230304245:39663439623363662d613333642d343239342d393738312d326563336235353235323961" volume_down

set_volume=10 exit well (no error on console) but doesn't do anything

atvremote --id C8:69:CD:6E:43:86 --companion-credentials "db120e921609b11ae66fb2ee2b4aa9f6adaf3e2e480a18e3d8356b29b7745f41:0b7048d68d80030752af99293c35df66c2611066f2afc041972c66d575c5f038:46383142303836342d453236422d343042412d424232432d313633454435463230304245:32623061303963342d363361652d343236352d393266322d333561363631653936623962" --airplay-credentials "db120e921609b11ae66fb2ee2b4aa9f6adaf3e2e480a18e3d8356b29b7745f41:5b194d29c5411690bc7f26e8dcf0ae763ed4b1249f37e4647fa9c51f8952eef9:46383142303836342d453236422d343042412d424232432d313633454435463230304245:39663439623363662d613333642d343239342d393738312d326563336235353235323961" set_volume=10

if needed I can post debug logs.. Thank you all 😊

postlund commented 3 years ago

That looks a bit strange. Debug logs would be helpful! πŸ‘

martinorob commented 3 years ago

volume_up works but exit with error

atvremote --id C8:69:CD:6E:43:86 --companion-credentials "db120e921609b11ae66fb2ee2b4aa9f6adaf3e2e480a18e3d8356b29b7745f41:0b7048d68d80030752af99293c35df66c2611066f2afc041972c66d575c5f038:46383142303836342d453236422d343042412d424232432d313633454435463230304245:32623061303963342d363361652d343236352d393266322d333561363631653936623962" --airplay-credentials "db120e921609b11ae66fb2ee2b4aa9f6adaf3e2e480a18e3d8356b29b7745f41:5b194d29c5411690bc7f26e8dcf0ae763ed4b1249f37e4647fa9c51f8952eef9:46383142303836342d453236422d343042412d424232432d313633454435463230304245:39663439623363662d613333642d343239342d393738312d326563336235353235323961" volume_up --debug
2021-09-22 23:05:20 DEBUG [pyatv.support.net]: Binding on *:5353
2021-09-22 23:05:20 DEBUG [pyatv.support.net]: Binding on 127.0.0.1:0
2021-09-22 23:05:20 DEBUG [pyatv.support.net]: Binding on 192.168.3.80:0
2021-09-22 23:05:20 DEBUG [pyatv.core.scan]: Auto-discovered AppleTV at 192.168.3.52:7000 via Protocol.AirPlay ({'acl': '0', 'btaddr': 'C8:69:CD:6E:43:85', 'deviceid': 'C8:69:CD:6E:43:86', 'fex': '1d9/Wt5fFbwI', 'features': '0x5A7FDFD5,0xBC155FDE', 'flags': '0x1644', 'gid': 'C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC', 'igl': '1', 'gcgl': '1', 'model': 'AppleTV5,3', 'protovers': '1.1', 'pi': '91688c86-df11-4c30-a35d-20c8bf8dd54d', 'psi': 'F81B0864-E26B-40BA-BB2C-163ED5F200BE', 'pk': 'f096f8e419ca6a0a76d3fafed380afe4b8f54dc4888980eb25c634ed746d92c5', 'srcvers': '566.25.43', 'osvers': '15.0', 'vv': '2'})
2021-09-22 23:05:20 DEBUG [pyatv.core.scan]: Auto-discovered AppleTV at 192.168.3.52:49153 via Protocol.Companion ({'rpmac': '1', 'rphn': 'f204d8147339', 'rpfl': '0x36782', 'rpha': '6e73964a98d5', 'rpmd': 'AppleTV5,3', 'rpvr': '300.66', 'rpad': 'f343f23ccbda', 'rphi': '38ac71913d95', 'rpba': 'F6:CE:77:03:4F:FA', 'rpmrtid': 'F81B0864-E26B-40BA-BB2C-163ED5F200BE'})
2021-09-22 23:05:20 DEBUG [pyatv.core.scan]: Auto-discovered AppleTV at 192.168.3.52:49152 via Protocol.MRP ({'modelname': 'Apple TV', 'allowpairing': 'YES', 'bluetoothaddress': "b'\\xc8i\\xcdnC\\x85'", 'macaddress': 'c8:69:cd:6e:43:86', 'name': 'AppleTV', 'uniqueidentifier': '8CD254F3-CA9C-4B4C-AEBD-113FC050DD45', 'systembuildversion': '19J346', 'localairplayreceiverpairingidentity': 'F81B0864-E26B-40BA-BB2C-163ED5F200BE'})
2021-09-22 23:05:20 DEBUG [pyatv.core.scan]: Auto-discovered C869CD6E4386@AppleTV at 192.168.3.52:7000 via Protocol.RAOP ({'cn': '0,1,2,3', 'da': 'true', 'et': '0,3,5', 'ft': '0x5A7FDFD5,0xBC155FDE', 'sf': '0x1644', 'md': '0,1,2', 'am': 'AppleTV5,3', 'pk': 'f096f8e419ca6a0a76d3fafed380afe4b8f54dc4888980eb25c634ed746d92c5', 'tp': 'UDP', 'vn': '65537', 'vs': '566.25.43', 'ov': '15.0', 'vv': '2'})
2021-09-22 23:05:20 INFO [pyatv.scripts.atvremote]: Auto-discovered AppleTV at 192.168.3.52
2021-09-22 23:05:20 DEBUG [pyatv.core.facade]: Adding handler for protocol Protocol.AirPlay
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay]: Remote control channel is supported
2021-09-22 23:05:20 DEBUG [pyatv.core.facade]: Adding handler for protocol Protocol.MRP
2021-09-22 23:05:20 DEBUG [pyatv.core.facade]: Adding handler for protocol Protocol.Companion
2021-09-22 23:05:20 DEBUG [pyatv.core.facade]: Adding handler for protocol Protocol.MRP
2021-09-22 23:05:20 DEBUG [pyatv.core.facade]: Adding handler for protocol Protocol.RAOP
2021-09-22 23:05:20 DEBUG [pyatv.core.facade]: Connecting to protocol: Protocol.AirPlay
2021-09-22 23:05:20 DEBUG [pyatv.core.facade]: Connecting to protocol: Protocol.MRP
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.remote_control]: Setting up remote control connection to 192.168.3.52:7000
2021-09-22 23:05:20 DEBUG [pyatv.support.http]: Connected to 192.168.3.52
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.auth]: Setting up new AirPlay Pair-Verify procedure with type AuthenticationType.HAP
2021-09-22 23:05:20 DEBUG [pyatv.support.http]: Sending HTTP/1.1 message: b'POST /pair-verify HTTP/1.1\r\nContent-Length: 37\r\nUser-Agent: AirPlay/320.20\r\nConnection: keep-alive\r\nX-Apple-HKP: 3\r\nContent-Type: application/octet-stream\r\n\r\n\x06\x01\x01\x03 \x00\x9f\xa7\x1b@K\xd3pS\x05a\xb9\xe6\xd8\xfc\x18y\x8b;\x9c\x8f\xe1\x08\x93\xf3e\xd6\x07\x99\x82\x03.'
2021-09-22 23:05:20 DEBUG [pyatv.support.http]: Received: b'HTTP/1.1 200 OK\r\nDate: Wed, 22 Sep 2021 21:05:20 GMT\r\nContent-Length: 159\r\nContent-Type: application/octet-stream\r\nServer: AirTunes/566.25.43\r\n\r\n\x05x/\xc4\x12."\x84\xc8\x12"s\x96\xbe\xe1\xd5\xd3^\xd3>2%\x8c\x10\xdf\'\x1cI+\xbb\xbe\xcd9\xd2\x9a1K\xdcH\x91\xd9\x90oV\xec(\xb9\x9a\xd7\xbf\xbaY\x1e^";\x86 \x12lhO\xb4f\x1a\x93Wa\x8f)F\x07\x00\xfb\x1ebe\x84Y\xe7\x84!\xe7$\x0c?\x83WvX\xf3[/\x83\x1bq\xbb\xc2\x02\x1c\xa5\x1d\xb8\x9a\x9b\x8ah\xe9\xdc){8\xb9J1u|\xc8L\x18\xd7\xd3\x06\x01\x02\x03 eQM\x1d\x1ct\xb6\xc0\x8e\xb1\x8cu\xbe\xc3\x03\xf9\xe3\xbe\xb4\'3y=MD\xfe}\xed\x9b\x9c\x86\x11'
2021-09-22 23:05:20 DEBUG [pyatv.support.http]: Got HTTP response: HttpResponse(protocol='HTTP', version='1.1', code=200, message='OK', headers={'date': 'Wed, 22 Sep 2021 21:05:20 GMT', 'content-length': '159', 'content-type': 'application/octet-stream', 'server': 'AirTunes/566.25.43'}, body=b'\x05x/\xc4\x12."\x84\xc8\x12"s\x96\xbe\xe1\xd5\xd3^\xd3>2%\x8c\x10\xdf\'\x1cI+\xbb\xbe\xcd9\xd2\x9a1K\xdcH\x91\xd9\x90oV\xec(\xb9\x9a\xd7\xbf\xbaY\x1e^";\x86 \x12lhO\xb4f\x1a\x93Wa\x8f)F\x07\x00\xfb\x1ebe\x84Y\xe7\x84!\xe7$\x0c?\x83WvX\xf3[/\x83\x1bq\xbb\xc2\x02\x1c\xa5\x1d\xb8\x9a\x9b\x8ah\xe9\xdc){8\xb9J1u|\xc8L\x18\xd7\xd3\x06\x01\x02\x03 eQM\x1d\x1ct\xb6\xc0\x8e\xb1\x8cu\xbe\xc3\x03\xf9\xe3\xbe\xb4\'3y=MD\xfe}\xed\x9b\x9c\x86\x11'):
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.auth.hap]: Device (Encrypted=2fc4122e2284c812227396bee1d5d35ed33e32258c10df271c492bbbbecd39d29a314bdc4891d9906f56ec28b99ad7bfba591e5e223b8620126c684fb4661a9357618f29460700fb1e62658459e78421e7240c3f83577658f35b2f831b71bbc2021ca51db89a9b8a68e9dc297b38b94a31757cc84c18d7d3, Public=db120e921609b11ae66fb2ee2b4aa9f6adaf3e2e480a18e3d8356b29b7745f41)
2021-09-22 23:05:20 DEBUG [pyatv.support.http]: Sending HTTP/1.1 message: b'POST /pair-verify HTTP/1.1\r\nContent-Length: 125\r\nUser-Agent: AirPlay/320.20\r\nConnection: keep-alive\r\nX-Apple-HKP: 3\r\nContent-Type: application/octet-stream\r\n\r\n\x06\x01\x03\x05xi\x96\xdf\xdd\r\x1fH\xea2\x08\xb5!\xcd\xc2C)\xc1I\x94\x1aq\x06\xf0\r!\\\xf5\xaa\x8e\x16\x86p\xe4 \xb2{ik\xa6r\xdb\x9a\x02\xdfk\x15\xc6\xad\x05\x80!\x9b\x9b$\x13\x83\x16\xbb\xb0u\xff\xd9\xcd\x00/IX19\x8e\xb3v>>9\xfanK\x9dba\x96\xdc\xaf\x961\xbc&B\x95H\x138\x07\xdcp\x9b\xddZ\x0e\xdd\x81N\xe9\xd6\xd6~\xf5\xc8\x11\x9f\x83\xdd\x90n\x80\xe6\xd6\x08|'
2021-09-22 23:05:20 DEBUG [pyatv.support.http]: Received: b'HTTP/1.1 200 OK\r\nDate: Wed, 22 Sep 2021 21:05:20 GMT\r\nContent-Length: 3\r\nContent-Type: application/octet-stream\r\nServer: AirTunes/566.25.43\r\n\r\n\x06\x01\x04'
2021-09-22 23:05:20 DEBUG [pyatv.support.http]: Got HTTP response: HttpResponse(protocol='HTTP', version='1.1', code=200, message='OK', headers={'date': 'Wed, 22 Sep 2021 21:05:20 GMT', 'content-length': '3', 'content-type': 'application/octet-stream', 'server': 'AirTunes/566.25.43'}, body=b'\x06\x01\x04'):
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_srp]: Keys (Input=f2ac45c9fde82dce18895770f9acd13e6632c6fee6b5762e306b960c46d6f2f7, Output=aaeab7d6c15a6f9cdc3549ebb3e1cad3a0dd6381cb996ce6e567423dff8ac986)
2021-09-22 23:05:20 DEBUG [pyatv.support.http]: Sending RTSP/1.0 message: b'SETUP rtsp://192.168.3.80/3499785473 RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nContent-Length: 367\r\nCSeq: 0\r\nDACP-ID: 61FE07D68508423B\r\nActive-Remote: 2383638422\r\nClient-Instance: 61FE07D68508423B\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$3E0DB397-FFED-465A-8896-D79C3EEEFFD3V550.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!'
2021-09-22 23:05:20 DEBUG [pyatv.support.http]: Received: b'RTSP/1.0 200 OK\r\nDate: Wed, 22 Sep 2021 21:05:20 GMT\r\nContent-Length: 59\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/566.25.43\r\nCSeq: 0\r\n\r\nbplist00\xd1\x01\x02YeventPort\x11\xc2N\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'
2021-09-22 23:05:20 DEBUG [pyatv.support.http]: Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Wed, 22 Sep 2021 21:05:20 GMT', 'content-length': '59', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/566.25.43', 'cseq': '0'}, body=b'bplist00\xd1\x01\x02YeventPort\x11\xc2N\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'):
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_srp]: Keys (Input=3b2a4e25211141fd4d92b682af4bebd84138f2a54faed20f795d7f4c14b0f5c2, Output=ad92204de802da50f8ed64acb4bc40c3ece597dc25da85c296d46515027f251e)
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Connected to 192.168.3.52:49742
2021-09-22 23:05:20 DEBUG [pyatv.support.http]: Sending RTSP/1.0 message: b'RECORD rtsp://192.168.3.80/3499785473 RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nCSeq: 1\r\nDACP-ID: 61FE07D68508423B\r\nActive-Remote: 2383638422\r\nClient-Instance: 61FE07D68508423B\r\n\r\n'
2021-09-22 23:05:20 DEBUG [pyatv.support.http]: Received: b'RTSP/1.0 200 OK\r\nDate: Wed, 22 Sep 2021 21:05:20 GMT\r\nContent-Length: 0\r\nAudio-Latency: 0\r\nServer: AirTunes/566.25.43\r\nCSeq: 1\r\n\r\n'
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Received data (Data=0004264aeb3e0fbc704d86142ddd132bf62764151a78cc4fefc66671957d8442f9affda286f57cc96794b4906cc9cf65685fc2a0607c83bea8cc346d84920bd8619c1afc47518682b6b22e3d2205952ea16a2dba465544b922b0a69a243646b855a273a56025d47c942741c61009e58ed7ab041477d2775f287cc6a458bf88be72b2faa8414868b41b5c47467f23a54202e79795b43171a38680afaad5abf466daf2ead543458e856364dc38b1d2106ce475c185cb5dcc8ce44a1d9062e42ffe6f71e45a1d1567b028eb7f9848ba1d2088008088744e8956ea45d7764b391874f95d3df5d30851fa94056ca5c8f7fa06da67f6b4043673716597e67576c08...)
2021-09-22 23:05:20 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': '1364', '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$F81B0864-E26B-40BA-BB2C-163ED5F200BE\x10\x02\xd3\x1f !"""_\x10\x15supportsInterstitials_\x10\x15supportsFPSSecureStop_\x10\x1dsupportsUIForAudioOnlyContent\t\t\t\x08\x11\x16D\tS1.1\x10\x04WAppleTV_\x10\x12192.168.3.80:64338_\x10\x11C8:69:CD:6E:43:86_\x10$91688c86-df11-4c30-a35d-20c8bf8dd54d\x08#\x00\x00\x00\x00\x00\x00\x00\x00\\1d9/Wt5fFbwIO\x11\x01\x84\x05acl=0\x18btaddr=C8:69:CD:6E:43:85\x1adeviceid=C8:69:CD:6E:43:86\x10fex=1d9/Wt5fFbwI\x1efeatures=0x5A7FDFD5,0xBC155FDE\x0cflags=0x1644(gid=C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC\x05igl=1\x06gcgl=1\x10model=AppleTV5,3\rprotovers=1.1\'pi=91688c86-df11-4c30-a35d-20c8bf8dd54d(psi=F81B0864-E26B-40BA-BB2C-163ED5F200BECpk=f096f8e419ca6a0a76d3fafed380afe4b8f54dc4888980eb25c634ed746d92c5\x11srcvers=566.25.43\x0bosvers=15.0\x04vv=2\xd434567889_\x10\x15lowLatencyAudioStream\\screenStream[audioStream\\bufferStream\x10\x00\x12\x01D\x08\x00\x12\x00\xe0\x00\x00Y566.25.43ZAppleTV5,3O\x10 \xf0\x96\xf8\xe4\x19\xcaj\nv\xd3\xfa\xfe\xd3\x80\xaf\xe4\xb8\xf5M\xc4\x88\x89\x80\xeb%\xc64\xedtm\x92\xc5_\x10\x11C8:69:CD:6E:43:86W1080p60\x13\xbc\x15_\xdeZ\x7f\xdf\xd5\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\x06\x02\x07\x02\x0b\x02\r\x02\x15\x02*\x02>\x02e\x02f\x02o\x02|\x04\x04\x04\r\x04%\x042\x04>\x04K\x04M\x04R\x04W\x04a\x04l\x04\x8f\x04\xa3\x04\xab\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\xb4')
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=4f00672e3b0c81e97f50e549cbdf932cfb95827867e580f414fe2154cce8914496f6bf46ce675ebf4563c3a23d28a829477bf66b286b51ea4e39ef10ec4718911fe9d541c4632cba1b9707185f1bc2d0697b89403dd54fd7e57ed40ada6095e931)
2021-09-22 23:05:20 DEBUG [pyatv.support.http]: Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Wed, 22 Sep 2021 21:05:20 GMT', 'content-length': '0', 'audio-latency': '0', 'server': 'AirTunes/566.25.43', 'cseq': '1'}, body=''):
2021-09-22 23:05:20 DEBUG [pyatv.support.http]: Sending RTSP/1.0 message: b'SETUP rtsp://192.168.3.80/3499785473 RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nContent-Length: 298\r\nCSeq: 2\r\nDACP-ID: 61FE07D68508423B\r\nActive-Remote: 2383638422\r\nClient-Instance: 61FE07D68508423B\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$88326948-6F81-4FAF-A8FF-D19CE09E18A5_\x10$1910A70F-DBC0-4242-AF95-115DB30604E1_\x10$A3265656-C316-4F34-8D31-13C2227A5337\x10\x02\x13H\x9e\xafE\x1b!\xf5\x94\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'
2021-09-22 23:05:20 DEBUG [pyatv.support.http]: Received: b'RTSP/1.0 200 OK\r\nDate: Wed, 22 Sep 2021 21:05:20 GMT\r\nContent-Length: 100\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/566.25.43\r\nCSeq: 2\r\n\r\nbplist00\xd1\x01\x02Wstreams\xa1\x03\xd3\x04\x05\x06\x07\x08\tTtypeXstreamIDXdataPort\x10\x82\x10\x01\x11\xc2O\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:'
2021-09-22 23:05:20 DEBUG [pyatv.support.http]: Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Wed, 22 Sep 2021 21:05:20 GMT', 'content-length': '100', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/566.25.43', 'cseq': '2'}, body=b'bplist00\xd1\x01\x02Wstreams\xa1\x03\xd3\x04\x05\x06\x07\x08\tTtypeXstreamIDXdataPort\x10\x82\x10\x01\x11\xc2O\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:'):
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_srp]: Keys (Input=2eff4a0fa6adbcb2e80d08bcc3dedd950f6e7324f86b7cc3286b26250758c58a, Output=e8dc633071e6ff77aa4bf04e4ef0696a3170d09c9604d9f08c46903ad3582f45)
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Connected to 192.168.3.52:49743
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=3c017c5e13d952a8d141329edb780732ff2427addf7157fd6f78719a7e3f0b9c08928e6a8e9aa194172a37ee716ce85488bf788cd68bf48cdb1d8e9405e07252d90d079338a6d8e9399c0016264f0131be37f2449f8c142b9630935e3e773fafa211cf70606321869b71331023938327cdde477c6b917111241cc297be01421f3fa8f3612541345e8725e8dfa998437ec96327ced32aa6565beb7e311322a2a911333c6f86c8ff3cf987395b3e0784b49a87d8b11f872e1ec8353b0f73e9909887f74cb31a1dc26054f02a4a248c07285ce2326e22932a7357438605bbcabeb55d36cb37f026d679a7b53e5f73760b526e3da59fece2ab9e4095f4dbc387f...)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: >> Send: Protobuf: type: DEVICE_INFO_MESSAGE
identifier: "5CCDD1F1-C1AB-4D29-BB19-AB5BDBABA21E"
errorCode: NoError
[deviceInfoMessage] {
  uniqueIdentifier: "a11fe3d6-3aab-4dcb-976d-9118841d7cee"
  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: "190AA0C2-DE28-4828-B895-D69F46C51B8A"
2021-09-22 23:05:20 DEBUG [pyatv.core.protocol]: Starting heartbeat loop (AirPlay:192.168.3.52)
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2000db5d699ae3adc676a9679f5a627610f693c93f5de5b9e6e6071222b26d8881f45d70e3010afd763b8d94756e5e7176232a0088b8dd3898b3dfadc3368f8922e4cb6ced9b3205448ff51ad81e32300d3b094530446e8a5b2f365f52a814de8e8d0c62043080fd7679dc8f2f04)
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Received data (Data=20009633af415690879b34307cc7cebf5e0d681f62998a24d71dd18d95044d140f96861df6e5e6018e2cf4b258d2ddc0ac55)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.channels]: Not enough data on data channel (has 32, expects 763)
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Received data (Data=db02f12f1b2767228906a7ec3c2df9822cfbda28b7b85f9dddfa0a2db3681e9c343e1b1f87bba71e2bd007fb7777043089efa084462809bcc213d76b95542afe7ac3dd399ed4409b6fe6113b6a6df2bdff2e2d1a03678731913ad052de5923b3721c282b671b3159f0eff8fdd0044a9bedd1d286d47e0f5d6fbc2b19ec5aea262783d677a36631c4196e8bb01f1f29bca09ea6702c54d82837f6955d6f8d3064e6ff634b3577bd1184b2b4e8f3f3ff73368e22ec71e52360526135a6aefd970d4c3961a5a4e73c1e8e920af0e3b2729ed10ff408019115be92f68e29858dac1a8780a5da5228bf3f16d853b05683d6ff3df11f9db3848b572b613d5c466a3...)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: DEVICE_INFO_MESSAGE
identifier: "5CCDD1F1-C1AB-4D29-BB19-AB5BDBABA21E"
[deviceInfoMessage] {
  uniqueIdentifier: "8CD254F3-CA9C-4B4C-AEBD-113FC050DD45"
  name: "AppleTV"
  localizedModelName: "Apple\302\240TV"
  systemBuildVersion: "19J346"
  applicationBundleIdentifier: "com.apple.mediaremoted"
  protocolVersion: 1
  lastSupportedMessageType: 111
  supportsSystemPairing: true
  allowsPairing: true
  systemMediaApplication: "com.apple.TVMusic"
  supportsACL: true
  supportsSharedQueue: true
  supportsExtendedMotion: true
  sharedQueueVersion: 3
  deviceUID: "F81B0864-E26B-40BA-BB2C-163ED5F200BE"
  managedConfigDeviceID: "c8:69:cd:6e:43:86"
  deviceClass: AppleTV
  logicalDeviceCount: 1
  isProxyGroupPlayer: true
  groupUID: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
  groupedDevices {
    name: "TV"
    localizedModelName: "AirPort10,115"
    deviceUID: "00:F7:6F:D4:4B:0A"
    groupUID: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
    clusterType: 0
    isClusterAware: false
    modelID: "AirPort10,115"
    42: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
  }
  isGroupLeader: true
  isAirplayActive: false
  systemPodcastApplication: "com.apple.podcasts"
  enderDefaultGroupUID: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
  airplayReceivers: "TVAirPlay"
  clusterType: 0
  isClusterAware: true
  modelID: "AppleTV5,3"
  40: 0
  41: "577E1BCA-2D9B-41C2-A8F8-C515CE8072D4"
  42: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
  43: "com.apple.TVBooks"
}
uniqueIdentifier: "56F4FB15-C89C-471D-80AA-F67037EA3697"
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=20000c98520244735463b1ca7f6d047b0bdbe67b4ed6ec1635651972ef7a45c5dcdcedc93a12e5e09e2de0de089ed0e81835)
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=93006001abbacd3c5685b5207098c2387cf69dc7ba67a968a1871e91af1342ba967f8ebc1df02574a85f7642ab075de8d89e82e3b3e8e3ccad8bb446feffd51fee7f373c1c9d1cb23972c23d643cbc297b6c91419cd63b62abb2328dd1e60805f7acc46bd208897bd6433c64f3c3b8b089b8454fdad5ad50325742887b6056f44d44449278a651786342e1a2d4f03c4690d0b676bd4e4fb78eb5f3b9c6da5fdeb41f67eeed)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: >> Send: Protobuf: type: SET_CONNECTION_STATE_MESSAGE
errorCode: NoError
[setConnectionStateMessage] {
  state: Connected
}
uniqueIdentifier: "DB5E3F72-DD27-4B30-B345-B2B580C52CA7"
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=c100a56cce38367a82585ec466f17b731b5807d4ed1a087e5bcc374b3a07ebc5f6c10d86b3c0b1591384b010dd41f0c43be33fe08a7312aeaa86dcbea7b546be6f028049a21336ef50324063a6c202daba0938938d5eed7b5f2d340585b2590129be0ec52658ffb232605929d96b7225b0bb689da271cf330a4b08af5044b3f84f4c31f14e37330b8ed8660b330a5ee896ff018bb3be0ab8a507898d3227492bbee6f7f96c4cecd60500f817b3c82cd04701c497401ca97d1c67b9c321cf66af225bbaab9b412623662f88eb421c227bfd85ea)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: >> Send: Protobuf: type: CLIENT_UPDATES_CONFIG_MESSAGE
identifier: "D8BD19BB-E196-4A8A-B8EA-4C7857CF7596"
errorCode: NoError
[clientUpdatesConfigMessage] {
  artworkUpdates: true
  nowPlayingUpdates: false
  volumeUpdates: true
  keyboardUpdates: true
  outputDeviceUpdates: true
}
uniqueIdentifier: "1916BE32-F986-4766-95CC-DC474469F85A"
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2000f4ab85482a4279ac1dbef5a7192b69a6828c21585d7e018fd05879679547222a3326d9557f8743a88b7fdef48720712f)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.channels]: Not enough data on data channel (has 32, expects 74)
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2a0093b5d81755042dafae9b871d6414cf1a962cc4cc4f6085808697f85b3866b1317ba70e011ecb7be391a5304842fdca3778c2cb21f3f5a22b73aa2000569c1aeb8a315455e7e443439b552dbb06be0ca0ef5e1225ee9fa4eb0ab760264fc391f2485d126c15ddd3465c2d0eab)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.channels]: Not enough data on data channel (has 32, expects 74)
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2a00c6bfb5031cd8d6eb1e742c62061ade7eb167c7b1468c0ed0f68ff6a47918b8defc4735ae24c9cb9904302f0921e6acf0688493a65ab1a27cb0d7)
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2000752c0f0a2e2725bd0f90242f3aa18e41fd054224772d7129edbca39c239080c733dbe870dcccf02bbae4077c0d71267d)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.channels]: Not enough data on data channel (has 32, expects 145)
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Received data (Data=710006623a8c4e316546e8c05109297bfef3d00ce45e6df15a2fb9c6680f304d6ae21af028d20cae33af41c1a9187996d023198a4979574d739524744b9b133c38cd1bd41fb25e98ef41c5bcedcadb324764ddfd29323d340dc8bd0c12546e56278c1cd21f33d3770f9bff1e83aa861472b0ef8520c89e87e4c40bccd59e2f5cea3041)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: REGISTER_FOR_GAME_CONTROLLER_EVENTS_MESSAGE
[registerForGameControllerEventsMessage] {
  1: 6
}
uniqueIdentifier: "E4BFC152-4D20-4780-A960-EC62467FFDEF"
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=200077cc817ead04d05a8182c318d47267a224b5f080edf249852047f0cb116e86ec75c5aed5943cb59ff19ffa5d84d09d30)
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2000930e4c1bf1e3009806c0cd9d4eb1a3162ca5a2b745a2d47ea03263b9fe837d608b84ad1af5cb60444a224e2dbc3e8a97cc10f7cbded6a5480582ed64a9b3e385a137e2bdf7a66be15500c9061df2fdadb93e060b618348c3d05283eff7420feb2d7c86b533510f9be7339c1b3bfa817c6d70269b4e9711b6139b608abddd9b30e0b4115e8f3db383770b02b6ca899311b3110df6fb093541e2a90d3b1eb6feca40e25ef338447b8fab46c85a582b23e5fdb59b431e277499247044b45d7b6ba0d2745deade81e87c3fe3e06195e8a42c8cbc77bff862a8190fb20355cd9334ae34c52dbfdfb72be8a4afd4dbae95133a0893028f1925377db95b93811...)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: UPDATE_OUTPUT_DEVICE_MESSAGE
[updateOutputDeviceMessage] {
  outputDevices {
    name: "TV"
    uniqueIdentifier: "00:F7:6F:D4:4B:0A"
    groupID: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
    modelID: "AirPort10,115"
    macAddress: "\000\367o\324K\n"
    canAccessRemoteAssets: false
    isRemoteControllable: false
    isGroupLeader: false
    isGroupable: true
    deviceType: AirPlay
    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: false
    supportsExternalScreen: false
    requiresAuthorization: false
    sourceInfo {
      routingContextUID: "577E1BCA-2D9B-41C2-A8F8-C515CE8072D4"
      multipleBuiltInDevices: false
    }
    isDeviceGroupable: true
    canRelayCommunicationChannel: true
    isProxyGroupPlayer: false
    canAccessAppleMusic: false
    canAccessiCloudMusicLibrary: false
    groupContainsGroupLeader: true
    supportsBufferedAirPlay: true
    canPlayEncryptedProgressiveDownloadAssets: false
    canFetchMediaDataFromSender: false
    resentsOptimizedUserInterfaceWhenPlayingFetchedAudioOnlyAssets: false
    isAirPlayReceiverSessionActive: false
    parentGroupContainsDiscoverableLeader: false
    isAddedToHomeKit: false
    volumeCapabilities: 2
    supportsHAP: false
    usingJSONProtocol: false
    clusterType: 0
    primaryUID: "00:F7:6F:D4:4B:0A"
    configuredClusterSize: 0
    producesLowFidelityAudio: false
    45: 0
    47: "AVOutputDeviceBluetoothListeningModeNormal"
    48: 0
    50: -1
    51: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
    52: 0
  }
  clusterAwareOutputDevices {
    name: "TV"
    uniqueIdentifier: "00:F7:6F:D4:4B:0A"
    groupID: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
    modelID: "AirPort10,115"
    macAddress: "\000\367o\324K\n"
    canAccessRemoteAssets: false
    isRemoteControllable: false
    isGroupLeader: false
    isGroupable: true
    deviceType: AirPlay
    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: false
    supportsExternalScreen: false
    requiresAuthorization: false
    sourceInfo {
      routingContextUID: "577E1BCA-2D9B-41C2-A8F8-C515CE8072D4"
      multipleBuiltInDevices: false
    }
    isDeviceGroupable: true
    canRelayCommunicationChannel: true
    isProxyGroupPlayer: false
    canAccessAppleMusic: false
    canAccessiCloudMusicLibrary: false
    groupContainsGroupLeader: true
    supportsBufferedAirPlay: true
    canPlayEncryptedProgressiveDownloadAssets: false
    canFetchMediaDataFromSender: false
    resentsOptimizedUserInterfaceWhenPlayingFetchedAudioOnlyAssets: false
    isAirPlayReceiverSessionActive: false
    parentGroupContainsDiscoverableLeader: false
    isAddedToHomeKit: false
    volumeCapabilities: 2
    supportsHAP: false
    usingJSONProtocol: false
    clusterType: 0
    primaryUID: "00:F7:6F:D4:4B:0A"
    configuredClusterSize: 0
    producesLowFidelityAudio: false
    45: 0
    47: "AVOutputDeviceBluetoothListeningModeNormal"
    48: 0
    50: -1
    51: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
    52: 0
  }
}
uniqueIdentifier: "162F311D-D8E2-42A1-8F40-9EC3F7DE45E7"
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_DEFAULT_SUPPORTED_COMMANDS_MESSAGE
[setDefaultSupportedCommandsMessage] {
  supportedCommands {
    supportedCommands {
      command: Play
      enabled: true
    }
    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: SetPlaybackSession
    }
    supportedCommands {
      command: PreloadedPlaybackSession
    }
  }
  displayID: "com.apple.TVMusic"
  playbackQueueCapabilities {
  }
  playerPath {
    client {
      bundleIdentifier: "com.apple.TVMusic"
    }
  }
}
uniqueIdentifier: "79193072-7422-4325-A266-E378C8E4A7C6"
2021-09-22 23:05:20 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 72 (SetDefaultSupportedCommandsMessage) to Listener(func=<bound method PlayerStateManager._handle_set_default_supported_commands of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x1034d4280>>, data=None)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_DEFAULT_SUPPORTED_COMMANDS_MESSAGE
[setDefaultSupportedCommandsMessage] {
  supportedCommands {
    supportedCommands {
      command: Play
      enabled: true
    }
    supportedCommands {
      command: SetPlaybackQueue
      enabled: true
      supportedPlaybackQueueTypes: 3
      supportedPlaybackQueueTypes: 6
      supportedPlaybackQueueTypes: 2
      supportedPlaybackQueueTypes: 5
      supportedPlaybackQueueTypes: 1
    }
    supportedCommands {
      command: SetPlaybackSession
      enabled: true
      supportedPlaybackSessionTypes: "com.apple.podcasts.MTPlaybackQueueController.GenericQueue"
      currentPlaybackSessionTypes: "com.apple.podcasts.MTPlaybackQueueController.GenericQueue"
    }
  }
  displayID: "com.apple.podcasts"
  playbackQueueCapabilities {
  }
  playerPath {
    client {
      bundleIdentifier: "com.apple.podcasts"
    }
  }
}
uniqueIdentifier: "BD49F958-4CF0-4267-BF93-D0C15060D518"
2021-09-22 23:05:20 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 72 (SetDefaultSupportedCommandsMessage) to Listener(func=<bound method PlayerStateManager._handle_set_default_supported_commands of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x1034d4280>>, data=None)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: ORIGIN_CLIENT_PROPERTIES_MESSAGE
uniqueIdentifier: "B3C2D18A-0E8C-42E6-B845-F84AA30043CA"
[originClientPropertiesMessage] {
  lastPlayingTimestamp: 654037520.9200029
}
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_NOW_PLAYING_CLIENT_MESSAGE
[setNowPlayingClientMessage] {
  client {
    processIdentifier: 263
    bundleIdentifier: "com.simpleiptv.client"
  }
}
uniqueIdentifier: "744370D8-6AA9-45CA-B232-195CEE79D68D"
2021-09-22 23:05:20 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 46 (SetNowPlayingClientMessage) to Listener(func=<bound method PlayerStateManager._handle_set_now_playing_client of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x1034d4280>>, data=None)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: UPDATE_CLIENT_MESSAGE
[updateClientMessage] {
  client {
    processIdentifier: 263
    bundleIdentifier: "com.simpleiptv.client"
    processUserIdentifier: 501
    displayName: "iPlayTV"
  }
}
uniqueIdentifier: "69A44C1F-C8EF-40A1-9FE2-44892C9FEFF6"
2021-09-22 23:05:20 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 55 (UpdateClientMessage) to Listener(func=<bound method PlayerStateManager._handle_update_client of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x1034d4280>>, data=None)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_STATE_MESSAGE
[setStateMessage] {
  supportedCommands {
    supportedCommands {
      command: Play
      enabled: true
    }
    supportedCommands {
      command: Pause
      enabled: true
    }
    supportedCommands {
      command: TogglePlayPause
      enabled: true
    }
    supportedCommands {
      command: NextTrack
      enabled: true
    }
    supportedCommands {
      command: PreviousTrack
      enabled: true
    }
  }
  displayName: "iPlayTV"
  playbackState: Playing
  playbackQueueCapabilities {
  }
  playerPath {
    origin {
      displayName: "Apple\302\240TV"
      identifier: 1280262988
    }
    client {
      processIdentifier: 263
      bundleIdentifier: "com.simpleiptv.client"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  playbackStateTimestamp: 654032520.880378
}
uniqueIdentifier: "EE0B8112-13FC-4910-8943-D169D56F6B42"
2021-09-22 23:05:20 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 4 (SetStateMessage) to Listener(func=<bound method PlayerStateManager._handle_set_state of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x1034d4280>>, data=None)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: PLAYER_CLIENT_PROPERTIES_MESSAGE
uniqueIdentifier: "9FFD0A47-B9AE-400A-A311-639CB7BBC212"
[playerClientPropertiesMessage] {
  playerPath {
    origin {
      displayName: "Apple\302\240TV"
      identifier: 1280262988
      5: 1
    }
    client {
      processIdentifier: 263
      bundleIdentifier: "com.simpleiptv.client"
      processUserIdentifier: 501
      displayName: "iPlayTV"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  lastPlayingTimestamp: 654032463.97727
}
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: UPDATE_CLIENT_MESSAGE
[updateClientMessage] {
  client {
    processIdentifier: 136
    bundleIdentifier: "com.apple.TVAirPlay"
    processUserIdentifier: 501
    displayName: "AirPlay"
  }
}
uniqueIdentifier: "A48C4F8F-C60C-4CDF-8C83-DA9877E90487"
2021-09-22 23:05:20 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 55 (UpdateClientMessage) to Listener(func=<bound method PlayerStateManager._handle_update_client of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x1034d4280>>, data=None)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_STATE_MESSAGE
[setStateMessage] {
  supportedCommands {
    supportedCommands {
      command: Play
      enabled: true
    }
    supportedCommands {
      command: Pause
      enabled: true
    }
    supportedCommands {
      command: TogglePlayPause
      enabled: true
    }
    supportedCommands {
      command: Stop
      enabled: true
    }
    supportedCommands {
      command: NextTrack
      enabled: true
    }
    supportedCommands {
      command: PreviousTrack
      enabled: true
    }
    supportedCommands {
      command: BeginFastForward
      enabled: true
    }
    supportedCommands {
      command: EndFastForward
      enabled: true
    }
    supportedCommands {
      command: BeginRewind
      enabled: true
    }
    supportedCommands {
      command: EndRewind
      enabled: true
    }
    supportedCommands {
      command: AdvanceRepeatMode
      enabled: true
    }
    supportedCommands {
      command: AdvanceShuffleMode
      enabled: true
    }
    supportedCommands {
      command: SeekToPlaybackPosition
      enabled: true
    }
  }
  displayName: "AirPlay"
  playbackState: Paused
  playbackQueueCapabilities {
  }
  playerPath {
    origin {
      displayName: "Apple\302\240TV"
      identifier: 1280262988
    }
    client {
      processIdentifier: 136
      bundleIdentifier: "com.apple.TVAirPlay"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  playbackStateTimestamp: 654001339.140793
}
uniqueIdentifier: "078232CA-8A92-4A59-86B2-D41B78A5A28F"
2021-09-22 23:05:20 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 4 (SetStateMessage) to Listener(func=<bound method PlayerStateManager._handle_set_state of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x1034d4280>>, data=None)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: PLAYER_CLIENT_PROPERTIES_MESSAGE
uniqueIdentifier: "F7BB4E6A-6968-47E8-B5BB-77230D856751"
[playerClientPropertiesMessage] {
  playerPath {
    origin {
      displayName: "Apple\302\240TV"
      identifier: 1280262988
      5: 1
    }
    client {
      processIdentifier: 136
      bundleIdentifier: "com.apple.TVAirPlay"
      processUserIdentifier: 501
      displayName: "AirPlay"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  lastPlayingTimestamp: -63114076800.0
}
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: UPDATE_CLIENT_MESSAGE
[updateClientMessage] {
  client {
    processIdentifier: 814
    bundleIdentifier: "com.plexapp.plex"
    processUserIdentifier: 501
    displayName: "Plex"
  }
}
uniqueIdentifier: "DB690310-7772-4D46-A8D4-E111E5E72A57"
2021-09-22 23:05:20 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 55 (UpdateClientMessage) to Listener(func=<bound method PlayerStateManager._handle_update_client of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x1034d4280>>, data=None)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_STATE_MESSAGE
[setStateMessage] {
  playbackQueue {
    location: 0
    contentItems {
      identifier: "19CEAF88-F05B-4AC7-A010-B668A1EBE192"
      metadata {
        title: "Tutti parlano di Jamie"
        trackArtistName: "Everybody\'s Talking About Jamie"
        duration: 6945.888
        artworkAvailable: true
        artworkMIMEType: "image/jpeg"
        elapsedTime: 93.292
        playbackRate: 0.0
        defaultPlaybackRate: 1.0
        mediaType: Video
        mediaSubType: UnknownMediaSubType
        nowPlayingInfoData: "bplist00\324\001\002\003\004\005\006\007\nX$versionY$archiverT$topX$objects\022\000\001\206\240_\020\017NSKeyedArchive...
        elapsedTimeTimestamp: 654012194.726288
        inferredTimestamp: 654012194.727554
        artworkIdentifier: "d19146f3e92683a6"
      }
    }
  }
  displayName: "Plex"
  playbackState: Paused
  playbackQueueCapabilities {
  }
  playerPath {
    origin {
      displayName: "Apple\302\240TV"
      identifier: 1280262988
    }
    client {
      processIdentifier: 814
      bundleIdentifier: "com.plexapp.plex"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  playbackStateTimestamp: 654012194.495096
}
uniqueIdentifier: "8155B22A-0876-4210-B498-650A248868ED"
2021-09-22 23:05:20 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 4 (SetStateMessage) to Listener(func=<bound method PlayerStateManager._handle_set_state of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x1034d4280>>, data=None)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: PLAYER_CLIENT_PROPERTIES_MESSAGE
uniqueIdentifier: "50D8F3AC-FF64-4493-BEBF-B3D2CC816F99"
[playerClientPropertiesMessage] {
  playerPath {
    origin {
      displayName: "Apple\302\240TV"
      identifier: 1280262988
      5: 1
    }
    client {
      processIdentifier: 814
      bundleIdentifier: "com.plexapp.plex"
      processUserIdentifier: 501
      displayName: "Plex"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  lastPlayingTimestamp: 654012194.495648
}
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: VOLUME_CONTROL_CAPABILITIES_DID_CHANGE_MESSAGE
[volumeControlCapabilitiesDidChangeMessage] {
  capabilities {
    volumeControlAvailable: true
    volumeCapabilities: Absolute
  }
  endpointUID: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
  outputDeviceUID: "00:F7:6F:D4:4B:0A"
}
uniqueIdentifier: "3B55C729-835F-419D-9C8E-3C7574CBDE6E"
2021-09-22 23:05:20 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 64 (VolumeControlCapabilitiesDidChangeMessage) to Listener(func=<bound method MrpAudio._volume_control_changed of <pyatv.protocols.mrp.MrpAudio object at 0x1034d4730>>, data=None)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: VOLUME_DID_CHANGE_MESSAGE
[volumeDidChangeMessage] {
  volume: 0.35928142
  endpointUID: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
  outputDeviceUID: "00:F7:6F:D4:4B:0A"
}
uniqueIdentifier: "D078F154-82AA-4BC6-8FC9-B8D3E4C5E85E"
2021-09-22 23:05:20 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 52 (VolumeDidChangeMessage) to Listener(func=<bound method MrpAudio._volume_did_change of <pyatv.protocols.mrp.MrpAudio object at 0x1034d4730>>, data=None)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: UNKNOWN_MESSAGE
identifier: "D8BD19BB-E196-4A8A-B8EA-4C7857CF7596"
uniqueIdentifier: "115F3C4F-9AA1-4E7F-B883-A8655BD1932C"
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=200060c0e7d05c1eb3527f41429d7f027a5f88ef5e6d243fb1bc2c291f9b8ec8f3d235fca9cab8e44e9e8bd876fefb8876c5)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.mrp.player_state]: Active client is now com.simpleiptv.client
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=b400b412716bb1e58e74287f0524d0e56a55c2a2698c32625bd7dd2113a7f737848f2c46206bf1d1f776f9510d0298acc339fe005fef37992bf0fc919d9c2b832ba7f227a34876bb00ad8c9dfe69e223c28bb2477047135b956605958711bb8c4dd6f407ca500c087c56282d16abeb4270bd9c6801a3583f175a8ca51ca8ae8f15f221086a63592cd5809db5c396e69567bbc1143770506d3ec3b28900ea67952addec8c8e052864bd551f50328c8d1b84985761362637e3c05e6c0b72ffd33414db94492cd7)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: >> Send: Protobuf: type: GET_KEYBOARD_SESSION_MESSAGE
identifier: "AF325D78-0199-4081-8DAD-D879B2EB53E4"
errorCode: NoError
uniqueIdentifier: "BF811BF8-83DE-4CA5-A585-5FF4758EDDE1"
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2000b096d25a5ae72a544e89f61bccb216a949b65b91159e1a138418ccb79445145e5aeb327e4ce3543b5d1aec7e50dfe1942a002e12777fe0d982eb475fad55d387367805130458fb8026e6491aaa084f58bd0ef40f6b24d6c1c6bf3099f1e18296bf973b281dbc6ac0c440a625)
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Received data (Data=20001a9d285c4af3b0a0307aad5591d42d78506d8f32cb5b43e0a5b4a4f301f3d195382bedd6c39322280de0eef2198fcb1ca90074c6ba545f0cdcb6486ef3b7e39fde229461fee838292b3e923d5794d259dfe10639bc302ce35f4539c939ba15b5c8692f1ee114bf8c4b2a25e0c02355054f3caa059bdd988f5188fcb74d387aaad765e2dbf42d2dc6136e5fd01c516ed51c3dbdb89eaccdb783e4266b25943c124693c82d694b00d25067c71e3e5dcbf0f6fba451a1f53cda19c79546b7b74f02a53b3d5fdae4279e7f9684f1cd7ec9e62514c114e9589fbf7663fd723a77a746c2c62632ac16c5d3ba1696)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: KEYBOARD_MESSAGE
identifier: "AF325D78-0199-4081-8DAD-D879B2EB53E4"
[keyboardMessage] {
  state: Unknown
  attributes {
    inputTraits {
      autocapitalizationType: None
      keyboardType: Default
      returnKeyType: Default
      enablesReturnKeyAutomatically: false
      secureTextEntry: false
      validTextRangeLocation: 0
      validTextRangeLength: 0
    }
  }
}
uniqueIdentifier: "40C8C45F-C54C-455A-93B3-3D60C93AACD2"
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=2000a18dff60117465725e3fa460ddeeb5f4fb6b37ae9ca55e1cfbe98d5d8dc21c7ec5d42e7620f41e683071d8352692745d)
2021-09-22 23:05:20 DEBUG [pyatv.core.facade]: Connecting to protocol: Protocol.Companion
2021-09-22 23:05:20 DEBUG [pyatv.core.facade]: Protocol Protocol.MRP already set up, ignoring
2021-09-22 23:05:20 DEBUG [pyatv.core.facade]: Connecting to protocol: Protocol.RAOP
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=ce0036c18413c0635c74ee98e462ed933d98917cf329828eb8aae329854868a951c28df9ee3ca264677c07b33513168b9d9db8aadcf72778eefd4630c512ec7c959c2931fe2e4d8dd72c261b1f7039bdfcc0b3109e7f8acecaff18c666ec2f6a364f3b67962f769de16c6304e8505a4f3e179b27aac3c4a0a69fe968b4027b8258bd3f09035e21128ab7551c2b655bf104d69ef3b5ad4e2729680c04ba72bbeb76a8cd7dd858eb205c0b15331f30bfc530948e581ddc5ec72ee0f21cf941f2d8a34476afb414d0d8a0322099740cf6753020a086c9f0babf4f5dde00fa80565e)
2021-09-22 23:05:20 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: "DC01FB85-499C-4E82-A9AC-07B68BAC0EEF"
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=ce009f1a81f439d687652cca11019dacf1dae73408f9b3920d7eb7f530b7064b6ce9ab1d34f7fdcc727f964c305b7b7a77e8548e149e7c8aa3d7b9c042d45ac0191b31aa65658f673870a836ca8f2b5d6e6548832c44d173119d208da41fa8dfcf8e34f00def3aef75c8c5e5ece1b0732423be713e8d58a734e23c3510289e7db3f2c584bed2863a8a50dd5907864467640b8fadd3a24ddcd95d5952a413feb524a77d7b2fcaff26632124b20daee25a481ce850b8ff5b4fd753f5a95bb990aa4e5f7e4aa794e88532f21cfd1d592f9e9ed8b00abe261277a34a9efb473bba92)
2021-09-22 23:05:20 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: "47023071-7018-48E6-9274-59EDDFE7DF70"
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2000d87dbd6074a2dddd502b8879dc57e12b1c5bca9ebbeecb1fb3a636187641da703e1d50e7d55471a867cc332c20d8a4c7)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.channels]: Not enough data on data channel (has 32, expects 74)
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2a0061131633dd0d45fd3a4556bd0d1c284f565049c8d8559d5146062062930ed8608e9b867c2ce7a8fc41608389088b470cadae70ab0cb13570a9bd)
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2000492a6d3508206c3d513f05ce62f5f9eb77596da4af8bee8db244a8dfa1c8a76c3b10f8f87ae9f8692a53a745679c83ba)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.channels]: Not enough data on data channel (has 32, expects 74)
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2a00783ea3e4811908b9dd3e9886596b3226848df9258ccacec176760cf815840d6dbdcf86855f9e9bccb9faf17021d46464efe58e8428a0baae19fe)
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Received data (Data=20009ecdf5d02b84c16e74b4e39a98b8663376d7511042a4d00234aa6be40969ab57d235252b159112733bda2173f63ea4a2ad0035113175bb4d7d56d94effacabe69b39c050d5dbbef833c953adf15481f23b64d4d2bc07f1e55794e353a110e121cfe6b1551b611d3cfee333f87839bff5e03a7cbc4345e1565c1cc5d4beb6a23d46ad6c61f95a9a3ba73ceb8afd8314ff02b34f8f57d86a22855dde624d8803b04415bed0e98a7bff9c507162fba3840d08dac554eeb92d6683a81661dddd510706fa3674ebb1ec8026597228813999946f1a378f33d92fd6d2ff307ebc0680c9e298130fb7b632b38bcefcb7942138)
2021-09-22 23:05:20 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: VOLUME_DID_CHANGE_MESSAGE
[volumeDidChangeMessage] {
  volume: 0.42178142
  endpointUID: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
  outputDeviceUID: "00:F7:6F:D4:4B:0A"
}
uniqueIdentifier: "A6CEF279-6738-4485-B680-A20503D76E72"
2021-09-22 23:05:20 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 52 (VolumeDidChangeMessage) to Listener(func=<bound method MrpAudio._volume_did_change of <pyatv.protocols.mrp.MrpAudio object at 0x1034d4730>>, data=None)
2021-09-22 23:05:20 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=2000daa7157d9baa05aef7609aa7c0c4ed03c9532c4f649698670931a0ff0bea2e783be1b1c468645cc93f1705bf2152cf2d)
2021-09-22 23:05:22 DEBUG [pyatv.core.protocol]: Sending periodic heartbeat 0 (AirPlay:192.168.3.52)
2021-09-22 23:05:22 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: 61FE07D68508423B\r\nActive-Remote: 2383638422\r\nClient-Instance: 61FE07D68508423B\r\n\r\n'
2021-09-22 23:05:22 DEBUG [pyatv.support.http]: Received: b'RTSP/1.0 200 OK\r\nDate: Wed, 22 Sep 2021 21:05:22 GMT\r\nContent-Length: 55\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/566.25.43\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'
2021-09-22 23:05:22 DEBUG [pyatv.support.http]: Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Wed, 22 Sep 2021 21:05:22 GMT', 'content-length': '55', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/566.25.43', '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'):
2021-09-22 23:05:22 DEBUG [pyatv.core.protocol]: Got heartbeat 0 (AirPlay:192.168.3.52)
2021-09-22 23:05:24 DEBUG [pyatv.core.protocol]: Sending periodic heartbeat 1 (AirPlay:192.168.3.52)
2021-09-22 23:05:24 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: 61FE07D68508423B\r\nActive-Remote: 2383638422\r\nClient-Instance: 61FE07D68508423B\r\n\r\n'
2021-09-22 23:05:24 DEBUG [pyatv.support.http]: Received: b'RTSP/1.0 200 OK\r\nDate: Wed, 22 Sep 2021 21:05:24 GMT\r\nContent-Length: 55\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/566.25.43\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'
2021-09-22 23:05:24 DEBUG [pyatv.support.http]: Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Wed, 22 Sep 2021 21:05:24 GMT', 'content-length': '55', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/566.25.43', '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'):
2021-09-22 23:05:24 DEBUG [pyatv.core.protocol]: Got heartbeat 1 (AirPlay:192.168.3.52)
2021-09-22 23:05:25 DEBUG [pyatv.protocols.airplay.mrp_connection]: Closing connection
2021-09-22 23:05:25 DEBUG [pyatv.scripts.atvremote]: Waiting for 1 remaining tasks
2021-09-22 23:05:25 DEBUG [pyatv.protocols.airplay.mrp_connection]: Disconnected from device: None
2021-09-22 23:05:25 DEBUG [pyatv.scripts.atvremote]: Connection was closed properly
2021-09-22 23:05:25 DEBUG [pyatv.core.protocol]: Stopping heartbeat loop at 3 (AirPlay:192.168.3.52)
2021-09-22 23:05:25 DEBUG [pyatv.support.http]: Connection closed
2021-09-22 23:05:25 DEBUG [pyatv.auth.hap_channel]: Connection was lost to remote
Traceback (most recent call last):
  File "/usr/local/Cellar/python@3.9/3.9.7/Frameworks/Python.framework/Versions/3.9/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/local/Cellar/python@3.9/3.9.7/Frameworks/Python.framework/Versions/3.9/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 "/usr/local/lib/python3.9/site-packages/pyatv/scripts/atvremote.py", line 700, in _run_application
    return await cli_handler(loop)
  File "/usr/local/lib/python3.9/site-packages/pyatv/scripts/atvremote.py", line 494, in cli_handler
    return await _handle_commands(args, config, loop)
  File "/usr/local/lib/python3.9/site-packages/pyatv/scripts/atvremote.py", line 595, in _handle_commands
    ret = await _handle_device_command(args, cmd, atv, loop)
  File "/usr/local/lib/python3.9/site-packages/pyatv/scripts/atvremote.py", line 627, in _handle_device_command
    return await _exec_command(atv.audio, cmd, True, *cmd_args)
  File "/usr/local/lib/python3.9/site-packages/pyatv/scripts/atvremote.py", line 666, in _exec_command
    value = await tmp(*args)
  File "/usr/local/lib/python3.9/site-packages/pyatv/core/facade.py", line 339, in volume_up
    return await self.relay("volume_up")()
  File "/usr/local/lib/python3.9/site-packages/pyatv/protocols/mrp/__init__.py", line 706, in volume_up
    await asyncio.wait_for(self._volume_event.wait(), timeout=5.0)
  File "/usr/local/Cellar/python@3.9/3.9.7/Frameworks/Python.framework/Versions/3.9/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

volume_down exit well (no error on console) but doesn't do anything

atvremote --id C8:69:CD:6E:43:86 --companion-credentials "db120e921609b11ae66fb2ee2b4aa9f6adaf3e2e480a18e3d8356b29b7745f41:0b7048d68d80030752af99293c35df66c2611066f2afc041972c66d575c5f038:46383142303836342d453236422d343042412d424232432d313633454435463230304245:32623061303963342d363361652d343236352d393266322d333561363631653936623962" --airplay-credentials "db120e921609b11ae66fb2ee2b4aa9f6adaf3e2e480a18e3d8356b29b7745f41:5b194d29c5411690bc7f26e8dcf0ae763ed4b1249f37e4647fa9c51f8952eef9:46383142303836342d453236422d343042412d424232432d313633454435463230304245:39663439623363662d613333642d343239342d393738312d326563336235353235323961" volume_down --debug
2021-09-22 23:39:37 DEBUG [pyatv.support.net]: Binding on *:5353
2021-09-22 23:39:37 DEBUG [pyatv.support.net]: Binding on 127.0.0.1:0
2021-09-22 23:39:37 DEBUG [pyatv.support.net]: Binding on 192.168.3.80:0
2021-09-22 23:39:37 DEBUG [pyatv.core.scan]: Auto-discovered AppleTV at 192.168.3.52:7000 via Protocol.AirPlay ({'acl': '0', 'btaddr': 'C8:69:CD:6E:43:85', 'deviceid': 'C8:69:CD:6E:43:86', 'fex': '1d9/Wt5fFbwI', 'features': '0x5A7FDFD5,0xBC155FDE', 'flags': '0x1644', 'gid': 'C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC', 'igl': '1', 'gcgl': '1', 'model': 'AppleTV5,3', 'protovers': '1.1', 'pi': '91688c86-df11-4c30-a35d-20c8bf8dd54d', 'psi': 'F81B0864-E26B-40BA-BB2C-163ED5F200BE', 'pk': 'f096f8e419ca6a0a76d3fafed380afe4b8f54dc4888980eb25c634ed746d92c5', 'srcvers': '566.25.43', 'osvers': '15.0', 'vv': '2'})
2021-09-22 23:39:37 DEBUG [pyatv.core.scan]: Auto-discovered AppleTV at 192.168.3.52:49153 via Protocol.Companion ({'rpmac': '1', 'rphn': '6442f3fabe89', 'rpfl': '0x36782', 'rpha': '3b3983b27783', 'rpmd': 'AppleTV5,3', 'rpvr': '300.66', 'rpad': '6a56ec9b45ca', 'rphi': '19e516c1a6b7', 'rpba': '57:EC:5B:55:A8:C8', 'rpmrtid': 'F81B0864-E26B-40BA-BB2C-163ED5F200BE'})
2021-09-22 23:39:37 DEBUG [pyatv.core.scan]: Auto-discovered AppleTV at 192.168.3.52:49152 via Protocol.MRP ({'modelname': 'Apple TV', 'allowpairing': 'YES', 'bluetoothaddress': "b'\\xc8i\\xcdnC\\x85'", 'macaddress': 'c8:69:cd:6e:43:86', 'name': 'AppleTV', 'uniqueidentifier': '8CD254F3-CA9C-4B4C-AEBD-113FC050DD45', 'systembuildversion': '19J346', 'localairplayreceiverpairingidentity': 'F81B0864-E26B-40BA-BB2C-163ED5F200BE'})
2021-09-22 23:39:37 DEBUG [pyatv.core.scan]: Auto-discovered C869CD6E4386@AppleTV at 192.168.3.52:7000 via Protocol.RAOP ({'cn': '0,1,2,3', 'da': 'true', 'et': '0,3,5', 'ft': '0x5A7FDFD5,0xBC155FDE', 'sf': '0x1644', 'md': '0,1,2', 'am': 'AppleTV5,3', 'pk': 'f096f8e419ca6a0a76d3fafed380afe4b8f54dc4888980eb25c634ed746d92c5', 'tp': 'UDP', 'vn': '65537', 'vs': '566.25.43', 'ov': '15.0', 'vv': '2'})
2021-09-22 23:39:37 INFO [pyatv.scripts.atvremote]: Auto-discovered AppleTV at 192.168.3.52
2021-09-22 23:39:37 DEBUG [pyatv.core.facade]: Adding handler for protocol Protocol.AirPlay
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay]: Remote control channel is supported
2021-09-22 23:39:37 DEBUG [pyatv.core.facade]: Adding handler for protocol Protocol.MRP
2021-09-22 23:39:37 DEBUG [pyatv.core.facade]: Adding handler for protocol Protocol.Companion
2021-09-22 23:39:37 DEBUG [pyatv.core.facade]: Adding handler for protocol Protocol.MRP
2021-09-22 23:39:37 DEBUG [pyatv.core.facade]: Adding handler for protocol Protocol.RAOP
2021-09-22 23:39:37 DEBUG [pyatv.core.facade]: Connecting to protocol: Protocol.AirPlay
2021-09-22 23:39:37 DEBUG [pyatv.core.facade]: Connecting to protocol: Protocol.MRP
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.remote_control]: Setting up remote control connection to 192.168.3.52:7000
2021-09-22 23:39:37 DEBUG [pyatv.support.http]: Connected to 192.168.3.52
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.auth]: Setting up new AirPlay Pair-Verify procedure with type AuthenticationType.HAP
2021-09-22 23:39:37 DEBUG [pyatv.support.http]: Sending HTTP/1.1 message: b'POST /pair-verify HTTP/1.1\r\nContent-Length: 37\r\nUser-Agent: AirPlay/320.20\r\nConnection: keep-alive\r\nX-Apple-HKP: 3\r\nContent-Type: application/octet-stream\r\n\r\n\x06\x01\x01\x03 \xbf\x83\xad8\x86%\x12\xae.\x92\xd7GF\xf5V\xdcO\xcb\xcf\x06\xb8zY\xe0\xcb\x8d\xe7\xf7\xdb\xa9\xdf{'
2021-09-22 23:39:37 DEBUG [pyatv.support.http]: Received: b'HTTP/1.1 200 OK\r\nDate: Wed, 22 Sep 2021 21:39:37 GMT\r\nContent-Length: 159\r\nContent-Type: application/octet-stream\r\nServer: AirTunes/566.25.43\r\n\r\n\x05x\xceu\xf1-\xd4\xa6x\xe20R\x82\x01\xd3"\xbas}\xab%\xfd\xe7\n\x07&\x15\xba;\x0e\x02\x92\xf2da\x06\xd0\x1a\xe6C\xb4\x03\xa6\x7f]\x9f\'\xde(\x044\x03\x8d\x97\xea\x92\x1a\xf4\x0c\xbc\xc2>\xfd\xcc\xb3M^\xb8\x05\xddm5}\xf3a\x897\xd0+\x07zQ\t\xef\x07\xe4\x07\xd4r\x04:w\xb0\xa64\xd8&\x18\xea\x95\xf1\xfd\x1c|\xd1\xb47\xc8N7G\xad{\x9a\x9cJ\xed\x96\x91\xb91\n\x06\x01\x02\x03 x~\r\x19\x00<\xe4\x1eH\xf5\x84\xec\xefO\xd2\xb5\xd2\xd6SR\x9dgk2#\xa1\x00\xff\xc1\x83<\x00'
2021-09-22 23:39:37 DEBUG [pyatv.support.http]: Got HTTP response: HttpResponse(protocol='HTTP', version='1.1', code=200, message='OK', headers={'date': 'Wed, 22 Sep 2021 21:39:37 GMT', 'content-length': '159', 'content-type': 'application/octet-stream', 'server': 'AirTunes/566.25.43'}, body=b'\x05x\xceu\xf1-\xd4\xa6x\xe20R\x82\x01\xd3"\xbas}\xab%\xfd\xe7\n\x07&\x15\xba;\x0e\x02\x92\xf2da\x06\xd0\x1a\xe6C\xb4\x03\xa6\x7f]\x9f\'\xde(\x044\x03\x8d\x97\xea\x92\x1a\xf4\x0c\xbc\xc2>\xfd\xcc\xb3M^\xb8\x05\xddm5}\xf3a\x897\xd0+\x07zQ\t\xef\x07\xe4\x07\xd4r\x04:w\xb0\xa64\xd8&\x18\xea\x95\xf1\xfd\x1c|\xd1\xb47\xc8N7G\xad{\x9a\x9cJ\xed\x96\x91\xb91\n\x06\x01\x02\x03 x~\r\x19\x00<\xe4\x1eH\xf5\x84\xec\xefO\xd2\xb5\xd2\xd6SR\x9dgk2#\xa1\x00\xff\xc1\x83<\x00'):
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.auth.hap]: Device (Encrypted=ce75f12dd4a678e230528201d322ba737dab25fde70a072615ba3b0e0292f2646106d01ae643b403a67f5d9f27de280434038d97ea921af40cbcc23efdccb34d5eb805dd6d357df3618937d02b077a5109ef07e407d472043a77b0a634d82618ea95f1fd1c7cd1b437c84e3747ad7b9a9c4aed9691b9310a, Public=db120e921609b11ae66fb2ee2b4aa9f6adaf3e2e480a18e3d8356b29b7745f41)
2021-09-22 23:39:37 DEBUG [pyatv.support.http]: Sending HTTP/1.1 message: b'POST /pair-verify HTTP/1.1\r\nContent-Length: 125\r\nUser-Agent: AirPlay/320.20\r\nConnection: keep-alive\r\nX-Apple-HKP: 3\r\nContent-Type: application/octet-stream\r\n\r\n\x06\x01\x03\x05x\x1e~X\x87\x921\xd3\x8b\x87R\x96KI\xd0\xb3\xbd\xdd;\\F\xba\xaeAj\xd5g}!\x97N!\xf9\xbf\x8a\x9cq\xe0<\t\x15\xf8\x14\x13\xfa\x17y\xdd\xb5\xe7\xb6\x16\x0bn\x12\xc7\xf5\x90\xed9\xce_$VcI&r\x94lF\xe7\x0c[!X\x1e\x08\x117P\x0c\xe2#)UO\xa8ca\xee\x95\xe8\xf5?\xb4\xd8n9\x9b2\x8f\x18\xcb\xedY\xd4\xdd\x04)D\xca-\xaf \x04W\x1fa\xb5\xa2'
2021-09-22 23:39:37 DEBUG [pyatv.support.http]: Received: b'HTTP/1.1 200 OK\r\nDate: Wed, 22 Sep 2021 21:39:37 GMT\r\nContent-Length: 3\r\nContent-Type: application/octet-stream\r\nServer: AirTunes/566.25.43\r\n\r\n\x06\x01\x04'
2021-09-22 23:39:37 DEBUG [pyatv.support.http]: Got HTTP response: HttpResponse(protocol='HTTP', version='1.1', code=200, message='OK', headers={'date': 'Wed, 22 Sep 2021 21:39:37 GMT', 'content-length': '3', 'content-type': 'application/octet-stream', 'server': 'AirTunes/566.25.43'}, body=b'\x06\x01\x04'):
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_srp]: Keys (Input=5627bca7cda679b7103557b5781c61dd100b45d2e36d7754038d725b05b8a54b, Output=93b3d2f70df4f7351a11ba66a3cf8533aaff2a2f833e71995115bc03668f1e4b)
2021-09-22 23:39:37 DEBUG [pyatv.support.http]: Sending RTSP/1.0 message: b'SETUP rtsp://192.168.3.80/3802877376 RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nContent-Length: 367\r\nCSeq: 0\r\nDACP-ID: 3863CB66A0B9388\r\nActive-Remote: 1101007681\r\nClient-Instance: 3863CB66A0B9388\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$476DF711-8E44-4562-AEC9-EAAB177E9FFDV550.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!'
2021-09-22 23:39:37 DEBUG [pyatv.support.http]: Received: b'RTSP/1.0 200 OK\r\nDate: Wed, 22 Sep 2021 21:39:37 GMT\r\nContent-Length: 59\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/566.25.43\r\nCSeq: 0\r\n\r\nbplist00\xd1\x01\x02YeventPort\x11\xc2T\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'
2021-09-22 23:39:37 DEBUG [pyatv.support.http]: Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Wed, 22 Sep 2021 21:39:37 GMT', 'content-length': '59', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/566.25.43', 'cseq': '0'}, body=b'bplist00\xd1\x01\x02YeventPort\x11\xc2T\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'):
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_srp]: Keys (Input=2320db7fb7cf25d5248609e6f024a9b613922211d94addb58cc2e217d9345dbe, Output=8439ebf73aa22af21892fe930d6378668e09d311aca5ddbdf22ccd6d504d5343)
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_channel]: Connected to 192.168.3.52:49748
2021-09-22 23:39:37 DEBUG [pyatv.support.http]: Sending RTSP/1.0 message: b'RECORD rtsp://192.168.3.80/3802877376 RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nCSeq: 1\r\nDACP-ID: 3863CB66A0B9388\r\nActive-Remote: 1101007681\r\nClient-Instance: 3863CB66A0B9388\r\n\r\n'
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_channel]: Received data (Data=000463fad13f326ca2aef1691365a55a0da600a231f80c4326a4e31fd8fecc351371d3c698d955e9ba77865616cd9c41c0a92d5b9a4df15570bfa08bb3f28017d28d1cbb81b234ac7d5e238a247096ac34458f099e01b4aae483793dc163bded7b222c33eb1b75f23b9ed3d44ff3e0285f029b192af72c23425b8cf51e19b9393184bf1b8d8a97959c3dbe8249d3a34fa409ebe0bb4ea8bded9b6c0823a46639610ff9af2776746a97fe36a83ec8779215593b0e678e89827cea199fa9897989f7ff2a4154ed129a363116dcb9f9e51cc5527fd8e4053011d8b80492c9851044422ae99a6bc131f9fe222d7ae6b8a6b4912ea1ca993132416a82ee9e11ba2...)
2021-09-22 23:39:37 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': '1364', '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$F81B0864-E26B-40BA-BB2C-163ED5F200BE\x10\x02\xd3\x1f !"""_\x10\x15supportsInterstitials_\x10\x15supportsFPSSecureStop_\x10\x1dsupportsUIForAudioOnlyContent\t\t\t\x08\x11\x16D\tS1.1\x10\x04WAppleTV_\x10\x12192.168.3.80:50628_\x10\x11C8:69:CD:6E:43:86_\x10$91688c86-df11-4c30-a35d-20c8bf8dd54d\x08#\x00\x00\x00\x00\x00\x00\x00\x00\\1d9/Wt5fFbwIO\x11\x01\x84\x05acl=0\x18btaddr=C8:69:CD:6E:43:85\x1adeviceid=C8:69:CD:6E:43:86\x10fex=1d9/Wt5fFbwI\x1efeatures=0x5A7FDFD5,0xBC155FDE\x0cflags=0x1644(gid=C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC\x05igl=1\x06gcgl=1\x10model=AppleTV5,3\rprotovers=1.1\'pi=91688c86-df11-4c30-a35d-20c8bf8dd54d(psi=F81B0864-E26B-40BA-BB2C-163ED5F200BECpk=f096f8e419ca6a0a76d3fafed380afe4b8f54dc4888980eb25c634ed746d92c5\x11srcvers=566.25.43\x0bosvers=15.0\x04vv=2\xd434567889_\x10\x15lowLatencyAudioStream\\screenStream[audioStream\\bufferStream\x10\x00\x12\x01D\x08\x00\x12\x00\xe0\x00\x00Y566.25.43ZAppleTV5,3O\x10 \xf0\x96\xf8\xe4\x19\xcaj\nv\xd3\xfa\xfe\xd3\x80\xaf\xe4\xb8\xf5M\xc4\x88\x89\x80\xeb%\xc64\xedtm\x92\xc5_\x10\x11C8:69:CD:6E:43:86W1080p60\x13\xbc\x15_\xdeZ\x7f\xdf\xd5\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\x06\x02\x07\x02\x0b\x02\r\x02\x15\x02*\x02>\x02e\x02f\x02o\x02|\x04\x04\x04\r\x04%\x042\x04>\x04K\x04M\x04R\x04W\x04a\x04l\x04\x8f\x04\xa3\x04\xab\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\xb4')
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=4f00bc9316f15b8b74893428f5081cf9b9592b8297f1dc450b5d9a2d573b06a46037121d0b906ecbea3d72368b425d722b0a3075b7e09c159a035eb9891cb2ef36d82dd9921e74d8d966381b1db7c585072a7dc755cacd3da871b07a64e472be88)
2021-09-22 23:39:37 DEBUG [pyatv.support.http]: Received: b'RTSP/1.0 200 OK\r\nDate: Wed, 22 Sep 2021 21:39:37 GMT\r\nContent-Length: 0\r\nAudio-Latency: 0\r\nServer: AirTunes/566.25.43\r\nCSeq: 1\r\n\r\n'
2021-09-22 23:39:37 DEBUG [pyatv.support.http]: Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Wed, 22 Sep 2021 21:39:37 GMT', 'content-length': '0', 'audio-latency': '0', 'server': 'AirTunes/566.25.43', 'cseq': '1'}, body=''):
2021-09-22 23:39:37 DEBUG [pyatv.support.http]: Sending RTSP/1.0 message: b'SETUP rtsp://192.168.3.80/3802877376 RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nContent-Length: 324\r\nCSeq: 2\r\nDACP-ID: 3863CB66A0B9388\r\nActive-Remote: 1101007681\r\nClient-Instance: 3863CB66A0B9388\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$A6E053F5-D75A-4635-8CAA-8E1F5322AD1B_\x10$1910A70F-DBC0-4242-AF95-115DB30604E1_\x10$D46E0917-9B6C-41BD-84E5-F94D341807C9\x10\x02\x14\x00\x00\x00\x00\x00\x00\x00\x00\xfdXbQ\x10\xc57;\x10\x82\t\x00\x08\x00\x0b\x00\x13\x00\x15\x00$\x00.\x00=\x00H\x00T\x00Y\x00^\x00u\x00\x9c\x00\xc3\x00\xea\x00\xec\x00\xfd\x00\xff\x00\x00\x00\x00\x00\x00\x02\x01\x00\x00\x00\x00\x00\x00\x00\x12\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x01\x00'
2021-09-22 23:39:37 DEBUG [pyatv.support.http]: Received: b'RTSP/1.0 200 OK\r\nDate: Wed, 22 Sep 2021 21:39:37 GMT\r\nContent-Length: 100\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/566.25.43\r\nCSeq: 2\r\n\r\nbplist00\xd1\x01\x02Wstreams\xa1\x03\xd3\x04\x05\x06\x07\x08\tTtypeXstreamIDXdataPort\x10\x82\x10\x01\x11\xc2U\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:'
2021-09-22 23:39:37 DEBUG [pyatv.support.http]: Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Wed, 22 Sep 2021 21:39:37 GMT', 'content-length': '100', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/566.25.43', 'cseq': '2'}, body=b'bplist00\xd1\x01\x02Wstreams\xa1\x03\xd3\x04\x05\x06\x07\x08\tTtypeXstreamIDXdataPort\x10\x82\x10\x01\x11\xc2U\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:'):
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_srp]: Keys (Input=19ab18630bbf27a1100e1cc4d8a012a9879a51f87b023cf32414590eb60d7261, Output=887aa8419dacdadd4fef10b14d4347a10b3b8db12bdd03eef79ba4a0831e0aa7)
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_channel]: Connected to 192.168.3.52:49749
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=3c015f22f4ca93dc403c3e1465ff88fd1215b4a4bb03ed304e7f942813f119feb89f22e4f62f3636a0bb440f3b52742e93e54268f203a85e2eb1348dd34fbd7fad7f2b9959d5e508a3c7467f2679a994f6da45b998a51665d28169cf85a2aeeaf023bfe4557e4e766841f9768970663969d058d390919e5be52cd59b4c51754d5cd81e81792c2832617739ac9c46ca8d794b9bcae1fe89eba54ca01ccbaf9425b9e046d2eb232bafa5d19573932b82d826a896df7a4401766ac2f793313cb53444e97190ea41331b8ea90a9ba45b20dd579865d570fa44d9d9f0d076ddd24e96f9415ac05c9c2717391c75ec82ff72555f019b58dbba03e88bb87f48e582f...)
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: >> Send: Protobuf: type: DEVICE_INFO_MESSAGE
identifier: "CBABBEFD-DFF2-4FD0-B8C7-7EB31AB24C9E"
errorCode: NoError
[deviceInfoMessage] {
  uniqueIdentifier: "d1bb811f-9fac-4d0c-b748-394a609cdbb8"
  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: "915BA70C-80C2-4C77-9256-6CA529E82E78"
2021-09-22 23:39:37 DEBUG [pyatv.core.protocol]: Starting heartbeat loop (AirPlay:192.168.3.52)
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2000d67f8c2392ea7c5f5e65a5a5d9fa45ce12e7a4e4b70d2be16e93a9405ef07edd35ccb72b00c40c60978b6f8388f243572a0091df84c172aee579993cbd4e59b9a88c0ea6f054a46c1d335169b3e46beaeb1fc6048a243a422a4b4bf2f852fdd186ea52ddeb947dadf14dbca9)
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2000e20bc1c007be58e96dc392f3c2b01338d3883e4713a35ac5cb22c8b4f78dccaa2829f0f400a337b60d94567a1dee0ba8)
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.channels]: Not enough data on data channel (has 32, expects 763)
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_channel]: Received data (Data=db023937f9ec00e6fec31129456103e668aabb129121b4bd85a1b1d0b9809113fa4c0695f9d0989d16f5ee605b9c72daf84f216dd02c47c967a475cc5ae555a6b6ac98656e5820803cb6d2fa2e1aecea855b1ac4d7c5c79497ed20633bc276cf3fc8553a781bca3103d8ce4b2ee409846c2980df0b7281cf048eafe32962d1d7593a844952b55868d3d641b57b6867d787d1b4d68a7ed10dfce62725b8b1209674bca14c6b4950a926562fe08c32d6230f9368c5a40fad9240a7e4768239288a12f440ec018eda38b357921a7640c72e23a89b6524bc5bd3ded886403e93bd648e6a9079a88fee9154319905ef2dd5658bc722c8776b3ed847e9d98bb583e...)
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: DEVICE_INFO_MESSAGE
identifier: "CBABBEFD-DFF2-4FD0-B8C7-7EB31AB24C9E"
[deviceInfoMessage] {
  uniqueIdentifier: "8CD254F3-CA9C-4B4C-AEBD-113FC050DD45"
  name: "AppleTV"
  localizedModelName: "Apple\302\240TV"
  systemBuildVersion: "19J346"
  applicationBundleIdentifier: "com.apple.mediaremoted"
  protocolVersion: 1
  lastSupportedMessageType: 111
  supportsSystemPairing: true
  allowsPairing: true
  systemMediaApplication: "com.apple.TVMusic"
  supportsACL: true
  supportsSharedQueue: true
  supportsExtendedMotion: true
  sharedQueueVersion: 3
  deviceUID: "F81B0864-E26B-40BA-BB2C-163ED5F200BE"
  managedConfigDeviceID: "c8:69:cd:6e:43:86"
  deviceClass: AppleTV
  logicalDeviceCount: 1
  isProxyGroupPlayer: true
  groupUID: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
  groupedDevices {
    name: "TV"
    localizedModelName: "AirPort10,115"
    deviceUID: "00:F7:6F:D4:4B:0A"
    groupUID: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
    clusterType: 0
    isClusterAware: false
    modelID: "AirPort10,115"
    42: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
  }
  isGroupLeader: true
  isAirplayActive: false
  systemPodcastApplication: "com.apple.podcasts"
  enderDefaultGroupUID: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
  airplayReceivers: "TVAirPlay"
  clusterType: 0
  isClusterAware: true
  modelID: "AppleTV5,3"
  40: 0
  41: "577E1BCA-2D9B-41C2-A8F8-C515CE8072D4"
  42: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
  43: "com.apple.TVBooks"
}
uniqueIdentifier: "8893DC4C-2865-45D7-BD65-875D9F3CEEB7"
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=2000f70e5ba14386db734a04b865c8e0e5b2d4da3978a0f1ba4fac4bc59ebdc7b54b144ccd3306613835036bca1f37708fa2)
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=930067c64e171dc353edd783a03f2049ee049c1c01e826a094de1f20626dc6a1db2f9ea829e790c6ef907b8c3029d6552a6adff644c81882fc82dc9c32a04237041efaf41b894a2da14132e5033bdfacfae2d209791508f1d2de30f98f6b3caeb4710e04ac2bcb111e84570df084c778c5b5af3ec40ced9e94180a9c7d7c53d14e82fa60d0c033b8863103f48b5d84a33df9a101418857470378b7f58dc46018a713d3376d)
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: >> Send: Protobuf: type: SET_CONNECTION_STATE_MESSAGE
errorCode: NoError
[setConnectionStateMessage] {
  state: Connected
}
uniqueIdentifier: "7E1E4C46-7867-4C8A-AEC9-78413630E6E7"
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=c1001f1a14c57e142bd6e8f856aef9400ef91550c3a3c19b79e81e72329b8b176cc8132d1620b8e6cf17b6ff18a4cce71e8aeaea092cdf002e5d8a3a49c0b012ccaa8ae85d6c4c5f041786f208d746ea4efaa8ce519dd50e7cda382d80c60d785825e18ec9fe7e6bc69c2b2233ebf074ab754e18201845fed00335a0fc2954e7e6c1fc85532fe9dbade07f4dd878d401a3b6681740c457be88c2b988335389cd46a2c0dabaa1dd4833901db2154142c0aa172fe681c82fe8612b0df6e35523b5d01d0a1996ab66b26adf23ca554ed202b28e31)
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: >> Send: Protobuf: type: CLIENT_UPDATES_CONFIG_MESSAGE
identifier: "79439801-886D-41C3-9FF1-735EE7780607"
errorCode: NoError
[clientUpdatesConfigMessage] {
  artworkUpdates: true
  nowPlayingUpdates: false
  volumeUpdates: true
  keyboardUpdates: true
  outputDeviceUpdates: true
}
uniqueIdentifier: "A2DAF1C6-9545-408A-A0E3-72496F681017"
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2000c517c749cef264b20ea0b7198b15c64f99455f69a31f1706fc4fa9af131bdb126c6b95ea4e5a85eeb1222600cb1374a02a0054f0cb48e249231f7f95d08d2782f6b50c733ffb11beabd47426dc4a2b0d0873e6e3a54129693653fc71b74af9c50c54009f1f9c2733a1fcee1b20005169af9af72a620437479aae2b1e7b9a25e5868126a34a7e39bd0419fe00f329b50ac9738b15f9c57408418234317a912a00e40a69d5800770968e0ccb0fadd324d70772da8973bd11802e454f02255357aaf228ce2bc8ed313e02144c79e054fa3184e4af2f4113674e226d)
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2000014bbf477f1fea08233dd24380c2aee84697a320d5b97c758f15d3745b4b518c5f839bc3e355453c1983db16cac3fd98710016a436207add8764487fc436e4c0a51260e2344ae6147582f2c48d6fb4ce4fc4f641e91fbf8646d917bb5a1fa4270eceb573f27863009b3deb86c7d7324d4e778778e78d72267a346114b447ecee81a82cd96ac35a7764c1ee5ba46502a024613baa0960891437c332727423c957da563a9cafcf8b7147a7614c525ccc59bf819b)
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: REGISTER_FOR_GAME_CONTROLLER_EVENTS_MESSAGE
[registerForGameControllerEventsMessage] {
  1: 6
}
uniqueIdentifier: "5961AF2A-C816-4250-BCA7-E816B522AFB1"
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=2000e71a4d12ac74c5969ae7c9bdab90e5005505034ce502b5206883e37443af023eb18a8b64334876fc79d6b28b9ff0c4d3)
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2000b2457fc7eeddf7ed4d9d645b0de74458860b98026c693e92dd7446b30fe638489fba27a3eb1482ca1f2c0fdd08b85db0)
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.channels]: Not enough data on data channel (has 32, expects 4332)
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_channel]: Received data (Data=cc10ce4939b94d3d95a1fdba3f0564b330860dd31f72fe017bb02569b125cb6c3287a9e8d018845800579ea31a0c4f75f63cbc1f2017dbc0fa304dfded0e74262d51b7704bf401ff668180fbf2b653b60289f915379de350c8dc785c1ab3873f28855156fb7ba980b0c1fb1d7f95a5fbf0c3f4dbea1a4b9beeed99611bffd77a1f44e7faef427c8acdd9a97b137d9778682750df7c6c4805b2c6dd11e36b6e714e377794a05749fb5d78736722d749004e71adfcfc523d8f0298e2369613c59e4068316d30fcd838060146f1d8d6b28a77f106cb130f4a9d30fb90a580e037aca26e975250aedc99caea5fe45b38be72f3c22df12578fa458604047aa21f0...)
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: UPDATE_OUTPUT_DEVICE_MESSAGE
[updateOutputDeviceMessage] {
  outputDevices {
    name: "TV"
    uniqueIdentifier: "00:F7:6F:D4:4B:0A"
    groupID: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
    modelID: "AirPort10,115"
    macAddress: "\000\367o\324K\n"
    canAccessRemoteAssets: false
    isRemoteControllable: false
    isGroupLeader: false
    isGroupable: true
    deviceType: AirPlay
    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: false
    supportsExternalScreen: false
    requiresAuthorization: false
    sourceInfo {
      routingContextUID: "577E1BCA-2D9B-41C2-A8F8-C515CE8072D4"
      multipleBuiltInDevices: false
    }
    isDeviceGroupable: true
    canRelayCommunicationChannel: true
    isProxyGroupPlayer: false
    canAccessAppleMusic: false
    canAccessiCloudMusicLibrary: false
    groupContainsGroupLeader: true
    supportsBufferedAirPlay: true
    canPlayEncryptedProgressiveDownloadAssets: false
    canFetchMediaDataFromSender: false
    resentsOptimizedUserInterfaceWhenPlayingFetchedAudioOnlyAssets: false
    isAirPlayReceiverSessionActive: false
    parentGroupContainsDiscoverableLeader: false
    isAddedToHomeKit: false
    volumeCapabilities: 2
    supportsHAP: false
    usingJSONProtocol: false
    clusterType: 0
    primaryUID: "00:F7:6F:D4:4B:0A"
    configuredClusterSize: 0
    producesLowFidelityAudio: false
    45: 0
    47: "AVOutputDeviceBluetoothListeningModeNormal"
    48: 0
    50: -1
    51: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
    52: 0
  }
  clusterAwareOutputDevices {
    name: "TV"
    uniqueIdentifier: "00:F7:6F:D4:4B:0A"
    groupID: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
    modelID: "AirPort10,115"
    macAddress: "\000\367o\324K\n"
    canAccessRemoteAssets: false
    isRemoteControllable: false
    isGroupLeader: false
    isGroupable: true
    deviceType: AirPlay
    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: false
    supportsExternalScreen: false
    requiresAuthorization: false
    sourceInfo {
      routingContextUID: "577E1BCA-2D9B-41C2-A8F8-C515CE8072D4"
      multipleBuiltInDevices: false
    }
    isDeviceGroupable: true
    canRelayCommunicationChannel: true
    isProxyGroupPlayer: false
    canAccessAppleMusic: false
    canAccessiCloudMusicLibrary: false
    groupContainsGroupLeader: true
    supportsBufferedAirPlay: true
    canPlayEncryptedProgressiveDownloadAssets: false
    canFetchMediaDataFromSender: false
    resentsOptimizedUserInterfaceWhenPlayingFetchedAudioOnlyAssets: false
    isAirPlayReceiverSessionActive: false
    parentGroupContainsDiscoverableLeader: false
    isAddedToHomeKit: false
    volumeCapabilities: 2
    supportsHAP: false
    usingJSONProtocol: false
    clusterType: 0
    primaryUID: "00:F7:6F:D4:4B:0A"
    configuredClusterSize: 0
    producesLowFidelityAudio: false
    45: 0
    47: "AVOutputDeviceBluetoothListeningModeNormal"
    48: 0
    50: -1
    51: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
    52: 0
  }
}
uniqueIdentifier: "354F7428-8082-4C7C-A354-505AFC5F8E58"
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_DEFAULT_SUPPORTED_COMMANDS_MESSAGE
[setDefaultSupportedCommandsMessage] {
  supportedCommands {
    supportedCommands {
      command: Play
      enabled: true
    }
    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: SetPlaybackSession
    }
    supportedCommands {
      command: PreloadedPlaybackSession
    }
  }
  displayID: "com.apple.TVMusic"
  playbackQueueCapabilities {
  }
  playerPath {
    client {
      bundleIdentifier: "com.apple.TVMusic"
    }
  }
}
uniqueIdentifier: "AC2204FA-EBDA-4E81-9B22-E7A6618D1618"
2021-09-22 23:39:37 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 72 (SetDefaultSupportedCommandsMessage) to Listener(func=<bound method PlayerStateManager._handle_set_default_supported_commands of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x10e46d5e0>>, data=None)
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_DEFAULT_SUPPORTED_COMMANDS_MESSAGE
[setDefaultSupportedCommandsMessage] {
  supportedCommands {
    supportedCommands {
      command: Play
      enabled: true
    }
    supportedCommands {
      command: SetPlaybackQueue
      enabled: true
      supportedPlaybackQueueTypes: 3
      supportedPlaybackQueueTypes: 6
      supportedPlaybackQueueTypes: 2
      supportedPlaybackQueueTypes: 5
      supportedPlaybackQueueTypes: 1
    }
    supportedCommands {
      command: SetPlaybackSession
      enabled: true
      supportedPlaybackSessionTypes: "com.apple.podcasts.MTPlaybackQueueController.GenericQueue"
      currentPlaybackSessionTypes: "com.apple.podcasts.MTPlaybackQueueController.GenericQueue"
    }
  }
  displayID: "com.apple.podcasts"
  playbackQueueCapabilities {
  }
  playerPath {
    client {
      bundleIdentifier: "com.apple.podcasts"
    }
  }
}
uniqueIdentifier: "E31B3AC4-0415-48B5-86ED-09DCED266CD0"
2021-09-22 23:39:37 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 72 (SetDefaultSupportedCommandsMessage) to Listener(func=<bound method PlayerStateManager._handle_set_default_supported_commands of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x10e46d5e0>>, data=None)
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: ORIGIN_CLIENT_PROPERTIES_MESSAGE
uniqueIdentifier: "476A6083-391D-4341-B8CB-A0E15BF09065"
[originClientPropertiesMessage] {
  lastPlayingTimestamp: 654039577.763838
}
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_NOW_PLAYING_CLIENT_MESSAGE
[setNowPlayingClientMessage] {
  client {
    processIdentifier: 263
    bundleIdentifier: "com.simpleiptv.client"
  }
}
uniqueIdentifier: "BAE56D04-AEC2-44F4-A0DD-5D6EB986DA2C"
2021-09-22 23:39:37 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 46 (SetNowPlayingClientMessage) to Listener(func=<bound method PlayerStateManager._handle_set_now_playing_client of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x10e46d5e0>>, data=None)
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: UPDATE_CLIENT_MESSAGE
[updateClientMessage] {
  client {
    processIdentifier: 263
    bundleIdentifier: "com.simpleiptv.client"
    processUserIdentifier: 501
    displayName: "iPlayTV"
  }
}
uniqueIdentifier: "20A97F20-17C1-41B3-A6E6-A5444572E575"
2021-09-22 23:39:37 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 55 (UpdateClientMessage) to Listener(func=<bound method PlayerStateManager._handle_update_client of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x10e46d5e0>>, data=None)
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_STATE_MESSAGE
[setStateMessage] {
  supportedCommands {
    supportedCommands {
      command: Play
      enabled: true
    }
    supportedCommands {
      command: Pause
      enabled: true
    }
    supportedCommands {
      command: TogglePlayPause
      enabled: true
    }
    supportedCommands {
      command: NextTrack
      enabled: true
    }
    supportedCommands {
      command: PreviousTrack
      enabled: true
    }
  }
  displayName: "iPlayTV"
  playbackState: Playing
  playbackQueueCapabilities {
  }
  playerPath {
    origin {
      displayName: "Apple\302\240TV"
      identifier: 1280262988
    }
    client {
      processIdentifier: 263
      bundleIdentifier: "com.simpleiptv.client"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  playbackStateTimestamp: 654032520.880378
}
uniqueIdentifier: "F8B2D92B-7BB2-45AA-9F67-AA8A6CA1EF42"
2021-09-22 23:39:37 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 4 (SetStateMessage) to Listener(func=<bound method PlayerStateManager._handle_set_state of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x10e46d5e0>>, data=None)
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: PLAYER_CLIENT_PROPERTIES_MESSAGE
uniqueIdentifier: "0E6C3DFF-0B0D-4965-8C3A-88D74E483C33"
[playerClientPropertiesMessage] {
  playerPath {
    origin {
      displayName: "Apple\302\240TV"
      identifier: 1280262988
      5: 1
    }
    client {
      processIdentifier: 263
      bundleIdentifier: "com.simpleiptv.client"
      processUserIdentifier: 501
      displayName: "iPlayTV"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  lastPlayingTimestamp: 654032463.97727
}
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: UPDATE_CLIENT_MESSAGE
[updateClientMessage] {
  client {
    processIdentifier: 136
    bundleIdentifier: "com.apple.TVAirPlay"
    processUserIdentifier: 501
    displayName: "AirPlay"
  }
}
uniqueIdentifier: "7D535C68-B054-4D3F-839A-3A864FE3483C"
2021-09-22 23:39:37 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 55 (UpdateClientMessage) to Listener(func=<bound method PlayerStateManager._handle_update_client of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x10e46d5e0>>, data=None)
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_STATE_MESSAGE
[setStateMessage] {
  supportedCommands {
    supportedCommands {
      command: Play
      enabled: true
    }
    supportedCommands {
      command: Pause
      enabled: true
    }
    supportedCommands {
      command: TogglePlayPause
      enabled: true
    }
    supportedCommands {
      command: Stop
      enabled: true
    }
    supportedCommands {
      command: NextTrack
      enabled: true
    }
    supportedCommands {
      command: PreviousTrack
      enabled: true
    }
    supportedCommands {
      command: BeginFastForward
      enabled: true
    }
    supportedCommands {
      command: EndFastForward
      enabled: true
    }
    supportedCommands {
      command: BeginRewind
      enabled: true
    }
    supportedCommands {
      command: EndRewind
      enabled: true
    }
    supportedCommands {
      command: AdvanceRepeatMode
      enabled: true
    }
    supportedCommands {
      command: AdvanceShuffleMode
      enabled: true
    }
    supportedCommands {
      command: SeekToPlaybackPosition
      enabled: true
    }
  }
  displayName: "AirPlay"
  playbackState: Paused
  playbackQueueCapabilities {
  }
  playerPath {
    origin {
      displayName: "Apple\302\240TV"
      identifier: 1280262988
    }
    client {
      processIdentifier: 136
      bundleIdentifier: "com.apple.TVAirPlay"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  playbackStateTimestamp: 654001339.140793
}
uniqueIdentifier: "6F867A5A-368D-42C0-9FE4-37C3D73AB4F4"
2021-09-22 23:39:37 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 4 (SetStateMessage) to Listener(func=<bound method PlayerStateManager._handle_set_state of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x10e46d5e0>>, data=None)
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: PLAYER_CLIENT_PROPERTIES_MESSAGE
uniqueIdentifier: "D10C535E-F292-438C-8AAB-B3896DF7A9ED"
[playerClientPropertiesMessage] {
  playerPath {
    origin {
      displayName: "Apple\302\240TV"
      identifier: 1280262988
      5: 1
    }
    client {
      processIdentifier: 136
      bundleIdentifier: "com.apple.TVAirPlay"
      processUserIdentifier: 501
      displayName: "AirPlay"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  lastPlayingTimestamp: -63114076800.0
}
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: UPDATE_CLIENT_MESSAGE
[updateClientMessage] {
  client {
    processIdentifier: 814
    bundleIdentifier: "com.plexapp.plex"
    processUserIdentifier: 501
    displayName: "Plex"
  }
}
uniqueIdentifier: "A7AA8995-FA96-4920-A80B-70607CA2B77E"
2021-09-22 23:39:37 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 55 (UpdateClientMessage) to Listener(func=<bound method PlayerStateManager._handle_update_client of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x10e46d5e0>>, data=None)
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_STATE_MESSAGE
[setStateMessage] {
  playbackQueue {
    location: 0
    contentItems {
      identifier: "19CEAF88-F05B-4AC7-A010-B668A1EBE192"
      metadata {
        title: "Tutti parlano di Jamie"
        trackArtistName: "Everybody\'s Talking About Jamie"
        duration: 6945.888
        artworkAvailable: true
        artworkMIMEType: "image/jpeg"
        elapsedTime: 93.292
        playbackRate: 0.0
        defaultPlaybackRate: 1.0
        mediaType: Video
        mediaSubType: UnknownMediaSubType
        nowPlayingInfoData: "bplist00\324\001\002\003\004\005\006\007\nX$versionY$archiverT$topX$objects\022\000\001\206\240_\020\017NSKeyedArchive...
        elapsedTimeTimestamp: 654012194.726288
        inferredTimestamp: 654012194.727554
        artworkIdentifier: "d19146f3e92683a6"
      }
    }
  }
  displayName: "Plex"
  playbackState: Paused
  playbackQueueCapabilities {
  }
  playerPath {
    origin {
      displayName: "Apple\302\240TV"
      identifier: 1280262988
    }
    client {
      processIdentifier: 814
      bundleIdentifier: "com.plexapp.plex"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  playbackStateTimestamp: 654012194.495096
}
uniqueIdentifier: "93B455DC-4C2E-422E-A399-E89B4146643A"
2021-09-22 23:39:37 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 4 (SetStateMessage) to Listener(func=<bound method PlayerStateManager._handle_set_state of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x10e46d5e0>>, data=None)
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: PLAYER_CLIENT_PROPERTIES_MESSAGE
uniqueIdentifier: "0ED70489-1658-42A2-9A5D-F35137B17645"
[playerClientPropertiesMessage] {
  playerPath {
    origin {
      displayName: "Apple\302\240TV"
      identifier: 1280262988
      5: 1
    }
    client {
      processIdentifier: 814
      bundleIdentifier: "com.plexapp.plex"
      processUserIdentifier: 501
      displayName: "Plex"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  lastPlayingTimestamp: 654012194.495648
}
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: VOLUME_CONTROL_CAPABILITIES_DID_CHANGE_MESSAGE
[volumeControlCapabilitiesDidChangeMessage] {
  capabilities {
    volumeControlAvailable: true
    volumeCapabilities: Absolute
  }
  endpointUID: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
  outputDeviceUID: "00:F7:6F:D4:4B:0A"
}
uniqueIdentifier: "CF64A0D3-784F-4084-B717-AE6D591FC96A"
2021-09-22 23:39:37 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 64 (VolumeControlCapabilitiesDidChangeMessage) to Listener(func=<bound method MrpAudio._volume_control_changed of <pyatv.protocols.mrp.MrpAudio object at 0x10e46d760>>, data=None)
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: VOLUME_DID_CHANGE_MESSAGE
[volumeDidChangeMessage] {
  volume: 0.51796407
  endpointUID: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
  outputDeviceUID: "00:F7:6F:D4:4B:0A"
}
uniqueIdentifier: "2BE7E47A-E6AB-4E8A-9F5D-FA332919567B"
2021-09-22 23:39:37 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 52 (VolumeDidChangeMessage) to Listener(func=<bound method MrpAudio._volume_did_change of <pyatv.protocols.mrp.MrpAudio object at 0x10e46d760>>, data=None)
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: UNKNOWN_MESSAGE
identifier: "79439801-886D-41C3-9FF1-735EE7780607"
uniqueIdentifier: "F57867E8-E687-4FC4-81C0-4DBCA4F6B09B"
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=2000318d65161d82f9541553f1a10dd0fcdda36a79a2469dc4dbccf78da7b8aafbdda4a6c283186b42f7f776413838da1519)
2021-09-22 23:39:37 DEBUG [pyatv.protocols.mrp.player_state]: Active client is now com.simpleiptv.client
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=b400bbb9cdb5fb01a1a4408bd55e20abaf9f12b35155e311aff710a0c318a9f1382454dcbdab289eacf9118b46d060b75ce3eb90d99e1a139018b37a8f3595a5880731e251c77edac4ab5c9b28fcc597adbaba2a227ab48d30db43c0a4fc28548a1818618018c59e8f53550748c0dfb7a080cfc96b651a3801c5db95d97e4cc8d5d072de4420638e342c547bae8ce7ec9f0b46d4ba9f9f83a37e50d8654475351fea28a42f117b5bbaa4a0d60d6131e562bf012643ee547d32cc89ee1f7695e1791a1f58dd03)
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: >> Send: Protobuf: type: GET_KEYBOARD_SESSION_MESSAGE
identifier: "54DF119B-F23D-451F-940E-E4581B108065"
errorCode: NoError
uniqueIdentifier: "386EC559-07AE-45B4-BD86-B30F919D80DD"
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_channel]: Received data (Data=20004dfb4936895aeadd98fe418f83618c5163cb83e5e4b467ece510d0736aff8a1941f20cefdca7932635678cf28b2c374b2a002a00e55904a0383954e80fb1193e1deb13d761f11bdc8576920867f0d2efd6ff0a0898f0d9ed005688a3f1e13200fddce0326504a5646ebe2973)
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2000d823a817cc95eb49e252c06c6f94ecb83cfdd9241d1cea37ac2b0832d836cffae6ef0615de998d8c3c17393256bc87e6a900d450b317cd81c2918ed5854fc95f9e27590ed03f3ac400c5898ec4fb81ab87a0120711d73dc49c497fb14e1a95d1ea7b12209ccee48cd89ec836f6f8ee98a3553eaa8c7a4a290baa40c6fb4a3b359a7211af37ecce5328b77888bbe3d8d59f1c738f45a5da96cf78864e14922968137b71cd9e12b7eb0850c5825a89a45aa5f741126d3bc71dcd1a81ccc90cbcf660eec4c9ada0365a28f789d72fd4636d54013836327c9e0807d3c50a712729ab5d1d57d004b7bc4305ce22)
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: KEYBOARD_MESSAGE
identifier: "54DF119B-F23D-451F-940E-E4581B108065"
[keyboardMessage] {
  state: Unknown
  attributes {
    inputTraits {
      autocapitalizationType: None
      keyboardType: Default
      returnKeyType: Default
      enablesReturnKeyAutomatically: false
      secureTextEntry: false
      validTextRangeLocation: 0
      validTextRangeLength: 0
    }
  }
}
uniqueIdentifier: "85842C4A-E67F-40E7-9C2E-2A0792407545"
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=2000e0b15029c48f40537a7b984d55f569c2d54df786e73eaf35b497129e37d008313e352f7d5712acf3b2c8ceae9d465d97)
2021-09-22 23:39:37 DEBUG [pyatv.core.facade]: Connecting to protocol: Protocol.Companion
2021-09-22 23:39:37 DEBUG [pyatv.core.facade]: Protocol Protocol.MRP already set up, ignoring
2021-09-22 23:39:37 DEBUG [pyatv.core.facade]: Connecting to protocol: Protocol.RAOP
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: Closing connection
2021-09-22 23:39:37 DEBUG [pyatv.scripts.atvremote]: Waiting for 1 remaining tasks
2021-09-22 23:39:37 DEBUG [pyatv.protocols.airplay.mrp_connection]: Disconnected from device: None
2021-09-22 23:39:37 DEBUG [pyatv.scripts.atvremote]: Connection was closed properly
2021-09-22 23:39:37 DEBUG [pyatv.core.protocol]: Stopping heartbeat loop at 1 (AirPlay:192.168.3.52)
2021-09-22 23:39:37 DEBUG [pyatv.support.http]: Connection closed
2021-09-22 23:39:37 DEBUG [pyatv.auth.hap_channel]: Connection was lost to remote
`

set_volume=10 exit well (no error on console) but doesn't do anything

`atvremote --id C8:69:CD:6E:43:86 --companion-credentials "db120e921609b11ae66fb2ee2b4aa9f6adaf3e2e480a18e3d8356b29b7745f41:0b7048d68d80030752af99293c35df66c2611066f2afc041972c66d575c5f038:46383142303836342d453236422d343042412d424232432d313633454435463230304245:32623061303963342d363361652d343236352d393266322d333561363631653936623962" --airplay-credentials "db120e921609b11ae66fb2ee2b4aa9f6adaf3e2e480a18e3d8356b29b7745f41:5b194d29c5411690bc7f26e8dcf0ae763ed4b1249f37e4647fa9c51f8952eef9:46383142303836342d453236422d343042412d424232432d313633454435463230304245:39663439623363662d613333642d343239342d393738312d326563336235353235323961" set_volume=10 --debug
2021-09-22 23:40:56 DEBUG [pyatv.support.net]: Binding on *:5353
2021-09-22 23:40:56 DEBUG [pyatv.support.net]: Binding on 127.0.0.1:0
2021-09-22 23:40:56 DEBUG [pyatv.support.net]: Binding on 192.168.3.80:0
2021-09-22 23:40:56 DEBUG [pyatv.core.scan]: Auto-discovered AppleTV at 192.168.3.52:7000 via Protocol.AirPlay ({'acl': '0', 'btaddr': 'C8:69:CD:6E:43:85', 'deviceid': 'C8:69:CD:6E:43:86', 'fex': '1d9/Wt5fFbwI', 'features': '0x5A7FDFD5,0xBC155FDE', 'flags': '0x1644', 'gid': 'C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC', 'igl': '1', 'gcgl': '1', 'model': 'AppleTV5,3', 'protovers': '1.1', 'pi': '91688c86-df11-4c30-a35d-20c8bf8dd54d', 'psi': 'F81B0864-E26B-40BA-BB2C-163ED5F200BE', 'pk': 'f096f8e419ca6a0a76d3fafed380afe4b8f54dc4888980eb25c634ed746d92c5', 'srcvers': '566.25.43', 'osvers': '15.0', 'vv': '2'})
2021-09-22 23:40:56 DEBUG [pyatv.core.scan]: Auto-discovered AppleTV at 192.168.3.52:49153 via Protocol.Companion ({'rpmac': '1', 'rphn': '6442f3fabe89', 'rpfl': '0x36782', 'rpha': '3b3983b27783', 'rpmd': 'AppleTV5,3', 'rpvr': '300.66', 'rpad': '6a56ec9b45ca', 'rphi': '19e516c1a6b7', 'rpba': '57:EC:5B:55:A8:C8', 'rpmrtid': 'F81B0864-E26B-40BA-BB2C-163ED5F200BE'})
2021-09-22 23:40:56 DEBUG [pyatv.core.scan]: Auto-discovered AppleTV at 192.168.3.52:49152 via Protocol.MRP ({'modelname': 'Apple TV', 'allowpairing': 'YES', 'bluetoothaddress': "b'\\xc8i\\xcdnC\\x85'", 'macaddress': 'c8:69:cd:6e:43:86', 'name': 'AppleTV', 'uniqueidentifier': '8CD254F3-CA9C-4B4C-AEBD-113FC050DD45', 'systembuildversion': '19J346', 'localairplayreceiverpairingidentity': 'F81B0864-E26B-40BA-BB2C-163ED5F200BE'})
2021-09-22 23:40:56 DEBUG [pyatv.core.scan]: Auto-discovered C869CD6E4386@AppleTV at 192.168.3.52:7000 via Protocol.RAOP ({'cn': '0,1,2,3', 'da': 'true', 'et': '0,3,5', 'ft': '0x5A7FDFD5,0xBC155FDE', 'sf': '0x1644', 'md': '0,1,2', 'am': 'AppleTV5,3', 'pk': 'f096f8e419ca6a0a76d3fafed380afe4b8f54dc4888980eb25c634ed746d92c5', 'tp': 'UDP', 'vn': '65537', 'vs': '566.25.43', 'ov': '15.0', 'vv': '2'})
2021-09-22 23:40:56 INFO [pyatv.scripts.atvremote]: Auto-discovered AppleTV at 192.168.3.52
2021-09-22 23:40:56 DEBUG [pyatv.core.facade]: Adding handler for protocol Protocol.AirPlay
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay]: Remote control channel is supported
2021-09-22 23:40:56 DEBUG [pyatv.core.facade]: Adding handler for protocol Protocol.MRP
2021-09-22 23:40:56 DEBUG [pyatv.core.facade]: Adding handler for protocol Protocol.Companion
2021-09-22 23:40:56 DEBUG [pyatv.core.facade]: Adding handler for protocol Protocol.MRP
2021-09-22 23:40:56 DEBUG [pyatv.core.facade]: Adding handler for protocol Protocol.RAOP
2021-09-22 23:40:56 DEBUG [pyatv.core.facade]: Connecting to protocol: Protocol.AirPlay
2021-09-22 23:40:56 DEBUG [pyatv.core.facade]: Connecting to protocol: Protocol.MRP
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.remote_control]: Setting up remote control connection to 192.168.3.52:7000
2021-09-22 23:40:56 DEBUG [pyatv.support.http]: Connected to 192.168.3.52
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.auth]: Setting up new AirPlay Pair-Verify procedure with type AuthenticationType.HAP
2021-09-22 23:40:56 DEBUG [pyatv.support.http]: Sending HTTP/1.1 message: b'POST /pair-verify HTTP/1.1\r\nContent-Length: 37\r\nUser-Agent: AirPlay/320.20\r\nConnection: keep-alive\r\nX-Apple-HKP: 3\r\nContent-Type: application/octet-stream\r\n\r\n\x06\x01\x01\x03 \xb1\xc5\xd0\x1b\x7f\x96\x08\x87\x1d\x895~\xa9\x8c\xcerp\xe7\x06\x16\xe4\xe6h\xc8\xe6D,\xa1\xd2"\x03\x12'
2021-09-22 23:40:56 DEBUG [pyatv.support.http]: Received: b"HTTP/1.1 200 OK\r\nDate: Wed, 22 Sep 2021 21:40:56 GMT\r\nContent-Length: 159\r\nContent-Type: application/octet-stream\r\nServer: AirTunes/566.25.43\r\n\r\n\x05xz&\xd2S\x85\xd8\x7f\x99_E\x11\x89\x147\xe7xQ\xd7Xa\x07\xc7\x0b[\xda\xe2\x0c\x8f@\xa78Go^\xae?\xd3\xcc\xce\xd0\x1b|\x1d\x8b\x1b\x98'\x81\x18\xc0Uy\xdd\x1d\xe7\x01_[U\xdb\x15Ey\xfaQu\xc42\x05)pf\x87\xf8[\t\xfb\x03\xd8d/\x96o\x1b1\x8d\xabi\x88r\xcf}'\x04\xb7\xc3\x80\x8f-\x8e\xd0\x18d\xb4^\xcd;.\xd1v\xf5\x02\xf9\xcf\xcdID\x84_\xc9\x06\x01\x02\x03 \x92g\x90h\x96\xf7\x07^\xf1\xa8\x84\x86G\x8d\x11\x11o\xa5\x17\xe2|\x08\xbc\x9cQ\xe1\xdf\xe3\x1e<\xe3k"
2021-09-22 23:40:56 DEBUG [pyatv.support.http]: Got HTTP response: HttpResponse(protocol='HTTP', version='1.1', code=200, message='OK', headers={'date': 'Wed, 22 Sep 2021 21:40:56 GMT', 'content-length': '159', 'content-type': 'application/octet-stream', 'server': 'AirTunes/566.25.43'}, body=b"\x05xz&\xd2S\x85\xd8\x7f\x99_E\x11\x89\x147\xe7xQ\xd7Xa\x07\xc7\x0b[\xda\xe2\x0c\x8f@\xa78Go^\xae?\xd3\xcc\xce\xd0\x1b|\x1d\x8b\x1b\x98'\x81\x18\xc0Uy\xdd\x1d\xe7\x01_[U\xdb\x15Ey\xfaQu\xc42\x05)pf\x87\xf8[\t\xfb\x03\xd8d/\x96o\x1b1\x8d\xabi\x88r\xcf}'\x04\xb7\xc3\x80\x8f-\x8e\xd0\x18d\xb4^\xcd;.\xd1v\xf5\x02\xf9\xcf\xcdID\x84_\xc9\x06\x01\x02\x03 \x92g\x90h\x96\xf7\x07^\xf1\xa8\x84\x86G\x8d\x11\x11o\xa5\x17\xe2|\x08\xbc\x9cQ\xe1\xdf\xe3\x1e<\xe3k"):
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.auth.hap]: Device (Encrypted=7a26d25385d87f995f4511891437e77851d7586107c70b5bdae20c8f40a738476f5eae3fd3ccced01b7c1d8b1b98278118c05579dd1de7015f5b55db154579fa5175c4320529706687f85b09fb03d8642f966f1b318dab698872cf7d2704b7c3808f2d8ed01864b45ecd3b2ed176f502f9cfcd4944845fc9, Public=db120e921609b11ae66fb2ee2b4aa9f6adaf3e2e480a18e3d8356b29b7745f41)
2021-09-22 23:40:56 DEBUG [pyatv.support.http]: Sending HTTP/1.1 message: b'POST /pair-verify HTTP/1.1\r\nContent-Length: 125\r\nUser-Agent: AirPlay/320.20\r\nConnection: keep-alive\r\nX-Apple-HKP: 3\r\nContent-Type: application/octet-stream\r\n\r\n\x06\x01\x03\x05x\x9d\xd6?\xdf\xd9"C6U~K\x887\xf0=\x9a\x94x\xa4\xcc\x06q\x86N\xdc\x90\x93\x875\\\xad[\xa6\xf8u\xc2\xaf8#\x86\xc6AGOD^\xc3E#y2#\x1fD\x9f\xb9V\xe7+\xc1\xeaa\xe5\xc3\xa1\x85\x1f\xbd\xaf\xd5,\x14&\x98\x1c\xd1\xe6\xcf\xeb`\x92"3\xc6\xaa\xefmH\x83\xf4\xbf\xeb\x92G\xf3Q\xaabp\x19\x15\xab\xbfp\xd4\xa4\x8d\xf8\xa8\xbb\n%\xfbI9\xdc\xc8\x86\x8a\x19'
2021-09-22 23:40:56 DEBUG [pyatv.support.http]: Received: b'HTTP/1.1 200 OK\r\nDate: Wed, 22 Sep 2021 21:40:56 GMT\r\nContent-Length: 3\r\nContent-Type: application/octet-stream\r\nServer: AirTunes/566.25.43\r\n\r\n\x06\x01\x04'
2021-09-22 23:40:56 DEBUG [pyatv.support.http]: Got HTTP response: HttpResponse(protocol='HTTP', version='1.1', code=200, message='OK', headers={'date': 'Wed, 22 Sep 2021 21:40:56 GMT', 'content-length': '3', 'content-type': 'application/octet-stream', 'server': 'AirTunes/566.25.43'}, body=b'\x06\x01\x04'):
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_srp]: Keys (Input=d39eb23dfe07fe1941e55c9ec8f615cb92d5f9073627cb13eec8572febfd2958, Output=1523582205e4bca2229592ed556b1e3599ebf9861a701485ef1e6a0c81edc200)
2021-09-22 23:40:56 DEBUG [pyatv.support.http]: Sending RTSP/1.0 message: b'SETUP rtsp://192.168.3.80/4284127714 RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nContent-Length: 367\r\nCSeq: 0\r\nDACP-ID: 7F1D8C757CDCFBE9\r\nActive-Remote: 3516795589\r\nClient-Instance: 7F1D8C757CDCFBE9\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$135F4AC7-CF23-45F8-AE98-DE0C7D0E7A8CV550.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!'
2021-09-22 23:40:56 DEBUG [pyatv.support.http]: Received: b'RTSP/1.0 200 OK\r\nDate: Wed, 22 Sep 2021 21:40:56 GMT\r\nContent-Length: 59\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/566.25.43\r\nCSeq: 0\r\n\r\nbplist00\xd1\x01\x02YeventPort\x11\xc2V\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'
2021-09-22 23:40:56 DEBUG [pyatv.support.http]: Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Wed, 22 Sep 2021 21:40:56 GMT', 'content-length': '59', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/566.25.43', 'cseq': '0'}, body=b'bplist00\xd1\x01\x02YeventPort\x11\xc2V\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'):
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_srp]: Keys (Input=b9767c1d0a4fd82d73f5725fb847506953f91b51a3d834185518e1014b053c79, Output=e5b70d153b70c749b9f344c40e2e7dd0a9807f5fa0a1549ed5779f413a69939c)
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Connected to 192.168.3.52:49750
2021-09-22 23:40:56 DEBUG [pyatv.support.http]: Sending RTSP/1.0 message: b'RECORD rtsp://192.168.3.80/4284127714 RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nCSeq: 1\r\nDACP-ID: 7F1D8C757CDCFBE9\r\nActive-Remote: 3516795589\r\nClient-Instance: 7F1D8C757CDCFBE9\r\n\r\n'
2021-09-22 23:40:56 DEBUG [pyatv.support.http]: Received: b'RTSP/1.0 200 OK\r\nDate: Wed, 22 Sep 2021 21:40:56 GMT\r\nContent-Length: 0\r\nAudio-Latency: 0\r\nServer: AirTunes/566.25.43\r\nCSeq: 1\r\n\r\n'
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Received data (Data=0004424218e57313ec8b039e68ddc6be56b12edc779e70da2ad0f259d50d709afa461042d626cb47a94a284e77f6233c5b39e99a5945e2674b12dfd073029a9c43a50d60f586934b1f9b5babddbf583fa5b8e27c10e901c8910aaed9dd60cc8de2ceae18799b9043b73f8a30a156d5bb4cb7fe52b494559edb7ccfda7bbd225f4015e670e877634c9a890fa7bf41a657b793bfff265564831f292cf853eba9088ca90d4fca1cfd3a9a8272f762b85a5fb22d5443a7a7c5b0961bc68a27d51ff30883969595cf9b0a58f129a94a1ed26b243cc007cf1f923b2b41f13d41eabfdd84ff040755c801469168b72361fe679efb08b5f283273093ca172ff030577...)
2021-09-22 23:40:56 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': '1364', '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$F81B0864-E26B-40BA-BB2C-163ED5F200BE\x10\x02\xd3\x1f !"""_\x10\x15supportsInterstitials_\x10\x15supportsFPSSecureStop_\x10\x1dsupportsUIForAudioOnlyContent\t\t\t\x08\x11\x16D\tS1.1\x10\x04WAppleTV_\x10\x12192.168.3.80:50660_\x10\x11C8:69:CD:6E:43:86_\x10$91688c86-df11-4c30-a35d-20c8bf8dd54d\x08#\x00\x00\x00\x00\x00\x00\x00\x00\\1d9/Wt5fFbwIO\x11\x01\x84\x05acl=0\x18btaddr=C8:69:CD:6E:43:85\x1adeviceid=C8:69:CD:6E:43:86\x10fex=1d9/Wt5fFbwI\x1efeatures=0x5A7FDFD5,0xBC155FDE\x0cflags=0x1644(gid=C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC\x05igl=1\x06gcgl=1\x10model=AppleTV5,3\rprotovers=1.1\'pi=91688c86-df11-4c30-a35d-20c8bf8dd54d(psi=F81B0864-E26B-40BA-BB2C-163ED5F200BECpk=f096f8e419ca6a0a76d3fafed380afe4b8f54dc4888980eb25c634ed746d92c5\x11srcvers=566.25.43\x0bosvers=15.0\x04vv=2\xd434567889_\x10\x15lowLatencyAudioStream\\screenStream[audioStream\\bufferStream\x10\x00\x12\x01D\x08\x00\x12\x00\xe0\x00\x00Y566.25.43ZAppleTV5,3O\x10 \xf0\x96\xf8\xe4\x19\xcaj\nv\xd3\xfa\xfe\xd3\x80\xaf\xe4\xb8\xf5M\xc4\x88\x89\x80\xeb%\xc64\xedtm\x92\xc5_\x10\x11C8:69:CD:6E:43:86W1080p60\x13\xbc\x15_\xdeZ\x7f\xdf\xd5\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\x06\x02\x07\x02\x0b\x02\r\x02\x15\x02*\x02>\x02e\x02f\x02o\x02|\x04\x04\x04\r\x04%\x042\x04>\x04K\x04M\x04R\x04W\x04a\x04l\x04\x8f\x04\xa3\x04\xab\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\xb4')
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=4f0018e0728ce3acc5a83f4a0c662072bf6a93a6d38cad4659a967566de88a2a7da87dbba66834a19c8a6d609d04590b487ecc3aaaa2bf44f4d3d756833b0149c9097e56c3fe4a576fb79a511b1f53f64d815c337e8b91e06491636ec09d5222d9)
2021-09-22 23:40:56 DEBUG [pyatv.support.http]: Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Wed, 22 Sep 2021 21:40:56 GMT', 'content-length': '0', 'audio-latency': '0', 'server': 'AirTunes/566.25.43', 'cseq': '1'}, body=''):
2021-09-22 23:40:56 DEBUG [pyatv.support.http]: Sending RTSP/1.0 message: b'SETUP rtsp://192.168.3.80/4284127714 RTSP/1.0\r\nUser-Agent: AirPlay/540.31\r\nContent-Length: 324\r\nCSeq: 2\r\nDACP-ID: 7F1D8C757CDCFBE9\r\nActive-Remote: 3516795589\r\nClient-Instance: 7F1D8C757CDCFBE9\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$5D23BF17-E9AB-4200-BE3B-FABD3739F08B_\x10$1910A70F-DBC0-4242-AF95-115DB30604E1_\x10$B37BD97D-4CAE-4A63-BF98-03FC34D158DB\x10\x02\x14\x00\x00\x00\x00\x00\x00\x00\x00\x94/`\xf8\xcf\xb2\x9aF\x10\x82\t\x00\x08\x00\x0b\x00\x13\x00\x15\x00$\x00.\x00=\x00H\x00T\x00Y\x00^\x00u\x00\x9c\x00\xc3\x00\xea\x00\xec\x00\xfd\x00\xff\x00\x00\x00\x00\x00\x00\x02\x01\x00\x00\x00\x00\x00\x00\x00\x12\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x01\x00'
2021-09-22 23:40:56 DEBUG [pyatv.support.http]: Received: b'RTSP/1.0 200 OK\r\nDate: Wed, 22 Sep 2021 21:40:56 GMT\r\nContent-Length: 100\r\nContent-Type: application/x-apple-binary-plist\r\nServer: AirTunes/566.25.43\r\nCSeq: 2\r\n\r\nbplist00\xd1\x01\x02Wstreams\xa1\x03\xd3\x04\x05\x06\x07\x08\tTtypeXstreamIDXdataPort\x10\x82\x10\x01\x11\xc2W\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:'
2021-09-22 23:40:56 DEBUG [pyatv.support.http]: Got RTSP response: HttpResponse(protocol='RTSP', version='1.0', code=200, message='OK', headers={'date': 'Wed, 22 Sep 2021 21:40:56 GMT', 'content-length': '100', 'content-type': 'application/x-apple-binary-plist', 'server': 'AirTunes/566.25.43', 'cseq': '2'}, body=b'bplist00\xd1\x01\x02Wstreams\xa1\x03\xd3\x04\x05\x06\x07\x08\tTtypeXstreamIDXdataPort\x10\x82\x10\x01\x11\xc2W\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:'):
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_srp]: Keys (Input=b99aa492afd1d323540e4f6c79de758fe1b7831689cee47e5be298565d852e97, Output=a5ca65ec21f900443ff3d6b4c41209348ff51b73100bff47151d3efc3c364e59)
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Connected to 192.168.3.52:49751
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=3c012962ef682d57b5eb70ba942f43e6c470fb1db8af6850810cde54517a339e9d3bfa58815372f7bf333b3d9d9715efebc75a5a8865e94f04701ca28e0a432caeee962e3232dcbe0809f355f7368a8c8f29cae1063df545477f39f5e9a8ee88277f7d8abf726e6d6856bc40eef0e50548742dbdc64d8fd09b21af7ca965810169c8a805a8f34716c729112f4ceff43ad2fdfcde53236e16bb4f189534f87f5c29c65edbde5664815dddfdb6738a44559aaa015085798efbdaff561a47b8339a074d5a693b3e7d41abd9c03e16ec2095c4c83db9a00162eb524e4891c22b5c920d7a5afd8c26bb0d9a4354e1e8b12118f3a8bdd71458adf252ea585238e67...)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: >> Send: Protobuf: type: DEVICE_INFO_MESSAGE
identifier: "254ECC44-806D-45CC-AEE1-1A95C1DE91F4"
errorCode: NoError
[deviceInfoMessage] {
  uniqueIdentifier: "7d3005b8-0a59-4681-8982-3cf1c30a9547"
  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: "B073028A-E83F-4181-B910-F9C49C843D24"
2021-09-22 23:40:56 DEBUG [pyatv.core.protocol]: Starting heartbeat loop (AirPlay:192.168.3.52)
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Received data (Data=20001f22ae7565ce462c83dfb60f29fbabc0f6a3932535f6955698d54598e2567352b26f286ab637f62c89436aa5b489c7962a0000d6b9ae660d142fe002b8cc1764ed74c0ac15e33fb5d47a1322f0eaa5e1b8563e71e0b3eb0a46ec379f120130de3407bee7ac77bc572d0379ca)
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Received data (Data=20003a92385c7417ed37a600031f66b1bf67f0450a80d76e2278bd0f36e26ee45b7853ec90c3b18071fe0b1d487772fcf3a4db02b79575555a4b5b29ff828deb2f1157b78f4221262262748ce35f8f8a3092898360017d6c0f633db78f15e0b151f7679e81d70e41b10493d0f5143cfe97a67d36fa65be75864b0d121cfb624f77ca13f61b1d147709b9639723fcad9ad69e6d19cec30f903b8aa3976f0a52bb904202b1660acc074721c21500aa1dcbc90c0ec8637672c8336fd535088cd7a87e608019f1a057be6a79a94f0ef2d1c4a7329db7b563e4d2c559d59e4ddb5a5935a151e85f1aed104c7297f5f61527ab356c2f86392c8cda93d907fb0c127...)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: DEVICE_INFO_MESSAGE
identifier: "254ECC44-806D-45CC-AEE1-1A95C1DE91F4"
[deviceInfoMessage] {
  uniqueIdentifier: "8CD254F3-CA9C-4B4C-AEBD-113FC050DD45"
  name: "AppleTV"
  localizedModelName: "Apple\302\240TV"
  systemBuildVersion: "19J346"
  applicationBundleIdentifier: "com.apple.mediaremoted"
  protocolVersion: 1
  lastSupportedMessageType: 111
  supportsSystemPairing: true
  allowsPairing: true
  systemMediaApplication: "com.apple.TVMusic"
  supportsACL: true
  supportsSharedQueue: true
  supportsExtendedMotion: true
  sharedQueueVersion: 3
  deviceUID: "F81B0864-E26B-40BA-BB2C-163ED5F200BE"
  managedConfigDeviceID: "c8:69:cd:6e:43:86"
  deviceClass: AppleTV
  logicalDeviceCount: 1
  isProxyGroupPlayer: true
  groupUID: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
  groupedDevices {
    name: "TV"
    localizedModelName: "AirPort10,115"
    deviceUID: "00:F7:6F:D4:4B:0A"
    groupUID: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
    clusterType: 0
    isClusterAware: false
    modelID: "AirPort10,115"
    42: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
  }
  isGroupLeader: true
  isAirplayActive: false
  systemPodcastApplication: "com.apple.podcasts"
  enderDefaultGroupUID: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
  airplayReceivers: "TVAirPlay"
  clusterType: 0
  isClusterAware: true
  modelID: "AppleTV5,3"
  40: 0
  41: "577E1BCA-2D9B-41C2-A8F8-C515CE8072D4"
  42: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
  43: "com.apple.TVBooks"
}
uniqueIdentifier: "356B916F-76B4-4E8B-8DF3-18EA46DF113F"
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=200004ede87798f0d794b2789a8fc93d8f2b39dcc84c9575d6ba1bd466e62e5cea3d0b6768129f2d382c6e568fee460d7602)
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=9300e52ef3e83b76179c7a54450b51517bbd211f86cb4fc0c305dffc30cb57eaabf89f3de2f12300a4fbf4b5b1492bcc0c4600177fe2db86d20b33ceac479953ab491c0a1ab04c74b114fb80731a8769e3ade44608ac509a96f5da2cb1de18816ba5179bf390e11db69a4d99b97c0df248e0245ccc4bbf3f706779d92b305e076d8f34815daf5c18677a42f545d31c4d10006c73224616ebf99550f2018bcee8b7fe2bc1dd)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: >> Send: Protobuf: type: SET_CONNECTION_STATE_MESSAGE
errorCode: NoError
[setConnectionStateMessage] {
  state: Connected
}
uniqueIdentifier: "A5A454A6-E08E-48DB-B90E-85C8FFD483BE"
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=c1000598514c67c44adcdb2c17839a71a3805338e2ac6fc3ca3c3fa45140d7499207f60967de6336725697292a27069f2efd61fa8d15c5a4cb53d111b60467c2ed5de9b196bc2fa7154ac1b74d67400016c8cbeaf74ea4942c4229d5c96ed10c828aa84c130f4e807f1e248322dca1989db2492f13b5f529a5bbbf1949cb25b8a21ca268ed0ba79d7b6458bc0db81d489f59ff1fea28a3e0c861a426ce3ebf7230f60edace15b8b072a64c35932a66adb58e7ecc5c281612df6059971fa4f9e07489be46e22daf3d8745a2dba336a06c136e81)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: >> Send: Protobuf: type: CLIENT_UPDATES_CONFIG_MESSAGE
identifier: "B8826E7E-1015-48A2-ABC2-D717958A57E8"
errorCode: NoError
[clientUpdatesConfigMessage] {
  artworkUpdates: true
  nowPlayingUpdates: false
  volumeUpdates: true
  keyboardUpdates: true
  outputDeviceUpdates: true
}
uniqueIdentifier: "91DE2908-4507-4C2D-89A4-E2544CAD2A41"
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2000c96119599f4694a1abed9c391ac51f47e9a69b07160b7f45ab086d8603d2567ba24ba76011f49ddc6ab32a88a5ab9ef42a006a78ac58332aa47ded568d903374c4475b095a328f5e7e61c67e40d25f72368f198b29e51cf15fb34472afc0ba849c2d8441513eb1e639366fe7)
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Received data (Data=20008d4d22c651ef970601e7f3930c05d1ee3ce2e74364a3dfb87e394d80b8c8bd08ea3756694eab694a948849cb6bebb0442a00ec84c5fbfb7e545e4877d62101304f3c7f1d3d7491035886908f65ff1f2b1f53bb8fb2f962246f97213c0f069c2f56d8c6401c2e6e3f9e86dc4e)
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2000924e970b462849014df5f58e5244e84aa9691d1b38572eb7128e7e5e828dc4fe95a51d98d89b5654872dd3af2db1b0a27100dc27c62ce1a5bae076970295b7f83133b2789e469324f1e4ce6cc1e64fda0679da31454b44b0e7ee17a9b9e9d8ac7c0693d66225ae0a7ab20a1f27a3a58510730349db5cb95e0e90b66561d3c98541a298f2c67711118b6e34d6e4ae60c54797c46b210c7c5aad92ac03d30dc0c23e74ec25db45255e7da76b414cdc2f1ca58c73)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: REGISTER_FOR_GAME_CONTROLLER_EVENTS_MESSAGE
[registerForGameControllerEventsMessage] {
  1: 6
}
uniqueIdentifier: "9E1FA848-F3D2-423F-ABA1-4C9C3EBF7D37"
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=2000dabf9c5a10ae7ed3a7dfccf6fd8c2a825f93e2cdd591fd5166590dfad4d35fa067d0f8c0d951bb035ca86bbbae3df4e1)
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Received data (Data=20005b2199d9020ae99397d5be22ba132c6e915484f0ba843222806b44aa4b053fd7f123a506cc0ffc044e1f5218e817a570)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.channels]: Not enough data on data channel (has 32, expects 4332)
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Received data (Data=cc10dec989149386b243ec51c159d847bf26e7b1d07ee36b5e7643096101f3dce5a067305cbbbee9a88105962d2bb2910eba8b00ab99c519ff65d937c5e649c706d454908a4690d1854226f00f9fc1d52bc27b3034f3f7d301733afff17d3b9e14f88b937553a8a6ac6efb29f975aaecf77df1e6c9704a261cb12f2689aafcfa9f2247370d79c1d364d7f9dc0c2ec7cba619d99dfba4d6e6493cdbbb42aad364362d36a762dbbf489dfde3294bea577b1dd79e90be6b66dd4dd66d74648d5cf6e5fc7b92f62207d103c7d452a3086bdd9489ef2a374b589893e5ff0e866d26f678e63ccdc39ff39ce4659aedb2de67b3549f85d9f805819a3380933d48637...)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: UPDATE_OUTPUT_DEVICE_MESSAGE
[updateOutputDeviceMessage] {
  outputDevices {
    name: "TV"
    uniqueIdentifier: "00:F7:6F:D4:4B:0A"
    groupID: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
    modelID: "AirPort10,115"
    macAddress: "\000\367o\324K\n"
    canAccessRemoteAssets: false
    isRemoteControllable: false
    isGroupLeader: false
    isGroupable: true
    deviceType: AirPlay
    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: false
    supportsExternalScreen: false
    requiresAuthorization: false
    sourceInfo {
      routingContextUID: "577E1BCA-2D9B-41C2-A8F8-C515CE8072D4"
      multipleBuiltInDevices: false
    }
    isDeviceGroupable: true
    canRelayCommunicationChannel: true
    isProxyGroupPlayer: false
    canAccessAppleMusic: false
    canAccessiCloudMusicLibrary: false
    groupContainsGroupLeader: true
    supportsBufferedAirPlay: true
    canPlayEncryptedProgressiveDownloadAssets: false
    canFetchMediaDataFromSender: false
    resentsOptimizedUserInterfaceWhenPlayingFetchedAudioOnlyAssets: false
    isAirPlayReceiverSessionActive: false
    parentGroupContainsDiscoverableLeader: false
    isAddedToHomeKit: false
    volumeCapabilities: 2
    supportsHAP: false
    usingJSONProtocol: false
    clusterType: 0
    primaryUID: "00:F7:6F:D4:4B:0A"
    configuredClusterSize: 0
    producesLowFidelityAudio: false
    45: 0
    47: "AVOutputDeviceBluetoothListeningModeNormal"
    48: 0
    50: -1
    51: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
    52: 0
  }
  clusterAwareOutputDevices {
    name: "TV"
    uniqueIdentifier: "00:F7:6F:D4:4B:0A"
    groupID: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
    modelID: "AirPort10,115"
    macAddress: "\000\367o\324K\n"
    canAccessRemoteAssets: false
    isRemoteControllable: false
    isGroupLeader: false
    isGroupable: true
    deviceType: AirPlay
    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: false
    supportsExternalScreen: false
    requiresAuthorization: false
    sourceInfo {
      routingContextUID: "577E1BCA-2D9B-41C2-A8F8-C515CE8072D4"
      multipleBuiltInDevices: false
    }
    isDeviceGroupable: true
    canRelayCommunicationChannel: true
    isProxyGroupPlayer: false
    canAccessAppleMusic: false
    canAccessiCloudMusicLibrary: false
    groupContainsGroupLeader: true
    supportsBufferedAirPlay: true
    canPlayEncryptedProgressiveDownloadAssets: false
    canFetchMediaDataFromSender: false
    resentsOptimizedUserInterfaceWhenPlayingFetchedAudioOnlyAssets: false
    isAirPlayReceiverSessionActive: false
    parentGroupContainsDiscoverableLeader: false
    isAddedToHomeKit: false
    volumeCapabilities: 2
    supportsHAP: false
    usingJSONProtocol: false
    clusterType: 0
    primaryUID: "00:F7:6F:D4:4B:0A"
    configuredClusterSize: 0
    producesLowFidelityAudio: false
    45: 0
    47: "AVOutputDeviceBluetoothListeningModeNormal"
    48: 0
    50: -1
    51: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
    52: 0
  }
}
uniqueIdentifier: "6CC62C4C-D070-49BB-A27A-B22F5F504B83"
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_DEFAULT_SUPPORTED_COMMANDS_MESSAGE
[setDefaultSupportedCommandsMessage] {
  supportedCommands {
    supportedCommands {
      command: Play
      enabled: true
    }
    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: SetPlaybackSession
    }
    supportedCommands {
      command: PreloadedPlaybackSession
    }
  }
  displayID: "com.apple.TVMusic"
  playbackQueueCapabilities {
  }
  playerPath {
    client {
      bundleIdentifier: "com.apple.TVMusic"
    }
  }
}
uniqueIdentifier: "24A724FB-4945-45F8-94F7-85B06B35B145"
2021-09-22 23:40:56 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 72 (SetDefaultSupportedCommandsMessage) to Listener(func=<bound method PlayerStateManager._handle_set_default_supported_commands of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x10a47fd90>>, data=None)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_DEFAULT_SUPPORTED_COMMANDS_MESSAGE
[setDefaultSupportedCommandsMessage] {
  supportedCommands {
    supportedCommands {
      command: Play
      enabled: true
    }
    supportedCommands {
      command: SetPlaybackQueue
      enabled: true
      supportedPlaybackQueueTypes: 3
      supportedPlaybackQueueTypes: 6
      supportedPlaybackQueueTypes: 2
      supportedPlaybackQueueTypes: 5
      supportedPlaybackQueueTypes: 1
    }
    supportedCommands {
      command: SetPlaybackSession
      enabled: true
      supportedPlaybackSessionTypes: "com.apple.podcasts.MTPlaybackQueueController.GenericQueue"
      currentPlaybackSessionTypes: "com.apple.podcasts.MTPlaybackQueueController.GenericQueue"
    }
  }
  displayID: "com.apple.podcasts"
  playbackQueueCapabilities {
  }
  playerPath {
    client {
      bundleIdentifier: "com.apple.podcasts"
    }
  }
}
uniqueIdentifier: "044F6C84-8C59-4C4A-BC26-62A8201CF97E"
2021-09-22 23:40:56 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 72 (SetDefaultSupportedCommandsMessage) to Listener(func=<bound method PlayerStateManager._handle_set_default_supported_commands of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x10a47fd90>>, data=None)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: ORIGIN_CLIENT_PROPERTIES_MESSAGE
uniqueIdentifier: "9E02A7C4-C3C9-4624-B335-0F9246D7AF91"
[originClientPropertiesMessage] {
  lastPlayingTimestamp: 654039656.748716
}
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_NOW_PLAYING_CLIENT_MESSAGE
[setNowPlayingClientMessage] {
  client {
    processIdentifier: 263
    bundleIdentifier: "com.simpleiptv.client"
  }
}
uniqueIdentifier: "142E3A5B-2360-4ADD-BFFE-A77781C7A123"
2021-09-22 23:40:56 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 46 (SetNowPlayingClientMessage) to Listener(func=<bound method PlayerStateManager._handle_set_now_playing_client of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x10a47fd90>>, data=None)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: UPDATE_CLIENT_MESSAGE
[updateClientMessage] {
  client {
    processIdentifier: 263
    bundleIdentifier: "com.simpleiptv.client"
    processUserIdentifier: 501
    displayName: "iPlayTV"
  }
}
uniqueIdentifier: "9790CBA5-3119-4839-9AE0-C580D1AC244A"
2021-09-22 23:40:56 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 55 (UpdateClientMessage) to Listener(func=<bound method PlayerStateManager._handle_update_client of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x10a47fd90>>, data=None)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_STATE_MESSAGE
[setStateMessage] {
  supportedCommands {
    supportedCommands {
      command: Play
      enabled: true
    }
    supportedCommands {
      command: Pause
      enabled: true
    }
    supportedCommands {
      command: TogglePlayPause
      enabled: true
    }
    supportedCommands {
      command: NextTrack
      enabled: true
    }
    supportedCommands {
      command: PreviousTrack
      enabled: true
    }
  }
  displayName: "iPlayTV"
  playbackState: Playing
  playbackQueueCapabilities {
  }
  playerPath {
    origin {
      displayName: "Apple\302\240TV"
      identifier: 1280262988
    }
    client {
      processIdentifier: 263
      bundleIdentifier: "com.simpleiptv.client"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  playbackStateTimestamp: 654032520.880378
}
uniqueIdentifier: "CC09EEA3-5149-4C9A-BAF6-645CECCAED2D"
2021-09-22 23:40:56 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 4 (SetStateMessage) to Listener(func=<bound method PlayerStateManager._handle_set_state of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x10a47fd90>>, data=None)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: PLAYER_CLIENT_PROPERTIES_MESSAGE
uniqueIdentifier: "DBB56691-9848-4EDB-ADC9-14533EFEA9F6"
[playerClientPropertiesMessage] {
  playerPath {
    origin {
      displayName: "Apple\302\240TV"
      identifier: 1280262988
      5: 1
    }
    client {
      processIdentifier: 263
      bundleIdentifier: "com.simpleiptv.client"
      processUserIdentifier: 501
      displayName: "iPlayTV"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  lastPlayingTimestamp: 654032463.97727
}
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: UPDATE_CLIENT_MESSAGE
[updateClientMessage] {
  client {
    processIdentifier: 136
    bundleIdentifier: "com.apple.TVAirPlay"
    processUserIdentifier: 501
    displayName: "AirPlay"
  }
}
uniqueIdentifier: "E55A9B20-EC22-4225-A5BB-34273F0855AF"
2021-09-22 23:40:56 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 55 (UpdateClientMessage) to Listener(func=<bound method PlayerStateManager._handle_update_client of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x10a47fd90>>, data=None)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_STATE_MESSAGE
[setStateMessage] {
  supportedCommands {
    supportedCommands {
      command: Play
      enabled: true
    }
    supportedCommands {
      command: Pause
      enabled: true
    }
    supportedCommands {
      command: TogglePlayPause
      enabled: true
    }
    supportedCommands {
      command: Stop
      enabled: true
    }
    supportedCommands {
      command: NextTrack
      enabled: true
    }
    supportedCommands {
      command: PreviousTrack
      enabled: true
    }
    supportedCommands {
      command: BeginFastForward
      enabled: true
    }
    supportedCommands {
      command: EndFastForward
      enabled: true
    }
    supportedCommands {
      command: BeginRewind
      enabled: true
    }
    supportedCommands {
      command: EndRewind
      enabled: true
    }
    supportedCommands {
      command: AdvanceRepeatMode
      enabled: true
    }
    supportedCommands {
      command: AdvanceShuffleMode
      enabled: true
    }
    supportedCommands {
      command: SeekToPlaybackPosition
      enabled: true
    }
  }
  displayName: "AirPlay"
  playbackState: Paused
  playbackQueueCapabilities {
  }
  playerPath {
    origin {
      displayName: "Apple\302\240TV"
      identifier: 1280262988
    }
    client {
      processIdentifier: 136
      bundleIdentifier: "com.apple.TVAirPlay"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  playbackStateTimestamp: 654001339.140793
}
uniqueIdentifier: "DEE83342-866F-40D3-8F51-AB00E4B95AAD"
2021-09-22 23:40:56 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 4 (SetStateMessage) to Listener(func=<bound method PlayerStateManager._handle_set_state of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x10a47fd90>>, data=None)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: PLAYER_CLIENT_PROPERTIES_MESSAGE
uniqueIdentifier: "C4047131-B026-4AAA-9B8D-1AF4749C2421"
[playerClientPropertiesMessage] {
  playerPath {
    origin {
      displayName: "Apple\302\240TV"
      identifier: 1280262988
      5: 1
    }
    client {
      processIdentifier: 136
      bundleIdentifier: "com.apple.TVAirPlay"
      processUserIdentifier: 501
      displayName: "AirPlay"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  lastPlayingTimestamp: -63114076800.0
}
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: UPDATE_CLIENT_MESSAGE
[updateClientMessage] {
  client {
    processIdentifier: 814
    bundleIdentifier: "com.plexapp.plex"
    processUserIdentifier: 501
    displayName: "Plex"
  }
}
uniqueIdentifier: "000950FD-8B53-4CFB-A677-50623112F9CF"
2021-09-22 23:40:56 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 55 (UpdateClientMessage) to Listener(func=<bound method PlayerStateManager._handle_update_client of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x10a47fd90>>, data=None)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: SET_STATE_MESSAGE
[setStateMessage] {
  playbackQueue {
    location: 0
    contentItems {
      identifier: "19CEAF88-F05B-4AC7-A010-B668A1EBE192"
      metadata {
        title: "Tutti parlano di Jamie"
        trackArtistName: "Everybody\'s Talking About Jamie"
        duration: 6945.888
        artworkAvailable: true
        artworkMIMEType: "image/jpeg"
        elapsedTime: 93.292
        playbackRate: 0.0
        defaultPlaybackRate: 1.0
        mediaType: Video
        mediaSubType: UnknownMediaSubType
        nowPlayingInfoData: "bplist00\324\001\002\003\004\005\006\007\nX$versionY$archiverT$topX$objects\022\000\001\206\240_\020\017NSKeyedArchive...
        elapsedTimeTimestamp: 654012194.726288
        inferredTimestamp: 654012194.727554
        artworkIdentifier: "d19146f3e92683a6"
      }
    }
  }
  displayName: "Plex"
  playbackState: Paused
  playbackQueueCapabilities {
  }
  playerPath {
    origin {
      displayName: "Apple\302\240TV"
      identifier: 1280262988
    }
    client {
      processIdentifier: 814
      bundleIdentifier: "com.plexapp.plex"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  playbackStateTimestamp: 654012194.495096
}
uniqueIdentifier: "0C3338A7-5CD6-40C7-822A-E0F2607BB003"
2021-09-22 23:40:56 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 4 (SetStateMessage) to Listener(func=<bound method PlayerStateManager._handle_set_state of <pyatv.protocols.mrp.player_state.PlayerStateManager object at 0x10a47fd90>>, data=None)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: PLAYER_CLIENT_PROPERTIES_MESSAGE
uniqueIdentifier: "BC030BDB-8573-4009-88CE-CA10A19A25F3"
[playerClientPropertiesMessage] {
  playerPath {
    origin {
      displayName: "Apple\302\240TV"
      identifier: 1280262988
      5: 1
    }
    client {
      processIdentifier: 814
      bundleIdentifier: "com.plexapp.plex"
      processUserIdentifier: 501
      displayName: "Plex"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
      6: 0
    }
  }
  lastPlayingTimestamp: 654012194.495648
}
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: VOLUME_CONTROL_CAPABILITIES_DID_CHANGE_MESSAGE
[volumeControlCapabilitiesDidChangeMessage] {
  capabilities {
    volumeControlAvailable: true
    volumeCapabilities: Absolute
  }
  endpointUID: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
  outputDeviceUID: "00:F7:6F:D4:4B:0A"
}
uniqueIdentifier: "21CC5882-1BA1-4F23-9166-4AA87E424219"
2021-09-22 23:40:56 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 64 (VolumeControlCapabilitiesDidChangeMessage) to Listener(func=<bound method MrpAudio._volume_control_changed of <pyatv.protocols.mrp.MrpAudio object at 0x10a498250>>, data=None)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: VOLUME_DID_CHANGE_MESSAGE
[volumeDidChangeMessage] {
  volume: 0.51796407
  endpointUID: "C87AD4D2-8E40-49A6-8C0F-DF0D3FE982BC"
  outputDeviceUID: "00:F7:6F:D4:4B:0A"
}
uniqueIdentifier: "340F08D9-5DB8-4B7A-86B5-6ECCE39F2677"
2021-09-22 23:40:56 DEBUG [pyatv.protocols.mrp.protocol]: Dispatching message with type 52 (VolumeDidChangeMessage) to Listener(func=<bound method MrpAudio._volume_did_change of <pyatv.protocols.mrp.MrpAudio object at 0x10a498250>>, data=None)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: UNKNOWN_MESSAGE
identifier: "B8826E7E-1015-48A2-ABC2-D717958A57E8"
uniqueIdentifier: "074CA9A5-A6E2-45CA-BC1C-A9CCF2523C9A"
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=20009abfc6fe14854a09e460a863190b273045354de052332018e79705e948d7a050aa9ac70cce344d8b5940855873a0fad7)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.mrp.player_state]: Active client is now com.simpleiptv.client
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=b40073cda6d7446f8619d6ca2d4dbc41b8cd7c6126583dd35812c9f6abb1404e578e694687b0cd90dac4a0d74d8b738faa4a5c58df3481d282ed3f069ed99a1efd624c9faf90aac9b9614313212f30bf84d7263c0d974a60310c490b78725d9910809b4e2c1a6d32fe79ce0a53321243ec5e7fc15615b45636b720e2e7469dafc9c2cdeef651794b8cd7bcc80dcc9043f9a3758fb05924d1b46502794c1365fc5687f481a4556e5faddca6d4b827dac4e7423e2b2ae01f62061affcafacdeba09ee585cb9916)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: >> Send: Protobuf: type: GET_KEYBOARD_SESSION_MESSAGE
identifier: "5C853160-A681-46E0-914D-16DACCBC9786"
errorCode: NoError
uniqueIdentifier: "DBB9654A-7D20-4133-A5B1-E1FF52FC4DE7"
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2000a81049fd5dadfcc05055b3e43a089cdaf836edd1397ab30e352f736a45226e7b69c12edbc1fd54582d7cf09d2300808e)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.channels]: Not enough data on data channel (has 32, expects 74)
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2a00fa54d6723955d1ee02b2aa06139a45be9014aae637a52512a3bdaa56a89b227a039a17026b3345dc3fd459a4f0b5032cffbb5a2b29c0be4dadaf)
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Received data (Data=20001fa619f29d0a739d0336c3b5f93f1b59c198109865e3c108424941baeb33fe689b1ad5d4a584f2f539c44d7e8962142e)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.channels]: Not enough data on data channel (has 32, expects 201)
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Received data (Data=a900e7af2c5437beb6d4394a34cf1a894bda0a78182f35767a06d0890746318fb791eade3726bf6d4f1108442e33b54decd0fc7c61af18936fcc5a8db94a7686eaa158d620b8de82384e51f0f5248ad9555d482aa43821860f92553f2b9d3227e71a59f2d1965243598cf6519ab54e33f53ee7d33f4de6631057f608117ae05db261d15104a2715690e983c7e53acf134a25f2ae33c9c63fbc6ec0f6f3f887f65a904dbe04405873b76bdb8064df90c6427b0aa728520ca5086846)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: KEYBOARD_MESSAGE
identifier: "5C853160-A681-46E0-914D-16DACCBC9786"
[keyboardMessage] {
  state: Unknown
  attributes {
    inputTraits {
      autocapitalizationType: None
      keyboardType: Default
      returnKeyType: Default
      enablesReturnKeyAutomatically: false
      secureTextEntry: false
      validTextRangeLocation: 0
      validTextRangeLength: 0
    }
  }
}
uniqueIdentifier: "06348585-7A19-4FC9-BB62-73C62917CB4E"
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=200080e6b3412d7f8a509af6fadec0c9a13795907f42d9c15ed17d15af783655e7874a3e0eb178b703fce958b7aa7e1f5593)
2021-09-22 23:40:56 DEBUG [pyatv.core.facade]: Connecting to protocol: Protocol.Companion
2021-09-22 23:40:56 DEBUG [pyatv.core.facade]: Protocol Protocol.MRP already set up, ignoring
2021-09-22 23:40:56 DEBUG [pyatv.core.facade]: Connecting to protocol: Protocol.RAOP
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=e200c12b5d123229295da2522d861ef6152c1c58ba01e64fc2bd9389a4168b839433f4666534f98940488ac464237e46d73fa17dd6ad0261e39814af6b721db9c4ae6eac7333f2ea2440f40cb188c362884d5ea589afa984c34fcbeb62b320b83779186e92a42613e506ccb66732c3197c116cd41e0d7beab9ba6a2f80aa9499ff42e27cbfc297dba0d90918facd37643b26f8eb0a11d159ac9e1d204e5de6da7383d0d8c45dbac66233b6b0f68d7070f840ce2a64d756094a706d67fda77960984c1d5e55382b230e66a73ac4dc906d46600da8b2a177b0e10fd360bf9fec6a1dcc948acb858f029c8d78dda4fab773f091d154)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: >> Send: Protobuf: type: SET_VOLUME_MESSAGE
identifier: "73D662AB-FB7F-4D78-9886-B627BF7B860D"
errorCode: NoError
[setVolumeMessage] {
  volume: 0.1
  outputDeviceUID: "F81B0864-E26B-40BA-BB2C-163ED5F200BE"
}
uniqueIdentifier: "0D18C940-0610-4FAB-8392-BB16A9FB3284"
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Received data (Data=2000f7f441342a4085072401473c447a39555645e26d9ba09ae1f4c0d71240430e2298d4459385dacf43385b1e686f75c50c2a00968eb4b37ee890ba5e66db8eb37633f89c7f25baba89290feb538b7a3182b6cd5b43fa853977c69142b742df9eccb6d0c9d713478d58b561e702)
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Received data (Data=20006b72c18baf41bcd84d10dce04a87c10190d8eece1ffa20711a8c7eb5f7e7f39cad2729ff1aa4a68de1e9edce437f3e8d0d015d8c0484acc001ff525055a330df37e454a1c746076992cab7a8805e45e1d205407917c617242514ee0c45c9d3cbcf60a34ac4470c358ae9882fe4a55a632fb1e9d5c5d6872a0cd3e8219b570bd4b2d8eba48aad72e3810ac19b3f36751fbd1e9ba531c5e064198052b4482f4b3282f9927567474d6ed3d86b7fe7b8b29e4d0666aaa86637aea5587ff8f9d010cf4e96b73cd647061509fc80ef2685163ca062e03d731486df9c237073cf2196497a26d4d185386c3fd135f3def6e58808f2bddaa7804ca7add889ba90b...)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: << Receive: Protobuf: type: UNKNOWN_MESSAGE
identifier: "73D662AB-FB7F-4D78-9886-B627BF7B860D"
errorCode: CouldNotFindTheGivenOutputdevice
errorDescription: "Could not find the given outputDevice"
uniqueIdentifier: "7B8D0EB0-59CE-40EB-9119-DEA86D707C0B"
93 {
  1: "kMRMediaRemoteFrameworkErrorDomain"
  2: 39
  3: "Could not find the given outputDevice"
}
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Sending data (Encrypted=20004a2a543b6b79d0bd3f135021b6d43ae9e319bf82cbf9b86d6ad09b78e072eb69dad3a2dda5acf1d880601baf4ee97c73)
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: Closing connection
2021-09-22 23:40:56 DEBUG [pyatv.scripts.atvremote]: Waiting for 1 remaining tasks
2021-09-22 23:40:56 DEBUG [pyatv.protocols.airplay.mrp_connection]: Disconnected from device: None
2021-09-22 23:40:56 DEBUG [pyatv.scripts.atvremote]: Connection was closed properly
2021-09-22 23:40:56 DEBUG [pyatv.core.protocol]: Stopping heartbeat loop at 1 (AirPlay:192.168.3.52)
2021-09-22 23:40:56 DEBUG [pyatv.support.http]: Connection closed
2021-09-22 23:40:56 DEBUG [pyatv.auth.hap_channel]: Connection was lost to remote
postlund commented 3 years ago

@martinorob Right, you have grouped players. I have not played around with that, so I'm not surprised it doesn't work. I'll try to come up with a fix for it.

martinorob commented 3 years ago

Thank you! I don’t know what are grouped player and if i can un-group it

postlund commented 3 years ago

You can group several AirPlay speakers together and output the same audio stream (in sync) to all of them for instance. Looks like your Apple TV is grouped with an AirPort Express named "TV", so I guess you have that set up somehow? You can change that by long-pressing the TV button and pick the audio output symbol.

postlund commented 3 years ago

@martinorob I have opened #1327, can you verify if that works?

martinorob commented 3 years ago

@martinorob I have opened #1327, can you verify if that works?

Thanks @postlund, are this change applied on the 0.9.1? If yes, nothing changed.. if no, how I can install this? Thank you

postlund commented 3 years ago

@martinorob I intentionally left it out of 0.9.1 before having it verified. You have some installation instructions here:

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

I can also trigger a docker image build, in case you can run docker containers?

martinorob commented 3 years ago

YEEEEEEEEEEEE it works like a charm!

postlund commented 3 years ago

Great! I'll merge the PR then. I'll give it a few days in case anything else comes up, otherwise I'll just make a new minor release with the change.

postlund commented 3 years ago

I have pushed the first version of the integration to:

https://github.com/postlund/hass-atv-beta

Available via HACS soon. Be sure to read the instructions before upgrading!

coolguymatt commented 3 years ago

I set up the beta integration and it is working very well, but it keeps discovering the same Apple TV over and over again. Example:

image

postlund commented 3 years ago

Huh, that's... interesting. That would somehow suggest that one or more unique identifiers are changing somehow. If I prepare a branch with additional debug logs, can you try that and send the logs to me? Would help debugging a lot.

postlund commented 3 years ago

Or maybe you can just add a log point yourself in config_flow.py (line 143) so it looks like this:

        # Extract unique identifier from service
        self.target_device = get_unique_id(service_type, name, properties)
        _LOGGER.error("Info: %s, identifier: %s", discovery_info, self.target_device)
        if self.target_device is None:
            return self.async_abort(reason="unknown

Sending the log by email to me is preferred as there will be some identifiers unnecessary to share with everyone when we can avoid it.