Skip to content
This repository has been archived by the owner on Jun 20, 2023. It is now read-only.

CAUSE: 3 Something went wrong. ApiException: 39508 #1021

Closed
kbobrowski opened this issue Aug 14, 2020 · 271 comments · Fixed by #1074 or #1108
Closed

CAUSE: 3 Something went wrong. ApiException: 39508 #1021

kbobrowski opened this issue Aug 14, 2020 · 271 comments · Fixed by #1074 or #1108
Assignees
Labels
bug Something isn't working mirrored-to-jira This item is also tracked internally in JIRA

Comments

@kbobrowski
Copy link
Contributor

kbobrowski commented Aug 14, 2020

This bug was mentioned many times due to various causes but this seems to be a new case.

  • Android 10
  • OnePlus 5T
  • CWA 1.2.0
  • Play Services 20.26.65
  • EN version: 15202902003

Exposure checks log:

August 8, 2020 09:27 (key count: 740)
August 8, 2020 09:27 (key count: 825)
August 8, 2020 09:27 (key count: 595)
August 8, 2020 09:27 (key count: 1790)
August 8, 2020 09:27 (key count: 2290)
August 8, 2020 09:27 (key count: 2520)
August 8, 2020 09:27 (key count: 1575)
August 8, 2020 09:27 (key count: 1405)
August 8, 2020 09:27 (key count: 1385)
August 8, 2020 09:27 (key count: 1645)

August 9, 2020 09:27 (key count: 825)
August 9, 2020 09:27 (key count: 595)
August 9, 2020 09:27 (key count: 1790)
August 9, 2020 09:27 (key count: 2290)
August 9, 2020 09:27 (key count: 2520)
August 9, 2020 09:27 (key count: 1575)
August 9, 2020 09:27 (key count: 1405)
August 9, 2020 09:27 (key count: 1385)
August 9, 2020 09:27 (key count: 1645)
August 9, 2020 09:27 (key count: 2813)
August 9, 2020 09:27 (key count: 2415)
August 9, 2020 09:27 (key count: 3050)
August 9, 2020 09:27 (key count: 2210)
August 9, 2020 09:27 (key count: 1655)

August 10, 2020 09:27 (key count: 595)
August 10, 2020 09:27 (key count: 1790)
August 10, 2020 09:27 (key count: 2290)
August 10, 2020 09:27 (key count: 2520)
August 10, 2020 09:27 (key count: 1575)
August 10, 2020 09:27 (key count: 1405)
August 10, 2020 09:27 (key count: 1385)
August 10, 2020 09:27 (key count: 1645)
August 10, 2020 09:27 (key count: 2813)
August 10, 2020 09:27 (key count: 2415)
August 10, 2020 09:27 (key count: 3050)
August 10, 2020 09:27 (key count: 2210)
August 10, 2020 09:27 (key count: 1655)
August 10, 2020 09:27 (key count: 565)

August 11, 2020 09:28 (key count: 1790)
August 11, 2020 09:28 (key count: 2290)
August 11, 2020 09:28 (key count: 2520)
August 11, 2020 09:28 (key count: 1575)
August 11, 2020 09:28 (key count: 1405)
August 11, 2020 09:28 (key count: 1385)
August 11, 2020 09:28 (key count: 1645)
August 11, 2020 09:28 (key count: 2813)
August 11, 2020 09:28 (key count: 2415)
August 11, 2020 09:28 (key count: 3050)
August 11, 2020 09:28 (key count: 2210)
August 11, 2020 09:28 (key count: 1655)
August 11, 2020 09:28 (key count: 565)
August 11, 2020 09:28 (key count: 2380)

August 12, 2020 09:56 (key count: 2290)
August 12, 2020 09:56 (key count: 2520)
August 12, 2020 09:56 (key count: 1575)
August 12, 2020 09:56 (key count: 1405)
August 12, 2020 09:56 (key count: 1385)
August 12, 2020 09:56 (key count: 1645)
August 12, 2020 09:56 (key count: 2813)
August 12, 2020 09:56 (key count: 2415)
August 12, 2020 09:56 (key count: 3050)
August 12, 2020 09:56 (key count: 2210)
August 12, 2020 09:56 (key count: 1655)
August 12, 2020 09:56 (key count: 565)
August 12, 2020 09:56 (key count: 2380)
August 12, 2020 09:59 (key count: 2285)

