Not reporting away after Geographic Region Exited event

[jorgror]

Model Name: iPhone 6s
Software Version: 13.5.1
App version: 2020.1 (17)

Home Assistant Core Version
0.111

Describe the bug
The app does no longer report "away" as it sends Geographic Region Exited event. The possition first updates to away when an Background Fetch notices that the phone is outside any defined zones. This have been working for over a year.

To Reproduce
Travel outside a zone and the phone location still reports in that zone until I enter a new zone or a Background Fetch is triggered.
Expected behavior
The phone location should report away when I leave a zone.
Screenshots
In my log I see that the iPhone is changing directly from Home (Hjemme) to work (Høllen).

Last week this worked fine:

iPhone app settings:

[TomBrien]

Hi I can’t reproduce this on 2020.1. Can you check that if the longitude and latitude attributes are updating. It’s also possible another device tracker sensor has been created might be worth checking that.

[jorgror]

I added a map to lovelace with device tracking for iPhone. I could not see a clear difference between the last two days (today and yesterday) when the device tracking does not work and days last week when the device tracking was working as expected.

If anything there might be more of a direct route between my home zone and work zone the last two days and maby more points just outside the home zone the previous week. But if I check my travel home today there is clearly a point just outside work zone right after I leave the work zone and the device still say that it was at work until I arrive at home.

[jorgror]

This is my moring commute today. There is clearly a GPS point outside my home zone, but the app reported home until I arrived at work.

[TomBrien]

How long does your commute take. With that being a single point I wonder if the away time is very small short and hidden in the plot. If you mouse over the Home segment and the Work segment do the times line up?

[jorgror]

The comute is 35 minutes. The zone is changing instant from home to work. This was not an issue last week or the last year for that matter. See the screenshot in first post for how it used to look.

[TomBrien]

This is very strange, those plots are generated by Home Assistant itself and I believe the attribution of the zone name is also handled by Home Assistant. Have you installed any add on (or indeed Home Assistant update) between when it was working and the current situation. Do you track any other devices and are they working?

[jorgror]

I updated my Home-Assistant over the weekend. The app also recieved an update. I will test to see if I manage to narrow down the issue by using other devices (my iPad) and downgradeing Home Assistant Core to a version I know it was working (0.110).

I do belive that the app is responsible for sending in and out of zone alerts using the iOS API and not beeing based on gps location for decideing if phone is inside zone or not. If I recall correctly this was atleast the case in app version 1.0 that did not report gps coordinates, just enter and leave zone alerts.

[TomBrien]

Yep the phone sends the in and out of Zone notices but it should just send locations the rest of the time. Can you check the following:

• Your background permissions for the app in iOS settings
• In iOS Settings>Home Assistant>Location that this is set to Always
• In the App's "App Configuration" menu under location "location" check all the update sources are enabled.

[jorgror]

I have looked more into this today. I tried walking my iPad but it did not trigger any location update (might be due to my shared internet from iPhone being unreliable).

I did notice something interesting though. The phone does send a zone-exit notice that home assistant picks up at the correct time when I leave a zone, but there is no change to "away" before a background fetch picks up that I'm outside the zone.

The following screenshots show my activity today. I leave work (Høllen) at 3:55:14 PM. I do not drive directly home, but do some shopping. At 4:26:09 PM there is a background fetch which notices that I'm no longer at work. I get home at 6:37:38 PM and the state changes to home as I enter my home-zone with Geographic Region Entered event. I later do a short walk outside my home-zone. There is a trigger that I leave home at 8:24:49 PM and a trigger that I enter home again at 8:37:04 PM but the device tracker is not updated to away when I leave so it just stays home for the walk.

For me it is important that the zone updates to away as soon as I leave a zone as many automations and also a work hours implementation I have created is dependent on instant updates. This has been working as intended for more than a year with both app version 1 and 2 on the same phone. The issue started sometime last weekend. I will try to downgrade Home-Assistant to 0.110 as I know that it worked in that version. I will report back tomorrow if that fixed the issue.

[jorgror]

I tested with Home Assistant 0.110.7 today. There is no difference regarding this issue.

[zacwest]

@jorgror Can you look in the in-app Settings > Event Log, do you see events like "current location delivery…" do you see these corresponding at the times you see the region exit events? Tap on them - can you match them up to whether the lat/long specified is within or without the zones?

[andyzickler]

I am having the same problem. I am seeing Phone Last Update Trigger changed to Geographic Region Exited in the HA Logbook and related entries in the app Event Log. However when looking at the payload for Home Exited the location is about a km away with a gps_accuracy of 2500. In fact i'm also seeing some entries that say Ignoring location with accuracy over threshold.Accuracy:2500.0m
I do get the phone notification at the correct location when i exit my Home zone.

Location Permission is set to Always. Motion Permission and Background Refresh are set to Enabled.

[jorgror]

Thanks for the tip about checking the logs from the app. I have pasted my complete log from todays morning commute where again the device_tracker in Home-Assistant did not register me leaving my home. From what I can read the app seems to correctly wake up and send update when I leave home at about 07:06. The location state is not updated in home assistant. I also have the same error message as @andyzickler: 'Ignoring location with accuracy over threshold.Accuracy: 1000.0m;' But I'm not sure if this matters, as location enter (at 07:33) has a similar error and that is correctly registered for device tracker in home assistant when I arrive at work.

https://gist.github.com/jorgror/5aa722d9cdf20a99c5eb365a7b0b574e

[kvermilion]

I've noticed that device_tracker entity associated with the app no longer gets set to "away" when I am out of the designated area, which it used to do very reliably. I had not made any changes on the Home Assistant side in quite a while before this started happening. The only zone I have defined is home, and when returning to that zone, the updates do happen automatically.

I noticed that pulling down to manually send an update works, but it appears that the automatic updates never happen.

I was very confident that this is a bug in the app introduced in a version my phone downloaded in the past few weeks--6/10 or a few days previous--however according to the app store, I see releases on 6/17, 6/12 and last year, so It really does not seem to be caused by a change in the app, then... maybe it was caused by an iOS update?

Phone is an iPhone 8 Plus (NQ962LL/A) running 13.5.1
App is 2020.2 (5)

[zacwest]

@kvermilion Can you also take a look at your logs as described above - are you seeing 'exited' events with very bad accuracy (1km+) at the same time you expect to go away?

My hunch is that, like other 13.4 location issues, Apple is now providing a lot less accurate locations as the result of various location events unless we request the system give us higher accuracy. It doesn't seem like the app's behavior has changed, just that the locations delivered automatically are less accurate.

[kvermilion]

@kvermilion Can you also take a look at your logs as described above - are you seeing 'exited' events with very bad accuracy (1km+) at the same time you expect to go away?

Yes, I am seeing those messages.

Do you think that this change in iOS can be mitigated in the app?

[zacwest]

I'm hopeful that it can be mitigated, but whether we can do it in a battery-efficient way will be an interesting experiment. We can actively turn on the GPS and request a better location, but if we're told "we existed this region with 1km accuracy" and you're <1km from the region, we can't really be sure you exited otherwise.

[kvermilion]

It's kind of interesting that the entry to zone does appear to get picked up, despite the (lack of) accuracy:

2020-06-23 08:05:21.432 [Info] > Rotated file /private/var/mobile/Containers/Shared/AppGroup/EF488EBA-1395-4C52-A737-041DCF1EB9D5/logs/log.txt to /private/var/mobile/Containers/Shared/AppGroup/EF488EBA-1395-4C52-A737-041DCF1EB9D5/logs/log_2020-06-23_080521.txt
2020-06-23 08:05:21.437 [Info] > Home Assistant Version: 2020.2 Build: 5 PID: 10775
2020-06-23 08:05:21.437 [Info] > XCGLogger Version: 7.0.1 - Level: Debug
2020-06-23 08:05:21.438 [Info] > XCGLogger writing log to: file:///private/var/mobile/Containers/Shared/AppGroup/EF488EBA-1395-4C52-A737-041DCF1EB9D5/logs/log.txt
2020-06-23 08:05:21.457 [Info] [main] [ClientEventStore.swift:23] ClientEventStore > ClientEvent {
	date = 2020-06-23 15:05:21 +0000;
	text = Submitting location for zone zone.home with trigger Geographic Region Entered.;
	typeString = locationUpdate;
	jsonData = <(null) — 0 total bytes>;
}
2020-06-23 08:05:21.462 [Verbose] [main] [RegionManager.swift:243] locationManager(_:didUpdateLocations:) > didUpdateLocations [<private> +/- 2500.00m (speed 0.00 mps / course 0.00) @ 6/23/20, 7:54:50 AM Pacific Daylight Time]
2020-06-23 08:05:21.467 [Info] [main] [ClientEventStore.swift:23] ClientEventStore > ClientEvent {
	date = 2020-06-23 15:05:21 +0000;
	text = Ignoring location with accuracy over threshold.Accuracy: 2500.0m;
	typeString = locationUpdate;
	jsonData = <(null) — 0 total bytes>;
}
2020-06-23 08:05:21.468 [Info] [main] [HAAPI.swift:479] SubmitLocation(updateType:location:zone:) > Location update payload: ["gps_accuracy": 100.0, "gps": [private], "battery": 91]
2020-06-23 08:05:21.496 [Verbose] [main] [WatchHelpers.swift:85] BuildWatchRenderTemplatePayload() > complications Results<WatchComplication> <0x1047286f0> (

)
2020-06-23 08:05:21.497 [Verbose] [main] [WatchHelpers.swift:91] BuildWatchRenderTemplatePayload() >     mostRecentlyReceievedContext.content
    nil []
