Integration stops working randomly

[albaintor]

Description

Hi,
my android (shield) TV integration stops working randomly

From the logs I have this repetitive warning, don't know why I have this as Android does not support now playing image:

2024-03-08 13:34:47.903602 +00:00	ui	WARN	qrc:/components/entities/media_player/ImageLoader.qml:61:5: QML Image: Error decoding: data:image/png;base64,: Unsupported image format
2024-03-08 13:34:47.820193 +00:00	ui	WARN	qrc:/components/entities/media_player/ImageLoader.qml:61:5: QML Image: Error decoding: data:image/png;base64,: Unsupported image format
2024-03-08 13:34:47.737474 +00:00	ui	WARN	qrc:/components/entities/media_player/ImageLoader.qml:61:5: QML Image: Error decoding: data:image/png;base64,: Unsupported image format
2024-03-08 13:34:47.645467 +00:00	ui	WARN	qrc:/components/entities/media_player/ImageLoader.qml:61:5: QML Image: Error decoding: data:image/png;base64,: Unsupported image format
2024-03-08 13:34:47.562410 +00:00	ui	WARN	qrc:/components/entities/media_player/ImageLoader.qml:61:5: QML Image: Error decoding: data:image/png;base64,: Unsupported image format
2024-03-08 13:34:47.479548 +00:00	ui	WARN	qrc:/components/entities/media_player/ImageLoader.qml:61:5: QML Image: Error decoding: data:image/png;base64,: Unsupported image format
2024-03-08 13:34:47.387415 +00:00	ui	WARN	qrc:/components/entities/media_player/ImageLoader.qml:61:5: QML Image: Error decoding: data:image/png;base64,: Unsupported image format
2024-03-08 13:34:47.304166 +00:00	ui	WARN	qrc:/components/entities/media_player/ImageLoader.qml:61:5: QML Image: Error decoding: data:image/png;base64,: Unsupported image format
2024-03-08 13:34:47.221269 +00:00	ui	WARN	qrc:/components/entities/media_player/ImageLoader.qml:61:5: QML Image: Error decoding: data:image/png;base64,: Unsupported image format
2024-03-08 13:34:47.128610 +00:00	ui	WARN	qrc:/components/entities/media_player/ImageLoader.qml:61:5: QML Image: Error decoding: data:image/png;base64,: Unsupported image format
2024-03-08 13:34:47.045612 +00:00	ui	WARN	qrc:/components/entities/media_player/ImageLoader.qml:61:5: QML Image: Error decoding: data:image/png;base64,: Unsupported image format
2024-03-08 13:34:46.962951 +00:00	ui	WARN	qrc:/components/entities/media_player/ImageLoader.qml:61:5: QML Image: Error decoding: data:image/png;base64,: Unsupported image format
2024-03-08 13:34:46.870786 +00:00	ui	WARN	qrc:/components/entities/media_player/ImageLoader.qml:61:5: QML Image: Error decoding: data:image/png;base64,: Unsupported image format

then key pressed but nothing happens on AndroidTV's side :

2024-03-08 13:34:33.758752 +00:00	ui	INFO	uc.ui.input: Key released: "DPAD_DOWN" "Activity_QMLTYPE_247(0x55a9e1ece0)"
2024-03-08 13:34:33.758242 +00:00	ui	INFO	qml: OVERRIDE RELEASED: DPAD_DOWN Activity_QMLTYPE_247(0x55a9e1ece0)
2024-03-08 13:34:33.725597 +00:00	ui	WARN	qrc:/components/entities/media_player/ImageLoader.qml:61:5: QML Image: Error decoding: data:image/png;base64,: Unsupported image format
2024-03-08 13:34:33.646885 +00:00	intg-androidtv	INFO	DEBUG:ucapi.api:[('127.0.0.1', 60446)] ->: {"kind": "resp", "req_id": 2256, "code": 200, "msg": "result", "msg_data": {}}
2024-03-08 13:34:33.646617 +00:00	intg-androidtv	INFO	INFO:driver:Got 00044BE87F74 command request: cursor_down None
2024-03-08 13:34:33.645345 +00:00	intg-androidtv	INFO	DEBUG:ucapi.api:[('127.0.0.1', 60446)] <-: {"kind":"req","id":2256,"msg":"entity_command","msg_data":{"cmd_id":"cursor_down","entity_id":"00044BE87F74","entity_type":"media_player"}}
2024-03-08 13:34:33.643512 +00:00	ui	INFO	uc.ui.input: Key pressed: "DPAD_DOWN" "Activity_QMLTYPE_247(0x55a9e1ece0)"
2024-03-08 13:34:33.643152 +00:00	ui	INFO	qml: OVERRIDE PRESSED: DPAD_DOWN Activity_QMLTYPE_247(0x55a9e1ece0)

Here are the logs :

UCR2_logs_2024-03-08.zip

How to Reproduce

