Android widgets service call's only work after I open the app

Mobile Apps Home Assistant Companion for Android
1

If a tap the widget I see a message on screen that the “service call failed” and a red cross is displayed on the widged. If I then quickly open the HA companion app and go back to my home screen where the widget is and try again the widget works.
If I try the widget again a few minutes later I get a spinning wheel displayed on the widget that lasts a long time until I open the app and the service call is handled.

I access home assistant trough a tailscale https proxy so I don’t have an internal URL set and wifi network configured. The above beheviour of the widgets is the same if I’m on my home wifi or somewhere else/mobile.

Anyone with an idea what could cause this behaviour and what I can try to fix it?

2

go to settings > companion app > troubleshooting > show and share logs then look for the failure when the widget says service call failed

3

Wow, the logging is verbose, even less than one minute of logs is too big for this post so put it on pastebin : companio app logs - Pastebin.com .
Pushed the widget at 8:48:02 and got the message on screen 10 seconds later that service call failed. Openend the app, closed it again and pushed the widget again at 8:48:32 and then I got the green checkmark and it worked.

Reading trough the logs I can make a guess what is going on. I have 3 servers configured in my app so I can switch between properties with the 3 finger swipe. The behaviour is the same if it is a widget from the current active server or not. I do however have one of the servers configured with a local url and wifi ssid’s next to the https:// proxy external url. To me it seems that the timeouts/connection problems are related to it trying to use the local url of that one server when not even at that location or connected to one of the listed wifi ssid’s

09-18 08:48:02.520  8996  8996 D ButtonWidget: Broadcast received: 
09-18 08:48:02.520  8996  8996 D ButtonWidget: Broadcast action: io.homeassistant.companion.android.widgets.button.ButtonWidget.CALL_SERVICE
09-18 08:48:02.520  8996  8996 D ButtonWidget: AppWidgetId: 26
09-18 08:48:02.520  8996  8996 D ButtonWidget: Calling widget service
09-18 08:48:02.530  8996  8996 D ButtonWidget: Service Call Data loaded:
09-18 08:48:02.530  8996  8996 D ButtonWidget: domain: switch
09-18 08:48:02.530  8996  8996 D ButtonWidget: service: turn_on
09-18 08:48:02.530  8996  8996 D ButtonWidget: service_data: {"entity_id":"switch.a4_slot_voordeur"}
09-18 08:48:02.566  8996  8996 D ButtonWidget: Sending service call to Home Assistant
09-18 08:48:02.570  8996  8996 D ServerConnectionInfo: localUrl is: true, usesInternalSsid is: false, usesWifi is: false
09-18 08:48:02.607  8996  9094 D TrafficStats: tagSocket(133) with statsTag=0xffffffff, statsUid=-1
09-18 08:48:12.633  8996  8996 E ButtonWidget: Could not send service call.
09-18 08:48:12.633  8996  8996 E ButtonWidget: io.homeassistant.companion.android.common.data.integration.IntegrationException: java.net.SocketTimeoutException: failed to connect to /192.168.10.42 (port 8123) from /100.81.218.235 (port 38960) after 10000ms
4

your issue is the server is not responding in time

widgets save the server ID so its very unlikely for it to get mixed up.

5

To rule out the issue with the local URL I removed the internal url en wifi SSID’s from the one server that still had them. Problem is still the same so question remains why is the server not responding to a service call coming from a widget but then does respond after I open and close the app.
In the below log (09-19 10:56:17.373 4329 4329 D TileExtensions: Tile: tile_1 is no longer in vi - Pastebin.com) I touch the widget a couple of times to have it immediatly say “Service call failed” (10:56:33), then I open the app close it again and try the widget again at timestamp 10:56:53.818 and the serice call works.
So question remains why?

