Skip to content

Commit cdfd291

Browse files
DzmitryFomchyngithub-actions[bot]
DzmitryFomchyn
authored and
github-actions[bot]
committed
Add more details to logs, make important logs as warnings (#9598)
GitOrigin-RevId: ca0062d9a186b26b83426785d7416f50d880325c
1 parent 50cf093 commit cdfd291

File tree

3 files changed

+99
-41
lines changed

3 files changed

+99
-41
lines changed

‎copilot/src/main/java/com/mapbox/navigation/copilot/work/HistoryUploadWorker.kt‎

Lines changed: 37 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,7 @@ import androidx.work.ExistingWorkPolicy
1010
import androidx.work.NetworkType
1111
import androidx.work.OneTimeWorkRequestBuilder
1212
import androidx.work.WorkManager
13+
import androidx.work.WorkRequest
1314
import androidx.work.WorkerParameters
1415
import com.mapbox.common.MapboxOptions
1516
import com.mapbox.common.TransferState
@@ -33,6 +34,7 @@ import com.mapbox.navigation.copilot.internal.CopilotSession
3334
import com.mapbox.navigation.copilot.internal.PushStatus
3435
import com.mapbox.navigation.copilot.internal.saveFilename
3536
import com.mapbox.navigation.utils.internal.logD
37+
import com.mapbox.navigation.utils.internal.logW
3638
import kotlinx.coroutines.Dispatchers
3739
import kotlinx.coroutines.suspendCancellableCoroutine
3840
import kotlinx.coroutines.withContext
@@ -51,6 +53,12 @@ internal class HistoryUploadWorker(
5153

5254
/**
5355
* doWork
56+
*
57+
* TODO(NAVAND-5879) worker can be stopped if it runs longer than 10 minutes
58+
*
59+
* A ListenableWorker is given a maximum of ten minutes to finish its execution and return a
60+
* Result. After this time has expired, the worker will be signalled to stop and its
61+
* com.google.common.util.concurrent.ListenableFuture will be cancelled.
5462
*/
5563
override suspend fun doWork(): Result = withContext(Dispatchers.IO) {
5664
val copilotSession = copilotSessionFrom(workerParams.inputData)
@@ -87,12 +95,17 @@ internal class HistoryUploadWorker(
8795
} else {
8896
failure(copilotSession)
8997
if (runAttemptCount >= MAX_RUN_ATTEMPT_COUNT) {
90-
logD("Result.failure()")
98+
logW("Result.failure(${recordingFile.name}|${sessionFile.name})")
9199
delete(recordingFile)
92100
delete(sessionFile)
93101
Result.failure()
94102
} else {
95-
logD("Result.retry()")
103+
logD(
104+
"Result.retry(" +
105+
"${recordingFile.name}|${sessionFile.name}, " +
106+
"runAttemptCount = $runAttemptCount" +
107+
")",
108+
)
96109
Result.retry()
97110
}
98111
}
@@ -129,7 +142,7 @@ internal class HistoryUploadWorker(
129142
}
130143

131144
TransferState.FAILED -> {
132-
logD(
145+
logW(
133146
"uploadStatus state = FAILED error = ${uploadStatus.error}; " +
134147
"HttpResponseData = ${uploadStatus.httpResult?.value}",
135148
)
@@ -160,7 +173,8 @@ internal class HistoryUploadWorker(
160173
}
161174
}
162175

163-
private fun logD(msg: String) = logD("[upload] $msg", LOG_CATEGORY)
176+
private fun logD(msg: String) = logD("[upload] [$id] $msg", LOG_CATEGORY)
177+
private fun logW(msg: String) = logW("[upload] [$id] $msg", LOG_CATEGORY)
164178

165179
internal companion object {
166180

@@ -179,9 +193,25 @@ internal class HistoryUploadWorker(
179193
private const val UPLOAD_SESSION_ID = "upload_session_id"
180194
private const val OWNER = "owner"
181195

182-
// 2^8 x 338 = 86528 / 3600 = 24.03 hours
183-
private const val MAX_RUN_ATTEMPT_COUNT = 8
184-
private const val DELAY_IN_SECONDS = 338L
196+
/**
197+
* Max backoff delay is limited by [WorkRequest.MAX_BACKOFF_MILLIS] (5 hours = 18 000 seconds).
198+
* The total cumulative retry time could be approximately 20 hours
199+
* (it can be more depending on system delays):
200+
*
201+
* 300 * 2⁰ = 300
202+
* 300 * 2¹ = 600
203+
* 300 * 2² = 1200
204+
* 300 * 2³ = 2400
205+
* 300 * 2⁴ = 4800
206+
* 300 * 2⁵ = 9600
207+
* 300 * 2⁶ = 19200 -> capped to 18000
208+
* 300 * 2⁷ = 38400 -> capped to 18000
209+
* 300 × 2⁸ = 76800 -> caped to 18000
210+
*
211+
* Total delay is 72900 seconds ≈ 20 hours
212+
*/
213+
const val MAX_RUN_ATTEMPT_COUNT = 9
214+
private const val DELAY_IN_SECONDS = 300L // 5 minutes
185215

186216
/**
187217
* uploadHistory

‎copilot/src/main/java/com/mapbox/navigation/copilot/work/PeriodicHistoryCleanupWorker.kt‎

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -22,7 +22,7 @@ import java.util.concurrent.TimeUnit
2222
/**
2323
* Periodic task worker that scans HISTORY_FILES_DIR and:
2424
* - schedules [HistoryUploadWorker] task for each .pbf.gz recording file that has
25-
* matching .metadata.json session file, expect the latest one
25+
* matching .metadata.json session file, expect the latest one (active copilot session)
2626
* - deletes all residual .pbf.gz recording files that's missing .metadata.json session file
2727
*
2828
* IMPORTANT: This worker expects all files to be chronologically named.
@@ -103,6 +103,8 @@ internal class PeriodicHistoryCleanupWorker(
103103
}
104104
}
105105

106+
private fun logD(msg: String) = logD("[cleanup] [$id] $msg", LOG_CATEGORY)
107+
106108
internal companion object {
107109

108110
private const val HISTORY_FILES_DIR: String = "history_files_dir"
@@ -137,8 +139,6 @@ internal class PeriodicHistoryCleanupWorker(
137139
)
138140
}
139141

140-
private fun logD(msg: String) = logD("[cleanup] $msg", LOG_CATEGORY)
141-
142142
private fun logE(msg: String) = logE("[cleanup] $msg", LOG_CATEGORY)
143143
}
144144
}

‎copilot/src/test/java/com/mapbox/navigation/copilot/HistoryUploadWorkerTest.kt‎

Lines changed: 59 additions & 31 deletions
Original file line numberDiff line numberDiff line change
@@ -25,13 +25,12 @@ import com.mapbox.navigation.copilot.internal.PushStatus
2525
import com.mapbox.navigation.copilot.internal.PushStatusObserver
2626
import com.mapbox.navigation.copilot.work.HistoryUploadWorker
2727
import com.mapbox.navigation.copilot.work.HistoryUploadWorker.Companion.putCopilotSession
28-
import com.mapbox.navigation.utils.internal.logD
28+
import com.mapbox.navigation.testing.LoggingFrontendTestRule
2929
import io.mockk.CapturingSlot
3030
import io.mockk.coEvery
3131
import io.mockk.every
3232
import io.mockk.mockk
3333
import io.mockk.mockkObject
34-
import io.mockk.mockkStatic
3534
import io.mockk.slot
3635
import io.mockk.unmockkAll
3736
import io.mockk.verify
@@ -41,6 +40,7 @@ import org.junit.Assert.assertEquals
4140
import org.junit.Assert.assertNotNull
4241
import org.junit.Assert.assertTrue
4342
import org.junit.Before
43+
import org.junit.Rule
4444
import org.junit.Test
4545
import java.io.File
4646

@@ -49,6 +49,9 @@ import java.io.File
4949
@OptIn(ExperimentalPreviewMapboxNavigationAPI::class)
5050
class HistoryUploadWorkerTest {
5151

52+
@get:Rule
53+
val loggerRule = LoggingFrontendTestRule()
54+
5255
private lateinit var mockedContext: Context
5356
private lateinit var mockedUploadServiceInterface: HttpServiceInterface
5457
private val mockedPushStatusObserver = mockk<PushStatusObserver>(relaxUnitFun = true)
@@ -74,12 +77,6 @@ class HistoryUploadWorkerTest {
7477

7578
@Before
7679
fun setup() {
77-
mockkStatic("com.mapbox.navigation.utils.internal.LoggerProviderKt")
78-
every { logD(msg = any(), category = any()) } answers {
79-
// // uncomment to verify log printout
80-
// println(secondArg<String?>() + " " + firstArg())
81-
}
82-
8380
// Mock File operations
8481
mockkObject(HistoryAttachmentsUtils)
8582
coEvery { rename(any(), any()) } coAnswers {
@@ -191,25 +188,6 @@ class HistoryUploadWorkerTest {
191188
)
192189
}
193190

194-
@Test
195-
fun `remove history file not called - FAILED`() = runBlocking {
196-
givenUploadServiceAnswer(
197-
uploadStatus(
198-
state = TransferState.FAILED,
199-
error = mockk<TransferError>(relaxed = true) {
200-
every { code } returns mockk<TransferErrorCode>()
201-
},
202-
),
203-
)
204-
205-
HistoryUploadWorker(mockedContext, workerParams(stubCopilotSession))
206-
.doWork()
207-
208-
verify(exactly = 0) {
209-
delete(any())
210-
}
211-
}
212-
213191
@Test
214192
fun `Result retry - FAILED`() = runBlocking {
215193
givenUploadServiceAnswer(
@@ -280,7 +258,55 @@ class HistoryUploadWorkerTest {
280258
}
281259

282260
@Test
283-
fun `remove history file - runAttemptCount greater or equal than MAX_RUN_ATTEMPT_COUNT`() =
261+
fun `remove history file not called - FAILED, runAttemptCount = 1`() = runBlocking {
262+
givenUploadServiceAnswer(
263+
uploadStatus(
264+
state = TransferState.FAILED,
265+
error = mockk<TransferError>(relaxed = true) {
266+
every { code } returns mockk<TransferErrorCode>()
267+
},
268+
),
269+
)
270+
271+
HistoryUploadWorker(mockedContext, workerParams(stubCopilotSession, runAttemptCount = 1))
272+
.doWork()
273+
274+
verify(exactly = 0) {
275+
delete(any())
276+
}
277+
}
278+
279+
@Test
280+
fun `remove history file - FAILED, runAttemptCount = MAX_RUN_ATTEMPT_COUNT`() =
281+
runBlocking {
282+
givenUploadServiceAnswer(
283+
uploadStatus(
284+
state = TransferState.FAILED,
285+
error = mockk<TransferError>(relaxed = true) {
286+
every { code } returns mockk<TransferErrorCode>()
287+
},
288+
),
289+
)
290+
291+
HistoryUploadWorker(
292+
mockedContext,
293+
workerParams(
294+
stubCopilotSession,
295+
runAttemptCount = HistoryUploadWorker.MAX_RUN_ATTEMPT_COUNT,
296+
),
297+
).doWork()
298+
299+
val deletedFiles = mutableListOf<File>()
300+
verify(exactly = 2) {
301+
delete(capture(deletedFiles))
302+
}
303+
assertEquals(2, deletedFiles.size)
304+
assertNotNull(deletedFiles.first { it.name.endsWith("pbf.gz") })
305+
assertNotNull(deletedFiles.first { it.name.endsWith("metadata.json") })
306+
}
307+
308+
@Test
309+
fun `remove history file - FINISHED 204`() =
284310
runBlocking {
285311
givenUploadServiceAnswer(
286312
uploadStatus(
@@ -290,7 +316,7 @@ class HistoryUploadWorkerTest {
290316
),
291317
)
292318

293-
HistoryUploadWorker(mockedContext, workerParams(stubCopilotSession, 8))
319+
HistoryUploadWorker(mockedContext, workerParams(stubCopilotSession))
294320
.doWork()
295321

296322
val deletedFiles = mutableListOf<File>()
@@ -314,8 +340,10 @@ class HistoryUploadWorkerTest {
314340
),
315341
)
316342

317-
val result = HistoryUploadWorker(mockedContext, workerParams(stubCopilotSession, 8))
318-
.doWork()
343+
val result = HistoryUploadWorker(
344+
mockedContext,
345+
workerParams(stubCopilotSession, HistoryUploadWorker.MAX_RUN_ATTEMPT_COUNT),
346+
).doWork()
319347

320348
assertTrue(result is ListenableWorker.Result.Failure)
321349
}

0 commit comments

Comments
 (0)