August 13, 2020 07:47 (key count: 2520)
August 13, 2020 07:47 (key count: 1575)
August 13, 2020 07:47 (key count: 1405)
August 13, 2020 07:47 (key count: 1385)
August 13, 2020 07:47 (key count: 1645)
August 13, 2020 07:47 (key count: 2813)
August 13, 2020 07:47 (key count: 2415)
August 13, 2020 07:47 (key count: 3050)
August 13, 2020 07:47 (key count: 2210)
August 13, 2020 07:47 (key count: 1655)
August 13, 2020 07:47 (key count: 565)
August 13, 2020 07:47 (key count: 2380)
August 13, 2020 07:47 (key count: 2285)
August 13, 2020 07:47 (key count: 3800)

August 14, 2020 07:36 (key count: 1575)
August 14, 2020 07:36 (key count: 1405)
August 14, 2020 07:36 (key count: 1385)
August 14, 2020 07:36 (key count: 1645)
August 14, 2020 07:36 (key count: 2813)
August 14, 2020 07:36 (key count: 2415)
August 14, 2020 07:36 (key count: 3050)
August 14, 2020 07:36 (key count: 2210)
August 14, 2020 07:36 (key count: 1655)
August 14, 2020 07:36 (key count: 565)
August 14, 2020 07:36 (key count: 2380)
August 14, 2020 07:36 (key count: 2285)
August 14, 2020 07:36 (key count: 3800)
August 14, 2020 07:36 (key count: 3940)

August 14, 2020 09:36 (key count: 1575)
August 14, 2020 09:36 (key count: 1405)
August 14, 2020 09:36 (key count: 1385)
August 14, 2020 09:36 (key count: 1645)
August 14, 2020 09:36 (key count: 2813)
August 14, 2020 09:36 (key count: 2415)

Internal Tracking ID: EXPOSUREAPP-2213

@kbobrowski kbobrowski added the bug Something isn't working label Aug 14, 2020
@kbobrowski
Copy link
Contributor Author

The app also displays "Updated: Yesterday, 07:46", so it did not register properly the check that was made today (14.08) at 07:36

@vaubaehn
Copy link
Contributor

vaubaehn commented Aug 14, 2020

Hi @kbobrowski , according to the wrong link to the faq, maybe it had been introduced by #864 (CWA v1.2.0) ?
Maybe #1007 after #996 may solve it? (CWA v1.3.0)

CWA displays yesterday's date - what do the Google Exposure Notifications ("COVID-19-Benachrichtigungen") display (update date in main screen)?

Can you provide a screenshot of the error message, if error is reproducable (would be only for my own curiosity, tbh)

@vaubaehn
Copy link
Contributor

@kbobrowski , some additional questions:
were both matchings on August 14 performed as a background task (CWA not in foreground)? Or was first background, second foreground?

@kbobrowski
Copy link
Contributor Author

Hi @vaubaehn , Google EN just displays the last date from the logs I posted, so "Last checked for potential exposure on today at 09:36". 39508 error happens every time I open the app now as the app holds "last time diagnosis keys were provided" at "yesterday, 07:36", so it will exceed limit of 20 calls every time. Will check tomorrow if the issue repeats again.

Not sure if it was background / foreground, I guess first could be background and second foreground.

@vaubaehn
Copy link
Contributor

@kbobrowski , one feature request for the ENF, that our devs here might direct to Google, could be that ProvideDiagnosisKeys() creates an object with some statistics about some technical results of that task, e. g., if the task had been completed successfully, time of last API-call, remaining count of API-calls. That would support the EN-apps (CWA) to validate if they may call ProvideDiagnosisKeys() without running into an exception.
Do you think that could be useful?

@kbobrowski
Copy link
Contributor Author

At the expense of making my app useless for the next couple of days I was shifting the date forward which was resetting internal GMS count and forcing update of diagnosis keys, and was not able to reproduce this error.

@vaubaehn that's a good idea to have some more information about whether the call to provideDiagnosisKeys was successful, but I think the implementation of CWA can be improved even without the action on Google side. Probably better implementation would be to just mirror the same mechanism that GMS is using to count the calls to provideDiagnosisKeys, and update this count before the call to provideDiagnosisKeys. This way it would be impossible to ever exceed quota limit. The GMS's algorithm is simply:

public class Quota {

  private long day = 0;
  private int count = 0;

  public void updateCount() {
    long currentDay = System.currentTimeMillis() / TimeUnit.HOURS.toMillis(24);
    if (currentDay > day) {
      day = currentDay;
      count = 0;
    }
    if (count < 20) {
      count += 1;
    }
  }

