2017-07-23 01:54:32,389 [INFO ]: No longer AFK (aw_watcher_afk.afk:99)
2017-07-23 04:19:23,139 [INFO ]: Woke up from suspend/hibernation (aw_watcher_afk.afk:94)
2017-07-23 04:19:23,735 [INFO ]: Received heartbeat after pulse window, inserting as new event. (bucket: aw-watcher-window_ker) (aw_server.api:154)
2017-07-23 04:19:24,141 [INFO ]: Became AFK (aw_watcher_afk.afk:105)
2017-07-23 04:19:24,226 [WARNING]: Inserting event that has a older timestamp than previous event!
Previous:{'id': 17206, 'timestamp': datetime.datetime(2017, 7, 23, 7, 52, 36, 809000, tzinfo=datetime.timezone.utc), 'duration': datetime.timedelta(0, 1606, 330391), 'data': {'status': 'hibernating'}}
Inserted:{'id': 17208, 'timestamp': datetime.datetime(2017, 7, 23, 7, 52, 1, 770000, tzinfo=datetime.timezone.utc), 'duration': datetime.timedelta(0, 1642, 370692), 'data': {'status': 'afk'}} (aw_datastore.datastore.Bucket:110)
2017-07-23 04:19:26,144 [INFO ]: No longer AFK (aw_watcher_afk.afk:99)
2017-07-23 10:37:25,039 [INFO ]: Woke up from suspend/hibernation (aw_watcher_afk.afk:94)
2017-07-23 10:37:25,206 [INFO ]: Received heartbeat after pulse window, inserting as new event. (bucket: aw-watcher-window_ker) (aw_server.api:154)
2017-07-23 10:37:26,040 [INFO ]: Became AFK (aw_watcher_afk.afk:105)
2017-07-23 10:37:26,129 [WARNING]: Inserting event that has a older timestamp than previous event!
Previous:{'id': 17218, 'timestamp': datetime.datetime(2017, 7, 23, 8, 23, 38, 523000, tzinfo=datetime.timezone.utc), 'duration': datetime.timedelta(0, 22426, 515437), 'data': {'status': 'hibernating'}}
Inserted:{'id': 17220, 'timestamp': datetime.datetime(2017, 7, 23, 8, 23, 33, 515000, tzinfo=datetime.timezone.utc), 'duration': datetime.timedelta(0, 22432, 525563), 'data': {'status': 'afk'}} (aw_datastore.datastore.Bucket:110)
2017-07-23 10:37:27,043 [INFO ]: No longer AFK (aw_watcher_afk.afk:99)
Looks like being afk starts a couple of seconds before closing the lid / going to sleep, and then on wake-up the hibernation event is added first, and then an afk
event (covering the same time period ? that time is logged twice ?) is added ?
I did compute that I have 12 days of logged time (the sum of events durations) over the last 10 days. Some of it might be due to two processes running, but if hibernated time is counted twice that's a much more likely explanation. Is it meant to be ?