09-19 10:56:17.373  4329  4329 D TileExtensions: Tile: tile_1 is no longer in view
09-19 10:56:33.912  4329  4329 D ButtonWidget: Broadcast received: 
09-19 10:56:33.912  4329  4329 D ButtonWidget: Broadcast action: io.homeassistant.companion.android.widgets.button.ButtonWidget.CALL_SERVICE
09-19 10:56:33.912  4329  4329 D ButtonWidget: AppWidgetId: 29
09-19 10:56:33.912  4329  4329 D ButtonWidget: Calling widget service
09-19 10:56:33.915  4329  4329 D ButtonWidget: Service Call Data loaded:
09-19 10:56:33.915  4329  4329 D ButtonWidget: domain: switch
09-19 10:56:33.915  4329  4329 D ButtonWidget: service: turn_on
09-19 10:56:33.915  4329  4329 D ButtonWidget: service_data: {"entity_id":["switch.a4_slot_poortje"]}
09-19 10:56:33.917  4329  4329 D ButtonWidget: Sending service call to Home Assistant
09-19 10:56:33.918  4329  4329 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: false
09-19 10:56:33.925  4329  4329 E ButtonWidget: Could not send service call.
09-19 10:56:39.308  4329  4329 D ButtonWidget: Broadcast received: 
09-19 10:56:39.308  4329  4329 D ButtonWidget: Broadcast action: io.homeassistant.companion.android.widgets.button.ButtonWidget.CALL_SERVICE
09-19 10:56:39.308  4329  4329 D ButtonWidget: AppWidgetId: 29
09-19 10:56:39.308  4329  4329 D ButtonWidget: Calling widget service
09-19 10:56:39.315  4329  4329 D ButtonWidget: Service Call Data loaded:
09-19 10:56:39.315  4329  4329 D ButtonWidget: domain: switch
09-19 10:56:39.315  4329  4329 D ButtonWidget: service: turn_on
09-19 10:56:39.315  4329  4329 D ButtonWidget: service_data: {"entity_id":["switch.a4_slot_poortje"]}
09-19 10:56:39.318  4329  4329 D ButtonWidget: Sending service call to Home Assistant
09-19 10:56:39.318  4329  4329 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: false
09-19 10:56:39.330  4329  4329 E ButtonWidget: Could not send service call.
09-19 10:56:43.829  4329  4329 D ButtonWidget: Broadcast received: 
09-19 10:56:43.829  4329  4329 D ButtonWidget: Broadcast action: io.homeassistant.companion.android.widgets.button.ButtonWidget.CALL_SERVICE
09-19 10:56:43.829  4329  4329 D ButtonWidget: AppWidgetId: 29
09-19 10:56:43.829  4329  4329 D ButtonWidget: Calling widget service
09-19 10:56:43.833  4329  4329 D ButtonWidget: Service Call Data loaded:
09-19 10:56:43.833  4329  4329 D ButtonWidget: domain: switch
09-19 10:56:43.833  4329  4329 D ButtonWidget: service: turn_on
09-19 10:56:43.833  4329  4329 D ButtonWidget: service_data: {"entity_id":["switch.a4_slot_poortje"]}
09-19 10:56:43.836  4329  4329 D ButtonWidget: Sending service call to Home Assistant
09-19 10:56:43.837  4329  4329 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: false
09-19 10:56:43.865  4329  4329 E ButtonWidget: Could not send service call.
09-19 10:56:47.745  4329  4524 D vulkan  : searching for layers in '/data/app/~~GwrekG1N0pk_Jjf8KsKrIw==/io.homeassistant.companion.android-tWok3bKZafBv2_RLlL7Dvg==/lib/arm64'
09-19 10:56:47.746  4329  4524 D vulkan  : searching for layers in '/data/app/~~GwrekG1N0pk_Jjf8KsKrIw==/io.homeassistant.companion.android-tWok3bKZafBv2_RLlL7Dvg==/base.apk!/lib/arm64-v8a'
09-19 10:56:47.748  4329  4524 D vulkan  : searching for layers in '/data/app/~~GwrekG1N0pk_Jjf8KsKrIw==/io.homeassistant.companion.android-tWok3bKZafBv2_RLlL7Dvg==/split_config.arm64_v8a.apk!/lib/arm64-v8a'
09-19 10:56:47.749  4329  4524 D vulkan  : searching for layers in '/data/app/~~GwrekG1N0pk_Jjf8KsKrIw==/io.homeassistant.companion.android-tWok3bKZafBv2_RLlL7Dvg==/split_config.xxhdpi.apk!/lib/arm64-v8a'
09-19 10:56:47.773  4329  4329 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:47.785  4329  4329 I cr_CombinedPProvider: #registerProvider() provider:WV.o8@d162f96 isPolicyCacheEnabled:false policyProvidersSize:0
09-19 10:56:47.787  4329  4329 I cr_PolicyProvider: #setManagerAndSource() 0
09-19 10:56:47.798  4329  4329 I cr_CombinedPProvider: #linkNativeInternal() 1
09-19 10:56:47.799  4329  4329 I cr_AppResProvider: #getApplicationRestrictionsFromUserManager() Bundle[EMPTY_PARCEL]
09-19 10:56:47.799  4329  4329 I cr_PolicyProvider: #notifySettingsAvailable() 0
09-19 10:56:47.799  4329  4329 I cr_CombinedPProvider: #onSettingsAvailable() 0
09-19 10:56:47.799  4329  4329 I cr_CombinedPProvider: #flushPolicies()
09-19 10:56:47.855  4329  4329 D CompatibilityChangeReporter: Compat change id reported: 214741472; UID 10250; state: ENABLED
09-19 10:56:47.860  4329  4329 D CompatibilityChangeReporter: Compat change id reported: 171228096; UID 10250; state: ENABLED
09-19 10:56:47.904  4329  4329 D CompatibilityChangeReporter: Compat change id reported: 210923482; UID 10250; state: ENABLED
09-19 10:56:47.904  4329  4329 D CompatibilityChangeReporter: Compat change id reported: 63938206; UID 10250; state: DISABLED
09-19 10:56:47.918  4329  4329 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:47.918  4329  4329 D IntegrationRepository: isAppLocked(): false. (LockEnabled: false, appActive: false, expireMillis: 0, currentMillis: 1726736207918)
09-19 10:56:47.923  4329  4329 D WebviewActivity: Current webview package com.google.android.webview and version 128.0.6613.146
09-19 10:56:47.925  4329  4329 D WebviewActivity: Matter/Thread step changed to NOT_STARTED
09-19 10:56:47.926  4329  4329 I ContentCaptureHelper: Setting logging level to OFF
09-19 10:56:47.927  4329  4329 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:47.928  4329  4329 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:47.928  4329  4329 D IntegrationRepository: isAppLocked(): false. (LockEnabled: false, appActive: false, expireMillis: 0, currentMillis: 1726736207928)
09-19 10:56:47.974  4329  4329 D CompatibilityChangeReporter: Compat change id reported: 237531167; UID 10250; state: DISABLED
09-19 10:56:47.998  4329  4329 D PressureSensor: Pressure sensor listener unregistered
09-19 10:56:48.111  4329  4329 D CompatibilityChangeReporter: Compat change id reported: 193247900; UID 10250; state: ENABLED
09-19 10:56:48.178  4329  4329 I ContentCaptureHelper: Setting logging level to OFF
09-19 10:56:48.195  4329  4364 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:48.196  4329  4364 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:48.196  4329  4373 I WM-Processor: Moving WorkSpec (ca97ea7c-ec2d-49ac-8764-798168378276) to the foreground
09-19 10:56:48.205  4329  4329 I WM-SystemFgDispatcher: Started foreground service Intent { act=ACTION_START_FOREGROUND cmp=io.homeassistant.companion.android/androidx.work.impl.foreground.SystemForegroundService (has extras) }
09-19 10:56:48.208  4329  4364 D SensorWorker: Updating all Sensors in foreground.
09-19 10:56:48.208  4329  4373 I WM-Processor: Moving WorkSpec (71ddb0ec-5c8e-4518-b44d-a9c6b6c2f6b5) to the foreground
09-19 10:56:48.209  4329  4364 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:48.209  4329  4364 D ActivitySM: Unregistering for activity updates.
09-19 10:56:48.209  4329  4364 D ActivitySM: Registering for activity updates.
09-19 10:56:48.210  4329  4329 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:48.210  4329  4329 D IntegrationRepository: isAppLocked(): false. (LockEnabled: false, appActive: false, expireMillis: 0, currentMillis: 1726736208210)
09-19 10:56:48.217  4329  4329 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:48.217  4329  4329 D ServerConnectionInfo: Using external URL
09-19 10:56:48.217  4329  4329 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:48.217  4329  4329 D ServerConnectionInfo: Using external URL
09-19 10:56:48.220  4329  4416 D WebSockManager: Starting to listen to Websocket
09-19 10:56:48.221  4329  4376 I WM-WorkerWrapper: Work [ id=ca97ea7c-ec2d-49ac-8764-798168378276, tags={ io.homeassistant.companion.android.sensors.SensorWorker } ] was cancelled
09-19 10:56:48.221  4329  4376 I WM-WorkerWrapper: java.util.concurrent.CancellationException: Task was cancelled.
09-19 10:56:48.221  4329  4376 I WM-WorkerWrapper: 	at androidx.work.impl.utils.futures.AbstractFuture.cancellationExceptionWithCause(AbstractFuture.java:1183)
09-19 10:56:48.221  4329  4376 I WM-WorkerWrapper: 	at androidx.work.impl.utils.futures.AbstractFuture.getDoneValue(AbstractFuture.java:513)
09-19 10:56:48.221  4329  4376 I WM-WorkerWrapper: 	at androidx.work.impl.utils.futures.AbstractFuture.get(AbstractFuture.java:474)
09-19 10:56:48.221  4329  4376 I WM-WorkerWrapper: 	at androidx.work.impl.WorkerWrapper$2.run(WorkerWrapper.java:316)
09-19 10:56:48.221  4329  4376 I WM-WorkerWrapper: 	at androidx.work.impl.utils.SerialExecutorImpl$Task.run(SerialExecutorImpl.java:96)
09-19 10:56:48.221  4329  4376 I WM-WorkerWrapper: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
09-19 10:56:48.221  4329  4376 I WM-WorkerWrapper: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
09-19 10:56:48.221  4329  4376 I WM-WorkerWrapper: 	at java.lang.Thread.run(Thread.java:1012)
09-19 10:56:48.223  4329  4416 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:48.224  4329  4416 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:48.225  4329  4416 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:48.226  4329  4416 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:48.227  4329  4422 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:48.227  4329  4422 D ServerConnectionInfo: Using external URL
09-19 10:56:48.227  4329  4422 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:48.227  4329  4422 D ServerConnectionInfo: Using external URL
09-19 10:56:48.228  4329  4422 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:48.228  4329  4422 D ServerConnectionInfo: Using external URL
09-19 10:56:48.232  4329  4329 I WM-SystemFgDispatcher: Started foreground service Intent { act=ACTION_START_FOREGROUND cmp=io.homeassistant.companion.android/androidx.work.impl.foreground.SystemForegroundService (has extras) }
09-19 10:56:48.253  4329  4422 D LocBroadcastReceiver: Background location updates appear to have stopped, restarting location updates
09-19 10:56:48.253  4329  4422 D LocBroadcastReceiver: Removing background location requests.
09-19 10:56:48.260  4329  4422 D LocBroadcastReceiver: Registering for location updates.
09-19 10:56:48.269  4329  4329 D ForegrndServiceLauncher: Check if service HighAccuracyLocationService is running. Service running = false
09-19 10:56:48.275  4329  4364 E SensorReceiver: Issue requesting updates for Meldingssensoren
09-19 10:56:48.275  4329  4364 E SensorReceiver: java.lang.NullPointerException: Attempt to invoke virtual method 'android.content.Context android.content.Context.getApplicationContext()' on a null object reference
09-19 10:56:48.275  4329  4364 E SensorReceiver: 	at android.content.ContextWrapper.getApplicationContext(ContextWrapper.java:152)
09-19 10:56:48.275  4329  4364 E SensorReceiver: 	at io.homeassistant.companion.android.sensors.NotificationSensorManager.updateActiveNotificationCount(NotificationSensorManager.kt:236)
09-19 10:56:48.275  4329  4364 E SensorReceiver: 	at io.homeassistant.companion.android.sensors.NotificationSensorManager.requestSensorUpdate(NotificationSensorManager.kt:102)
09-19 10:56:48.275  4329  4364 E SensorReceiver: 	at io.homeassistant.companion.android.common.sensors.SensorManager$DefaultImpls.requestSensorUpdate(SensorManager.kt:138)
09-19 10:56:48.275  4329  4364 E SensorReceiver: 	at io.homeassistant.companion.android.sensors.NotificationSensorManager.requestSensorUpdate(NotificationSensorManager.kt:25)
09-19 10:56:48.275  4329  4364 E SensorReceiver: 	at io.homeassistant.companion.android.common.sensors.SensorReceiverBase.updateSensors(SensorReceiverBase.kt:184)
09-19 10:56:48.275  4329  4364 E SensorReceiver: 	at io.homeassistant.companion.android.common.sensors.SensorWorkerBase$doWork$2.invokeSuspend(SensorWorkerBase.kt:67)
09-19 10:56:48.275  4329  4364 E SensorReceiver: 	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
09-19 10:56:48.275  4329  4364 E SensorReceiver: 	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:104)
09-19 10:56:48.275  4329  4364 E SensorReceiver: 	at kotlinx.coroutines.internal.LimitedDispatcher$Worker.run(LimitedDispatcher.kt:111)
09-19 10:56:48.275  4329  4364 E SensorReceiver: 	at kotlinx.coroutines.scheduling.TaskImpl.run(Tasks.kt:99)
09-19 10:56:48.275  4329  4364 E SensorReceiver: 	at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:584)
09-19 10:56:48.275  4329  4364 E SensorReceiver: 	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:811)
09-19 10:56:48.275  4329  4364 E SensorReceiver: 	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:715)
09-19 10:56:48.275  4329  4364 E SensorReceiver: 	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:702)
09-19 10:56:48.280  4329  4364 D PressureSensor: Pressure sensor listener registered
09-19 10:56:48.280  4329  4364 D ProximitySensor: Re-registering listener as it appears to be stuck
09-19 10:56:48.297  4329  4364 D ProximitySensor: Proximity sensor listener registered
09-19 10:56:48.300  4329  4364 E SensorReceiver: Exception while awaiting sensor updates.
09-19 10:56:48.300  4329  4364 E SensorReceiver: kotlinx.coroutines.JobCancellationException: Job was cancelled; job=JobImpl{Cancelling}@7d9ff88
09-19 10:56:48.300  4329  4414 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:48.300  4329  4363 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:48.305  4329  4363 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:48.309  4329  4422 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:48.310  4329  4414 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:48.310  4329  4422 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:48.360  4329  4688 D TrafficStats: tagSocket(297) with statsTag=0xffffffff, statsUid=-1
09-19 10:56:48.379  4329  4329 D ProximitySensor: Proximity sensor listener unregistered
09-19 10:56:48.426  4329  4692 D TrafficStats: tagSocket(381) with statsTag=0xffffffff, statsUid=-1
09-19 10:56:48.428  4329  4586 D WebviewActivity: External bus {"type":"config/get","id":1}
09-19 10:56:48.428  4329  4329 D WebviewActivity: externalBus({"id":1,"type":"result","success":true,"result":{"hasSettingsScreen":true,"canWriteTag":true,"hasExoPlayer":true,"canCommissionMatter":true,"canImportThreadCredentials":true,"hasAssist":true,"hasBarCodeScanner":1}});
09-19 10:56:48.430  4329  4693 D TrafficStats: tagSocket(296) with statsTag=0xffffffff, statsUid=-1
09-19 10:56:48.431  4329  4694 D TrafficStats: tagSocket(298) with statsTag=0xffffffff, statsUid=-1
09-19 10:56:48.440  4329  4329 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:48.440  4329  4329 D ServerConnectionInfo: Using external URL
09-19 10:56:48.440  4329  4329 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:48.440  4329  4329 D ServerConnectionInfo: Using external URL
09-19 10:56:48.446  4329  4692 D TrafficStats: tagSocket(393) with statsTag=0xffffffff, statsUid=-1
09-19 10:56:48.555  4329  4329 D PressureSensor: Pressure sensor listener unregistered
09-19 10:56:48.557  4329  4329 D WebviewActivity: Callback null
09-19 10:56:48.557  4329  4329 D WebviewActivity: Color from webview is "#101e24-SPACER-#111111"
09-19 10:56:48.558  4329  4329 D WebviewActivity: Color from webview is "#101e24-SPACER-#111111"
09-19 10:56:48.560  4329  4414 D WebViewPresenterImpl: Try getting color from webview color "#101e24".
09-19 10:56:48.560  4329  4414 I WebViewPresenterImpl: Found color -15720924.
09-19 10:56:48.560  4329  4414 D WebViewPresenterImpl: Try getting color from webview color "#111111".
09-19 10:56:48.560  4329  4414 I WebViewPresenterImpl: Found color -15658735.
09-19 10:56:48.651  4329  4639 D WebSocketRepository: Websocket: onOpen
09-19 10:56:48.651  4329  4639 D WebSocketRepository: Websocket: onMessage (text)
09-19 10:56:48.654  4329  4639 D WebSocketRepository: Message number null received
09-19 10:56:48.654  4329  4414 D WebSocketRepository: Auth Requested
09-19 10:56:48.682  4329  4639 D WebSocketRepository: Websocket: onMessage (text)
09-19 10:56:48.682  4329  4639 D WebSocketRepository: Message number null received
09-19 10:56:48.683  4329  4414 D WebSocketRepository: Sending message 1: {type=supported_features, id=1, features={coalesce_messages=1}}
09-19 10:56:48.683  4329  4414 D WebSocketRepository: Sending message 2: {type=mobile_app/push_notification_channel, webhook_id=0049019dc7dd99a23f1d48dc6df7f79cbd05ba55f4ff4451609fb2efee940736, support_confirm=true, id=2}
09-19 10:56:48.683  4329  4414 D WebSocketRepository: Message number 2 sent
09-19 10:56:48.717  4329  4639 D WebSocketRepository: Websocket: onMessage (text)
09-19 10:56:48.718  4329  4639 D WebSocketRepository: Message number 1 received
09-19 10:56:48.745  4329  4639 D WebSocketRepository: Websocket: onMessage (text)
09-19 10:56:48.745  4329  4639 D WebSocketRepository: Message number 2 received
09-19 10:56:48.746  4329  4414 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:48.817  4329  4693 D TrafficStats: tagSocket(263) with statsTag=0xffffffff, statsUid=-1
09-19 10:56:48.821  4329  4586 D WebviewActivity: External bus {"type":"connection-status","payload":{"event":"connected"},"id":2}
09-19 10:56:48.822  4329  4329 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:48.912  4329  4368 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:49.085  4329  4586 D WebviewActivity: External bus {"type":"theme-update","id":3}
09-19 10:56:49.115  4329  4329 D WebviewActivity: Color from webview is "#101e24-SPACER-#111111"
09-19 10:56:49.115  4329  4329 D WebviewActivity: Color from webview is "#101e24-SPACER-#111111"
09-19 10:56:49.115  4329  4368 D WebViewPresenterImpl: Try getting color from webview color "#101e24".
09-19 10:56:49.115  4329  4368 I WebViewPresenterImpl: Found color -15720924.
09-19 10:56:49.116  4329  4368 D WebViewPresenterImpl: Try getting color from webview color "#111111".
09-19 10:56:49.116  4329  4368 I WebViewPresenterImpl: Found color -15658735.
09-19 10:56:49.288  4329  4419 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:50.120  4329  4558 D CompatibilityChangeReporter: Compat change id reported: 258825825; UID 10250; state: DISABLED
09-19 10:56:50.999  4329  4329 D IntegrationRepository: setAppActive(): false
09-19 10:56:51.000  4329  4329 D IntegrationRepository: setAppActive(): false
09-19 10:56:51.008  4329  4329 D SensorReceiver: Received intent: io.homeassistant.companion.android.UPDATE_SENSORS
09-19 10:56:51.010  4329  4329 D VRI[WebViewActivity]: visibilityChanged oldVisibility=true newVisibility=false
09-19 10:56:51.014  4329  4414 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:51.021  4329  4414 D ActivitySM: Unregistering for activity updates.
09-19 10:56:51.022  4329  4414 D ActivitySM: Registering for activity updates.
09-19 10:56:51.098  4329  4329 D LocBroadcastReceiver: Got single accurate location update: Location[fused 51.224264,4.419289 hAcc=100.0 et=+16h0m35s177ms alt=57.81599580618702 vAcc=100.0]
09-19 10:56:51.098  4329  4329 D LocBroadcastReceiver: Location accurate enough, all done with high accuracy.
09-19 10:56:51.099  4329  4329 D LocBroadcastReceiver: Last Location: 
09-19 10:56:51.099  4329  4329 D LocBroadcastReceiver: Coords:(51.224264, 4.4192893)
09-19 10:56:51.099  4329  4329 D LocBroadcastReceiver: Accuracy: 100.0
09-19 10:56:51.099  4329  4329 D LocBroadcastReceiver: Bearing: 0.0
09-19 10:56:51.106  4329  4329 D LocBroadcastReceiver: Begin evaluating if location update should be skipped
09-19 10:56:51.106  4329  4329 D LocBroadcastReceiver: Received location that is 90 milliseconds old, 1726736211016 compared to 1726736211106 with source fused
09-19 10:56:51.112  4329  4329 D LocBroadcastReceiver: Last Location: 
09-19 10:56:51.112  4329  4329 D LocBroadcastReceiver: Coords:(51.224264, 4.4192893)
09-19 10:56:51.112  4329  4329 D LocBroadcastReceiver: Accuracy: 100.0
09-19 10:56:51.112  4329  4329 D LocBroadcastReceiver: Bearing: 0.0
09-19 10:56:51.114  4329  4419 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:51.119  4329  4329 D LocBroadcastReceiver: Begin evaluating if location update should be skipped
09-19 10:56:51.119  4329  4329 D LocBroadcastReceiver: Received location that is 103 milliseconds old, 1726736211016 compared to 1726736211119 with source fused
09-19 10:56:51.121  4329  4368 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:51.128  4329  4329 D LocBroadcastReceiver: Received location update.
09-19 10:56:51.134  4329  4329 D ForegrndServiceLauncher: Check if service HighAccuracyLocationService is running. Service running = false
09-19 10:56:51.135  4329  4419 D LocBroadcastReceiver: Last Location: 
09-19 10:56:51.135  4329  4419 D LocBroadcastReceiver: Coords:(51.224264, 4.4192893)
09-19 10:56:51.135  4329  4419 D LocBroadcastReceiver: Accuracy: 100.0
09-19 10:56:51.135  4329  4419 D LocBroadcastReceiver: Bearing: 0.0
09-19 10:56:51.135  4329  4364 D LocBroadcastReceiver: Last Location: 
09-19 10:56:51.135  4329  4364 D LocBroadcastReceiver: Coords:(51.224264, 4.4192893)
09-19 10:56:51.135  4329  4364 D LocBroadcastReceiver: Accuracy: 100.0
09-19 10:56:51.135  4329  4364 D LocBroadcastReceiver: Bearing: 0.0
09-19 10:56:51.138  4329  4419 D LocBroadcastReceiver: Begin evaluating if location update should be skipped
09-19 10:56:51.138  4329  4419 D LocBroadcastReceiver: Skipping old location update since time is before the last one we sent, received: 1726736211016 last sent: {9=1726736211106, 10=1726736211119}
09-19 10:56:51.138  4329  4364 D LocBroadcastReceiver: Begin evaluating if location update should be skipped
09-19 10:56:51.138  4329  4364 D LocBroadcastReceiver: Skipping old location update since time is before the last one we sent, received: 1726736211016 last sent: {9=1726736211106, 10=1726736211119}
09-19 10:56:51.186  4329  4329 D LocBroadcastReceiver: Not requesting accurate location, last accurate location was too recent
09-19 10:56:51.187  4329  4329 D ForegrndServiceLauncher: Check if service HighAccuracyLocationService is running. Service running = false
09-19 10:56:51.211  4329  4414 E SensorReceiver: Issue requesting updates for Meldingssensoren
09-19 10:56:51.211  4329  4414 E SensorReceiver: java.lang.NullPointerException: Attempt to invoke virtual method 'android.content.Context android.content.Context.getApplicationContext()' on a null object reference
09-19 10:56:51.211  4329  4414 E SensorReceiver: 	at android.content.ContextWrapper.getApplicationContext(ContextWrapper.java:152)
09-19 10:56:51.211  4329  4414 E SensorReceiver: 	at io.homeassistant.companion.android.sensors.NotificationSensorManager.updateActiveNotificationCount(NotificationSensorManager.kt:236)
09-19 10:56:51.211  4329  4414 E SensorReceiver: 	at io.homeassistant.companion.android.sensors.NotificationSensorManager.requestSensorUpdate(NotificationSensorManager.kt:102)
09-19 10:56:51.211  4329  4414 E SensorReceiver: 	at io.homeassistant.companion.android.common.sensors.SensorManager$DefaultImpls.requestSensorUpdate(SensorManager.kt:138)
09-19 10:56:51.211  4329  4414 E SensorReceiver: 	at io.homeassistant.companion.android.sensors.NotificationSensorManager.requestSensorUpdate(NotificationSensorManager.kt:25)
09-19 10:56:51.211  4329  4414 E SensorReceiver: 	at io.homeassistant.companion.android.common.sensors.SensorReceiverBase.updateSensors(SensorReceiverBase.kt:184)
09-19 10:56:51.211  4329  4414 E SensorReceiver: 	at io.homeassistant.companion.android.common.sensors.SensorReceiverBase$onReceive$3.invokeSuspend(SensorReceiverBase.kt:154)
09-19 10:56:51.211  4329  4414 E SensorReceiver: 	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
09-19 10:56:51.211  4329  4414 E SensorReceiver: 	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:104)
09-19 10:56:51.211  4329  4414 E SensorReceiver: 	at kotlinx.coroutines.internal.LimitedDispatcher$Worker.run(LimitedDispatcher.kt:111)
09-19 10:56:51.211  4329  4414 E SensorReceiver: 	at kotlinx.coroutines.scheduling.TaskImpl.run(Tasks.kt:99)
09-19 10:56:51.211  4329  4414 E SensorReceiver: 	at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:584)
09-19 10:56:51.211  4329  4414 E SensorReceiver: 	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:811)
09-19 10:56:51.211  4329  4414 E SensorReceiver: 	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:715)
09-19 10:56:51.211  4329  4414 E SensorReceiver: 	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:702)
09-19 10:56:51.219  4329  4414 D PressureSensor: Pressure sensor listener registered
09-19 10:56:51.224  4329  4414 D ProximitySensor: Proximity sensor listener registered
09-19 10:56:51.235  4329  4414 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:51.235  4329  4416 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:51.235  4329  4419 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:51.236  4329  4414 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:51.237  4329  4416 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:51.238  4329  4419 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:51.298  4329  4329 D ProximitySensor: Proximity sensor listener unregistered
09-19 10:56:51.337  4329  4419 D LocBroadcastReceiver: Location update sent successfully for 9 as exact
09-19 10:56:51.372  4329  4363 D LocBroadcastReceiver: Location update sent successfully for 10 as exact
09-19 10:56:51.440  4329  4329 D PressureSensor: Pressure sensor listener unregistered
09-19 10:56:51.474  4329  4414 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:51.752  4329  4363 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:51.754  4329  4414 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:51.985  4329  4414 I SensorReceiver: Sensor updates and sync completed
09-19 10:56:53.813  4329  4329 D ButtonWidget: Broadcast received: 
09-19 10:56:53.813  4329  4329 D ButtonWidget: Broadcast action: io.homeassistant.companion.android.widgets.button.ButtonWidget.CALL_SERVICE
09-19 10:56:53.813  4329  4329 D ButtonWidget: AppWidgetId: 29
09-19 10:56:53.814  4329  4329 D ButtonWidget: Calling widget service
09-19 10:56:53.818  4329  4329 D ButtonWidget: Service Call Data loaded:
09-19 10:56:53.818  4329  4329 D ButtonWidget: domain: switch
09-19 10:56:53.818  4329  4329 D ButtonWidget: service: turn_on
09-19 10:56:53.818  4329  4329 D ButtonWidget: service_data: {"entity_id":["switch.a4_slot_poortje"]}
09-19 10:56:53.821  4329  4329 D ButtonWidget: Sending service call to Home Assistant
09-19 10:56:53.823  4329  4329 D ServerConnectionInfo: localUrl is: false, usesInternalSsid is: false, usesWifi is: true
09-19 10:56:54.065  4329  4329 D ButtonWidget: Service call sent successfully
09-19 10:56:56.748  4329  4329 D ActivitySM: Received activity update.
09-19 10:56:59.791  4329  4378 W WM-Processor: Didn't find WorkSpec for id WorkGenerationalId(workSpecId=d9602b98-5bce-468f-93e8-591c0240f820, generation=0)
09-19 10:57:16.388  4329  4329 D WebviewActivity: Matter/Thread step changed to NOT_STARTED
6