  public boolean canCallProvideDiagnosisKeys() {
    return count < 20;
  }
}

But right now CWA is only executing executeFetchDateUpdate(currentDate) after all 14 calls were successful, otherwise it is not executed at all which leads to exceeded quota.

@vaubaehn
Copy link
Contributor

@kbobrowski , right, CWA could improve here, but I suspect ENF to fail matching keys under some conditions (#774 (comment)) , but counting the call though. In that case, CWA couldn't do anything about it...

@kbobrowski
Copy link
Contributor Author

@vaubaehn right, EN may fail to match keys and still count the call, we have seen it e.g. with error 10 - these kind of bugs have to be fixed by Google. But the disadvantage of current CWA implementation is that in this situation it is practically guaranteed that 39508 error will follow as CWA is not maintaining any count of calls to provideDiagnosisKeys. This 39508 error will appear every time the app is launched, which leads to bad UX.

I think CWA should maintain internal count of calls and simply not attempt to call if the quota is already exceeded. What would be very useful is to instead display the information about it (perhaps in another UI section), together with information about original error, which is currently not displayed to the user if it has happened in the background.

@vaubaehn
Copy link
Contributor

vaubaehn commented Aug 14, 2020

By the way, I found us often handling with the rate limit/quota of ProvideDiagnosisKeys(), but I still couldn't find any information on why Apple and Google actually set a quota.
As the diagnosis keys are downloaded by the app without control of ENF, it's not about preventing DOS of server.
Only reasons I could imagine is either preventing some kind of brute force against TEKs (information disclosure), or preventing high CPU load (load through cryptography while matching; intentionally or accidently DOS against device). Is there any information released, why a quota is introduced here?

@kbobrowski
Copy link
Contributor Author

I don't know why the quota is here, I can only speculate that the reason is "privacy" (there are some theoretically possible scenarios which may lead to some privacy implications if there is no quota at all) or "battery"

@vaubaehn
Copy link
Contributor

I hope it's not the latter ("battery")... because that might underline the CPU load caused by cryptography, In that case, I don't know where this all might lead to, when a) amount of users of CWA should increase significantly one day, b) reported positive cases are drastically increasing (2nd wave * more users), c) big events are planned/more using of public transport in cold weather (much more collected RPIs)...
If ENFs WakeUpService can also ensure full CPU power (not only ensuring to start the scheduled task once per day) for ProvideDiagnosisKeys() as a background service while the system dozes to be completed successfully without time out, then everything will be fine. If not...

Anyway, have a nice week-end!

@kbobrowski
Copy link
Contributor Author

People are also reporting this error on twitter: https://twitter.com/elliwir/status/1294262706762063873

@vaubaehn Have a nice weekend as well!

@vaubaehn
Copy link
Contributor

I couldn't resist to have one more look here...
If you follow the twitter-link, and follow the whole conversation of @daimpi, there is a screenshot providing the user's version of ENF - version 16203016000 is obviously being rolled out! #933 (comment)
@kbobrowski maybe you already got the update, but your cached version number is still showing v1.5? You may check later, if it changed...
And thanks :), now I'm gone

@kbobrowski
Copy link
Contributor Author

@vaubaehn it's still v1.5 for me

@vaubaehn vaubaehn mentioned this issue Aug 14, 2020
8 tasks
@daimpi
Copy link

daimpi commented Aug 15, 2020

There definitely more people with this problem. Here is just one other recent example: https://twitter.com/DieterKlinkner/status/1294588826908753920

One thing that caught my attention is that this person seemingly also has a quite intensive routine to try and get the app going.

@ghost ghost assigned JoachimFritsch Aug 17, 2020
@ghost ghost added the mirrored-to-jira This item is also tracked internally in JIRA label Aug 17, 2020
@daimpi
Copy link

daimpi commented Aug 17, 2020

I got another user reporting this problem and for them not opening the app for 24h doesn't seem to have solved the issue.

Device: Samsung Galaxy A6
CWA 1.2.1

Any ideas?

@kbobrowski
Copy link
Contributor Author

My working assumption is the timeout - if fetching diagnosis keys and submitting them to API is not finished within 60 seconds then the transaction is terminated, and if some diagnosis keys were already submitted in this terminated transaction, then next retry may lead to exceeded quota.

While testing this with artificial delay in the transaction it also happened very rarely (only once in many tries) that transaction hanged without completing a single call to provideDiagnosisKeys, which lead to the timeout.

One possibly important thing here is that CWA already operates with very thin timeout margin - without introducing any artificial delay and on the fast wifi network (100 Mbps) the whole process of fetching 14 diagnosis keys and submitting all of them to the API takes about 45 seconds on a slow Android 6 device, which is 75% of available timeout. Interestingly the description while fetching keys says that it may take "couple of minutes", but after 1 minute there is hard termination.

The only counter argument to this is that in my case (logs from the first post in this issue) on Android 10 all 14 diagnosis keys have been submitted, and then transaction was repeated, so it's quite unlikely that timeout happened while API was processing 14th key and just before updating last-fetch-date, still possible though.

@daimpi
Copy link

daimpi commented Aug 17, 2020

One possibly important thing here is that CWA already operates with very thin timeout margin - without introducing any artificial delay and on the fast wifi network (100 Mbps) the whole process of fetching 14 diagnosis keys and submitting all of them to the API takes about 45 seconds on a slow Android 6 device, which is 75% of available timeout.

Wow… that's much longer than I'd have thought this process takes… I've always assumed that this is done in a few seconds max. I guess the limiting factor in this case is not the bandwidth but the (cryptography-) performance of the SoC, right?

What would speak for this hypothesis is the fact that the Galaxy A6 mentioned above is certainly not the most potent device… On which device did you observe the 45s sync time?

@kbobrowski
Copy link
Contributor Author

@daimpi I guess slow device (Motorola G2) plays a role here, but it seems that just downloading keys takes significant portion of this timeout limit (if it has to download all 14 of them).

Similar issue reported in #1030 , if it is the same pattern as in my case (all 14 keys successfully submitted, but then CWA retried the same day), then I think timeout hypothesis would be less likely

@s-martin
Copy link

Same here.

Moto G6 Plus
Android 9
CWA 1.2.1
Google Play Services 20.30.19

@kbobrowski
Copy link
Contributor Author

kbobrowski commented Aug 18, 2020

Another exposure log provided by @not-a-feature (#1030 (comment)):

August 12, 2020 02:18 (key count: 2290)
August 12, 2020 02:18 (key count: 2520)
August 12, 2020 02:18 (key count: 1575)
August 12, 2020 02:18 (key count: 1405)
August 12, 2020 02:18 (key count: 1385)
August 12, 2020 02:18 (key count: 1645)
August 12, 2020 02:18 (key count: 2813)
August 12, 2020 02:18 (key count: 2415)
August 12, 2020 02:18 (key count: 3050)
August 12, 2020 02:18 (key count: 2210)
August 12, 2020 02:18 (key count: 1655)
August 12, 2020 02:18 (key count: 565)

August 13, 2020 02:48 (key count: 2520)
August 13, 2020 02:48 (key count: 1575)
August 13, 2020 02:48 (key count: 1405)
August 13, 2020 02:48 (key count: 1385)
August 13, 2020 02:48 (key count: 1645)
August 13, 2020 02:48 (key count: 2813)
August 13, 2020 02:48 (key count: 2415)
August 13, 2020 02:48 (key count: 3050)
August 13, 2020 02:48 (key count: 2210)
August 13, 2020 02:48 (key count: 1655)
August 13, 2020 02:48 (key count: 565)
August 13, 2020 02:48 (key count: 2380)
August 13, 2020 02:48 (key count: 2285)
August 13, 2020 02:48 (key count: 3800)

August 14, 2020 01:59 (key count: 1575)
August 14, 2020 01:59 (key count: 1405)
August 14, 2020 01:59 (key count: 1385)
August 14, 2020 01:59 (key count: 1645)
August 14, 2020 01:59 (key count: 2813)
August 14, 2020 01:59 (key count: 2415)
August 14, 2020 01:59 (key count: 3050)
August 14, 2020 01:59 (key count: 2210)
August 14, 2020 01:59 (key count: 1655)
August 14, 2020 01:59 (key count: 565)
August 14, 2020 01:59 (key count: 2380)
August 14, 2020 01:59 (key count: 2285)
August 14, 2020 01:59 (key count: 3800)

August 15, 2020 02:34 (key count: 1405)
August 15, 2020 02:34 (key count: 1385)
August 15, 2020 02:34 (key count: 1645)
August 15, 2020 02:34 (key count: 2813)
August 15, 2020 02:34 (key count: 2415)
August 15, 2020 02:34 (key count: 3050)
August 15, 2020 02:34 (key count: 2210)
August 15, 2020 02:34 (key count: 1655)
August 15, 2020 02:34 (key count: 565)
August 15, 2020 02:34 (key count: 2380)
August 15, 2020 02:34 (key count: 2285)
August 15, 2020 02:34 (key count: 3800)
August 15, 2020 02:34 (key count: 3940)
August 15, 2020 02:34 (key count: 3020)

August 16, 2020 03:37 (key count: 1385)
August 16, 2020 03:37 (key count: 1645)
August 16, 2020 03:37 (key count: 2813)
August 16, 2020 03:37 (key count: 2415)
August 16, 2020 03:37 (key count: 3050)
August 16, 2020 03:37 (key count: 2210)
August 16, 2020 03:37 (key count: 1655)
August 16, 2020 03:37 (key count: 565)
August 16, 2020 03:37 (key count: 2380)
August 16, 2020 03:37 (key count: 2285)
August 16, 2020 03:37 (key count: 3800)
August 16, 2020 03:37 (key count: 3940)
August 16, 2020 03:37 (key count: 3020)
August 16, 2020 03:37 (key count: 2675)

August 17, 2020 02:00 (key count: 1645)
August 17, 2020 02:00 (key count: 2813)
August 17, 2020 02:00 (key count: 2415)
August 17, 2020 02:00 (key count: 3050)
August 17, 2020 02:00 (key count: 2210)
August 17, 2020 02:00 (key count: 1655)
August 17, 2020 02:00 (key count: 565)
August 17, 2020 02:00 (key count: 2380)
August 17, 2020 02:00 (key count: 2285)
August 17, 2020 02:00 (key count: 3800)
August 17, 2020 02:00 (key count: 3940)
August 17, 2020 02:00 (key count: 3020)
August 17, 2020 02:00 (key count: 2675)

August 18, 2020 02:31 (key count: 2813)
August 18, 2020 02:31 (key count: 2415)
August 18, 2020 02:31 (key count: 3050)
August 18, 2020 02:31 (key count: 2210)
August 18, 2020 02:31 (key count: 1655)
August 18, 2020 02:31 (key count: 565)
August 18, 2020 02:31 (key count: 2380)
August 18, 2020 02:31 (key count: 2285)
August 18, 2020 02:31 (key count: 3800)

August 18, 2020 02:33 (key count: 2813)
August 18, 2020 02:33 (key count: 2415)
August 18, 2020 02:33 (key count: 3050)
August 18, 2020 02:33 (key count: 2210)
August 18, 2020 02:33 (key count: 1655)
August 18, 2020 02:33 (key count: 565)
August 18, 2020 02:33 (key count: 2380)
August 18, 2020 02:33 (key count: 2285)
August 18, 2020 02:33 (key count: 3800)
August 18, 2020 02:33 (key count: 3940)
August 18, 2020 02:33 (key count: 3020)

so this time CWA only submitted 9 keys on 18.08 02:31, and then retried submitting 11 keys 18.08 02:33. So I guess the timeout hypothesis is still possible, perhaps new Play Services is taking a bit more time to process provideDiagnosisKeys call, or fails sometimes by hanging indefinitely or there is another error.

Would be great if CWA allowed for exporting logs for the last 48 hours or so, just storing them in a text file and allowing user to export it from the app, otherwise there is no easy way to know what was the first error that happened, 39508 is just a consequence of it.

@vaubaehn
Copy link
Contributor

vaubaehn commented Aug 18, 2020

Same here today.

LG-H815 (LG G4)
Android 6.0
CWA 1.2.1 (since 3 days)
ENF 16203019000 in the morning. now: 16203302004
GPS 20.30.19

Usually background update worked like a charm for me (usually around 8:23am, +- 3 minutes).
After updating CWA to 1.2.1, the day before yesterday manual check (before expected update) at 7:00am.
Yesterday, manual check (before expected update) at 5:21am.
Today, no automatic update until 8:30 (checked via COVID-19-notifications) with telephone plugged to charge. Then reading news in internet. phone still plugged to charge.
Checking again for update via Covid-19-notifications at 9:08am -> update was done at 08:53am but 20 checks all within the same minute! First 14 + 6 duplicate of the first. Then opening CWA: API 39508.

=> "Cause 9002 Timed Out while waiting for 60000 ms" highly unlikely.

@kbobrowski
Copy link
Contributor Author

I was trying to reproduce something by calling provideDiagnosisKeys over 3000 times in one hour but it always worked (in the foreground). @vaubaehn if you had all the 20 calls in the same minute then indeed timeout error is unlikely. Would be good to stress-test API in the background mode to see what is failing here, perhaps some issues with background job

@daimpi
Copy link

daimpi commented Aug 18, 2020

I got another user reporting this problem and for them not opening the app for 24h doesn't seem to have solved the issue.

Device: Samsung Galaxy A6
CWA 1.2.1

The user reported back today that after not opening CWA for another 24h the problem seems to have finally disappeared for them 🙂.

@daimpi
Copy link

daimpi commented Oct 21, 2020

@vaubaehn are we talking about @LSDJGLKJG or @PapaBravo ?

Former looks to me like a classical case of silent 9002 timeout (now instead of 60s presumably after 180s), while the latter seems to be a case of API (10), no?

@vaubaehn
Copy link
Contributor

@daimpi we are actually talking about @LSDJGLKJG 👍

  • According to ENF log, API call counter and GoogleQuotaCounter in CWA must already have been reset for the new day for entry 1.
  • there were 20 calls all over the day. Because CWA 1.5.0 now has a (working) GoogleQuotaCalculator, there should be no more API39508.
  • If there was a timeout, the reported error should be Cause 9002, and not Cause 3
  • Reported Cause 3 points to ENF, and as API39508 should be excepted, only API 10 remains.

But I'm not sure, this is why I asked for more error details :)

@DanielKroegerPriv
Copy link

Version 1.5.0 helped me out after 24h wait. Thanks alot for fast fix and good handling.

@vthomw
Copy link

vthomw commented Oct 21, 2020

still receiving the "CAUSE: 3 Something went wrong. ApiException: 39508" message on my

  • Samsung S5neo
  • Android 6
  • CWA 1.5.0

Screenshot_20201021-131336

@ka223
Copy link

ka223 commented Oct 21, 2020

@vthomw Have the same error message every time I open this app.

Xiaomi 8a, MIUI 11.0.1 (Android 10)
CWA 1.5.0

@vthomw
Copy link

vthomw commented Oct 21, 2020

I guess I have to wait 24 hours with the app closed .. lets see what happens tomorrow.

@daimpi
Copy link

daimpi commented Oct 21, 2020

@vaubaehn Thanks, thb I'm wasn't entirely familiar with all the details of the new 1.5 approach. A few questions for my understanding:

  • According to ENF log, API call counter and GoogleQuotaCounter in CWA must already have been reset for the new day for entry 1.

Do you infer this from the timestamp being after 00:00 UTC, or something else?

  • there were 20 calls all over the day. Because CWA 1.5.0 now has a (working) GoogleQuotaCalculator, there should be no more API39508.

I totally forgot that CWA now has a quota calculator, that's cool 👍. Yes you're right this should actually prevent 39508 if it was working correctly 🤔.

  • If there was a timeout, the reported error should be Cause 9002, and not Cause 3

Let's imagine the following scenario: a very slow device which is hitting the timeout limit of 3min. In this case there will be 20 times 9002 timeouts but they will not be "silent" b/c GoogleQuotaCounter prevents a 21st call which would trigger error 39508 which would cover up the 9002 error. Is this the correct reasoning?

  • Reported Cause 3 points to ENF, and as API39508 should be excepted, only API 10 remains.

But I'm not sure, this is why I asked for more error details :)

Good point, let's wait for more info from @LSDJGLKJG.

@LSDJGLKJG
Copy link

Hey,
@daimpi I did not read your message until today, but something seems to have happened. I opened the app today, just now, and everything is working fine. It says it updated today at 2:23.
The log says there were only two encounters today, which is possible, as I only did a short trip to the supermarket. And I didn't see my flatmates today. Is it possible that my app (or my phone...) is unable to cope with too many encounters in one day? And that there are too many encounters if I spend the whole day with one of my flatmates who has the app as well?

I will just wait and see how it goes over the next few days, I guess.

@LSDJGLKJG
Copy link

@vaubaehn Sorry that I can't give you more error details, now that the error seems to fixed.

@daimpi
Copy link

daimpi commented Oct 21, 2020

@LSDJGLKJG great that it seems to be working for you now 👍 🙂

Could you maybe share your EN log from today as well, just for comparison?

The log says there were only two encounters today,

Could you share a screenshot of this?

Is it possible that my app (or my phone...) is unable to cope with too many encounters in one day? And that there are too many encounters if I spend the whole day with one of my flatmates who has the app as well?

Unlikely. The real computational cost seems to come from the expansion of diagnosis Keys (via @mh-) :

The expensive operation is AES, not the 16 byte comparison.

We recently had a detailed discussion on this topic in the community Slack if you're interested to learn more 🙂.

I will just wait and see how it goes over the next few days, I guess.

Sounds good, let us know how it goes 🙂.

@LSDJGLKJG
Copy link

Alright, here it is:
all-exposure-checks.txt

@Erbsenklemmer
Copy link

I had the same problem error#39508.
I have updated the App yesterday and keep it closed for nearly 24 hours.
Now I have reopened it again and the bug is done! The information screen shows the correct days and state.
I am satisfied. Congratulations for this fix👍!

@dieLouisa
Copy link

Yesterday updated to CWA 1.5.0 (from the app store).
When I opened the updated app yesterday, still got the error 39508.
So I waited until this morning.
App updated at 02:03 am.
Now everything is working fine.
Thank you!

Gigaset GS160
Android 6.0
App Version 1.5.0

Same with my phone 😀 it's working now.
Samsung SM-A300FU
Android 6.0.1
App Version 1.5.0

Thank you!

@BN72
Copy link

BN72 commented Oct 22, 2020

The update solved my problem. After about six weeks I can check the risk status again.

Samsung Galaxy S5 mini (SM-G800F)
Android 6.0.1

@d4rken
Copy link
Member

d4rken commented Oct 22, 2020

@daimpi @vaubaehn

I totally forgot that CWA now has a quota calculator, that's cool +1. Yes you're right this should actually prevent 39508 if it was working correctly thinking.

The quota calculator is currently not armed. It tracks the quota and can be armed in a future update while already knowing the correct values, but currently it will not prevent submission to the ENF. This decision was made to not accidentally hide an underlying issue, as the quota of 20 calls should be enough on 95% of devices, those that have the newer ENF, where we can submit all files in one call. We should not be able to reach the quota limit 🤔 .

@LSDJGLKJG
Copy link

Works fine today, too. I'm really happy.

@daimpi
Copy link

daimpi commented Oct 22, 2020

@d4rken thanks for clarifying 🙂.

Did you see my post above? There @LSDJGLKJG's phone actually hit the limit of 20 calls.

My guess was that this was caused by silent 9002 timeouts, as this is something we have seen before the release of CWA 1.5 with low powered devices. What I'm wondering: if CWA gets the timeout, will it next time again submit the whole package of DKs to ENF, or will it only submit the "rest" which hasn't been processed yet? Because if it every time submits everything again, what is stopping it from timing out on every submission and then retrying again? If this happens it's easy to hit the limit of 20 calls. Does this make sense?

@d4rken
Copy link
Member

d4rken commented Oct 22, 2020

Did you see my post above? There @LSDJGLKJG's phone actually hit the limit of 20 calls.

I missed that. I currently don't why it would retry this often.
Assuming there may be an exception being thrown, the retry timing does not seem to fit the "retry" behavior specified in https://github.com/corona-warn-app/cwa-app-android/blob/master/Corona-Warn-App/src/main/java/de/rki/coronawarnapp/worker/BackgroundWorkBuilder.kt
Though this retry mechanism kicking in because the whole transaction failed, is AFAICT the only reason it would repeat so often.

My guess was that this was caused by silent 9002 timeouts, as this is something we have seen before the release of CWA 1.5 with low powered devices. What I'm wondering: if CWA gets the timeout, will it next time again submit the whole package of DKs to ENF, or will it only submit the "rest" which hasn't been processed yet?

It will submit all available (those in the cache) packages. If only the download times out for a few files and the transaction timeout it not reached, it will continue with those files that are available. So even if a few downloads timeout each time, even a slow device/network should eventually have and submit all files, if at least one download completes per attempt.

At least one key package has to have been downloaded because the DefaultDiagnosisKeyProvider would have skipped the submission if the file list is empty.

Because if it every time submits everything again, what is stopping it from timing out on every submission and then retrying again? If this happens it's easy to hit the limit of 20 calls. Does this make sense?

That's theoretically possible, I'm just not sure what would lead to this. 20+ times in a row. Could the device be downloading files slow enough to reach 3 minute timeouts on every attempt? It's all on the same day too. So there would have to be a least one valid existing file, and in 20 attempts it never manages to download all existing ones, so a success ratio below 1 per attempt. As it seems to be fixed, maybe that was the case 🤔.

The timeout increase in the hotfix should improve this behavior. Would arming the quota calculator have helped here? It would only have hidden the issue, wouldn't it?

@LSDJGLKJG Wifi at home? 4G?

@daimpi
Copy link

daimpi commented Oct 22, 2020

@d4rken @vaubaehn thanks for the detailed explanations (also over at #1187). I'm still trying to fully wrap my head around everything, but this helps a lot 😊 ❤️.

Regarding

Would arming the quota calculator have helped here? It would only have hidden the issue, wouldn't it?

Yes I would think so too.

@schneik1 reported a similar story wrt multiple checks above (just that theirs didn't go all the way to 39508):

Mit 1.5.0 funktioniert es auch auf meinem alten S5 mini mit Android 6.0.1

Gut gemacht, vielen Dank

Ich verstehe nur noch nicht warum die Überprüfung auf mögliche ... um ca. 2:00 beginnt und alle ca 45 Min. wiederholt wird, bis ich um 7:00 die App geöffnet habe.

but unfortunately their log seems to have been corrupted, so I couldn't check this yet.

@schneik1 könntest du einen neuen log für uns hochladen, da dein alter scheinbar beschädigt ist? TIA 🙂

@vaubaehn
Copy link
Contributor

Yes, @schneik1 , a new ENF log would be nice. The other one looks a bit fishy to me. 🐟

@daimpi
Copy link

daimpi commented Oct 22, 2020

@vaubaehn well actually… 🤓
Dolphins are not fish.

Ok I'll see myself out 🏃 😂

@vthomw
Copy link

vthomw commented Oct 22, 2020

success .. update to 1.5.0 and a 24 hr wait fixed it. And my CWA still shows a green low risk.

@schneik1
Copy link

@daimpi Hier der 2.Versuch.
@vaubaehn Attached a new portion of fish :-)

Nach Installation von 1.5.0:
20.10. 2:17-7:20 15 Abfragen mit immer 319766 Schlüssel
21.10. 2:40-5:59 11 Abfragen mit immer 314522 Schlüssel
22.10. 3:03-3:48 4 Abfragen mit immer 307304 Schlüssel
Die Abfragen werden weniger.

Gruß
Schneik1

all-exposure-checks.txt

@vaubaehn
Copy link
Contributor

vaubaehn commented Oct 22, 2020

@schneik1 Super, vielen Dank! Nun fühle ich mich von einem ENF log geküsst, nicht von einem Delfin ;)

Schön, dass es jetzt funktioniert, aber eine Frage hätte ich trotzdem noch, weil das ENF log doch etwas merkwürdig aussieht: Wie oft öffnest du die Corona-Warn-App? 1x am Tag, alle paar Tage, 1x die Woche, oder seltener? Oder schaust du gerne in den Google-COVID-19-Benachrichtigungen rein, ohne die App zu öffnen?
Die Antwort auf die Frage könnte helfen zu verstehen, ob möglicherweise das Power Management von Android die mehrfachen Anfragen bedingen könnte.

@vaubaehn
Copy link
Contributor

@schneik1 ... und noch ein paar weitere Fragen:

  • hattest du zwischendrin mal die App-Daten gelöscht?
  • wie verbindet sich dein Telefon nachts mit dem Internet: WLAN oder mobil (LTE/4G/3G)? Wie ist die Empfangsqualität am Standort des Telefons?
  • wie viel freier Speicher hat der interne Speicher deines Telefons (nur intern, nicht externe SD Karte)

@corona-warn-app corona-warn-app locked as off-topic and limited conversation to collaborators Oct 23, 2020
@svengabr
Copy link
Member

UPDATE
This bug has been fixed with the currently available version 1.5 of the Corona Warn App. We therefore ask you to update the app accordingly.

IMPORTANT:
After updating to version 1.5 it will take up to 24 hours until the error is gone.


Hello everyone,

we are happy to hear many positive feedback after updating to 1.5 but since this issue with over 300 comments is too bloated, it makes it really hard to seperate new issues. This is why I needed to lock this conversation.

I did create a follow up topic in case you are still receiving the same error after updating to 1.5

Thank you very much for your understanding.

Best regards,
SG

Corona-Warn-App Open Source Team

@corona-warn-app corona-warn-app deleted a comment from schneik1 Oct 26, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.