From 20ba02db57ab2124afece5a96cc2924aa5fd0b73 Mon Sep 17 00:00:00 2001 From: SpiritCroc Date: Thu, 3 Mar 2022 08:55:34 +0100 Subject: [PATCH] [TMP] Raise sync logging level So we get these in rageshakes Change-Id: I1efb8dd759cd03607ade0611c92a87df1b20c7f3 --- .../sdk/internal/session/sync/SyncTask.kt | 16 ++++----- .../internal/session/sync/job/SyncThread.kt | 36 +++++++++---------- 2 files changed, 26 insertions(+), 26 deletions(-) diff --git a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/session/sync/SyncTask.kt b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/session/sync/SyncTask.kt index 1ee62ad774..70b3dbf787 100644 --- a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/session/sync/SyncTask.kt +++ b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/session/sync/SyncTask.kt @@ -88,7 +88,7 @@ internal class DefaultSyncTask @Inject constructor( } private suspend fun doSync(params: SyncTask.Params): SyncResponse { - Timber.tag(loggerTag.value).d("Sync task started on Thread: ${Thread.currentThread().name}") + Timber.tag(loggerTag.value).i("Sync task started on Thread: ${Thread.currentThread().name}") val requestParams = HashMap() var timeout = 0L @@ -115,7 +115,7 @@ internal class DefaultSyncTask @Inject constructor( var syncResponseToReturn: SyncResponse? = null val syncStatisticsData = SyncStatisticsData(isInitialSync, params.afterPause) if (isInitialSync) { - Timber.tag(loggerTag.value).d("INIT_SYNC with filter: ${requestParams["filter"]}") + Timber.tag(loggerTag.value).i("INIT_SYNC with filter: ${requestParams["filter"]}") val initSyncStrategy = initialSyncStrategy logDuration("INIT_SYNC strategy: $initSyncStrategy", loggerTag) { if (initSyncStrategy is InitialSyncStrategy.Optimized) { @@ -147,7 +147,7 @@ internal class DefaultSyncTask @Inject constructor( } defaultSyncStatusService.endAll() } else { - Timber.tag(loggerTag.value).d("Start incremental sync request") + Timber.tag(loggerTag.value).i("Start incremental sync request") defaultSyncStatusService.setStatus(SyncStatusService.Status.IncrementalSyncIdle) val syncResponse = try { executeRequest(globalErrorReceiver) { @@ -163,20 +163,20 @@ internal class DefaultSyncTask @Inject constructor( } val nbRooms = syncResponse.rooms?.invite.orEmpty().size + syncResponse.rooms?.join.orEmpty().size + syncResponse.rooms?.leave.orEmpty().size val nbToDevice = syncResponse.toDevice?.events.orEmpty().size - Timber.tag(loggerTag.value).d("Incremental sync request parsing, $nbRooms room(s) $nbToDevice toDevice(s)") + Timber.tag(loggerTag.value).i("Incremental sync request parsing, $nbRooms room(s) $nbToDevice toDevice(s)") defaultSyncStatusService.setStatus(SyncStatusService.Status.IncrementalSyncParsing( rooms = nbRooms, toDevice = nbToDevice )) syncResponseHandler.handleResponse(syncResponse, token, null) syncResponseToReturn = syncResponse - Timber.tag(loggerTag.value).d("Incremental sync done") + Timber.tag(loggerTag.value).i("Incremental sync done") defaultSyncStatusService.setStatus(SyncStatusService.Status.IncrementalSyncDone) } syncStatisticsData.treatmentSyncTime = SystemClock.elapsedRealtime() syncStatisticsData.nbOfRooms = syncResponseToReturn?.rooms?.join?.size ?: 0 sendStatistics(syncStatisticsData) - Timber.tag(loggerTag.value).d("Sync task finished on Thread: ${Thread.currentThread().name}") + Timber.tag(loggerTag.value).i("Sync task finished on Thread: ${Thread.currentThread().name}") // Should throw if null as it's a mandatory value. return syncResponseToReturn!! } @@ -185,7 +185,7 @@ internal class DefaultSyncTask @Inject constructor( val workingFile = File(workingDir, "initSync.json") val status = initialSyncStatusRepository.getStep() if (workingFile.exists() && status >= InitialSyncStatus.STEP_DOWNLOADED) { - Timber.tag(loggerTag.value).d("INIT_SYNC file is already here") + Timber.tag(loggerTag.value).i("INIT_SYNC file is already here") reportSubtask(defaultSyncStatusService, InitSyncStep.Downloading, 1, 0.3f) { // Empty task } @@ -245,7 +245,7 @@ internal class DefaultSyncTask @Inject constructor( // Log some stats val nbOfJoinedRooms = syncResponse.rooms?.join?.size ?: 0 val nbOfJoinedRoomsInFile = syncResponse.rooms?.join?.values?.count { it.ephemeral is LazyRoomSyncEphemeral.Stored } - Timber.tag(loggerTag.value).d("INIT_SYNC $nbOfJoinedRooms rooms, $nbOfJoinedRoomsInFile ephemeral stored into files") + Timber.tag(loggerTag.value).i("INIT_SYNC $nbOfJoinedRooms rooms, $nbOfJoinedRoomsInFile ephemeral stored into files") logDuration("INIT_SYNC Database insertion", loggerTag) { syncResponseHandler.handleResponse(syncResponse, null, defaultSyncStatusService) diff --git a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/session/sync/job/SyncThread.kt b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/session/sync/job/SyncThread.kt index 2460720adc..d93f350377 100644 --- a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/session/sync/job/SyncThread.kt +++ b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/session/sync/job/SyncThread.kt @@ -93,7 +93,7 @@ internal class SyncThread @Inject constructor(private val syncTask: SyncTask, fun restart() = synchronized(lock) { if (!isStarted) { - Timber.tag(loggerTag.value).d("Resume sync...") + Timber.tag(loggerTag.value).i("Resume sync...") isStarted = true // Check again server availability and the token validity canReachServer = true @@ -104,7 +104,7 @@ internal class SyncThread @Inject constructor(private val syncTask: SyncTask, fun pause() = synchronized(lock) { if (isStarted) { - Timber.tag(loggerTag.value).d("Pause sync...") + Timber.tag(loggerTag.value).i("Pause sync...") isStarted = false retryNoNetworkTask?.cancel() syncScope.coroutineContext.cancelChildren() @@ -112,7 +112,7 @@ internal class SyncThread @Inject constructor(private val syncTask: SyncTask, } fun kill() = synchronized(lock) { - Timber.tag(loggerTag.value).d("Kill sync...") + Timber.tag(loggerTag.value).i("Kill sync...") updateStateTo(SyncState.Killing) retryNoNetworkTask?.cancel() syncScope.coroutineContext.cancelChildren() @@ -136,21 +136,21 @@ internal class SyncThread @Inject constructor(private val syncTask: SyncTask, } override fun run() { - Timber.tag(loggerTag.value).d("Start syncing...") + Timber.tag(loggerTag.value).i("Start syncing...") isStarted = true networkConnectivityChecker.register(this) backgroundDetectionObserver.register(this) registerActiveCallsObserver() while (state != SyncState.Killing) { - Timber.tag(loggerTag.value).d("Entering loop, state: $state") + Timber.tag(loggerTag.value).i("Entering loop, state: $state") if (!isStarted) { - Timber.tag(loggerTag.value).d("Sync is Paused. Waiting...") + Timber.tag(loggerTag.value).i("Sync is Paused. Waiting...") updateStateTo(SyncState.Paused) synchronized(lock) { lock.wait() } - Timber.tag(loggerTag.value).d("...unlocked") + Timber.tag(loggerTag.value).i("...unlocked") } else if (!canReachServer) { - Timber.tag(loggerTag.value).d("No network. Waiting...") + Timber.tag(loggerTag.value).i("No network. Waiting...") updateStateTo(SyncState.NoNetwork) // We force retrying in RETRY_WAIT_TIME_MS maximum. Otherwise it will be unlocked by onConnectivityChanged() or restart() retryNoNetworkTask = Timer(SyncState.NoNetwork.toString(), false).schedule(RETRY_WAIT_TIME_MS) { @@ -160,15 +160,15 @@ internal class SyncThread @Inject constructor(private val syncTask: SyncTask, } } synchronized(lock) { lock.wait() } - Timber.tag(loggerTag.value).d("...retry") + Timber.tag(loggerTag.value).i("...retry") } else if (!isTokenValid) { if (state == SyncState.Killing) { continue } - Timber.tag(loggerTag.value).d("Token is invalid. Waiting...") + Timber.tag(loggerTag.value).i("Token is invalid. Waiting...") updateStateTo(SyncState.InvalidToken) synchronized(lock) { lock.wait() } - Timber.tag(loggerTag.value).d("...unlocked") + Timber.tag(loggerTag.value).i("...unlocked") } else { if (state !is SyncState.Running) { updateStateTo(SyncState.Running(afterPause = true)) @@ -179,7 +179,7 @@ internal class SyncThread @Inject constructor(private val syncTask: SyncTask, afterPause -> 0L /* No timeout after a pause */ else -> DEFAULT_LONG_POOL_TIMEOUT } - Timber.tag(loggerTag.value).d("Execute sync request with timeout $timeout") + Timber.tag(loggerTag.value).i("Execute sync request with timeout $timeout") val params = SyncTask.Params(timeout, SyncPresence.Online, afterPause = afterPause) val sync = syncScope.launch { previousSyncResponseHasToDevice = doSync(params) @@ -187,10 +187,10 @@ internal class SyncThread @Inject constructor(private val syncTask: SyncTask, runBlocking { sync.join() } - Timber.tag(loggerTag.value).d("...Continue") + Timber.tag(loggerTag.value).i("...Continue") } } - Timber.tag(loggerTag.value).d("Sync killed") + Timber.tag(loggerTag.value).i("Sync killed") updateStateTo(SyncState.Killed) backgroundDetectionObserver.unregister(this) networkConnectivityChecker.unregister(this) @@ -223,9 +223,9 @@ internal class SyncThread @Inject constructor(private val syncTask: SyncTask, } if (failure is Failure.NetworkConnection && failure.cause is SocketTimeoutException) { // Timeout are not critical - Timber.tag(loggerTag.value).d("Timeout") + Timber.tag(loggerTag.value).i("Timeout") } else if (failure is CancellationException) { - Timber.tag(loggerTag.value).d("Cancelled") + Timber.tag(loggerTag.value).i("Cancelled") } else if (failure.isTokenError()) { // No token or invalid token, stop the thread Timber.tag(loggerTag.value).w(failure, "Token error") @@ -235,7 +235,7 @@ internal class SyncThread @Inject constructor(private val syncTask: SyncTask, Timber.tag(loggerTag.value).e(failure) if (failure !is Failure.NetworkConnection || failure.cause is JsonEncodingException) { // Wait 10s before retrying - Timber.tag(loggerTag.value).d("Wait 10s") + Timber.tag(loggerTag.value).i("Wait 10s") delay(RETRY_WAIT_TIME_MS) } } @@ -250,7 +250,7 @@ internal class SyncThread @Inject constructor(private val syncTask: SyncTask, } private fun updateStateTo(newState: SyncState) { - Timber.tag(loggerTag.value).d("Update state from $state to $newState") + Timber.tag(loggerTag.value).i("Update state from $state to $newState") if (newState == state) { return }