home-assistant / android

:iphone: Home Assistant Companion for Android
https://companion.home-assistant.io/
Apache License 2.0
2.35k stars 656 forks source link

Device controls quick setting stuck in perpetual "loading" state #4711

Closed Jay2645 closed 1 month ago

Jay2645 commented 1 month ago

Home Assistant Android app version(s): 2024.10.1-full

Android version(s): Android 14, build AD1A.240905.004

Device model(s): Pixel 9

Home Assistant version: 2024.10.1

Last working Home Assistant release (if known): 2024.10.1

Description of problem, include YAML if issue is related to notifications:

On some devices, trying to access device controls via the Android "Quick Settings" tile causes entities to perpetually be in a "loading" state.

This does not resolve itself over multiple minutes, even if the app is closed and reopened or if you attempt to add new controls.

This can happen on some devices but not others. My fiance had a Pixel 6 Pro where this always happened to her; I had a Pixel 6 where it never happened to me. Now I have a Pixel 9 and it happens every time for me, whereas it always works for my fiance. The app version is the same, the config is the same (fresh install of the app), the only difference is the hardware and which account is in use.

Companion App Logs:

--------- beginning of system
10-09 22:55:48.545 32450 32450 W ActivityThread: getPackageInfo() called with an older ApplicationInfo than the cached version for package io.homeassistant.companion.android
--------- beginning of main
10-09 22:56:48.239 32450 32450 D LocBroadcastReceiver: Received location update.
10-09 22:56:48.275 32450 32450 D ForegrndServiceLauncher: Check if service HighAccuracyLocationService is running. Service running = false
10-09 22:56:48.279 32450 32643 D LocBroadcastReceiver: Last Location: 
10-09 22:56:48.279 32450 32643 D LocBroadcastReceiver: Coords:(34.0911386, -117.9041598)
10-09 22:56:48.279 32450 32643 D LocBroadcastReceiver: Accuracy: 100.0
10-09 22:56:48.279 32450 32643 D LocBroadcastReceiver: Bearing: 0.0
10-09 22:56:48.281 32450 32643 D LocBroadcastReceiver: Begin evaluating if location update should be skipped
10-09 22:56:48.281 32450 32643 D LocBroadcastReceiver: Received location that is 94 milliseconds old, 1728539808187 compared to 1728539808281 with source fused
10-09 22:56:48.281 32450 32643 D LocBroadcastReceiver: Duplicate location received, not sending to HA
10-09 22:57:00.335 32450 32450 D IntegrationRepository: isAppLocked(): false. (LockEnabled: false, appActive: false, expireMillis: 1728539764917, currentMillis: 1728539820335)
10-09 22:57:00.354 32450 32450 E mpanion.android: Invalid resource ID 0x00000000.
10-09 22:57:00.355 32450 32450 E mpanion.android: Invalid resource ID 0x00000000.
10-09 22:57:00.355 32450 32450 E mpanion.android: Invalid resource ID 0x00000000.
10-09 22:57:00.355 32450 32450 E mpanion.android: Invalid resource ID 0x00000000.
10-09 22:57:00.355 32450 32450 E mpanion.android: Invalid resource ID 0x00000000.
10-09 22:57:00.355 32450 32450 E mpanion.android: Invalid resource ID 0x00000000.
10-09 22:57:00.355 32450 32450 E mpanion.android: Invalid resource ID 0x00000000.
10-09 22:57:00.379 32450 32450 D IntegrationRepository: isAppLocked(): false. (LockEnabled: false, appActive: false, expireMillis: 1728539764917, currentMillis: 1728539820379)
10-09 22:57:00.379 32450 32450 D IntegrationRepository: setAppActive(): true
10-09 22:57:01.880 32450 32450 E mpanion.android: Invalid resource ID 0x00000000.
10-09 22:57:02.005 32450 32450 E mpanion.android: Invalid resource ID 0x00000000.
10-09 22:57:02.982 32450 32450 E mpanion.android: Invalid resource ID 0x00000000.
10-09 22:57:02.983 32450 32450 E mpanion.android: Invalid resource ID 0x00000000.
10-09 22:57:02.983 32450 32450 E mpanion.android: Invalid resource ID 0x00000000.
10-09 22:57:02.983 32450 32450 E mpanion.android: Invalid resource ID 0x00000000.
10-09 22:57:05.359 32450 32450 D CompatibilityChangeReporter: Compat change id reported: 163400105; UID 10295; state: ENABLED
10-09 22:57:05.361 32450 32643 D LogcatReader: Read logcat for pid 32450
10-09 22:57:05.435 32450 32643 D LogcatReader: Done reading logcat for pid 32450
10-09 22:57:15.557 32450 32450 E mpanion.android: Invalid resource ID 0x00000000.
10-09 22:57:15.557 32450 32450 E mpanion.android: Invalid resource ID 0x00000000.
10-09 22:57:15.558 32450 32450 E mpanion.android: Invalid resource ID 0x00000000.
10-09 22:57:15.558 32450 32450 E mpanion.android: Invalid resource ID 0x00000000.
10-09 22:57:15.624 32450 32450 E mpanion.android: Invalid resource ID 0x00000000.
10-09 22:57:15.625 32450 32450 E mpanion.android: Invalid resource ID 0x00000000.
10-09 22:57:15.625 32450 32450 E mpanion.android: Invalid resource ID 0x00000000.
10-09 22:57:15.625 32450 32450 E mpanion.android: Invalid resource ID 0x00000000.
10-09 22:57:15.627 32450 32450 I ImeTracker: io.homeassistant.companion.android:1aa3f9ef: onRequestHide at ORIGIN_CLIENT reason HIDE_SOFT_INPUT_CLOSE_CURRENT_SESSION fromUser false
10-09 22:57:17.998 32450 32450 D IntegrationRepository: setAppActive(): false
10-09 22:57:17.999 32450 32450 D IntegrationRepository: setAppActive(): false
10-09 22:57:18.024 32450 32450 D HaConProService: publisherFor [2.cover.bedroom_blind, 2.light.bed_headboard, 2.light.main_bedroom_lights, 2.input_button.sleep_o_clock, 2.input_button.alternate_bedroom_lights, 2.light.office, 2.input_boolean.office_fan_on_off]
10-09 22:57:18.302 32450   778 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
10-09 22:57:18.307 32450   778 D HaConProService: request 100000
10-09 22:57:18.310 32450 32643 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
10-09 22:57:18.310 32450 32643 D ServerConnectionInfo: Using external URL
10-09 22:57:18.316 32450 32656 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
10-09 22:57:18.316 32450 32656 D ServerConnectionInfo: Using external URL
10-09 22:57:18.316 32450 32479 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
10-09 22:57:18.316 32450 32479 D ServerConnectionInfo: Using external URL
10-09 22:57:18.316 32450 32642 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
10-09 22:57:18.316 32450 32642 D ServerConnectionInfo: Using external URL
10-09 22:57:18.318 32450 32656 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
10-09 22:57:18.318 32450 32656 D ServerConnectionInfo: Using external URL
10-09 22:57:18.319 32450 32642 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
10-09 22:57:18.319 32450 32642 D ServerConnectionInfo: Using external URL
10-09 22:57:18.319 32450 32479 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
10-09 22:57:18.319 32450 32479 D ServerConnectionInfo: Using external URL
10-09 22:57:18.336 32450 32673 D TrafficStats: tagSocket(251) with statsTag=0xffffffff, statsUid=-1
10-09 22:57:18.336 32450   799 D TrafficStats: tagSocket(294) with statsTag=0xffffffff, statsUid=-1
10-09 22:57:18.336 32450   801 D TrafficStats: tagSocket(295) with statsTag=0xffffffff, statsUid=-1
10-09 22:57:19.070 32450   789 D WebSocketRepository: Websocket: onOpen
10-09 22:57:19.070 32450   790 D WebSocketRepository: Websocket: onOpen
10-09 22:57:19.070 32450   791 D WebSocketRepository: Websocket: onOpen
10-09 22:57:19.071 32450   791 D WebSocketRepository: Websocket: onMessage (text)
10-09 22:57:19.071 32450   790 D WebSocketRepository: Websocket: onMessage (text)
10-09 22:57:19.071 32450   789 D WebSocketRepository: Websocket: onMessage (text)
10-09 22:57:19.162 32450   789 D WebSocketRepository: Message number null received
10-09 22:57:19.164 32450 32642 D WebSocketRepository: Auth Requested
10-09 22:57:19.168 32450   791 D WebSocketRepository: Message number null received
10-09 22:57:19.168 32450   790 D WebSocketRepository: Message number null received
10-09 22:57:19.170 32450 32479 D WebSocketRepository: Auth Requested
10-09 22:57:19.170 32450 32656 D WebSocketRepository: Auth Requested
10-09 22:57:19.266 32450   791 D WebSocketRepository: Websocket: onMessage (text)
10-09 22:57:19.266 32450   790 D WebSocketRepository: Websocket: onMessage (text)
10-09 22:57:19.266 32450   789 D WebSocketRepository: Websocket: onMessage (text)
10-09 22:57:19.268 32450   789 D WebSocketRepository: Message number null received
10-09 22:57:19.268 32450   790 D WebSocketRepository: Message number null received
10-09 22:57:19.268 32450   791 D WebSocketRepository: Message number null received
10-09 22:57:19.269 32450 32642 D WebSocketRepository: Sending message 1: {type=supported_features, id=1, features={coalesce_messages=1}}
10-09 22:57:19.270 32450 32657 D WebSocketRepository: Sending message 1: {type=supported_features, id=1, features={coalesce_messages=1}}
10-09 22:57:19.270 32450 32479 D WebSocketRepository: Sending message 1: {type=supported_features, id=1, features={coalesce_messages=1}}
10-09 22:57:19.274 32450 32657 D WebSocketRepository: Sending message 2: {type=config/device_registry/list, id=2}
10-09 22:57:19.274 32450 32479 D WebSocketRepository: Sending message 2: {type=config/entity_registry/list, id=2}
10-09 22:57:19.274 32450 32479 D WebSocketRepository: Message number 2 sent
10-09 22:57:19.274 32450 32657 D WebSocketRepository: Message number 2 sent
10-09 22:57:19.275 32450 32642 D WebSocketRepository: Sending message 2: {type=config/area_registry/list, id=2}
10-09 22:57:19.275 32450 32642 D WebSocketRepository: Message number 2 sent
10-09 22:57:19.382 32450   790 D WebSocketRepository: Websocket: onMessage (text)
10-09 22:57:19.385 32450   790 D WebSocketRepository: Message number 1 received
10-09 22:57:19.389 32450   791 D WebSocketRepository: Websocket: onMessage (text)
10-09 22:57:19.390 32450   789 D WebSocketRepository: Websocket: onMessage (text)
10-09 22:57:19.391 32450   791 D WebSocketRepository: Message number 1 received
10-09 22:57:19.391 32450   789 D WebSocketRepository: Message number 1 received
10-09 22:57:19.512 32450   791 D WebSocketRepository: Websocket: onMessage (text)
10-09 22:57:19.519 32450   791 D WebSocketRepository: Message number 2 received
10-09 22:57:19.802 32450   790 D WebSocketRepository: Websocket: onMessage (text)
10-09 22:57:19.840 32450   790 D WebSocketRepository: Message number 2 received
10-09 22:57:20.822 32450   789 D WebSocketRepository: Websocket: onMessage (text)
10-09 22:57:20.976 32450   789 D WebSocketRepository: Message number 2 received
10-09 22:57:21.130 32450 32458 I mpanion.android: Background concurrent mark compact GC freed 598048(23MB) AllocSpace objects, 73(8576KB) LOS objects, 75% free, 23MB/93MB, paused 1.233ms,2.546ms total 126.753ms
10-09 22:57:21.146 32450   807 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
10-09 22:57:21.150 32450 32479 D WebSocketRepository: Sending message 3: {type=subscribe_events, event_type=area_registry_updated, id=3}
10-09 22:57:21.150 32450 32479 D WebSocketRepository: Message number 3 sent
10-09 22:57:21.264 32450   790 D WebSocketRepository: Websocket: onMessage (text)
10-09 22:57:21.265 32450   790 D WebSocketRepository: Message number 3 received
10-09 22:57:21.272 32450 32477 D WebSocketRepository: Sending message 4: {type=subscribe_events, event_type=device_registry_updated, id=4}
10-09 22:57:21.273 32450 32477 D WebSocketRepository: Message number 4 sent
10-09 22:57:21.385 32450   790 D WebSocketRepository: Websocket: onMessage (text)
10-09 22:57:21.387 32450   790 D WebSocketRepository: Message number 4 received
10-09 22:57:21.393 32450 32656 D WebSocketRepository: Sending message 5: {type=subscribe_events, event_type=entity_registry_updated, id=5}
10-09 22:57:21.394 32450 32656 D WebSocketRepository: Message number 5 sent
10-09 22:57:21.518 32450   790 D WebSocketRepository: Websocket: onMessage (text)
10-09 22:57:21.519 32450   790 D WebSocketRepository: Message number 5 received
10-09 22:57:21.527 32450   805 D WebSocketRepository: Sending message 6: {type=subscribe_entities, entity_ids=[cover.bedroom_blind, light.bed_headboard, light.main_bedroom_lights, input_button.sleep_o_clock, input_button.alternate_bedroom_lights, light.office, input_boolean.office_fan_on_off], id=6}
10-09 22:57:21.530 32450   805 D WebSocketRepository: Message number 6 sent
10-09 22:57:21.656 32450   790 D WebSocketRepository: Websocket: onMessage (text)
10-09 22:57:21.664 32450   790 D WebSocketRepository: Message number 6 received
10-09 22:57:21.665 32450   790 D WebSocketRepository: Message number 6 received
10-09 22:57:21.789 32450 32657 D HaConProService: Sending 7 entities to subscriber
10-09 22:57:21.798 32450 32656 D CompatibilityChangeReporter: Compat change id reported: 247079863; UID 10295; state: ENABLED
10-09 22:57:21.893 32450 32450 D IntegrationRepository: isAppLocked(): false. (LockEnabled: false, appActive: false, expireMillis: 1728539838998, currentMillis: 1728539841892)
10-09 22:57:21.916 32450   778 D HaConProService: cancel
10-09 22:57:21.923 32450   812 D WebSocketRepository: Unsubscribing from subscribe_events with data {event_type=area_registry_updated}
10-09 22:57:21.924 32450   817 D WebSocketRepository: Unsubscribing from subscribe_entities with data {entity_ids=[cover.bedroom_blind, light.bed_headboard, light.main_bedroom_lights, input_button.sleep_o_clock, input_button.alternate_bedroom_lights, light.office, input_boolean.office_fan_on_off]}
10-09 22:57:21.924 32450   812 D WebSocketRepository: Sending message 7: {type=unsubscribe_events, subscription=3, id=7}
10-09 22:57:21.925 32450   812 D WebSocketRepository: Message number 7 sent
10-09 22:57:21.925 32450   806 D WebSocketRepository: Unsubscribing from subscribe_events with data {event_type=entity_registry_updated}
10-09 22:57:21.925 32450   817 D WebSocketRepository: Sending message 8: {type=unsubscribe_events, subscription=6, id=8}
10-09 22:57:21.926 32450   817 D WebSocketRepository: Message number 8 sent
10-09 22:57:21.926 32450   806 D WebSocketRepository: Sending message 9: {type=unsubscribe_events, subscription=5, id=9}
10-09 22:57:21.926 32450   813 D WebSocketRepository: Unsubscribing from subscribe_events with data {event_type=device_registry_updated}
10-09 22:57:21.926 32450   806 D WebSocketRepository: Message number 9 sent
10-09 22:57:21.926 32450   813 D WebSocketRepository: Sending message 10: {type=unsubscribe_events, subscription=4, id=10}
10-09 22:57:21.926 32450   813 D WebSocketRepository: Message number 10 sent
10-09 22:57:21.933 32450 32450 D IntegrationRepository: isAppLocked(): false. (LockEnabled: false, appActive: false, expireMillis: 1728539838998, currentMillis: 1728539841933)
10-09 22:57:21.933 32450 32450 D IntegrationRepository: setAppActive(): true
10-09 22:57:22.041 32450   790 D WebSocketRepository: Websocket: onMessage (text)
10-09 22:57:22.042 32450   790 D WebSocketRepository: Message number 7 received
10-09 22:57:22.116 32450   790 D WebSocketRepository: Websocket: onMessage (text)
10-09 22:57:22.119 32450   790 D WebSocketRepository: Message number 8 received
10-09 22:57:22.119 32450   790 D WebSocketRepository: Message number 9 received
10-09 22:57:22.119 32450   790 D WebSocketRepository: Message number 10 received
10-09 22:57:22.257 32450   790 D WebSocketRepository: Websocket: onClosing code: 1001, reason: 
10-09 22:57:22.258 32450   790 D WebSocketRepository: Websocket: onClosed
10-09 22:57:23.602 32450   880 D LogcatReader: Read logcat for pid 32450

Screenshot or video of problem:

Screenshot_20241009-225129

Screenshot_20241009-225125

Additional information: This is similar to #2123 and #2710. Trying the workarounds listed there doesn't seem to fix the issue.

jpelgrom commented 1 month ago

The log file looks a bit weird with 3 connections active (?). Can you reproduce the issue again and provide another log so we can see if it's showing the same?

Specifically for adding controls: do you have multiple servers configured in the app, and if so are all of them online? It will try to load entities from all servers and might take a bit longer if a server is offline.

I have a very similar setup (Pixel on latest Android 14) and am not seeing any issues loading controls.

Jay2645 commented 1 month ago

I only have 1 server configured in the app. Although for some reason now it works every time? I'm going to close this for now and reopen if I see it again and can get you those details.