2020-06-23 08:05:21.497 [Verbose] [main] [WatchHelpers.swift:130] updateComplications() > No complications have templates, not sending the request!
2020-06-23 08:05:21.985 [Verbose] [main] [HAAPI.swift:495] SubmitLocation(updateType:location:zone:) > Device seen via webhook!
2020-06-23 08:05:21.995 [Info] [main] [ClientEventStore.swift:23] ClientEventStore > ClientEvent {
	date = 2020-06-23 15:05:21 +0000;
	text = Home entered;
	typeString = locationUpdate;
	jsonData = <length = 24, bytes = 0x7b0a2020226770735f616363757261637922203a20313030 — 109 total bytes>;
}
2020-06-23 08:05:21.997 [Verbose] [main] [AppDelegate.swift:876] setupFirebase() > Logging event location_update to analytics
2020-06-23 08:05:22.010 [Info] [main] [ClientEventStore.swift:23] ClientEventStore > ClientEvent {
	date = 2020-06-23 15:05:21 +0000;
	text = Succeeded updating zone zone.home with trigger Geographic Region Entered.;
	typeString = locationUpdate;
	jsonData = <(null) — 0 total bytes>;
}
2020-06-23 08:05:22.035 [Info] [main] [ClientEventStore.swift:23] ClientEventStore > ClientEvent {
	date = 2020-06-23 15:05:22 +0000;
	text = EndBackgroundTask: zone.home-GPSRegionEnter-2020-06-23 15:05:21 +0000;
	typeString = locationUpdate;
	jsonData = <(null) — 0 total bytes>;
}

Maybe I can work around this in my Home Assistant configuration by adding zones surrounding my home called "Away."

[jorgror]

@zacwest Why would we need accurate gps to update the position to away? iOS trigger the app by telling it that the phone have left the zone. Can’t we just trust this? It seems very reliable in my case.

[kvermilion]

@jorgror, the problem as I understand it is that the reported accuracy is so poor, it cannot be determined whether the phone has actually left the zone. For example, if your zone is 100m radius and your reported location is 500m from the center, but accuracy is 1000m, the phone could well be in the zone. Accepting such location updates could lead to spurious zone leaving events.

[jorgror]

If the zone updates were so bad that we could not trust them, I would agree. But do we have any proof that’s the case. I’m pretty sure that v1 of the app never used gps coordinates, and that was very accurate when entering and leaving zone. Apple uses similar zones in their app to alert when leaving and entering. It would anyways be better to trust Apple if the GPS accuracy is to low to be certain, because for me today it does not work good at all.

One interesting thought is that there is no recent change to the app or home assistant that has been linked to this bug. Could the inaccuracy be in iOS intentional by Apple to increase user privacy?

[kvermilion]

One interesting thought is that there is no recent change to the app or home assistant that has been linked to this bug.

I agree. I believe that it was an iOS update (13.5.1 is my guess) that the caused the behavior change, since neither an app or Home Assistant update correlates with the behavior change. They probably did some work on the background location services in order to support their new Exposure Notification API.

I also agree that ignoring the GPS coordinates and their accuracy if the zone events are accurate would preferable.

[zacwest]

Digging through the logs a bit, it's worth focusing on the Location update payload that happens after any region exit -- no matter what the location accuracy, the current location is reported when a region exited event is encountered. From the logs above, nothing's being held back there.

I'm looking specifically at @jorgror's logs for this timeline. (Thank you for attaching logs. You might want to delete that Gist or otherwise redact the lat/long inside for privacy reasons.)

1. 2020-06-22 07:06:51.020 wake
2. 2020-06-22 07:06:51.983 told exited zone.home
3. 2020-06-22 07:06:52.233 submitted location from exiting, accuracy 2500 (actual: 1822 from center)
4. 2020-06-22 07:06:53.325 completed location update network request
5. 2020-06-22 07:35:31.192 told entered zone.hollen
6. 2020-06-22 07:35:31.204 submitted location from entering, accuracy 250
7. 2020-06-22 07:35:31.865 completed location update network request

