Fix possible notification loop (EXPOSUREAPP-4036) (#1750)

* Adding missing log tags, otherwise displays "BaseContinuationImpl" etc.

* Remember the last risk level result for which we did a change check.
This fixed the issue that if no new risk level calculation happened, and the last one triggered a notification,
killing and restarting the app would also trigger a notification.

Co-authored-by: Ralf Gehrer <ralfgehrer@users.noreply.github.com>
Co-authored-by: BMItter <46747780+BMItter@users.noreply.github.com>

Corona-Warn-App/src/main/java/de/rki/coronawarnapp/appconfig/ConfigChangeDetector.kt

@@ -24,14 +24,14 @@ class ConfigChangeDetector @Inject constructor(
 ) {
 
     fun launch() {
-        Timber.v("Monitoring config changes.")
+        Timber.tag(TAG).v("Monitoring config changes.")
         appConfigProvider.currentConfig
             .distinctUntilChangedBy { it.identifier }
             .onEach {
-                Timber.v("Running app config change checks.")
+                Timber.tag(TAG).v("Running app config change checks.")
                 check(it.identifier)
             }
-            .catch { Timber.e(it, "App config change checks failed.") }
+            .catch { Timber.tag(TAG).e(it, "App config change checks failed.") }
             .launchIn(appScope)
     }
 
@@ -39,17 +39,21 @@ class ConfigChangeDetector @Inject constructor(
     internal suspend fun check(newIdentifier: String) {
         if (riskLevelSettings.lastUsedConfigIdentifier == null) {
             // No need to reset anything if we didn't calculate a risklevel yet.
-            Timber.d("Config changed, but no previous identifier is available.")
+            Timber.tag(TAG).d("Config changed, but no previous identifier is available.")
             return
         }
 
         val oldConfigId = riskLevelSettings.lastUsedConfigIdentifier
         if (newIdentifier != oldConfigId) {
-            Timber.i("New config id ($newIdentifier) differs from last one ($oldConfigId), resetting.")
+            Timber.tag(TAG).i("New config id ($newIdentifier) differs from last one ($oldConfigId), resetting.")
             riskLevelStorage.clear()
             taskController.submit(DefaultTaskRequest(RiskLevelTask::class, originTag = "ConfigChangeDetector"))
         } else {
-            Timber.v("Config identifier ($oldConfigId) didn't change, NOOP.")
+            Timber.tag(TAG).v("Config identifier ($oldConfigId) didn't change, NOOP.")
         }
     }
+
+    companion object {
+        private const val TAG = "ConfigChangeDetector"
+    }
 }

Corona-Warn-App/src/main/java/de/rki/coronawarnapp/risk/RiskLevelChangeDetector.kt

@@ -25,6 +25,7 @@ class RiskLevelChangeDetector @Inject constructor(
     @AppContext private val context: Context,
     @AppScope private val appScope: CoroutineScope,
     private val riskLevelStorage: RiskLevelStorage,
+    private val riskLevelSettings: RiskLevelSettings,
     private val notificationManagerCompat: NotificationManagerCompat,
     private val foregroundState: ForegroundState
 ) {
@@ -48,6 +49,13 @@ class RiskLevelChangeDetector @Inject constructor(
         val oldResult = changedLevels.first()
         val newResult = changedLevels.last()
 
+        val lastCheckedResult = riskLevelSettings.lastChangeCheckedRiskLevelTimestamp
+        if (lastCheckedResult == newResult.calculatedAt) {
+            Timber.d("We already checked this risk level change, skipping further checks.")
+            return
+        }
+        riskLevelSettings.lastChangeCheckedRiskLevelTimestamp = newResult.calculatedAt
+
         val oldRiskLevel = oldResult.riskLevel
         val newRiskLevel = newResult.riskLevel
 

Corona-Warn-App/src/main/java/de/rki/coronawarnapp/risk/RiskLevelSettings.kt

@@ -3,6 +3,7 @@ package de.rki.coronawarnapp.risk
 import android.content.Context
 import androidx.core.content.edit
 import de.rki.coronawarnapp.util.di.AppContext
+import org.joda.time.Instant
 import javax.inject.Inject
 import javax.inject.Singleton
 
@@ -24,8 +25,17 @@ class RiskLevelSettings @Inject constructor(
             putString(PKEY_RISKLEVEL_CALC_LAST_CONFIG_ID, value)
         }
 
+    var lastChangeCheckedRiskLevelTimestamp: Instant?
+        get() = prefs.getLong(PKEY_LAST_CHANGE_CHECKED_RISKLEVEL_TIMESTAMP, 0L).let {
+            if (it != 0L) Instant.ofEpochMilli(it) else null
+        }
+        set(value) = prefs.edit {
+            putLong(PKEY_LAST_CHANGE_CHECKED_RISKLEVEL_TIMESTAMP, value?.millis ?: 0L)
+        }
+
     companion object {
         private const val NAME_SHARED_PREFS = "risklevel_localdata"
         private const val PKEY_RISKLEVEL_CALC_LAST_CONFIG_ID = "risklevel.config.identifier.last"
+        private const val PKEY_LAST_CHANGE_CHECKED_RISKLEVEL_TIMESTAMP = "PKEY_RISKLEVEL_CALC_LAST_CONFIG_ID"
     }
 }

Corona-Warn-App/src/main/java/de/rki/coronawarnapp/util/WatchdogService.kt

@@ -34,18 +34,18 @@ class WatchdogService @Inject constructor(
     fun launch() {
         // Only do this if the background jobs are enabled
         if (!ConnectivityHelper.autoModeEnabled(context)) {
-            Timber.d("Background jobs are not enabled, aborting.")
+            Timber.tag(TAG).d("Background jobs are not enabled, aborting.")
             return
         }
 
-        Timber.v("Acquiring wakelocks for watchdog routine.")
+        Timber.tag(TAG).v("Acquiring wakelocks for watchdog routine.")
         ProcessLifecycleOwner.get().lifecycleScope.launch {
             // A wakelock as the OS does not handle this for us like in the background job execution
             val wakeLock = createWakeLock()
             // A wifi lock to wake up the wifi connection in case the device is dozing
             val wifiLock = createWifiLock()
 
-            Timber.d("Automatic mode is on, check if we have downloaded keys already today")
+            Timber.tag(TAG).d("Automatic mode is on, check if we have downloaded keys already today")
 
             val state = taskController.submitBlocking(
                 DefaultTaskRequest(
@@ -55,7 +55,7 @@ class WatchdogService @Inject constructor(
                 )
             )
             if (state.isFailed) {
-                Timber.e(state.error, "RetrieveDiagnosisKeysTransaction failed")
+                Timber.tag(TAG).e(state.error, "RetrieveDiagnosisKeysTransaction failed")
                 // retry the key retrieval in case of an error with a scheduled work
                 BackgroundWorkScheduler.scheduleDiagnosisKeyOneTimeWork()
             }
@@ -78,6 +78,7 @@ class WatchdogService @Inject constructor(
         .apply { acquire() }
 
     companion object {
+        private const val TAG = "WatchdogService"
         private const val TEN_MINUTE_TIMEOUT_IN_MS = 10 * 60 * 1000L
     }
 }

Corona-Warn-App/src/main/java/de/rki/coronawarnapp/util/worker/WorkManagerProvider.kt

@@ -15,17 +15,21 @@ class WorkManagerProvider @Inject constructor(
 ) {
 
     val workManager by lazy {
-        Timber.v("Setting up WorkManager.")
+        Timber.tag(TAG).v("Setting up WorkManager.")
         val configuration = Configuration.Builder().apply {
             setMinimumLoggingLevel(android.util.Log.DEBUG)
             setWorkerFactory(cwaWorkerFactory)
         }.build()
 
-        Timber.v("WorkManager initialize...")
+        Timber.tag(TAG).v("WorkManager initialize...")
         WorkManager.initialize(context, configuration)
 
         WorkManager.getInstance(context).also {
-            Timber.v("WorkManager setup done: %s", it)
+            Timber.tag(TAG).v("WorkManager setup done: %s", it)
         }
     }
+
+    companion object {
+        private const val TAG = "WorkManagerProvider"
+    }
 }

Corona-Warn-App/src/test/java/de/rki/coronawarnapp/risk/RiskLevelChangeDetectorTest.kt

@@ -37,6 +37,7 @@ class RiskLevelChangeDetectorTest : BaseTest() {
     @MockK lateinit var riskLevelStorage: RiskLevelStorage
     @MockK lateinit var notificationManagerCompat: NotificationManagerCompat
     @MockK lateinit var foregroundState: ForegroundState
+    @MockK lateinit var riskLevelSettings: RiskLevelSettings
 
     @BeforeEach
     fun setup() {
@@ -48,6 +49,8 @@ class RiskLevelChangeDetectorTest : BaseTest() {
         every { LocalData.submissionWasSuccessful() } returns false
         every { foregroundState.isInForeground } returns flowOf(true)
         every { notificationManagerCompat.areNotificationsEnabled() } returns true
+        every { riskLevelSettings.lastChangeCheckedRiskLevelTimestamp = any() } just Runs
+        every { riskLevelSettings.lastChangeCheckedRiskLevelTimestamp } returns null
     }
 
     @AfterEach
@@ -73,7 +76,8 @@ class RiskLevelChangeDetectorTest : BaseTest() {
         appScope = scope,
         riskLevelStorage = riskLevelStorage,
         notificationManagerCompat = notificationManagerCompat,
-        foregroundState = foregroundState
+        foregroundState = foregroundState,
+        riskLevelSettings = riskLevelSettings
     )
 
     @Test
@@ -160,6 +164,29 @@ class RiskLevelChangeDetectorTest : BaseTest() {
         }
     }
 
+    @Test
+    fun `risklevel went from LOW to HIGH but it is has already been processed`() {
+        every { riskLevelStorage.riskLevelResults } returns flowOf(
+            listOf(
+                createRiskLevel(INCREASED_RISK, calculatedAt = Instant.EPOCH.plus(1)),
+                createRiskLevel(LOW_LEVEL_RISK, calculatedAt = Instant.EPOCH)
+            )
+        )
+        every { riskLevelSettings.lastChangeCheckedRiskLevelTimestamp } returns Instant.EPOCH.plus(1)
+
+        runBlockingTest {
+            val instance = createInstance(scope = this)
+            instance.launch()
+
+            advanceUntilIdle()
+
+            coVerifySequence {
+                LocalData wasNot Called
+                notificationManagerCompat wasNot Called
+            }
+        }
+    }
+
     @Test
     fun `evaluate risk level change detection function`() {
         RiskLevelChangeDetector.hasHighLowLevelChanged(UNDETERMINED, UNDETERMINED) shouldBe false