Connection closes instantly with tvOS 18.4 (companion protocol)
Describe the bug
I have 2 AppleTV boxes : one on tvOS 18.3 and another with 18.4 beta. The one with 18.4 beta raises a connection lost exception right after the connection (the other one works fine). I paired the device with 2 protocols : companion and airplay. The disconnection is raised when using the companion protocol, (airplay is fine). Edit : tested with python 3.12 and 3.13, on windows and a Ubuntu docker instance.
See the sample code below to reproduce it with the following steps
- Pair the Apple TV device with companion protocol using tvOS 18.4
- Connect to it with pyatv
- Subscribe to connection lost/closed events by implementing the
DeviceListenerinterface - The client will receive a lost connection event a few milliseconds later
class AppleTvClient(DeviceListener):
async def start_client():
self._atv = AppleTv(device=config, loop=_LOOP)
await self._atv.connect()
self._atv.listener = self
def connection_lost(self, _exception) -> None:
_LOG.exception("[%s] Lost connection %s", self.log_id, _exception)
def connection_closed(self) -> None:
_LOG.debug("[%s] Connection closed!", self.log_id)
### Error log
Extraction of logs (full logs attached), see the `pyatv.protocols.companion.connection:Connection lost to remote device: None`
```log
DEBUG:__main__:[Salon Apple TV] Updating app list
DEBUG:pyatv.protocols.companion.protocol:Exchange OPACK: {'_i': 'FetchLaunchableApplicationsEvent', '_t': 2, '_c': {}, '_x': 20683}
DEBUG:pyatv.protocols.companion.protocol:Send OPACK: {'_i': 'FetchLaunchableApplicationsEvent', '_t': 2, '_c': {}, '_x': 20683}
DEBUG:pyatv.protocols.companion.connection:>> Send data (Data=e4425f696046657463684c61756e636861626c654170706c69636174696f6e734576656e74425f740a425f63e0425f7831cb50, FrameType=08)
DEBUG:pyatv.protocols.companion.connection:>> Send (Encrypted=9321a4c7e7672125d7db2a4e7e1e1085ad6c605d165f5368a476b89b75d326b14f4a7d4a3b2221343d9cbee4ef0d264de86dcda9f2b08497c63b6509afaf1fd60bc865, Header=08000043)
DEBUG:pyatv.protocols.companion.connection:Received data (Data=080003eb9c2012840d634416fce4079ce20dc26d7569db9e9507e25b7cd0def7b968dac4e67e28be8e99c408ce5937d44e5e0f9bede16d49f318b49b0e1f72fa1fe8d0c8ebd170533f8348e962ef89e87a79d620968457e2b7e60f28c0022ebceff90b2dbf400a69ae8294863e28f7c2b288cbbb8298d1797993dcd96fd5c0e033e3c8c904d8f2fa5f6b5410512d24fb23caee1a5aa9d814fe41e2131974255ce1f5a80601701fe4568d2009ca872ce2a120f67c49244b0310f2acd2010916a2011bf0cc24ea2da236bd4741e8119e9506a3379a7ac5022c44a81209bb12330c9acc8aee21ee636246874d332915730bef7598d82174f23934845dc1a9de6...)
DEBUG:pyatv.protocols.companion.protocol:Received frame FrameType.E_OPACK: b'\xe4B_x1\xcbPC_rT\nB_c\xefa!com.canalplusdistrib.mycanal.prodGmyCANALScom.firecore.infuseFInfuseQcom.apple.FitnessEFormeRcom.apple.podcastsHPodcastsRcom.cbs.canada.appJParamount+Rcom.apple.TVMoviesEFilmsUcom.apple.TVWatchListBTVRcom.apple.TVPhotosFPhotosTcom.apple.TVAppStoreJApp\xc2\xa0StoreUcom.amazon.aiv.AIVAppKPrime VideoQcom.apple.TVShowsKS\xc3\xa9ries\xc2\xa0TVPcom.apple.ArcadeFArcadeTorg.videolan.vlc-iosCVLCRcom.apple.TVSearchJRechercherNfr.kaze.kzplayCADNYtv.molotov.MolotovAppProdIMolotovTVWcom.apple.TVHomeSharingKOrdinateursRcom.apple.facetimeHFaceTimeVcom.google.ios.youtubeGYouTubeQtv.mrmc.mrmc.tvosDMrMCYcom.lvmh.RadioClassiqueTVORadio ClassiqueTcom.olimsoft.oplayerGOPlayer[com.dailymotion.dailymotionMdailymotionTV^com.ubisoft.raymanadventurestvQRayman AdventuresUcom.disney.disneyplusGDisney+Tcom.apple.TVSettingsIR\xc3\xa9glagesUcom.apple.appleeventsR\xc3\x89v\xc3\xa9nements AppleScom.netflix.NetflixGNetflixWcom.firecore.infuse.proLInfuse Pro 4Qcom.apple.TVMusicGMusiqueXcom.allocine.applifranceIAlloCin\xc3\xa9\x03B_t\x0b'
DEBUG:pyatv.protocols.companion.protocol:Process incoming OPACK frame (FrameType.E_OPACK): {'_x': 20683, '_rT': 2, '_c': {'com.canalplusdistrib.mycanal.prod': 'myCANAL', 'com.firecore.infuse': 'Infuse', 'com.apple.Fitness': 'Forme', 'com.apple.podcasts': 'Podcasts', 'com.cbs.canada.app': 'Paramount+', 'com.apple.TVMovies': 'Films', 'com.apple.TVWatchList': 'TV', 'com.apple.TVPhotos': 'Photos', 'com.apple.TVAppStore': 'App\xa0Store', 'com.amazon.aiv.AIVApp': 'Prime Video', 'com.apple.TVShows': 'Séries\xa0TV', 'com.apple.Arcade': 'Arcade', 'org.videolan.vlc-ios': 'VLC', 'com.apple.TVSearch': 'Rechercher', 'fr.kaze.kzplay': 'ADN', 'tv.molotov.MolotovAppProd': 'MolotovTV', 'com.apple.TVHomeSharing': 'Ordinateurs', 'com.apple.facetime': 'FaceTime', 'com.google.ios.youtube': 'YouTube', 'tv.mrmc.mrmc.tvos': 'MrMC', 'com.lvmh.RadioClassiqueTV': 'Radio Classique', 'com.olimsoft.oplayer': 'OPlayer', 'com.dailymotion.dailymotion': 'dailymotionTV', 'com.ubisoft.raymanadventurestv': 'Rayman Adventures', 'com.disney.disneyplus': 'Disney+', 'com.apple.TVSettings': 'Réglages', 'com.apple.appleevents': 'Événements Apple', 'com.netflix.Netflix': 'Netflix', 'com.firecore.infuse.pro': 'Infuse Pro 4', 'com.apple.TVMusic': 'Musique', 'com.allocine.applifrance': 'AlloCiné'}, '_t': 3}
DEBUG:pyatv.protocols.companion.connection:Connection lost to remote device: None
DEBUG:pyatv.protocols.airplay.mrp_connection:Closing connection
How to reproduce the bug?
- Pair the Apple TV device with companion protocol using tvOS 18.4
- Connect to it with pyatv
- Subscribe to connection lost/closed events by implementing the
DeviceListenerinterface - The client will receive a lost connection event a few milliseconds later
What is expected behavior?
The client should not disconnect (unless there is a network failure...)
Operating System
Tested on Windows and Ubuntu
Python
3.12
pyatv
16.0.0
Device
Apple TV 4K (gen 2), tvOS 18.4
Additional context
I have analyzed the code of the implementation of the companion protocol : at this state I see nothing wrong that could explain the disconnections on your side.
I rather think that Apple introduced a (very short) timeout after connection : any companion command will be processed successfully after connection, but 100 milliseconds later the connection is closed. Is it intended ? this seems really too short This means that each time we want to use this protocol (list/launch apps, HID commands...) we have to reconnect. Is there a keep alive flag or timeout setting in the protocol ?
Hi I have figured out how to resolve it, but additional info is needed.
The problem comes from the _systemInfo message sent at the beginning
File pyatv/protocols/companion/api.py : line 193
The _i parameter with fixed value "cafecafecafe", when replaced by the expected value (taken from atvproxy in my situation), the connection remains active :
await self._send_command(
"_systemInfo",
{
"_bf": 0,
"_cf": 512,
"_clFl": 128,
"_i": "5b74ef08347f", # TODO: Figure out what to put here => "cafecafecafe" don't work anymore
"_idsID": creds.client_id,
# Not really device id here, but better then anything...
"_pubID": info.device_id,
"_sf": 256, # Status flags?
"_sv": "170.18", # Software Version (I guess?)
"model": info.model,
"name": info.name,
},
)
But I don't know how it is calculated. I have tried several values around this one "5b74ef08347f" and it works. But the value cafecafecafe raises a disconnection every times. Even cafecafecaf0 works. It is like Apple blacklisted your static value here.
What is sure is that this identifier is related to the device and always the same :
- Same iPhone on AppleTV 4K 1 : 5b74ef08347f
- Same iPhone on AppleTV 4K (2nd gen) 2 : 5b74ef08347f
- iPad on Apple TV 1 or 2 : ee1a0dead92c
I'm still looking into this. I'm still not sure what the identifier in _i means or if it's globally unique for the device. But I do feel that we should generate an identifier, store it in amongst all other settings and use the same identifier in subsequent calls.
Did you get atvproxy working btw? I can't see the Proxy device anymore. I suspect some kind of validation is done now that wasn't done before (and that atvproxy can't handle).
Actually yes atvproxy worked. This is how I figured out which differences between 2 Apple TVs (one in tvOS 18.4 another one in tvOS 18.3)
But still it reminds me that I had this proxy not appearing issue. I don't remember I fixed it
Interesting. The proxy device does not show up for me. Will have to dig into that later... What I have found is that _i is a device identifier handled by IDS, which I believe is simple "Identify Service". It lives inside the identityservicesd daemon process. Not sure how it is assigned yet though.