Cwa-app-android: CWA risk update timestamp different to Google timestamp (by one or two minutes)

Created on 30 Jul 2020  路  14Comments  路  Source: corona-warn-app/cwa-app-android

Avoid duplicates

  • [X] Bug is not mentioned in the FAQ
  • [X] Bug is specific for Android only, for general issues / questions that apply to iOS and Android please raise them in the documentation repository
  • [X] Bug is not already reported in another issue

Describe the bug


The last update time shown by CWA is sometimes one minute or two minutes earlier or later than the update time shown in the Google ENF UI.

Expected behaviour


This is a minor issue.
The timestamp shown by CWA for the last update should be the same as the timestamp shown in the Google ENF UI in the overview screen and in the exposure checks log.

Steps to reproduce the issue

  1. View CWA risk status
    Note text similar to "Updated: Today, 07:54"
  2. Settings > Google > COVID-19 exposure notifications
    Note text similar to "Last checked for potential exposure on today at 07:55"
  3. Open "Exposure checks" from step 2. and confirm that the timestamp of the individual records for the latest check is the same as the timestamp shown in the overview from step 2.

Technical details

  • Mobile device: Samsung Galaxy A5 (2017) SM-A520F
  • Android version: 8.0.0
  • CWA Version: 1.1.1 1.3.1
  • Google Exposure Notifications System Version: 15202902003 17203704005

Internal Tracking ID: EXPOSUREAPP-1991

bug mirrored-to-jira

Most helpful comment

Just for me speaking, on my slow phone, ENF timestamp was always after CWA timestamp. At the moment CWA's timestamp is 2 minutes before ENF's. Snail race condition, imho. ;) Edit: And I never saw device time before ENF timestamp.

I mean the discrepancy between the ENF log and the device clock (https://github.com/corona-warn-app/cwa-app-android/issues/948#issuecomment-670088844).

Did you already do something concretely? I was thinking about coding a proposal for that as an excercise, maybe till middle/end of next week, depending on my own workload. If you already have a progress on that issue, I'd skip beginning anything.

I'm already working on a set of classes that will be accessible via the ENFClient class. The idea is to track the ENF submission calls, track all broadcasts from the ENF, and have a timeout mechanism to notice "missing callbacks" to notice issues in the ENF that didn't result in an exception being thrown to us.

I hope to solve 3 issues by making this class available to other parts of the app:

  • Show better timestamps
  • Show a more accurate "something is currently happening" progress indicator
  • Better error handling later know when a calculation failed on Google's end without throwing us an exception

Hope to create a PR today. Feedback on that is welcome :+1:.
Currently struggling a bit with a few unit tests for some async behavior :dizzy_face:, I'll get there :coffee: .

All 14 comments

Hello @MikeMcC399,

thanks for pointing this out. I will take this into the discussion with our development team.

Best regards,
LMM

Corona-Warn-App Open Source Team

Hello @MikeMcC399 ,

thanks again for your investigation. Our developers have been informed. This bug probably occurs due to different rounding strategies and will be inspected as soon as possible.

Best regards,
LMM

Corona-Warn-App Open Source Team

I noticed the Google Exposure Notification Framework (Version 15202902003) showing a time one minute into the future.
The text was "Last checked for potential exposure today at 19:49" whilst the system clock was showing the time as 19:48.
It looks like Google ENF may be rounding up the time and so maybe Google will need to make a fix.

Screenshot_20200806-194845_Google Play services

People who already read some of my comments in this repository, may know, that I'm sometimes doing some wild guesses about the source of a problem, sometimes more elaborate, sometimes less... Hope, no-one is bothered about that. If yes, please leave a note.
That being said, here my wild guess about this issue:

May it be, that CWA's timestamp is being set upon beginning checking for exposures, and ENF's timestamp at completion of checks?
As it takes some time for the checks to be performed, an overlap from one minute to the other might occur, and the reported deviation of timestamps might be the result.

Edit: that was the more less elaborate guess...
Now saw the problem clearly in the screenshot... I'm out...

Just some curiosity to report mirrored from over at https://github.com/corona-warn-app/cwa-app-android/issues/1187#issuecomment-714583114

My CWA status today:

My EN log entry today:
{"timestamp":"22. Oktober 2020, 03:02","keyCount":307304,"matchesCount":0,"appName":"Corona-Warn","hash":"oTbVuBbNBBnFzm25gcZH9lTOjOFRPEViypUZH7h9JzA="}

I.e. my CWA timestamp is one minute after my EN timestamp.

Maybe in my case it's a rounding error by ENF in the other direction? As long as the time difference doesn't exceed 1 min I won't be able to tell for sure I guess but it's also not that important tbh ^^

My device:

  • Samsung Galaxy S8 (Android 9)
  • CWA 1.5.0
  • ENF v. 17203915000

@daimpi
Thanks for your feedback!

I checked on one device I own and I'm also seeing the CWA timestamp one minute later than the EN timestamp, on another device the timestamps are identical. Both are updated to CWA 1.5.0 and I guess the change in which comes first is due to the version change from 1.3.1 to 1.5.0 and the replacement of 14 entries with just one entry per day (when things are working correctly).

I've therefore updated the title to say the timestamps are different without saying which way around.

The timestamp in the CWA on the card is set after the key retrieval & submission is done by the app.

It's possible that it's a racecondition. Theoretically the ENF can finish calculation before we store the timestamp, and we can also set the timestamp before the ENF does finish calculation. I have not looked into any rounding related issues, but I'm looking into changing the displayed timestamp to be "ENF calculation end" instead of "key provision to the ENF".

The ENF displaying a timestamp newer than the actual device time looks like rounding (on purpose?) on Google's side. Did it exceed 1 minute for anyone?

@d4rken

Did it exceed 1 minute for anyone?

Just for me speaking, on my slow phone, ENF timestamp was always after CWA timestamp. At the moment CWA's timestamp is 2 minutes before ENF's. Snail race condition, imho. ;) Edit: And I never saw device time before ENF timestamp.