1/ Launch an activity with TV + Android TV (nvidia shield) integration + HT receiver (media player entity from home assistant)
2/ Use the shield : navigate through menus, launch media
3/ After a while (happens randomly), the commands are not processed (play, pause, down arrow...)

I have set up the remote to go to sleep after 30min. In the activities I didn't enable the option to prevent sleeping, so maybe the remote goes to sleep during 2/ and 3/

Expected behavior

Android TV integration keeps on working

Integration version

No response

Additional context

No response

[zehnm]

I've finished the Apple TV rewrite and will focus next on the Android TV. Not having any command errors in the logs is suspicious. I have a Shield TV as well and try to reproduce it. It's possible that some return state isn't checked or a disconnect event is missed...

[albaintor]

Hi Markus, did you manage to find the problem ?
I have this issue regularly (every day or 2 days). Just after reboot of the remote, the integration works fine. Even after stop/restart of the shield activity it still works correctly, even after a few hours.

This is really weird as the driver receives the commands order and seem to process them with no error : intg-androidtv INFO INFO:driver:Got 00044BE87F74 command request: home None
It is as if the transport stream didn't work behind ? maybe a disconnection which is not caught ?

[albaintor]

Update : while started (and not working) commands responded again after 20 minutes
Here are the logs : the first lines around 11:05 are the working commands, whereas at 10:53 they were not.
UCR2_logs_2024-03-27 (2).zip

Could it be related to keys press / release mechanism ?

[zehnm]

I couldn't reproduce it so far, but I've also been working on PR #34 for a while which changed the connection & reconnection logic. Maybe it's fixed, otherwise I'll investigate it further after the new features have been merged.

[albaintor]

I have just set up your modifications in an external driver and configured it as my main entity for the Shield. I'll let you know

[zehnm]

I could reproduce two issues where communication breaks and no error is returned for several minutes from the communication library:

1. Network interface changes of the Android TV device, e.g. from LAN to WiFi
2. Client certificate gets invalid (shouldn't happen in normal use, only while developing and restoring an old certificate)

I'm a bit surprised about the first case, since I thought there's a keep-alive ping in the background. Maybe that changed, or I confuse it with the Android TV integration in Home Assistant. I'll investigate it after the multi-device PR is merged.

[zehnm]

One issue is in the androidtvremote2 library: sending a command is just fire and forget without a return value, even if the library determines that there's no connection :-(

• _send_message in base.py
  https://github.com/tronikos/androidtvremote2/blob/e54e33772e61e4ccb24b0c5ba6e0f2ad3efb2547/src/androidtvremote2/base.py#L66-L79

        if not self.transport or self.transport.is_closing():
            LOGGER.debug("Connection is closed!")
            return

I've added a transport check workaround and will most likely submit a patch for the send_key_command method.

[albaintor]

The case when network interface changes (LAN to WIFI) should not occur in my setup (plugged in ethernet) but I guess that my ISP router may sometimes have dropouts. There is indeed no reconnection logic in the library which should be done on lower level inside the library.
Thank you for raising this and making a workaround

[zehnm]

I've started a new branch fix/28_lost-connection for refactoring and improving the connection logic. This should fix the dead connection issue and give immediate feedback, if a command couldn't be sent to the device because there's not transport available.
This requires more testing before I'll merge it into the main branch.
The main branch already contains debug logging of the androidtvremote2 library to better see what's going on (or not).

Changed IP addresses are still only handled after wakeup of the remote. Devices are disconnected before sleep, then reconnected after wakeup. IP change detection is included in the initial connection logic. Unfortunately the reconnection task of androidtvremote2 only has a callback handler for authentication errors and doesn't provide more events. It can only be stopped by calling disconnect().

[albaintor]

Hi Markus,
ok I have just applied your branch on my external integration. Something that I would suggest that has disappeared from the previous PR I submitted : the profiles files are read from the $HOME folder, whereas they should read from the integration folder. On my setup the docker loads the integration files from an external mount, so that it is easier to update. This is not a common use I agree but as the profiles folder sits next to the intg-XXX driver files, one would expect to put them all in the same folder.
So I had applied a condition load on profile files from driver.py. What do you think ? (in that case if it fails to load from config_dir path it will check after the current path)

 # Internal driver mode
    profile_path = os.path.join(api.config_dir_path, "config/profiles")
    # External driver mode
    if not os.path.exists(profile_path):
        profile_path = "config/profiles"
    device_profile.load(profile_path)

[zehnm]

This is already handled with ENV variables: https://github.com/unfoldedcircle/integration-python-library?tab=readme-ov-file#environment-variables and implemented in the Python integration library.
When running in a container you can simply set the UC_CONFIG_HOME or HOME environment variable to your mountpoint.
This is required for the correct runtime behaviour on the Remote Two.

The profile loading path is currently not correct and will fix it tomorrow:

profile_path = os.path.join(api.config_dir_path, "config/profiles")

it may not contain the config/ prefix to run correctly on the Remote Two.

[albaintor]

Ok thanks it works