filippodb
/
SchildiChat-android
mirror of https://github.com/SchildiChat/SchildiChat-android.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

[TMP] Raise sync logging level 

So we get these in rageshakes

Change-Id: I1efb8dd759cd03607ade0611c92a87df1b20c7f3
This commit is contained in:
SpiritCroc 2022-03-03 08:55:34 +01:00
parent ad3beec3cf
commit 20ba02db57
2 changed files with 26 additions and 26 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

16
matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/session/sync/SyncTask.kt
View File

@ -88,7 +88,7 @@ internal class DefaultSyncTask @Inject constructor(
} }
private suspend fun doSync(params: SyncTask.Params): SyncResponse { 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<String, String>() val requestParams = HashMap<String, String>()
var timeout = 0L var timeout = 0L
@ -115,7 +115,7 @@ internal class DefaultSyncTask @Inject constructor(
var syncResponseToReturn: SyncResponse? = null var syncResponseToReturn: SyncResponse? = null
val syncStatisticsData = SyncStatisticsData(isInitialSync, params.afterPause) val syncStatisticsData = SyncStatisticsData(isInitialSync, params.afterPause)
if (isInitialSync) { 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 val initSyncStrategy = initialSyncStrategy
logDuration("INIT_SYNC strategy: $initSyncStrategy", loggerTag) { logDuration("INIT_SYNC strategy: $initSyncStrategy", loggerTag) {
if (initSyncStrategy is InitialSyncStrategy.Optimized) { if (initSyncStrategy is InitialSyncStrategy.Optimized) {
@ -147,7 +147,7 @@ internal class DefaultSyncTask @Inject constructor(
} }
defaultSyncStatusService.endAll() defaultSyncStatusService.endAll()
} else { } else {
Timber.tag(loggerTag.value).d("Start incremental sync request") Timber.tag(loggerTag.value).i("Start incremental sync request")
defaultSyncStatusService.setStatus(SyncStatusService.Status.IncrementalSyncIdle) defaultSyncStatusService.setStatus(SyncStatusService.Status.IncrementalSyncIdle)
val syncResponse = try { val syncResponse = try {
executeRequest(globalErrorReceiver) { 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 nbRooms = syncResponse.rooms?.invite.orEmpty().size + syncResponse.rooms?.join.orEmpty().size + syncResponse.rooms?.leave.orEmpty().size
val nbToDevice = syncResponse.toDevice?.events.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( defaultSyncStatusService.setStatus(SyncStatusService.Status.IncrementalSyncParsing(
rooms = nbRooms, rooms = nbRooms,
toDevice = nbToDevice toDevice = nbToDevice
)) ))
syncResponseHandler.handleResponse(syncResponse, token, null) syncResponseHandler.handleResponse(syncResponse, token, null)
syncResponseToReturn = syncResponse syncResponseToReturn = syncResponse
Timber.tag(loggerTag.value).d("Incremental sync done") Timber.tag(loggerTag.value).i("Incremental sync done")
defaultSyncStatusService.setStatus(SyncStatusService.Status.IncrementalSyncDone) defaultSyncStatusService.setStatus(SyncStatusService.Status.IncrementalSyncDone)
} }
syncStatisticsData.treatmentSyncTime = SystemClock.elapsedRealtime() syncStatisticsData.treatmentSyncTime = SystemClock.elapsedRealtime()
syncStatisticsData.nbOfRooms = syncResponseToReturn?.rooms?.join?.size ?: 0 syncStatisticsData.nbOfRooms = syncResponseToReturn?.rooms?.join?.size ?: 0
sendStatistics(syncStatisticsData) 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. // Should throw if null as it's a mandatory value.
return syncResponseToReturn!! return syncResponseToReturn!!
} }
@ -185,7 +185,7 @@ internal class DefaultSyncTask @Inject constructor(
val workingFile = File(workingDir, "initSync.json") val workingFile = File(workingDir, "initSync.json")
val status = initialSyncStatusRepository.getStep() val status = initialSyncStatusRepository.getStep()
if (workingFile.exists() && status >= InitialSyncStatus.STEP_DOWNLOADED) { 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) { reportSubtask(defaultSyncStatusService, InitSyncStep.Downloading, 1, 0.3f) {
// Empty task // Empty task
} }
@ -245,7 +245,7 @@ internal class DefaultSyncTask @Inject constructor(
// Log some stats // Log some stats
val nbOfJoinedRooms = syncResponse.rooms?.join?.size ?: 0 val nbOfJoinedRooms = syncResponse.rooms?.join?.size ?: 0
val nbOfJoinedRoomsInFile = syncResponse.rooms?.join?.values?.count { it.ephemeral is LazyRoomSyncEphemeral.Stored } 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) { logDuration("INIT_SYNC Database insertion", loggerTag) {
syncResponseHandler.handleResponse(syncResponse, null, defaultSyncStatusService) syncResponseHandler.handleResponse(syncResponse, null, defaultSyncStatusService)

36
matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/session/sync/job/SyncThread.kt
View File

@ -93,7 +93,7 @@ internal class SyncThread @Inject constructor(private val syncTask: SyncTask,
fun restart() = synchronized(lock) { fun restart() = synchronized(lock) {
if (!isStarted) { if (!isStarted) {
Timber.tag(loggerTag.value).d("Resume sync...") Timber.tag(loggerTag.value).i("Resume sync...")
isStarted = true isStarted = true
// Check again server availability and the token validity // Check again server availability and the token validity
canReachServer = true canReachServer = true
@ -104,7 +104,7 @@ internal class SyncThread @Inject constructor(private val syncTask: SyncTask,
fun pause() = synchronized(lock) { fun pause() = synchronized(lock) {
if (isStarted) { if (isStarted) {
Timber.tag(loggerTag.value).d("Pause sync...") Timber.tag(loggerTag.value).i("Pause sync...")
isStarted = false isStarted = false
retryNoNetworkTask?.cancel() retryNoNetworkTask?.cancel()
syncScope.coroutineContext.cancelChildren() syncScope.coroutineContext.cancelChildren()
@ -112,7 +112,7 @@ internal class SyncThread @Inject constructor(private val syncTask: SyncTask,
} }
fun kill() = synchronized(lock) { fun kill() = synchronized(lock) {
Timber.tag(loggerTag.value).d("Kill sync...") Timber.tag(loggerTag.value).i("Kill sync...")
updateStateTo(SyncState.Killing) updateStateTo(SyncState.Killing)
retryNoNetworkTask?.cancel() retryNoNetworkTask?.cancel()
syncScope.coroutineContext.cancelChildren() syncScope.coroutineContext.cancelChildren()
@ -136,21 +136,21 @@ internal class SyncThread @Inject constructor(private val syncTask: SyncTask,
} }
override fun run() { override fun run() {
Timber.tag(loggerTag.value).d("Start syncing...") Timber.tag(loggerTag.value).i("Start syncing...")
isStarted = true isStarted = true
networkConnectivityChecker.register(this) networkConnectivityChecker.register(this)
backgroundDetectionObserver.register(this) backgroundDetectionObserver.register(this)
registerActiveCallsObserver() registerActiveCallsObserver()
while (state != SyncState.Killing) { while (state != SyncState.Killing) {
Timber.tag(loggerTag.value).d("Entering loop, state: $state") Timber.tag(loggerTag.value).i("Entering loop, state: $state")
if (!isStarted) { if (!isStarted) {
Timber.tag(loggerTag.value).d("Sync is Paused. Waiting...") Timber.tag(loggerTag.value).i("Sync is Paused. Waiting...")
updateStateTo(SyncState.Paused) updateStateTo(SyncState.Paused)
synchronized(lock) { lock.wait() } synchronized(lock) { lock.wait() }
Timber.tag(loggerTag.value).d("...unlocked") Timber.tag(loggerTag.value).i("...unlocked")
} else if (!canReachServer) { } else if (!canReachServer) {
Timber.tag(loggerTag.value).d("No network. Waiting...") Timber.tag(loggerTag.value).i("No network. Waiting...")
updateStateTo(SyncState.NoNetwork) updateStateTo(SyncState.NoNetwork)
// We force retrying in RETRY_WAIT_TIME_MS maximum. Otherwise it will be unlocked by onConnectivityChanged() or restart() // 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) { 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() } synchronized(lock) { lock.wait() }
Timber.tag(loggerTag.value).d("...retry") Timber.tag(loggerTag.value).i("...retry")
} else if (!isTokenValid) { } else if (!isTokenValid) {
if (state == SyncState.Killing) { if (state == SyncState.Killing) {
continue continue
} }
Timber.tag(loggerTag.value).d("Token is invalid. Waiting...") Timber.tag(loggerTag.value).i("Token is invalid. Waiting...")
updateStateTo(SyncState.InvalidToken) updateStateTo(SyncState.InvalidToken)
synchronized(lock) { lock.wait() } synchronized(lock) { lock.wait() }
Timber.tag(loggerTag.value).d("...unlocked") Timber.tag(loggerTag.value).i("...unlocked")
} else { } else {
if (state !is SyncState.Running) { if (state !is SyncState.Running) {
updateStateTo(SyncState.Running(afterPause = true)) 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 */ afterPause -> 0L /* No timeout after a pause */
else -> DEFAULT_LONG_POOL_TIMEOUT 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 params = SyncTask.Params(timeout, SyncPresence.Online, afterPause = afterPause)
val sync = syncScope.launch { val sync = syncScope.launch {
previousSyncResponseHasToDevice = doSync(params) previousSyncResponseHasToDevice = doSync(params)
@ -187,10 +187,10 @@ internal class SyncThread @Inject constructor(private val syncTask: SyncTask,
runBlocking { runBlocking {
sync.join() 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) updateStateTo(SyncState.Killed)
backgroundDetectionObserver.unregister(this) backgroundDetectionObserver.unregister(this)
networkConnectivityChecker.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) { if (failure is Failure.NetworkConnection && failure.cause is SocketTimeoutException) {
// Timeout are not critical // Timeout are not critical
Timber.tag(loggerTag.value).d("Timeout") Timber.tag(loggerTag.value).i("Timeout")
} else if (failure is CancellationException) { } else if (failure is CancellationException) {
Timber.tag(loggerTag.value).d("Cancelled") Timber.tag(loggerTag.value).i("Cancelled")
} else if (failure.isTokenError()) { } else if (failure.isTokenError()) {
// No token or invalid token, stop the thread // No token or invalid token, stop the thread
Timber.tag(loggerTag.value).w(failure, "Token error") 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) Timber.tag(loggerTag.value).e(failure)
if (failure !is Failure.NetworkConnection || failure.cause is JsonEncodingException) { if (failure !is Failure.NetworkConnection || failure.cause is JsonEncodingException) {
// Wait 10s before retrying // Wait 10s before retrying
Timber.tag(loggerTag.value).d("Wait 10s") Timber.tag(loggerTag.value).i("Wait 10s")
delay(RETRY_WAIT_TIME_MS) delay(RETRY_WAIT_TIME_MS)
} }
} }
@ -250,7 +250,7 @@ internal class SyncThread @Inject constructor(private val syncTask: SyncTask,
} }
private fun updateStateTo(newState: SyncState) { 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) { if (newState == state) {
return return
} }