but I'm looking into changing the displayed timestamp to be "ENF calculation end" instead of "key provision to the ENF".

Did you already do something concretely? I was thinking about coding a proposal for that as an excercise, maybe till middle/end of next week, depending on my own workload. If you already have a progress on that issue, I'd skip beginning anything.

Just for me speaking, on my slow phone, ENF timestamp was always after CWA timestamp. At the moment CWA's timestamp is 2 minutes before ENF's. Snail race condition, imho. ;) Edit: And I never saw device time before ENF timestamp.

I mean the discrepancy between the ENF log and the device clock (https://github.com/corona-warn-app/cwa-app-android/issues/948#issuecomment-670088844).

Did you already do something concretely? I was thinking about coding a proposal for that as an excercise, maybe till middle/end of next week, depending on my own workload. If you already have a progress on that issue, I'd skip beginning anything.

I'm already working on a set of classes that will be accessible via the ENFClient class. The idea is to track the ENF submission calls, track all broadcasts from the ENF, and have a timeout mechanism to notice "missing callbacks" to notice issues in the ENF that didn't result in an exception being thrown to us.

I hope to solve 3 issues by making this class available to other parts of the app:

  • Show better timestamps
  • Show a more accurate "something is currently happening" progress indicator
  • Better error handling later know when a calculation failed on Google's end without throwing us an exception

Hope to create a PR today. Feedback on that is welcome :+1:.
Currently struggling a bit with a few unit tests for some async behavior :dizzy_face:, I'll get there :coffee: .

Edit: And I never saw device time before ENF timestamp.

I mean the discrepancy between the ENF log and the device clock (#948 (comment)).

Yes, yes, I got it after submitting the comment :)

I'm already working on a set of classes that will be accessible via the ENFClient class.

Ehm, my proposal would have been... let's say, a little bit more simple. Happily awaiting your first class dinner, and skipping to cook a scrambled egg then ;)
Enjoy your coffee!

The issue of slightly differing timestamps is still apparent in CWA Android 1.7.1.

App shows:
Updated: Today, 17:01

Google exposure log shows:
Timestamp
28 November 2020, 17:00

The previous timestamps in the Google exposure log for today were:

28 November 2020, 13:00
28 November 2020, 09:00
28 November 2020, 05:00
28 November 2020, 00:20

Currently still waiting on an answer from Google, previous solutions still were off by a few minutes, so we can't continue on this unless Google tells us what the timestamp represents and how it's calculated on their end :slightly_frowning_face: .

@d4rken

Currently still waiting on an answer from Google, previous solutions still were off by a few minutes, so we can't continue on this unless Google tells us what the timestamp represents and how it's calculated on their end 馃檨 .

... or Google extends their API to share their timestamp, so that all UIs are using the same value.

Just throwing my 2ct in ...

If the root cause is different rounding of the same timestamp, then it would indeed be less confusing to have this aligned.

But if the root cause is that the timestamps refer to different phases in the background check (e.g. Google shows when their API was called / begin of check, and cwa shows when the check was successfully finished) - in such a case different timestamps could give more information for troubleshooting, like: what was the total duration of the check? Was there a check that was started but then aborted?

Was this page helpful?
0 / 5 - 0 ratings

Related issues

tandreb picture tandreb  路  3Comments

egandro picture egandro  路  3Comments

ParthaEth picture ParthaEth  路  3Comments

wmertens picture wmertens  路  3Comments

zeus24 picture zeus24  路  3Comments