Given this, I would expect the device tracker would have reported that you were 'away' with the 07:06 time update. As far as I can tell, there's no reason to believe the app is misbehaving in this instance.

---

Hypothesis 1: The network request errored out server-side

@jorgror (or anybody else really) Can you check if there is a webhook location update in the logs at the timestamp we think we're submitting the network request, the next time this happens? You'll likely need to increase your log level:

logger:
  logs:
    homeassistant.components.mobile_app: debug

Hypothesis 2: The device tracker logic (core-side) is incorrect

Can you answer a few questions for me:

1. Do you have any device trackers set up for your person that aren't the iOS app? For example, the icloud one?
2. Can you pull the history of your device_tracker entity? We'll do this using the API:

curl -X GET -H "Authorization: Bearer TOKEN_FROM_PROFILE" \
  -H "Content-Type: application/json" \
  "http://localhost:8123/api/history/period/2020-06-22?filter_entity_id=device_tracker.YOUR_DEVICE_NAME"

(replace the TOKEN_FROM_PROFILE with a "Long-Lived Access Tokens" from your profile, YOUR_DEVICE_NAME to complete the entity id, and 2020-06-22 with the date (if it is different).

With that: do you see updates we expect from the network requests above (or for other people: from your own logs)?

[zacwest]

Following the chain of Hypothesis 2: I think the accuracy getting worse here is causing the issue, but not client-side.

The logic in core for deciding whether you're in a zone looks like:

within_zone = zone_dist - radius < zone.attributes[ATTR_RADIUS]
# within_zone = 1822 [actual distance] - 2500 [accuracy] < 100 = -678 < 100 = True

Since this is deciding you're inside the radius for being -678 meters inside of it, it's not marking you as not_home.

The thing is: I'm not sure this is wrong. It's likely protecting poor location updates from drifting the user out of a zone when they are already in it. Right now, the code biases towards being within a zone. GPS drift, poor connectivity to cellular or the GPS satellites, can cause you to drift in a pattern that looks a lot like what's happening here.

[zacwest]

Oh and re: entry working -- it looks like the app ignores accuracy for enter events and sets your location as being directly within the zone. For some, this is not a feature but a bug, see #404 and #178 for discussion on that one. There's probably some things we can do to fluff this number (set accuracy to distance_from_outer_radius - 1 or something) but i'm worried about potential cascading side effects of ignoring the accuracy number we're given.

The big questions here become:

• How accurate is the "you exited" part of the region monitoring? Can we completely rely on Apple's notification here? I have reminders set up for geographic regions in my phone, and I definitely get them occasionally inaccurately.
• How much battery use would it be to spin up the GPS when entering/exiting a region? That doesn't seem like a super common event. Can we work around this by using concentric regions and deal with multiple regions validating each other?

[jorgror]

Researching a little bit, Apple does suggest buried in other documentation, that the location associated with entry/exit events shouldn't be trusted without pulling actual GPS:

The monitoring techniques described below provide entry and exit notifications only. To determine the user’s actual location when a notification is received, you must call the requestLocation: or startUpdatingLocation: method of the location manager object.

So there is two alternatives then:

• Pull GPS
• Send fake coordinates which we know Home-Assistant would accept as outside the zone.

[kvermilion]

For what it is worth, my workaround of surrounding my home with zones worked this morning, which makes sense given the zone entry behavior that @zacwest described:

the app ignores accuracy for enter events and sets your location as being directly within the zone

It sounds like the fix is going to be to request a GPS location after the exit & entry events happen in order to get a (hopefully) more accurate location, it sounds like spurious exit events are not too common so impact on battery life should not be significant.

I recall several months ago that I would occasionally notice that I would be reported as home when ~500m away from the zone, but it didn't cause an impact given my use case, so I shrugged it off. The change might fix that behavior and make ignoring accuracy for enter events no longer necessary as well, again assuming that the location given after calling requestLocation or startUpdatingLocation is accurate.

[jorgror]

Hypothesis 1: The network request errored out server-side

@jorgror (or anybody else really) Can you check if there is a webhook location update in the logs at the timestamp we think we're submitting the network request, the next time this happens? You'll likely need to increase your log level:

logger:
  logs:
    homeassistant.components.mobile_app: debug

I have recorded a new incident of device_tracker not updating to away when I leave a zone. This time I also have logger-logs with mobile_app: debug. This time i left at about 19:35 (17:35 in UTC) and arrived back home at 21:25.

State changes (from rest api): https://gist.github.com/jorgror/1af57876f000edcad1d284a4334bbc22
App logs: https://gist.github.com/jorgror/3cdd09042f51528967291e1fc5d66abf
Logger logs (docker logs home-assistant 2>&1 | grep homeassistant.components.mobile_app ): https://gist.github.com/jorgror/cbdd373a6b16f967b4553445591c5cee

[zacwest]

Thanks for the logs @jorgror - I think we can safely confirm the app is sending the information to the server, but the accuracy is causing the behavior problem.

[zacwest]

I told the commit to close this, but I want to validate it before actually closing it, so I am reopening.

A new beta of 2020.3 should be going out in a few hours which will includes the above change; please grab the latest beta and give it a try when you can.

[jorgror]

I told the commit to close this, but I want to validate it before actually closing it, so I am reopening.

A new beta of 2020.3 should be going out in a few hours which will includes the above change; please grab the latest beta and give it a try when you can.

I signed up for TestFlight, but I can not see a new build.

[TomBrien]

A build started last night but it can take a little while to be processed by Apple. I would expect it to go come out at some point today depending on Robbie's availability

[ntilley905]

Very small dataset here, but after updating to the new build which includes this fix, I got my first correct state update since this issue began. For me this worked!

[andyzickler]

Hmm I tried the beta and am still getting poor accuracy. I do have Use In-Development Updating set to true, but is there some other step i need to do? I only went for a short walk out of the zone and back, but tomorrow i'll be out longer and try again.

[zacwest]

@andyzickler I believe you are on a older build of the beta app. Please double check you are on 2020.3 (3).

[andyzickler]

Just checked on the about page and I am on 2020.3 (3)

[andyzickler]

Success this time!
I'm not sure if this was needed, but i closed and restarted the app (I had Use In-Development Updating set already, but wasn't sure if it only took affect on restart) Then today the log for the exited home event did have a good accuracy

