Description
I realized why there are a lot of duration:0 events in the raw data store. I initially thought this was due to storing the same events twice(#38), however this turned out not to be the case.
Android's default UsageStatsManager should actually produce close to no events of duration 0 for apps with a UI. Every UI app has a move_to_foreground and a move_to_background, so all events should have at least some milliseconds of time on screen if captured correctly.
Here's what's happening:
Android has 2 other events: screen_interactive and screen_non_interactive. Whenever you're in an application, and the screen goes to sleep, or you lock the screen, the screen_non_interactive event shoots first, only then followed by a move_to_background event. Because AW merges events next to each other, this essentially adds an event in the middle, and breaks the chain. Let's say you start Firefox. You get a move_to_foreground when you start Firefox, you spend 20 minutes, and then lock the screen. Android sends a screen_non_interactive, then a move_to_background. As a result both Firefox events have duration 0 instead of 20 minutes.
Here's an example:
{
"id": 60381,
"timestamp": "2020-06-14T00:00:45.523Z",
"duration": 0.0,
"data": {
"app": "Firefox",
"classname": "org.mozilla.gecko.BrowserApp",
"package": "org.mozilla.firefox"
}
},
{
"id": 60380,
"timestamp": "2020-06-14T00:00:45.435Z",
"duration": 0.0,
"data": {
"app": "Android system",
"package": "android"
}
},
{
"id": 60379,
"timestamp": "2020-06-13T23:57:20.015Z",
"duration": 0.0,
"data": {
"app": "Firefox",
"classname": "org.mozilla.gecko.BrowserApp",
"package": "org.mozilla.firefox"
}
},
Look at the timestamps of Firefox and Android System for confirmation: 2020-06-14T00:00:45.523Z and 2020-06-14T00:00:45.435Z, to see that Android sends them in the order I specified above. Here AW reports I spent 0 time on Firefox, when in reality I spent 3 minutes
This occurs almost every time you lock your phone/your phone goes to sleep by itself, and is probably the main cause for: ActivityWatch/activitywatch/issues/440.
To reproduce
- Get the Raw data for the Android Bucket
- Take a look at all of the events with duration: 0. Notice how they're separated by the Android System call.
You can also confirm this order by printing out the events to LogCat as they come, making sure to print the event_type with them.
To fix
In SendHeartbeatsTask, when iterating through the loop of events, if the event type is screen_non_interactive, check if next event has same app name as previous event. If they do, then process next event first, and only after that, process screen_non_interactive. Everything else should be the same
To make debugging easier, it would be good to store 'event_type' directly in data. This would make it a lot easier to later look through the events and make sure the behaviours between all event types are correct.
EDIT: Also related to this: #34