Trip end notifications needs to be tweaked to be more meaningful #372

shankari · 2019-04-12T05:17:02Z

@asiripanich reports in e-mission/e-mission-phone#517 that

very often when I wait to cross the app registers that my trip has ended.

@ipsita0012 also reports similar issues

Let's use this issue to track what is going on and whether we can add simple configurable checks to the transition notification code to reduce the incidence of these false positives

shankari · 2019-04-12T05:18:12Z

@asiripanich

first, do you see this behavior on android or on iOS? android is a lot more configurable wrt this behavior than iOS

I know that @ipsita0012 is on iOS

shankari · 2020-08-14T23:05:23Z

@JackBikes if you send me the logs and the rough time that this happened - e.g. "here are the logs, and this happened around 3pm MDT on 12th Aug", I can see what happened and come up with some ideas on how to fix it.

asiripanich · 2020-08-14T23:35:34Z

@asiripanich

first, do you see this behavior on android or on iOS? android is a lot more configurable wrt this behavior than iOS

I know that @ipsita0012 is on iOS

mine was on iOS

shankari · 2020-08-15T04:12:32Z

I think @JackBikes is also on iOS. Maybe this is mainly a problem with iOS? I haven't seen this yet on my iOS test phones, but if somebody sends me logs and times, I'm happy to investigate.

JackBikes · 2020-08-15T16:18:16Z

I am on iOS, just to confirm.

…

On Aug 14, 2020, at 10:12 PM, shankari ***@***.***> wrote: I think @JackBikes is also on iOS. Maybe this is mainly a problem with iOS? I haven't seen this yet on my iOS test phones, but if somebody sends me logs and times, I'm happy to investigate. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or unsubscribe.

shankari · 2020-08-25T04:46:35Z

so @JackBikes sent me his logs and I took a look. Many of the trips are correct, but I persistently see a pattern in which we get the VISIT_ENDED and VISIT_STARTED notifications with the same timestamp - e.g.

723,1597147042.38541,2020-08-11T05:57:22.385410-06:00,"In TripDiaryStateMachine, received transition T_VISIT_ENDED in state STATE_ONGOING_TRIP"
729,1597147042.4176302,2020-08-11T05:57:22.417630-06:00,"In TripDiaryStateMachine, received transition T_VISIT_STARTED in state STATE_ONGOING_TRIP"

I have also seen this as part of the MobilityNet dataset (Figure 7.3 (top) and Table 7.4), so it does happen periodically. I can think of a couple of fixes:

A potential fix is to suppress the T_VISIT_STARTED transition if it occurs within a small delta of the T_VISIT_ENDED.
A second potential fix is to not change the state if we get a too quick transition, and also not display the notification if the trip duration is too small.

Looking at the data from @JackBikes, a reasonable definition of "small delta" would be 1 min. While most of the short lived trips are under a second, I do see this as well

2958,1597405106.7088802,2020-08-14T05:38:26.708880-06:00,"In TripDiaryStateMachine, received transition T_VISIT_ENDED in state STATE_ONGOING_TRIP"
2967,1597405142.6610699,2020-08-14T05:39:02.661070-06:00,"In TripDiaryStateMachine, received transition T_VISIT_STARTED in state STATE_ONGOING_TRIP"

Let's try with one minute and see what happens.

shankari · 2020-08-25T05:08:15Z

The problem with (1) is that it the T_VISIT_STARTED transition does not have any state, so it does not know when the T_VISIT_ENDED transition occurred. We do store some state in the state machine, so let's try to change based on (2).

shankari · 2020-08-25T05:18:22Z

We need to be a bit careful about which transitions to check against. If we look more closely at the first example in #372 (comment)

We actually got the geofence exit ~ 15 mins before the VISIT_ENDED notification