[zacwest]

Oh yeah, it does require restarting the app to switch over, I forgot about that. Glad it's working better for you now!

[jorgror]

I got around to test the new Test Flight app 2020.3 (4) with "In-Development Updating" enabled. I did notice some change in behavior, but not as good as before the issue. This time I left at 07:07. The first update did (region_exit) did not update my location to away, but a new update (significant position change) at 07:18 did set the device to away.

Logs:
device tracker: https://gist.github.com/jorgror/a17f9bee7e61c532b90b88a34a6d49c3
home-assistant mobile_app logs: https://gist.github.com/jorgror/b40e7fbf8ba90bfc230cd714e4c21fbd
app logs: https://gist.github.com/jorgror/b2dfe7f37dcdfa8b0ca30e879668bb45

[zacwest]

Thanks again for the logs! It looks like we waited a while but never got a more accurate location from the system. I've just done #719 to see if the distance filter is the cause; the next build should help us out there. So more logs once (5) comes out please!

If we still don't see an improvement to accuracy with that and I can't think of anything else, I'll add logic in that (with poor accuracy) just reports in-or-out status for the region. The big unknown is still how accurate/reliable these region entry/exit events are.

[kvermilion]

The beta versions have been working well for my use case so far. I'll continue to monitor.

[zacwest]

2020.3+ should have greatly improved the In-Development Updating setting, and its improvements are now enabled by default for future releases. Considering this issue (thematically) closed. Please join us in Discord or create a new GitHub issue to report future instances of poor location accuracy on 2020.3+ with the setting on, or 2020.4+.

[kvermilion]

Somehow, it looks like it is back.

I downloaded a new beta on either Friday (sometime after the morning) or Saturday (in the morning) which seems to have made the app location stop updating to "away."

I also gave 2020.3.1 a go, and saw the same behavior.

Here's a gist of my log running 2020.4 Build: 3 from Sunday morning. I left home a bit before 7am and returned a bit before 8am: https://gist.github.com/kvermilion/5470507da6aa8c82e326139e49970ded

It was very reliable before Saturday... and Saturday I was away for around 12 hours without the app being marked away.

Edit: just taking a quick look at the release notes, it seems that this is plausibly caused by: 5431a12

[zacwest]

@kvermilion Could you restart your phone and see if the issue crops up again? It appears there is an iOS bug that will get it stuck with poor location accuracy until a restart, at which point it does return to normal.

[kvermilion]

@zacwest 2020.3.1 (1) seems to be working after restarting my phone. I'll keep that in mind in the future. Thanks!