Usually in cases like this it comes down to server setup. The main issue is that the app does not expect to get an error as such and these errors are only fixable on the client end. The app gets URLs and does not expect to get a timeout or any other error that the server may return (or not return).

now that you removed the local URL what URL do you see in the logs? The current logs you shared does not have teh traceback and therefore we cannot see what changed. You may need to replicate again to get a full traceback there.

have you also check HA core logs at the time of occurence to see if there was an issue there?

7

It this case the problem might well be DNS (in"t it always).
2 of the 3 configured servers use Tailscale as https proxy and can be reached by the same URL no matter where I am. My oldest instance I have a local reverse proxy running and and split DNS (so if on wifi it resolves to the local IP of the reverse proxy, if on mobile or somewhere else it it resolves to the external IP of the router with port forwarding etc…).
I’m thinking the problem might be DNS caching when switching networks going in and out the house. I’ll switch that instance to use it’s nabu casa URL in the app instead of the reverse proxy and check if that indeed fixes things…

8

sadly, DNS wasn’t the issue this time.
Behaviour is still the same. Full log here --------- beginning of main09-21 08:47:00.710 10875 10875 I mpanion.android: U - Pastebin.com
3 failed service call, open app, close app, 1 succesfull service call.
I have widgets linked for two of the configured servers and behaviour is the same no matter where I am or how I’m connected to the internet, independant on the active/selected server in the app.
I do see some “java.lang.NullPointerException: Attempt to invoke virtual method” in the log.

What can I try next?
You suggested to check HA core logs but from which of the 3 instances?

Unless you see something obvious in the logs I will remove 2 of the servers from the app and see if the issue is solved when I only have one server configured.

9

i am seeing all kinds of failures but still no actual traceback. I do see some timing out which suggests the server is not responding. In some cases we get no response and assume things like no zones. It appears all this fails after a 30 second time out.

09-21 08:47:01.499 10875 11014 E WebSocketRepository: Websocket: onFailure
09-21 08:47:01.516 10875 10875 E BeaconTransmitter: Advertisement start failed, code: 3
09-21 08:47:01.524 10875 10909 E TileExtensions: Unable to get state for tile
09-21 08:47:01.558 10875 11012 E LocBroadcastReceiver: Error receiving zones from Home Assistant
09-21 08:47:01.562 10875 11020 E LocBroadcastReceiver: Error receiving zones from Home Assistant
09-21 08:47:01.563 10875 11020 W LocBroadcastReceiver: No zones, skipping zone based location updates
09-21 08:47:01.563 10875 11006 E LocBroadcastReceiver: Error receiving zones from Home Assistant
09-21 08:47:01.565 10875 10875 I BeaconTransmitter: Advertisement start succeeded.
09-21 08:47:01.565 10875 10875 E WebSocketRepository: Unable to connect
09-21 08:47:01.565 10875 10875 W WebSocketRepository: Unable to send message, not connected: WebSocketRequest(message={type=subscribe_trigger, trigger={platform=state, entity_id=[switch.garagepoort_knop]}}, timeout=30000, eventFlow=kotlinx.coroutines.flow.ReadonlySharedFlow@44124c6, eventTimeout=0, onEvent=capacity=64,data=[], onResponse=null)
09-21 08:47:01.565 10875 10875 E WebSocketRepository: Unable to subscribe to subscribe_trigger with data {trigger={platform=state, entity_id=[switch.garagepoort_knop]}}

it also looks like an unknown host error is shown to the app which is another error the app cannot work around.

09-21 08:47:02.259 10875 10910 W SensorReceiver: Exception while updating sensors: IntegrationException: java.net.UnknownHostException

The one error you saw is safe to ignore and already fixed in the beta and completely unrelated to the issue you are seeing.

09-21 08:47:01.599 10875 10910 E SensorReceiver: java.lang.NullPointerException: Attempt to invoke virtual method 'android.content.Context android.content.Context.getApplicationContext()' on a null object reference