686,1597146582.0006099,2020-08-11T05:49:42.000610-06:00,Received platform-specific notification T_EXITED_GEOFENCE
693,1597146582.05276,2020-08-11T05:49:42.052760-06:00,Received platform-specific notification T_TRIP_STARTED
695,1597146582.0690699,2020-08-11T05:49:42.069070-06:00,Moved from STATE_WAITING_FOR_TRIP_START to STATE_ONGOING_TRIP

715,1597147042.3582,2020-08-11T05:57:22.358200-06:00,"Received visit notification = <+39.73087073,-105.03116972> +/- 92.76m (2020-08-11 03:44:32 +0000 to 2020-08-11 11:50:19 +0000)"
723,1597147042.38541,2020-08-11T05:57:22.385410-06:00,"In TripDiaryStateMachine, received transition T_VISIT_ENDED in state STATE_ONGOING_TRIP"

And then we got a visit started just after that. So comparing VISIT_ENDED and VISIT_STARTED would be a valid check but not TRIP_STARTED

724,1597147042.39379,2020-08-11T05:57:22.393790-06:00,"Received visit notification = <+39.72744342,-105.03121412> +/- 89.09m (2020-08-11 11:50:20 +0000 to -)"
729,1597147042.4176302,2020-08-11T05:57:22.417630-06:00,"In TripDiaryStateMachine, received transition T_VISIT_STARTED in state STATE_ONGOING_TRIP"
731,1597147042.42965,2020-08-11T05:57:22.429650-06:00,Received platform-specific notification T_TRIP_END_DETECTED

We have two choices - we can either cache the timestamp of the last VISIT_ENDED or just retrieve it from the DB. Retrieving it from the DB is easier and is not that challenging wrt performance, since we only do it when we receive a VISIT_STARTED. We can cache later for better performance.

shankari · 2020-08-25T05:22:37Z

Actually, we do a lot more checking against prior entries in the Delegate, not the state machine, so maybe (1) is actually a better choice.

shankari · 2020-08-25T05:38:11Z

Actually, no because we want to preserve all the raw data in case we want to change the logic (e.g. definition of "small delta") later. Generate the transition and deal with it correctly in the FSM by having the new state == currState.

shankari · 2020-08-25T06:13:36Z

Implemented and briefly tested in the emulator. Don't actually see this in the real world myself so will wait for @JackBikes to test once I push tomorrow.

JackBikes · 2020-08-25T15:27:18Z

Thanks for the updates, Shankari! Look forward to seeing the updates. Jack Todd Director of Communications and Policy, Bicycle Colorado Pronouns: he/him/his 1525 Market Street, Suite 100 Denver, CO 80202 Cell: (303) 523-4231 bicyclecolorado.org <https://www.bicyclecolorado.org/bike-news/social-justice/>

…

On Tue, Aug 25, 2020 at 12:13 AM shankari ***@***.***> wrote: Implemented and briefly tested in the emulator. Don't actually see this in the real world myself so will wait for @JackBikes <https://github.com/JackBikes> to test once I push tomorrow. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#372 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AQTXBKOZRMUUAWVCKKHFXJTSCNJB3ANCNFSM4HFNMD6A> .

shankari · 2020-09-01T00:27:34Z

As feared, this fixed caused some real fixes to be missed:
ios_sunday_focus.gz

The trip to the park was sort of fine, except that it actually took closer to 5 mins and not 20.

3922,1598814180.49461,2020-08-30T12:03:00.494610-07:00,"In TripDiaryStateMachine, received transition T_EXITED_GEOFENCE in state STATE_WAITING_FOR_TRIP_START"
4273,1598815204.4778302,2020-08-30T12:20:04.477830-07:00,"In TripDiaryStateMachine, received transition T_TRIP_END_DETECTED in state STATE_ONGOING_TRIP"

Then, the trip departure was detected at 12:23, and we received the VISIT_STARTED ~ 5 mins later.

4330,1598815390.82127,2020-08-30T12:23:10.821270-07:00,"In TripDiaryStateMachine, received transition T_EXITED_GEOFENCE in state STATE_WAITING_FOR_TRIP_START"

4480,1598815646.3722901,2020-08-30T12:27:26.372290-07:00,"In TripDiaryStateMachine, received transition T_VISIT_ENDED in state STATE_ONGOING_TRIP"
4494,1598815691.34361,2020-08-30T12:28:11.343610-07:00,"In TripDiaryStateMachine, received transition T_VISIT_STARTED in state STATE_ONGOING_TRIP"

But it was too soon after the VISIT_ENDED, so we never stopped the trip.

4495,1598815691.40768,2020-08-30T12:28:11.407680-07:00,"Invalid visit started transition: visitStartT.transition = T_VISIT_STARTED, visitEndT.transition = T_VISIT_ENDED,deltaTs = 44.964533"

shankari · 2020-09-01T00:28:10Z

Couple of questions:

why aren't we getting the silent push notifications? I don't see anything in this time range

4927,1598835183.12004,2020-08-30T17:53:03.120040-07:00,"Recieved location <> +/- 5.00m (speed 0.45 mps / course 9.14) @ 8/30/20, 5:53:02 PM Pacific Daylight Time, ongoing trip = true"
4928,1598864704.0857198,2020-08-31T02:05:04.085720-07:00,"Recieved location <> +/- 10.00m (speed 0.95 mps / course 304.45) @ 8/31/20, 2:05:03 AM Pacific Daylight Time, ongoing trip = true"

given that we have bumped up the frequency to 1 meter, why isn't the regular trip end detection working?

4497,1598815907.1175199,2020-08-30T12:31:47.117520-07:00,"Recieved location <+37.39098923,-122.08645189> +/- 10.00m (speed 0.22 mps / course 150.12) @ 8/30/20, 12:31:46 PM Pacific Daylight Time, ongoing trip = true"
...
4531,1598816022.09175,2020-08-30T12:33:42.091750-07:00,"Recieved location <+37.39101534,-122.08649816> +/- 10.00m (speed 0.44 mps / course 109.34) @ 8/30/20, 12:33:41 PM Pacific Daylight Time, ongoing trip = true"
4532,1598816028.38044,2020-08-30T12:33:48.380440-07:00,Application will enter the foreground
...
4818,1598816113.76435,2020-08-30T12:35:13.764350-07:00,Application went to the background
4819,1598816116.3640802,2020-08-30T12:35:16.364080-07:00,"Recieved location <+37.39106806,-122.08651920> +/- 10.00m (speed 0.25 mps / course 23.55) @ 8/30/20, 12:35:15 PM Pacific Daylight Time, ongoing trip = true"
...
4921,1598816606.09661,2020-08-30T12:43:26.096610-07:00,"Recieved location <+37.39101701,-122.08650520> +/- 10.00m (speed 0.20 mps / course 322.03) @ 8/30/20, 12:43:25 PM Pacific Daylight Time, ongoing trip = true"

why don't we get any points when we are in the foreground?

shankari · 2020-09-01T00:28:55Z

One fairly simple workaround is to treat a very quick VISIT_STARTED as a potential invalid point, not a guaranteed one. We can schedule a task to be run ~ 10 mins after we receive the VISIT_STARTED and look at the distance covered in that time.

shankari · 2020-09-03T04:28:43Z

why aren't we getting the silent push notifications? I don't see anything in this time range

Because they are not enabled in the crontab. Duh!

given that we have bumped up the frequency to 1 meter, why isn't the regular trip end detection working?

Because on iOS, due to the distance filter, we don't currently check for regular trip end as part of the location callback. We only check it as part of the silent push notification callback, which, of course, is not invoked because of the lack of crontab.

        if([ConfigManager instance].is_duty_cycling) {
        if ([TripDiaryActions hasTripEnded]) {
            [[NSNotificationCenter defaultCenter] postNotificationName:CFCTransitionNotificationName
                                                                object:CFCTransitionTripEndDetected];

shankari · 2020-09-05T17:49:34Z

Testing this: test phone 3, v0.0.4
Will take some short trips.

Sometimes, we get a `VISIT_STARTED` within a second after a `VISIT_ENDED`. Note that the `VISIT_ENDED` is actually delayed significantly although the timestamp in the visit notification is fairly close. The notification was generated 7 minutes after the geofence exit, which is itself generated a few minutes after the actual trip start. ``` 686,1597146582.0006099,2020-08-11T05:49:42.000610-06:00,Received platform-specific notification T_EXITED_GEOFENCE 715,1597147042.3582,2020-08-11T05:57:22.358200-06:00,"Received visit notification = <+39.73087073,-105.03116972> +/- 92.76m (2020-08-11 03:44:32 +0000 to 2020-08-11 11:50:19 +0000)" 724,1597147042.39379,2020-08-11T05:57:22.393790-06:00,"Received visit notification = <+39.72744342,-105.03121412> +/- 89.09m (2020-08-11 11:50:20 +0000 to -)" ``` In this fix, we detect whether the resulting `VISIT_STARTED` is invalid because it is too close to a `VISIT_ENDED` and if so, we silently ignore the transition and don't change the FSM state. This is a potential fix for e-mission/e-mission-docs#372

Check back in TRIP_END mins and see if the trip actually ended or not e-mission/e-mission-docs#372 (comment) Testing done: - Doesn't crash anything - Unsure if it fixes anything, since we haven't run into the situation since Need more testing, but checking this in so we can get started on the next set of changes.

shankari added the enhancement New feature or request label Apr 17, 2019

shankari added the ceo-ebike label Aug 14, 2020

shankari mentioned this issue Aug 14, 2020

Sensitivity of travel range/time stopped? #562

Closed

shankari mentioned this issue Sep 4, 2020

Multi-day trips on iOS due to error getting locations for geofencing #572

Closed

shankari mentioned this issue Sep 16, 2021

publish the e-mission-phone app on F-droid ? #671

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Trip end notifications needs to be tweaked to be more meaningful #372

Trip end notifications needs to be tweaked to be more meaningful #372

shankari commented Apr 12, 2019 •

edited

Loading

shankari commented Apr 12, 2019

shankari commented Aug 14, 2020

asiripanich commented Aug 14, 2020

shankari commented Aug 15, 2020

JackBikes commented Aug 15, 2020 via email

shankari commented Aug 25, 2020

shankari commented Aug 25, 2020

shankari commented Aug 25, 2020

shankari commented Aug 25, 2020

shankari commented Aug 25, 2020 •

edited

Loading

shankari commented Aug 25, 2020

JackBikes commented Aug 25, 2020 via email

shankari commented Sep 1, 2020

shankari commented Sep 1, 2020

shankari commented Sep 1, 2020

shankari commented Sep 3, 2020

shankari commented Sep 5, 2020

Trip end notifications needs to be tweaked to be more meaningful #372

Trip end notifications needs to be tweaked to be more meaningful #372

Comments

shankari commented Apr 12, 2019 • edited Loading

shankari commented Apr 12, 2019

shankari commented Aug 14, 2020

asiripanich commented Aug 14, 2020

shankari commented Aug 15, 2020

JackBikes commented Aug 15, 2020 via email

shankari commented Aug 25, 2020

shankari commented Aug 25, 2020

shankari commented Aug 25, 2020

shankari commented Aug 25, 2020

shankari commented Aug 25, 2020 • edited Loading

shankari commented Aug 25, 2020

JackBikes commented Aug 25, 2020 via email

shankari commented Sep 1, 2020

shankari commented Sep 1, 2020

shankari commented Sep 1, 2020

shankari commented Sep 3, 2020

shankari commented Sep 5, 2020

shankari commented Apr 12, 2019 •

edited

Loading

shankari commented Aug 25, 2020 •

edited

Loading