Implement specific logs to analyse (EXPOSUREAPP-3440) (#1563)

* improved logging for Bakcground Worker

* loggin added in updateRiskLevelScore

Notification Permissions logged and notification sent is loggged

* merge conflict resolution

* uniformity in Log tags

Co-authored-by: harambasicluka <64483219+harambasicluka@users.noreply.github.com>

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

 package de.rki.coronawarnapp.risk
 
 import androidx.annotation.VisibleForTesting
+import androidx.core.app.NotificationManagerCompat
 import com.google.android.gms.nearby.exposurenotification.ExposureSummary
 import de.rki.coronawarnapp.CoronaWarnApplication
 import de.rki.coronawarnapp.R
@@ -195,18 +196,30 @@ class DefaultRiskLevels @Inject constructor(
     @VisibleForTesting
     internal fun updateRiskLevelScore(riskLevel: RiskLevel) {
         val lastCalculatedScore = RiskLevelRepository.getLastCalculatedScore()
+        Timber.d("last CalculatedS core is ${lastCalculatedScore.raw} and Current Risk Level is ${riskLevel.raw}")
+
         if (RiskLevel.riskLevelChangedBetweenLowAndHigh(
                 lastCalculatedScore,
                 riskLevel
             ) && !LocalData.submissionWasSuccessful()
         ) {
+            Timber.d(
+                "Notification Permission = ${
+                    NotificationManagerCompat.from(CoronaWarnApplication.getAppContext()).areNotificationsEnabled()
+                }"
+            )
+
             NotificationHelper.sendNotification(
                 CoronaWarnApplication.getAppContext().getString(R.string.notification_body)
             )
+
+            Timber.d("Risk level changed and notification sent. Current Risk level is ${riskLevel.raw}")
         }
         if (lastCalculatedScore.raw == RiskLevelConstants.INCREASED_RISK &&
             riskLevel.raw == RiskLevelConstants.LOW_LEVEL_RISK) {
             LocalData.isUserToBeNotifiedOfLoweredRiskLevel = true
+
+            Timber.d("Risk level changed LocalData is updated. Current Risk level is ${riskLevel.raw}")
         }
         RiskLevelRepository.setRiskLevelScore(riskLevel)
     }

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

@@ -7,6 +7,7 @@ import com.squareup.inject.assisted.Assisted
 import com.squareup.inject.assisted.AssistedInject
 import de.rki.coronawarnapp.playbook.Playbook
 import de.rki.coronawarnapp.util.worker.InjectedWorkerFactory
+import timber.log.Timber
 
 /**
  * One time background noise worker
@@ -25,6 +26,7 @@ class BackgroundNoiseOneTimeWorker @AssistedInject constructor(
      * @return Result
      */
     override suspend fun doWork(): Result {
+        Timber.d("$id: doWork() started. Run attempt: $runAttemptCount")
         var result = Result.success()
 
         try {
@@ -38,6 +40,7 @@ class BackgroundNoiseOneTimeWorker @AssistedInject constructor(
             }
         }
 
+        Timber.d("$id: doWork() finished with %s", result)
         return result
     }
 

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

@@ -34,7 +34,7 @@ class BackgroundNoisePeriodicWorker @AssistedInject constructor(
      * @see BackgroundConstants.NUMBER_OF_DAYS_TO_RUN_PLAYBOOK
      */
     override suspend fun doWork(): Result {
-        Timber.d("Background job started. Run attempt: $runAttemptCount")
+        Timber.d("$id: doWork() started. Run attempt: $runAttemptCount")
 
         var result = Result.success()
         try {
@@ -57,11 +57,13 @@ class BackgroundNoisePeriodicWorker @AssistedInject constructor(
                 Result.retry()
             }
         }
+        Timber.d("$id: doWork() finished with %s", result)
         return result
     }
 
     private fun stopWorker() {
         BackgroundWorkScheduler.WorkType.BACKGROUND_NOISE_PERIODIC_WORK.stop()
+        Timber.d("$id: worker stopped")
     }
 
     @AssistedInject.Factory

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

@@ -43,19 +43,20 @@ class DiagnosisTestResultRetrievalPeriodicWorker @AssistedInject constructor(
      */
     override suspend fun doWork(): Result {
 
-        Timber.d("Background job started. Run attempt: $runAttemptCount")
+        Timber.d("$id: doWork() started. Run attempt: $runAttemptCount")
         BackgroundWorkHelper.sendDebugNotification(
             "TestResult Executing: Start", "TestResult started. Run attempt: $runAttemptCount "
         )
 
         if (runAttemptCount > BackgroundConstants.WORKER_RETRY_COUNT_THRESHOLD) {
-            Timber.d("Background job failed after $runAttemptCount attempts. Rescheduling")
+            Timber.d("$id doWork() failed after $runAttemptCount attempts. Rescheduling")
 
             BackgroundWorkHelper.sendDebugNotification(
                 "TestResult Executing: Failure", "TestResult failed with $runAttemptCount attempts"
             )
-
             BackgroundWorkScheduler.scheduleDiagnosisKeyPeriodicWork()
+            Timber.d("$id Rescheduled background worker")
+
             return Result.failure()
         }
         var result = Result.success()
@@ -65,10 +66,13 @@ class DiagnosisTestResultRetrievalPeriodicWorker @AssistedInject constructor(
                     System.currentTimeMillis()
                 ) < BackgroundConstants.POLLING_VALIDITY_MAX_DAYS
             ) {
+                Timber.d(" $id maximum days not exceeded")
                 val testResult = SubmissionService.asyncRequestTestResult()
                 initiateNotification(testResult)
+                Timber.d(" $id Test Result Notification Initiated")
             } else {
                 stopWorker()
+                Timber.d(" $id worker stopped")
             }
         } catch (e: Exception) {
             result = Result.retry()
@@ -77,6 +81,7 @@ class DiagnosisTestResultRetrievalPeriodicWorker @AssistedInject constructor(
         BackgroundWorkHelper.sendDebugNotification(
             "TestResult Executing: End", "TestResult result: $result "
         )
+        Timber.d("$id: doWork() finished with %s", result)
 
         return result
     }
@@ -94,9 +99,10 @@ class DiagnosisTestResultRetrievalPeriodicWorker @AssistedInject constructor(
      */
     private fun initiateNotification(testResult: TestResult) {
         if (LocalData.isTestResultNotificationSent() || LocalData.submissionWasSuccessful()) {
+            Timber.d("$id: Notification already sent or there was a successful submission")
             return
         }
-
+        Timber.d("$id: Test Result retried is $testResult")
         if (testResult == TestResult.NEGATIVE || testResult == TestResult.POSITIVE ||
             testResult == TestResult.INVALID
         ) {
@@ -107,6 +113,7 @@ class DiagnosisTestResultRetrievalPeriodicWorker @AssistedInject constructor(
                     CoronaWarnApplication.getAppContext()
                         .getString(R.string.notification_body)
                 )
+                Timber.d("$id: Test Result available and notification is initiated")
             }
             LocalData.isTestResultNotificationSent(true)
             stopWorker()
@@ -122,7 +129,7 @@ class DiagnosisTestResultRetrievalPeriodicWorker @AssistedInject constructor(
     private fun stopWorker() {
         LocalData.initialPollingForTestResultTimeStamp(0L)
         BackgroundWorkScheduler.WorkType.DIAGNOSIS_TEST_RESULT_PERIODIC_WORKER.stop()
-
+        Timber.d("$id: Background worker stopped")
         BackgroundWorkHelper.sendDebugNotification(
             "TestResult Stopped", "TestResult Stopped"
         )