Open wbyoung opened 1 month ago
dshokouhi
commented
1 month ago For troubleshooting location updates from android first ensure that you have tracking setup properly, next check location tracking history. The app sends 1 update at a time. However the server processes those updates is beyond scope for teh app. Please provide location tracking history and logs from the app to show the issue you are experiencing.
steps and how to access location history are mentioned in the link above.
wbyoung
commented
1 month ago I'm having a hard time seeing this through all the abstractions—I don't see the request being sent and waiting for the server response nor anything that clearly shows there's a queue of requests being processed. (Care to help me understand it at all?)
I know it's possible my phone sends bad location data, but it seem unusual for this issue to appear cross-platform.
I've tried loading logs from the app, but I usually don't catch it in time (since I'm driving), and the logs that appear in the app seem to be truncated to only the last few minutes.
dshokouhi
commented
1 month ago I don't see the request being sent and waiting for the server response nor anything that clearly shows there's a queue of requests being processed. (Care to help me understand it at all?)
the location tracking history will be kept for 48 hours and should help you understand how often reports are sent to the server, the logs dont go back far enough but history should be helpful here.
wbyoung
commented
1 month ago Oh, I've also looked at the location history and seen that it's not sending stale data as part of the updates.
But that's not the issue I'm suggesting exists here. Knowing that a location change is valid at time X and sending it is fine. But if another happens at time Y and enough time has passed to consider that update not stale as well, then both updates get sent.
If the app ensures these are sent in sequence, then I can't imagine a race condition scenario. But if they're sent in parallel (Y is sent before ensuring X completed or failed), then there's a possible race condition at play. Y could reach the server before X.
dshokouhi
commented
1 month ago But that's not the issue I'm suggesting exists here. Knowing that a location change is valid at time X and sending it is fine. But if another happens at time Y and enough time has passed to consider that update not stale as well, then both updates get sent.
If the app ensures these are sent in sequence, then I can't imagine a race condition scenario. But if they're sent in parallel (Y is sent before ensuring X completed or failed), then there's a possible race condition at play. Y could reach the server before X.
all of that logic is in the same function actually, we evaluate the location report timestamp and compare that with what was last received and sent.
if you feel there is still a race condition you will be able to see that in the app and HA core debug logs
wbyoung
commented
1 month ago The time check that's in there is theoretically not enough to prevent a race condition. Again, I'm discussing an issue that's networking related rather than based on the order in which things happen within the app. And I'm guessing that ioScope.launch is starting an asynchronous job, so it seems that two calls to serverManager(latestContext).integrationRepository(serverId).updateLocation(updateLocation) can be in flight at once (but usually at least 5 seconds apart). That does not mean that the first request will make it to the HA server first. 5 seconds is obviously a long time for computers, but when network conditions are poor (such as mobile networks), request timeout can take a really long time. According to this Stack overflow post, the socket timeout is 60 seconds, but that is just the maximum period inactivity between two consecutive data packets. That means that when the update location request happens it could be:
I also believe that (based on reading the code), there's another race condition that allows update requests to happen faster than 5s apart (even when the requests may be received in order):
lastLocationSend[serverId] for request A now that it's completelastLocationSend[serverId] for request B now that it's completeIgnoring all of the above right now, I found that in my case, the issues seem to be arriving from getting all three possible update types to occur nearly simultaneously: background update, geofencing, and single precise location. According to the location history view in the companion app, these are all sent in the same second.
It appears that geolocaiton updates also skip the 5 second debounce based check.
Case 1
Update A and B are sent during the same second.
I don't have the server logs, but I do have it set up so I get an automation trace for each update. These arrived out of order to the server.
Side note: In case it matters, the sequence of steps to get to that trace are: a trigger based sensor that uses an action to pre-compute some values and fires off an event with the info I want recorded in the automation trace. The automation just listens for that event (so I can debug the trigger based sensor). Regardless, this theoretically all happens in order, but that's based off of my observations using HA and not a deeper knowledge. Also, the original trigger values are captured in these traces, so it's easy to see the from_state and to_state match a given set of GPS coordinates and verify the order by checking the from_state matches the previous to_state.
First update received:
platform: state
entity_id: person.wbyoung
time_fired: '2024-10-04T01:28:14.796263+00:00'
from_state:
state: Area Name
attributes:
editable: true
id: wbyoung
device_trackers:
- device_tracker.pixel
latitude: PRIOR_LAT
longitude: LRIOR_LNG
gps_accuracy: 3
to_state:
state: Area Name
attributes:
editable: true
id: wbyoung
device_trackers:
- device_tracker.pixel
latitude: B_LAT
longitude: B_LNG
gps_accuracy: 2Second update received:
platform: state
entity_id: person.wbyoung
time_fired: '2024-10-04T01:28:14.930057+00:00'
from_state:
state: Area Name
attributes:
editable: true
id: wbyoung
device_trackers:
- device_tracker.pixel
latitude: B_LAT
longitude: B_LNG
gps_accuracy: 2
to_state:
state: Area Name
attributes:
editable: true
id: wbyoung
device_trackers:
- device_tracker.pixel
latitude: A_LAT
longitude: A_LNG
gps_accuracy: 3Cases 2-5
These all arrived in the order that they were sent from the companion app. They, however, were all sent so close in time that every one of them had me jump backwards a bit like this (taken from the map):
So they're more of an issue of sending multiple updates within 5 seconds of each other (probably partly because some are geofence updates and probably partly because the last sent isn't recorded until after the request succeeds).
dshokouhi
commented
4 weeks ago ok can see why you opted to file a core bug, ultimately for the app I am not sure this is going to be doable. We have a lot of logic in place for the current features and until this moment we have not heard complaints from any users.
5 seconds is actually the default interval for high accuracy mode so that cannot be changed.
For webhooks we have a 30 second timeout actually.
All of the logic currently in place should not be changed as it will lead to other issues. Another things to consider, there is no historical data allowed so the app must assume we are always sending the latest data to the server and that it is being accepted.
wbyoung
commented
2 weeks ago Ok, well I believe I've worked around the issue with what I'm working on, but I believe there are certainly still at least one obvious issue that can result in several changes being sent at the same time instead of actually having a 5 second gap.
I understand the complexity of all of this stuff, and maybe it'd be better not to fix & just leave it the way it is for simplicity. It's solved for the 90%, maybe not north the last 10% (which I'm certainly part of for what I'm using it for).
I'll leave it open in case someone else wants to discuss, but I'll let the bot close it if there's no more future discussion.
Home Assistant Android app version(s): 2024.9.4-full
Android version(s): 14, security update from September 5th, 2024
Device model(s): Pixel 7
Home Assistant version: core-2024.10.0
Last working Home Assistant release (if known):
Description of problem, include YAML if issue is related to notifications:
It seems as though location updates are sent asynchronously to the HA server and that they may arrive out of order. I briefly looked at the code base, but there are several layers of abstraction going on which is making it hard for me to verify that they are indeed sent asynchronously.
I reported this in https://github.com/home-assistant/core/issues/126972 where there is a lot more detail about the issue I experienced and also a possible fix.
Companion App Logs:
Screenshot or video of problem:
Additional information: