From cf863f0a37a2aaaa7a94002522ba04e2b3d8365c Mon Sep 17 00:00:00 2001 From: Matthias Urhahn <matthias.urhahn@sap.com> Date: Mon, 30 Nov 2020 15:53:29 +0100 Subject: [PATCH] Use key package day/hour to determine data staleness (EXPOSUREAPP-4042) (#1748) * Add missing RiskLevelStorage reset call when using the internal app reset functionality. * Improve TaskController logging. * Use the day/hour of the last key package download to determine whether the key pkgs are outdated when calculating the risk level. Co-authored-by: BMItter <46747780+BMItter@users.noreply.github.com> Co-authored-by: harambasicluka <64483219+harambasicluka@users.noreply.github.com> --- .../rki/coronawarnapp/risk/RiskLevelTask.kt | 52 +++++++++++-------- .../rki/coronawarnapp/risk/TimeVariables.kt | 36 ------------- .../rki/coronawarnapp/task/TaskController.kt | 7 ++- .../task/internal/InternalTaskState.kt | 6 +++ .../coronawarnapp/risk/RiskLevelTaskTest.kt | 30 ++++++----- .../coronawarnapp/risk/TimeVariablesTest.kt | 5 -- 6 files changed, 60 insertions(+), 76 deletions(-) diff --git a/Corona-Warn-App/src/main/java/de/rki/coronawarnapp/risk/RiskLevelTask.kt b/Corona-Warn-App/src/main/java/de/rki/coronawarnapp/risk/RiskLevelTask.kt index 1f87c65a6..d3d813eb9 100644 --- a/Corona-Warn-App/src/main/java/de/rki/coronawarnapp/risk/RiskLevelTask.kt +++ b/Corona-Warn-App/src/main/java/de/rki/coronawarnapp/risk/RiskLevelTask.kt @@ -4,11 +4,10 @@ import android.content.Context import de.rki.coronawarnapp.appconfig.AppConfigProvider import de.rki.coronawarnapp.appconfig.ConfigData import de.rki.coronawarnapp.appconfig.ExposureWindowRiskCalculationConfig +import de.rki.coronawarnapp.diagnosiskeys.storage.KeyCacheRepository import de.rki.coronawarnapp.exception.ExceptionCategory -import de.rki.coronawarnapp.exception.RiskLevelCalculationException import de.rki.coronawarnapp.exception.reporting.report import de.rki.coronawarnapp.nearby.ENFClient -import de.rki.coronawarnapp.risk.RiskLevel.UNKNOWN_RISK_OUTDATED_RESULTS import de.rki.coronawarnapp.risk.RiskLevelResult.FailureReason import de.rki.coronawarnapp.risk.storage.RiskLevelStorage import de.rki.coronawarnapp.task.Task @@ -25,6 +24,7 @@ import kotlinx.coroutines.flow.Flow import kotlinx.coroutines.flow.asFlow import kotlinx.coroutines.flow.first import org.joda.time.Duration +import org.joda.time.Instant import timber.log.Timber import javax.inject.Inject import javax.inject.Provider @@ -38,7 +38,8 @@ class RiskLevelTask @Inject constructor( private val backgroundModeStatus: BackgroundModeStatus, private val riskLevelSettings: RiskLevelSettings, private val appConfigProvider: AppConfigProvider, - private val riskLevelStorage: RiskLevelStorage + private val riskLevelStorage: RiskLevelStorage, + private val keyCacheRepository: KeyCacheRepository ) : Task<DefaultProgress, RiskLevelTaskResult> { private val internalProgress = ConflatedBroadcastChannel<DefaultProgress>() @@ -72,10 +73,14 @@ class RiskLevelTask @Inject constructor( } private suspend fun determineRiskLevelResult(configData: ConfigData): RiskLevelTaskResult { + val nowUTC = timeStamper.nowUTC.also { + Timber.d("The current time is %s", it) + } + if (!isNetworkEnabled(context)) { Timber.i("Risk not calculated, internet unavailable.") return RiskLevelTaskResult( - calculatedAt = timeStamper.nowUTC, + calculatedAt = nowUTC, failureReason = FailureReason.NO_INTERNET ) } @@ -83,15 +88,15 @@ class RiskLevelTask @Inject constructor( if (!enfClient.isTracingEnabled.first()) { Timber.i("Risk not calculated, tracing is disabled.") return RiskLevelTaskResult( - calculatedAt = timeStamper.nowUTC, + calculatedAt = nowUTC, failureReason = FailureReason.TRACING_OFF ) } - if (calculationNotPossibleBecauseOfOutdatedResults()) { + if (areKeyPkgsOutDated(nowUTC)) { Timber.i("Risk not calculated, results are outdated.") return RiskLevelTaskResult( - calculatedAt = timeStamper.nowUTC, + calculatedAt = nowUTC, failureReason = when (backgroundJobsEnabled()) { true -> FailureReason.OUTDATED_RESULTS false -> FailureReason.OUTDATED_RESULTS_MANUAL @@ -103,22 +108,26 @@ class RiskLevelTask @Inject constructor( return calculateRiskLevel(configData) } - private fun calculationNotPossibleBecauseOfOutdatedResults(): Boolean { - Timber.tag(TAG).d("Evaluating calculationNotPossibleBecauseOfOutdatedResults()") - // if the last calculation is longer in the past as the defined threshold we return the stale state - val timeSinceLastDiagnosisKeyFetchFromServer = - TimeVariables.getTimeSinceLastDiagnosisKeyFetchFromServer() - ?: throw RiskLevelCalculationException( - IllegalArgumentException("Time since last exposure calculation is null") - ) - /** we only return outdated risk level if the threshold is reached AND the active tracing time is above the - defined threshold because [UNKNOWN_RISK_INITIAL] overrules [UNKNOWN_RISK_OUTDATED_RESULTS] */ - return (timeSinceLastDiagnosisKeyFetchFromServer.millisecondsToHours() > - TimeVariables.getMaxStaleExposureRiskRange() && isActiveTracingTimeAboveThreshold()).also { + private suspend fun areKeyPkgsOutDated(nowUTC: Instant): Boolean { + Timber.tag(TAG).d("Evaluating areKeyPkgsOutDated(nowUTC=%s)", nowUTC) + + val latestDownload = keyCacheRepository.getAllCachedKeys().maxByOrNull { + it.info.toDateTime() + } + if (latestDownload == null) { + Timber.w("areKeyPkgsOutDated(): No downloads available, why is the RiskLevelTask running? Aborting!") + return true + } + + val downloadAge = Duration(latestDownload.info.toDateTime(), nowUTC).also { + Timber.d("areKeyPkgsOutDated(): Age is %dh for latest key package: %s", it.standardHours, latestDownload) + } + + return (downloadAge.isLongerThan(STALE_DOWNLOAD_LIMIT) && isActiveTracingTimeAboveThreshold()).also { if (it) { - Timber.tag(TAG).i("Calculation was not possible because reults are outdated.") + Timber.tag(TAG).i("areKeyPkgsOutDated(): Calculation was not possible because reults are outdated.") } else { - Timber.tag(TAG).d("Results are not out dated, continuing evaluation.") + Timber.tag(TAG).d("areKeyPkgsOutDated(): Key pkgs are fresh :), continuing evaluation.") } } } @@ -199,5 +208,6 @@ class RiskLevelTask @Inject constructor( companion object { private val TAG: String? = RiskLevelTask::class.simpleName + private val STALE_DOWNLOAD_LIMIT = Duration.standardHours(48) } } diff --git a/Corona-Warn-App/src/main/java/de/rki/coronawarnapp/risk/TimeVariables.kt b/Corona-Warn-App/src/main/java/de/rki/coronawarnapp/risk/TimeVariables.kt index dc90f38b4..2c442de6f 100644 --- a/Corona-Warn-App/src/main/java/de/rki/coronawarnapp/risk/TimeVariables.kt +++ b/Corona-Warn-App/src/main/java/de/rki/coronawarnapp/risk/TimeVariables.kt @@ -79,19 +79,6 @@ object TimeVariables { */ fun getMinActivatedTracingTime(): Int = MIN_ACTIVATED_TRACING_TIME - /** - * The timeRange until the calculated exposure figures are rated as stale. - * In hours. - */ - private const val MAX_STALE_EXPOSURE_RISK_RANGE = 48 - - /** - * Getter function for [MAX_STALE_EXPOSURE_RISK_RANGE] - * - * @return stale threshold in hours - */ - fun getMaxStaleExposureRiskRange(): Int = MAX_STALE_EXPOSURE_RISK_RANGE - private const val MILISECONDS_IN_A_SECOND = 1000 private const val SECONDS_IN_A_MINUTES = 60 private const val MINUTES_IN_AN_HOUR = 60 @@ -139,33 +126,10 @@ object TimeVariables { fun getInitialExposureTracingActivationTimestamp(): Long? = LocalData.initialTracingActivationTimestamp() - /** - * timestamp when the last successful exposureRisk calculation happened read from the mobile device storage. - * Last time when the transaction was successfully executed - * - * @return last time in milliseconds [de.rki.coronawarnapp.transaction.RetrieveDiagnosisKeysTransaction] - * was run successfully - */ - // because we have risk level calculation and key retrieval calculation - fun getLastTimeDiagnosisKeysFromServerFetch(): Long? = - LocalData.lastTimeDiagnosisKeysFromServerFetch()?.time - /**************************************************** * CALCULATED TIME VARIABLES ****************************************************/ - /** - * The time since the last successful exposure calculation ran in foreground or background. - * In milliseconds - * - * @return time in milliseconds since the exposure calculation was run successfully - */ - fun getTimeSinceLastDiagnosisKeyFetchFromServer(): Long? { - val lastTimeDiagnosisKeysFromServerFetch = - getLastTimeDiagnosisKeysFromServerFetch() ?: return null - return System.currentTimeMillis() - lastTimeDiagnosisKeysFromServerFetch - } - /** * The time the tracing is active. * diff --git a/Corona-Warn-App/src/main/java/de/rki/coronawarnapp/task/TaskController.kt b/Corona-Warn-App/src/main/java/de/rki/coronawarnapp/task/TaskController.kt index b7cc4ca6e..36d2b2c85 100644 --- a/Corona-Warn-App/src/main/java/de/rki/coronawarnapp/task/TaskController.kt +++ b/Corona-Warn-App/src/main/java/de/rki/coronawarnapp/task/TaskController.kt @@ -148,7 +148,12 @@ class TaskController @Inject constructor( } } - Timber.tag(TAG).v("Tasks after processing (count=%d):\n%s", size, values.joinToString("\n")) + Timber.tag(TAG).v( + "Tasks after processing (count=%d):\n%s", + size, values.sortedBy { it.finishedAt }.joinToString("\n") { + it.toLogString() + } + ) } private fun procressFinishedTasks(data: Map<UUID, InternalTaskState>): Map<UUID, InternalTaskState> { diff --git a/Corona-Warn-App/src/main/java/de/rki/coronawarnapp/task/internal/InternalTaskState.kt b/Corona-Warn-App/src/main/java/de/rki/coronawarnapp/task/internal/InternalTaskState.kt index 1eb0c52be..8ac4fd5df 100644 --- a/Corona-Warn-App/src/main/java/de/rki/coronawarnapp/task/internal/InternalTaskState.kt +++ b/Corona-Warn-App/src/main/java/de/rki/coronawarnapp/task/internal/InternalTaskState.kt @@ -32,4 +32,10 @@ internal data class InternalTaskState( startedAt != null -> ExecutionState.RUNNING else -> ExecutionState.PENDING } + + fun toLogString(): String = """ + ${request.type.simpleName} state=${executionState.name} id=$id + startedAt=$startedAt finishedAt=$finishedAt result=${result != null} error=$error + arguments=${request.arguments} config=$config + """.trimIndent() } diff --git a/Corona-Warn-App/src/test/java/de/rki/coronawarnapp/risk/RiskLevelTaskTest.kt b/Corona-Warn-App/src/test/java/de/rki/coronawarnapp/risk/RiskLevelTaskTest.kt index df3dbcab8..4d1170052 100644 --- a/Corona-Warn-App/src/test/java/de/rki/coronawarnapp/risk/RiskLevelTaskTest.kt +++ b/Corona-Warn-App/src/test/java/de/rki/coronawarnapp/risk/RiskLevelTaskTest.kt @@ -6,6 +6,7 @@ import android.net.Network import android.net.NetworkCapabilities import de.rki.coronawarnapp.appconfig.AppConfigProvider import de.rki.coronawarnapp.appconfig.ConfigData +import de.rki.coronawarnapp.diagnosiskeys.storage.KeyCacheRepository import de.rki.coronawarnapp.nearby.ENFClient import de.rki.coronawarnapp.risk.storage.RiskLevelStorage import de.rki.coronawarnapp.task.Task @@ -37,26 +38,15 @@ class RiskLevelTaskTest : BaseTest() { @MockK lateinit var configData: ConfigData @MockK lateinit var appConfigProvider: AppConfigProvider @MockK lateinit var riskLevelStorage: RiskLevelStorage + @MockK lateinit var keyCacheRepository: KeyCacheRepository private val arguments: Task.Arguments = object : Task.Arguments {} - private fun createTask() = RiskLevelTask( - riskLevels = riskLevels, - context = context, - enfClient = enfClient, - timeStamper = timeStamper, - backgroundModeStatus = backgroundModeStatus, - riskLevelSettings = riskLevelSettings, - appConfigProvider = appConfigProvider, - riskLevelStorage = riskLevelStorage - ) - @BeforeEach fun setup() { MockKAnnotations.init(this) mockkObject(TimeVariables) - every { TimeVariables.getLastTimeDiagnosisKeysFromServerFetch() } returns null coEvery { appConfigProvider.getAppConfig() } returns configData every { configData.identifier } returns "config-identifier" @@ -73,13 +63,27 @@ class RiskLevelTaskTest : BaseTest() { every { timeStamper.nowUTC } returns Instant.EPOCH every { riskLevelSettings.lastUsedConfigIdentifier = any() } just Runs + + coEvery { keyCacheRepository.getAllCachedKeys() } returns emptyList() } + private fun createTask() = RiskLevelTask( + riskLevels = riskLevels, + context = context, + enfClient = enfClient, + timeStamper = timeStamper, + backgroundModeStatus = backgroundModeStatus, + riskLevelSettings = riskLevelSettings, + appConfigProvider = appConfigProvider, + riskLevelStorage = riskLevelStorage, + keyCacheRepository = keyCacheRepository + ) + @Test fun `last used config ID is set after calculation`() = runBlockingTest { // val task = createTask() // task.run(arguments) // -// verify { riskLevelData.lastUsedConfigIdentifier = "config-identifier" } +// verify { riskLevelSettings.lastUsedConfigIdentifier = "config-identifier" } } } diff --git a/Corona-Warn-App/src/test/java/de/rki/coronawarnapp/risk/TimeVariablesTest.kt b/Corona-Warn-App/src/test/java/de/rki/coronawarnapp/risk/TimeVariablesTest.kt index 4b4651965..63d994fc6 100644 --- a/Corona-Warn-App/src/test/java/de/rki/coronawarnapp/risk/TimeVariablesTest.kt +++ b/Corona-Warn-App/src/test/java/de/rki/coronawarnapp/risk/TimeVariablesTest.kt @@ -34,11 +34,6 @@ class TimeVariablesTest { Assert.assertEquals(TimeVariables.getMinActivatedTracingTime(), 24) } - @Test - fun getMaxStaleExposureRiskRange() { - Assert.assertEquals(TimeVariables.getMaxStaleExposureRiskRange(), 48) - } - @Test fun getManualKeyRetrievalDelay() { mockkObject(CWADebug) -- GitLab