diff --git a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/api/session/Session.kt b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/api/session/Session.kt index 36ab007314..be924e2063 100644 --- a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/api/session/Session.kt +++ b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/api/session/Session.kt @@ -54,6 +54,7 @@ import org.matrix.android.sdk.api.session.securestorage.SecureStorageService import org.matrix.android.sdk.api.session.securestorage.SharedSecretStorageService import org.matrix.android.sdk.api.session.signout.SignOutService import org.matrix.android.sdk.api.session.space.SpaceService +import org.matrix.android.sdk.api.session.statistics.StatisticsListener import org.matrix.android.sdk.api.session.sync.FilterService import org.matrix.android.sdk.api.session.sync.SyncState import org.matrix.android.sdk.api.session.sync.model.SyncResponse @@ -287,7 +288,7 @@ interface Session : /** * A global session listener to get notified for some events. */ - interface Listener : SessionLifecycleObserver { + interface Listener : StatisticsListener, SessionLifecycleObserver { /** * Called when the session received new invites to room so the client can react to it once. */ diff --git a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/api/session/statistics/StatisticEvent.kt b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/api/session/statistics/StatisticEvent.kt new file mode 100644 index 0000000000..946792d31e --- /dev/null +++ b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/api/session/statistics/StatisticEvent.kt @@ -0,0 +1,37 @@ +/* + * Copyright (c) 2022 The Matrix.org Foundation C.I.C. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.matrix.android.sdk.api.session.statistics + +/** + * Statistic Events. You can subscribe to received such events using [Session.Listener] + */ +sealed interface StatisticEvent { + /** + * Initial sync request, response downloading, and treatment (parsing and storage) of response + */ + data class InitialSyncRequest(val requestDurationMs: Int, + val downloadDurationMs: Int, + val treatmentDurationMs: Int, + val nbOfJoinedRooms: Int) : StatisticEvent + + /** + * Incremental sync event + */ + data class SyncTreatment(val durationMs: Int, + val afterPause: Boolean, + val nbOfJoinedRooms: Int) : StatisticEvent +} diff --git a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/api/session/statistics/StatisticsListener.kt b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/api/session/statistics/StatisticsListener.kt new file mode 100644 index 0000000000..a2cb7910a7 --- /dev/null +++ b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/api/session/statistics/StatisticsListener.kt @@ -0,0 +1,23 @@ +/* + * Copyright (c) 2022 The Matrix.org Foundation C.I.C. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.matrix.android.sdk.api.session.statistics + +import org.matrix.android.sdk.api.session.Session + +interface StatisticsListener { + fun onStatisticsEvent(session: Session, statisticEvent: StatisticEvent) = Unit +} 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 621a08a414..1ee62ad774 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 @@ -16,10 +16,13 @@ package org.matrix.android.sdk.internal.session.sync +import android.os.SystemClock import okhttp3.ResponseBody import org.matrix.android.sdk.api.logger.LoggerTag +import org.matrix.android.sdk.api.session.Session import org.matrix.android.sdk.api.session.initsync.InitSyncStep import org.matrix.android.sdk.api.session.initsync.SyncStatusService +import org.matrix.android.sdk.api.session.statistics.StatisticEvent import org.matrix.android.sdk.api.session.sync.model.LazyRoomSyncEphemeral import org.matrix.android.sdk.api.session.sync.model.SyncResponse import org.matrix.android.sdk.internal.di.SessionFilesDirectory @@ -28,6 +31,8 @@ import org.matrix.android.sdk.internal.network.GlobalErrorReceiver import org.matrix.android.sdk.internal.network.TimeOutInterceptor import org.matrix.android.sdk.internal.network.executeRequest import org.matrix.android.sdk.internal.network.toFailure +import org.matrix.android.sdk.internal.session.SessionListeners +import org.matrix.android.sdk.internal.session.dispatchTo import org.matrix.android.sdk.internal.session.filter.FilterRepository import org.matrix.android.sdk.internal.session.homeserver.GetHomeServerCapabilitiesTask import org.matrix.android.sdk.internal.session.initsync.DefaultSyncStatusService @@ -49,7 +54,8 @@ internal interface SyncTask : Task { data class Params( val timeout: Long, - val presence: SyncPresence? + val presence: SyncPresence?, + val afterPause: Boolean ) } @@ -62,6 +68,8 @@ internal class DefaultSyncTask @Inject constructor( private val syncTokenStore: SyncTokenStore, private val getHomeServerCapabilitiesTask: GetHomeServerCapabilitiesTask, private val userStore: UserStore, + private val session: Session, + private val sessionListeners: SessionListeners, private val syncTaskSequencer: SyncTaskSequencer, private val globalErrorReceiver: GlobalErrorReceiver, @SessionFilesDirectory @@ -105,6 +113,7 @@ internal class DefaultSyncTask @Inject constructor( val readTimeOut = (params.timeout + TIMEOUT_MARGIN).coerceAtLeast(TimeOutInterceptor.DEFAULT_LONG_TIMEOUT) var syncResponseToReturn: SyncResponse? = null + val syncStatisticsData = SyncStatisticsData(isInitialSync, params.afterPause) if (isInitialSync) { Timber.tag(loggerTag.value).d("INIT_SYNC with filter: ${requestParams["filter"]}") val initSyncStrategy = initialSyncStrategy @@ -112,7 +121,7 @@ internal class DefaultSyncTask @Inject constructor( if (initSyncStrategy is InitialSyncStrategy.Optimized) { roomSyncEphemeralTemporaryStore.reset() workingDir.mkdirs() - val file = downloadInitSyncResponse(requestParams) + val file = downloadInitSyncResponse(requestParams, syncStatisticsData) syncResponseToReturn = reportSubtask(defaultSyncStatusService, InitSyncStep.ImportingAccount, 1, 0.7F) { handleSyncFile(file, initSyncStrategy) } @@ -127,6 +136,9 @@ internal class DefaultSyncTask @Inject constructor( ) } } + // We cannot distinguish request and download in this case. + syncStatisticsData.requestInitSyncTime = SystemClock.elapsedRealtime() + syncStatisticsData.downloadInitSyncTime = syncStatisticsData.requestInitSyncTime logDuration("INIT_SYNC Database insertion", loggerTag) { syncResponseHandler.handleResponse(syncResponse, token, defaultSyncStatusService) } @@ -161,12 +173,15 @@ internal class DefaultSyncTask @Inject constructor( Timber.tag(loggerTag.value).d("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}") // Should throw if null as it's a mandatory value. return syncResponseToReturn!! } - private suspend fun downloadInitSyncResponse(requestParams: Map): File { + private suspend fun downloadInitSyncResponse(requestParams: Map, syncStatisticsData: SyncStatisticsData): File { val workingFile = File(workingDir, "initSync.json") val status = initialSyncStatusRepository.getStep() if (workingFile.exists() && status >= InitialSyncStatus.STEP_DOWNLOADED) { @@ -181,7 +196,7 @@ internal class DefaultSyncTask @Inject constructor( getSyncResponse(requestParams, MAX_NUMBER_OF_RETRY_AFTER_TIMEOUT) } } - + syncStatisticsData.requestInitSyncTime = SystemClock.elapsedRealtime() if (syncResponse.isSuccessful) { logDuration("INIT_SYNC Download and save to file", loggerTag) { reportSubtask(defaultSyncStatusService, InitSyncStep.Downloading, 1, 0.1f) { @@ -196,6 +211,7 @@ internal class DefaultSyncTask @Inject constructor( throw syncResponse.toFailure(globalErrorReceiver) .also { Timber.tag(loggerTag.value).w("INIT_SYNC request failure: $this") } } + syncStatisticsData.downloadInitSyncTime = SystemClock.elapsedRealtime() initialSyncStatusRepository.setStep(InitialSyncStatus.STEP_DOWNLOADED) } return workingFile @@ -239,6 +255,45 @@ internal class DefaultSyncTask @Inject constructor( } } + /** + * Aggregator to send stat event. + */ + class SyncStatisticsData( + val isInitSync: Boolean, + val isAfterPause: Boolean + ) { + val startTime = SystemClock.elapsedRealtime() + var requestInitSyncTime = startTime + var downloadInitSyncTime = startTime + var treatmentSyncTime = startTime + var nbOfRooms: Int = 0 + } + + private fun sendStatistics(data: SyncStatisticsData) { + sendStatisticEvent( + if (data.isInitSync) { + (StatisticEvent.InitialSyncRequest( + requestDurationMs = (data.requestInitSyncTime - data.startTime).toInt(), + downloadDurationMs = (data.downloadInitSyncTime - data.requestInitSyncTime).toInt(), + treatmentDurationMs = (data.treatmentSyncTime - data.downloadInitSyncTime).toInt(), + nbOfJoinedRooms = data.nbOfRooms, + )) + } else { + StatisticEvent.SyncTreatment( + durationMs = (data.treatmentSyncTime - data.startTime).toInt(), + afterPause = data.isAfterPause, + nbOfJoinedRooms = data.nbOfRooms + ) + } + ) + } + + private fun sendStatisticEvent(statisticEvent: StatisticEvent) { + session.dispatchTo(sessionListeners) { session, listener -> + listener.onStatisticsEvent(session, statisticEvent) + } + } + companion object { private const val MAX_NUMBER_OF_RETRY_AFTER_TIMEOUT = 50 diff --git a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/session/sync/job/SyncService.kt b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/session/sync/job/SyncService.kt index c17b31b910..0ecf91f6fa 100644 --- a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/session/sync/job/SyncService.kt +++ b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/session/sync/job/SyncService.kt @@ -152,7 +152,7 @@ abstract class SyncService : Service() { private suspend fun doSync() { Timber.v("## Sync: Execute sync request with timeout $syncTimeoutSeconds seconds") - val params = SyncTask.Params(syncTimeoutSeconds * 1000L, SyncPresence.Offline) + val params = SyncTask.Params(syncTimeoutSeconds * 1000L, SyncPresence.Offline, afterPause = false) try { // never do that in foreground, let the syncThread work syncTask.execute(params) 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 b6ea7a68f7..2460720adc 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 @@ -173,13 +173,14 @@ internal class SyncThread @Inject constructor(private val syncTask: SyncTask, if (state !is SyncState.Running) { updateStateTo(SyncState.Running(afterPause = true)) } + val afterPause = state.let { it is SyncState.Running && it.afterPause } val timeout = when { - previousSyncResponseHasToDevice -> 0L /* Force timeout to 0 */ - state.let { it is SyncState.Running && it.afterPause } -> 0L /* No timeout after a pause */ - else -> DEFAULT_LONG_POOL_TIMEOUT + previousSyncResponseHasToDevice -> 0L /* Force timeout to 0 */ + afterPause -> 0L /* No timeout after a pause */ + else -> DEFAULT_LONG_POOL_TIMEOUT } Timber.tag(loggerTag.value).d("Execute sync request with timeout $timeout") - val params = SyncTask.Params(timeout, SyncPresence.Online) + val params = SyncTask.Params(timeout, SyncPresence.Online, afterPause = afterPause) val sync = syncScope.launch { previousSyncResponseHasToDevice = doSync(params) } diff --git a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/session/sync/job/SyncWorker.kt b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/session/sync/job/SyncWorker.kt index bdccb59221..423a4e553f 100644 --- a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/session/sync/job/SyncWorker.kt +++ b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/session/sync/job/SyncWorker.kt @@ -113,7 +113,7 @@ internal class SyncWorker(context: Context, workerParameters: WorkerParameters, * Will return true if the sync response contains some toDevice events. */ private suspend fun doSync(timeout: Long): Boolean { - val taskParams = SyncTask.Params(timeout * 1000, SyncPresence.Offline) + val taskParams = SyncTask.Params(timeout * 1000, SyncPresence.Offline, afterPause = false) val syncResponse = syncTask.execute(taskParams) return syncResponse.toDevice?.events?.isNotEmpty().orFalse() } diff --git a/vector/src/main/java/im/vector/app/features/analytics/extensions/PerformanceTimerExt.kt b/vector/src/main/java/im/vector/app/features/analytics/extensions/PerformanceTimerExt.kt new file mode 100644 index 0000000000..11b4b670d3 --- /dev/null +++ b/vector/src/main/java/im/vector/app/features/analytics/extensions/PerformanceTimerExt.kt @@ -0,0 +1,51 @@ +/* + * Copyright (c) 2022 New Vector Ltd + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package im.vector.app.features.analytics.extensions + +import im.vector.app.features.analytics.plan.PerformanceTimer +import org.matrix.android.sdk.api.session.statistics.StatisticEvent + +fun StatisticEvent.toListOfPerformanceTimer(): List { + return when (this) { + is StatisticEvent.InitialSyncRequest -> + listOf( + PerformanceTimer( + name = PerformanceTimer.Name.InitialSyncRequest, + timeMs = requestDurationMs + downloadDurationMs, + itemCount = nbOfJoinedRooms + ), + PerformanceTimer( + name = PerformanceTimer.Name.InitialSyncParsing, + timeMs = treatmentDurationMs, + itemCount = nbOfJoinedRooms + ) + ) + is StatisticEvent.SyncTreatment -> + if (afterPause) { + listOf( + PerformanceTimer( + name = PerformanceTimer.Name.StartupIncrementalSync, + timeMs = durationMs, + itemCount = nbOfJoinedRooms + ) + ) + } else { + // We do not report + emptyList() + } + } +} diff --git a/vector/src/main/java/im/vector/app/features/session/SessionListener.kt b/vector/src/main/java/im/vector/app/features/session/SessionListener.kt index c1ee0b527e..37db55959f 100644 --- a/vector/src/main/java/im/vector/app/features/session/SessionListener.kt +++ b/vector/src/main/java/im/vector/app/features/session/SessionListener.kt @@ -20,16 +20,21 @@ import androidx.lifecycle.LiveData import androidx.lifecycle.MutableLiveData import im.vector.app.core.extensions.postLiveEvent import im.vector.app.core.utils.LiveEvent +import im.vector.app.features.analytics.AnalyticsTracker +import im.vector.app.features.analytics.extensions.toListOfPerformanceTimer import im.vector.app.features.call.vectorCallService import kotlinx.coroutines.cancelChildren import kotlinx.coroutines.launch import org.matrix.android.sdk.api.failure.GlobalError import org.matrix.android.sdk.api.session.Session +import org.matrix.android.sdk.api.session.statistics.StatisticEvent import javax.inject.Inject import javax.inject.Singleton @Singleton -class SessionListener @Inject constructor() : Session.Listener { +class SessionListener @Inject constructor( + private val analyticsTracker: AnalyticsTracker +) : Session.Listener { private val _globalErrorLiveData = MutableLiveData>() val globalErrorLiveData: LiveData> @@ -45,6 +50,12 @@ class SessionListener @Inject constructor() : Session.Listener { } } + override fun onStatisticsEvent(session: Session, statisticEvent: StatisticEvent) { + statisticEvent.toListOfPerformanceTimer().forEach { + analyticsTracker.capture(it) + } + } + override fun onSessionStopped(session: Session) { session.coroutineScope.coroutineContext.cancelChildren() }