diff --git a/changelog.d/8780.misc b/changelog.d/8780.misc new file mode 100644 index 00000000000..03253757559 --- /dev/null +++ b/changelog.d/8780.misc @@ -0,0 +1 @@ +Improve UTD reporting by adding additional fields to the report. diff --git a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/api/session/LiveEventListener.kt b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/api/session/LiveEventListener.kt index b4b283c86a2..ce0a01a4918 100644 --- a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/api/session/LiveEventListener.kt +++ b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/api/session/LiveEventListener.kt @@ -16,6 +16,7 @@ package org.matrix.android.sdk.api.session +import org.matrix.android.sdk.api.session.crypto.MXCryptoError import org.matrix.android.sdk.api.session.events.model.Event import org.matrix.android.sdk.api.util.JsonDict @@ -27,7 +28,7 @@ interface LiveEventListener { fun onEventDecrypted(event: Event, clearEvent: JsonDict) - fun onEventDecryptionError(event: Event, throwable: Throwable) + fun onEventDecryptionError(event: Event, cryptoError: MXCryptoError) fun onLiveToDeviceEvent(event: Event) diff --git a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/crypto/Device.kt b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/crypto/Device.kt index 0bd6ed06d1c..d2865f0f65f 100644 --- a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/crypto/Device.kt +++ b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/crypto/Device.kt @@ -172,8 +172,6 @@ internal class Device @AssistedInject constructor( * This will not fetch out fresh data from the Rust side. **/ internal fun toCryptoDeviceInfo(): CryptoDeviceInfo { -// val keys = innerDevice.keys.map { (keyId, key) -> keyId to key }.toMap() - return CryptoDeviceInfo( deviceId = innerDevice.deviceId, userId = innerDevice.userId, diff --git a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/crypto/OlmMachine.kt b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/crypto/OlmMachine.kt index f90ae4a3452..4fe59fb1dde 100644 --- a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/crypto/OlmMachine.kt +++ b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/crypto/OlmMachine.kt @@ -189,18 +189,21 @@ internal class OlmMachine @Inject constructor( is OwnUserIdentity -> ownIdentity.trustsOurOwnDevice() else -> false } + val ownDevice = inner.getDevice(userId(), deviceId, 0u)!! + val creationTime = ownDevice.firstTimeSeenTs.toLong() return CryptoDeviceInfo( deviceId(), userId(), - // TODO pass the algorithms here. - listOf(), + ownDevice.algorithms, keys, mapOf(), - UnsignedDeviceInfo(), + UnsignedDeviceInfo( + deviceDisplayName = ownDevice.displayName + ), DeviceTrustLevel(crossSigningVerified, locallyVerified = true), false, - null + creationTime ) } @@ -291,7 +294,7 @@ internal class OlmMachine @Inject constructor( // checking the returned to devices to check for room keys. // XXX Anyhow there is now proper signaling we should soon stop parsing them manually receiveSyncChanges.toDeviceEvents.map { - outAdapter.fromJson(it) ?: Event() + outAdapter.fromJson(it) ?: Event() } } @@ -882,6 +885,7 @@ internal class OlmMachine @Inject constructor( inner.queryMissingSecretsFromOtherSessions() } } + @Throws(CryptoStoreException::class) suspend fun enableBackupV1(key: String, version: String) { return withContext(coroutineDispatchers.computation) { diff --git a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/session/StreamEventsManager.kt b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/session/StreamEventsManager.kt index ce34b0430ec..3e7beed0472 100644 --- a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/session/StreamEventsManager.kt +++ b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/session/StreamEventsManager.kt @@ -22,6 +22,7 @@ import kotlinx.coroutines.SupervisorJob import kotlinx.coroutines.launch import org.matrix.android.sdk.api.extensions.tryOrNull import org.matrix.android.sdk.api.session.LiveEventListener +import org.matrix.android.sdk.api.session.crypto.MXCryptoError import org.matrix.android.sdk.api.session.crypto.model.MXEventDecryptionResult import org.matrix.android.sdk.api.session.events.model.Event import timber.log.Timber @@ -75,7 +76,7 @@ internal class StreamEventsManager @Inject constructor() { } } - fun dispatchLiveEventDecryptionFailed(event: Event, error: Throwable) { + fun dispatchLiveEventDecryptionFailed(event: Event, error: MXCryptoError) { Timber.v("## dispatchLiveEventDecryptionFailed ${event.eventId}") coroutineScope.launch { listeners.forEach { diff --git a/vector-app/src/main/java/im/vector/app/VectorApplication.kt b/vector-app/src/main/java/im/vector/app/VectorApplication.kt index 7b41c127736..fe4cc3311b0 100644 --- a/vector-app/src/main/java/im/vector/app/VectorApplication.kt +++ b/vector-app/src/main/java/im/vector/app/VectorApplication.kt @@ -51,6 +51,7 @@ import im.vector.app.core.debug.LeakDetector import im.vector.app.core.di.ActiveSessionHolder import im.vector.app.core.pushers.FcmHelper import im.vector.app.core.resources.BuildMeta +import im.vector.app.features.analytics.DecryptionFailureTracker import im.vector.app.features.analytics.VectorAnalytics import im.vector.app.features.call.webrtc.WebRtcCallManager import im.vector.app.features.configuration.VectorConfiguration @@ -100,6 +101,7 @@ class VectorApplication : @Inject lateinit var callManager: WebRtcCallManager @Inject lateinit var invitesAcceptor: InvitesAcceptor @Inject lateinit var autoRageShaker: AutoRageShaker + @Inject lateinit var decryptionFailureTracker: DecryptionFailureTracker @Inject lateinit var vectorFileLogger: VectorFileLogger @Inject lateinit var vectorAnalytics: VectorAnalytics @Inject lateinit var flipperProxy: FlipperProxy @@ -130,6 +132,7 @@ class VectorApplication : vectorAnalytics.init() invitesAcceptor.initialize() autoRageShaker.initialize() + decryptionFailureTracker.start() vectorUncaughtExceptionHandler.activate() // Remove Log handler statically added by Jitsi diff --git a/vector/src/main/java/im/vector/app/UISIDetector.kt b/vector/src/main/java/im/vector/app/UISIDetector.kt index 4a9d8ae266c..7188fb0dc93 100644 --- a/vector/src/main/java/im/vector/app/UISIDetector.kt +++ b/vector/src/main/java/im/vector/app/UISIDetector.kt @@ -18,6 +18,7 @@ package im.vector.app import org.matrix.android.sdk.api.extensions.orFalse import org.matrix.android.sdk.api.session.LiveEventListener +import org.matrix.android.sdk.api.session.crypto.MXCryptoError import org.matrix.android.sdk.api.session.events.model.Event import org.matrix.android.sdk.api.session.events.model.content.EncryptedEventContent import org.matrix.android.sdk.api.session.events.model.toModel @@ -84,7 +85,7 @@ class UISIDetector(private val timeoutMillis: Long = 30_000L) : LiveEventListene } } - override fun onEventDecryptionError(event: Event, throwable: Throwable) { + override fun onEventDecryptionError(event: Event, cryptoError: MXCryptoError) { val eventId = event.eventId val roomId = event.roomId if (!enabled || eventId == null || roomId == null) return diff --git a/vector/src/main/java/im/vector/app/core/di/ActiveSessionHolder.kt b/vector/src/main/java/im/vector/app/core/di/ActiveSessionHolder.kt index 472d0896f9a..5523c849944 100644 --- a/vector/src/main/java/im/vector/app/core/di/ActiveSessionHolder.kt +++ b/vector/src/main/java/im/vector/app/core/di/ActiveSessionHolder.kt @@ -23,7 +23,6 @@ import im.vector.app.core.pushers.UnregisterUnifiedPushUseCase import im.vector.app.core.services.GuardServiceStarter import im.vector.app.core.session.ConfigureAndStartSessionUseCase import im.vector.app.features.analytics.DecryptionFailureTracker -import im.vector.app.features.analytics.plan.Error import im.vector.app.features.call.webrtc.WebRtcCallManager import im.vector.app.features.crypto.keysrequest.KeyRequestHandler import im.vector.app.features.crypto.verification.IncomingVerificationRequestHandler @@ -75,11 +74,6 @@ class ActiveSessionHolder @Inject constructor( session.callSignalingService().addCallListener(callManager) imageManager.onSessionStarted(session) guardServiceStarter.start() - decryptionFailureTracker.currentModule = if (session.cryptoService().name() == "rust-sdk") { - Error.CryptoModule.Rust - } else { - Error.CryptoModule.Native - } } suspend fun clearActiveSession() { diff --git a/vector/src/main/java/im/vector/app/features/analytics/DecryptionFailure.kt b/vector/src/main/java/im/vector/app/features/analytics/DecryptionFailure.kt new file mode 100644 index 00000000000..f7fb177e12c --- /dev/null +++ b/vector/src/main/java/im/vector/app/features/analytics/DecryptionFailure.kt @@ -0,0 +1,76 @@ +/* + * Copyright (c) 2024 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 + +import im.vector.app.features.analytics.plan.Error +import org.matrix.android.sdk.api.session.crypto.MXCryptoError + +data class DecryptionFailure( + val timeStamp: Long, + val roomId: String, + val failedEventId: String, + val error: MXCryptoError, + val wasVisibleOnScreen: Boolean, + val ownIdentityTrustedAtTimeOfDecryptionFailure: Boolean, + // If this is set, it means that the event was decrypted but late. Will be -1 if + // the event was not decrypted after the maximum wait time. + val timeToDecryptMillis: Long? = null, + val isMatrixDotOrg: Boolean, + val isFederated: Boolean? = null, + val eventLocalAgeAtDecryptionFailure: Long? = null +) + +fun DecryptionFailure.toAnalyticsEvent(): Error { + val errorMsg = (error as? MXCryptoError.Base)?.technicalMessage ?: error.message + return Error( + context = "mxc_crypto_error_type|${errorMsg}", + domain = Error.Domain.E2EE, + name = this.toAnalyticsErrorName(), + // this is deprecated keep for backward compatibility + cryptoModule = Error.CryptoModule.Rust, + cryptoSDK = Error.CryptoSDK.Rust, + eventLocalAgeMillis = eventLocalAgeAtDecryptionFailure?.toInt(), + isFederated = isFederated, + isMatrixDotOrg = isMatrixDotOrg, + timeToDecryptMillis = timeToDecryptMillis?.toInt() ?: -1, + wasVisibleToUser = wasVisibleOnScreen, + userTrustsOwnIdentity = ownIdentityTrustedAtTimeOfDecryptionFailure, + ) +} + +private fun DecryptionFailure.toAnalyticsErrorName(): Error.Name { + val error = this.error + val name = if (error is MXCryptoError.Base) { + when (error.errorType) { + MXCryptoError.ErrorType.UNKNOWN_INBOUND_SESSION_ID, + MXCryptoError.ErrorType.KEYS_WITHHELD -> Error.Name.OlmKeysNotSentError + MXCryptoError.ErrorType.OLM -> Error.Name.OlmUnspecifiedError + MXCryptoError.ErrorType.UNKNOWN_MESSAGE_INDEX -> Error.Name.OlmIndexError + else -> Error.Name.UnknownError + } + } else { + Error.Name.UnknownError + } + // check if it's an expected UTD! + val localAge = this.eventLocalAgeAtDecryptionFailure + val isHistorical = localAge != null && localAge < 0 + if (isHistorical && !this.ownIdentityTrustedAtTimeOfDecryptionFailure) { + return Error.Name.HistoricalMessage + } + + return name +} diff --git a/vector/src/main/java/im/vector/app/features/analytics/DecryptionFailureTracker.kt b/vector/src/main/java/im/vector/app/features/analytics/DecryptionFailureTracker.kt index d596741d532..fcbc67169eb 100644 --- a/vector/src/main/java/im/vector/app/features/analytics/DecryptionFailureTracker.kt +++ b/vector/src/main/java/im/vector/app/features/analytics/DecryptionFailureTracker.kt @@ -16,149 +16,282 @@ package im.vector.app.features.analytics -import im.vector.app.features.analytics.plan.Error -import im.vector.lib.core.utils.compat.removeIfCompat -import im.vector.lib.core.utils.flow.tickerFlow +import im.vector.app.ActiveSessionDataSource import im.vector.lib.core.utils.timer.Clock +import kotlinx.coroutines.CancellationException import kotlinx.coroutines.CoroutineScope import kotlinx.coroutines.Dispatchers +import kotlinx.coroutines.Job import kotlinx.coroutines.SupervisorJob -import kotlinx.coroutines.cancel +import kotlinx.coroutines.delay +import kotlinx.coroutines.flow.distinctUntilChanged import kotlinx.coroutines.flow.launchIn import kotlinx.coroutines.flow.onEach import kotlinx.coroutines.launch +import kotlinx.coroutines.sync.Mutex +import kotlinx.coroutines.sync.withLock +import org.matrix.android.sdk.api.MatrixPatterns +import org.matrix.android.sdk.api.session.LiveEventListener +import org.matrix.android.sdk.api.session.Session import org.matrix.android.sdk.api.session.crypto.MXCryptoError +import org.matrix.android.sdk.api.session.events.model.Event import org.matrix.android.sdk.api.session.room.timeline.TimelineEvent +import org.matrix.android.sdk.api.util.JsonDict +import timber.log.Timber import javax.inject.Inject import javax.inject.Singleton -private data class DecryptionFailure( - val timeStamp: Long, - val roomId: String, - val failedEventId: String, - val error: MXCryptoError.ErrorType -) -private typealias DetailedErrorName = Pair - +// If we can decrypt in less than 4s, we don't report private const val GRACE_PERIOD_MILLIS = 4_000 -private const val CHECK_INTERVAL = 2_000L + +// A tick to check when a decryption failure as exceeded the max time +private const val CHECK_INTERVAL = 10_000L + +// If we can't decrypt after 60s, we report failures +private const val MAX_WAIT_MILLIS = 60_000 /** - * Tracks decryption errors that are visible to the user. + * Tracks decryption errors. * When an error is reported it is not directly tracked via analytics, there is a grace period * that gives the app a few seconds to get the key to decrypt. + * + * Decrypted under 4s => No report + * Decrypted before MAX_WAIT_MILLIS => Report with time to decrypt + * Not Decrypted after MAX_WAIT_MILLIS => Report with time = -1 */ @Singleton class DecryptionFailureTracker @Inject constructor( private val analyticsTracker: AnalyticsTracker, + private val sessionDataSource: ActiveSessionDataSource, private val clock: Clock -) { +) : Session.Listener, LiveEventListener { + + // The active session (set by the sessionDataSource) + private var activeSession: Session? = null + + // The coroutine scope to use for the tracker + private var scope: CoroutineScope = CoroutineScope(Dispatchers.IO + SupervisorJob()) + + // Map of eventId to tracked failure + // Only accessed on a `post` call, ensuring sequential access + private val trackedEventsMap = mutableMapOf() - private val scope: CoroutineScope = CoroutineScope(SupervisorJob()) - private val failures = mutableListOf() + // List of eventId that have been reported, to avoid double reporting private val alreadyReported = mutableListOf() - var currentModule: Error.CryptoModule? = null + // Mutex to ensure sequential access to internal state + private val mutex = Mutex() - init { - start() - } + // Used to unsubscribe from the active session data source + private lateinit var activeSessionSourceDisposable: Job - fun start() { - tickerFlow(scope, CHECK_INTERVAL) - .onEach { - checkFailures() - }.launchIn(scope) + // The ticker job, to report permanent UTD (not decrypted after MAX_WAIT_MILLIS) + private var currentTicker: Job? = null + + /** + * Start the tracker. + * + * @param scope The coroutine scope to use, exposed for tests. If null, it will use the default one + */ + fun start(scope: CoroutineScope? = null) { + if (scope != null) { + this.scope = scope + } + observeActiveSession() } fun stop() { - scope.cancel() + Timber.v("Stop DecryptionFailureTracker") + activeSessionSourceDisposable.cancel(CancellationException("Closing DecryptionFailureTracker")) + + activeSession?.removeListener(this) + activeSession?.eventStreamService()?.removeEventStreamListener(this) + activeSession = null } - fun e2eEventDisplayedInTimeline(event: TimelineEvent) { - scope.launch(Dispatchers.Default) { - val mCryptoError = event.root.mCryptoError - if (mCryptoError != null) { - addDecryptionFailure(DecryptionFailure(clock.epochMillis(), event.roomId, event.eventId, mCryptoError)) - } else { - removeFailureForEventId(event.eventId) + private fun post(block: suspend () -> Unit) { + scope.launch { + mutex.withLock { + block() } } } - /** - * Can be called when the timeline is disposed in order - * to grace those events as they are not anymore displayed on screen. - * */ - fun onTimeLineDisposed(roomId: String) { - scope.launch(Dispatchers.Default) { - synchronized(failures) { - failures.removeIfCompat { it.roomId == roomId } + private suspend fun rescheduleTicker() { + currentTicker = scope.launch { + Timber.v("Reschedule ticker") + delay(CHECK_INTERVAL) + post { + checkFailures() + currentTicker = null + if (trackedEventsMap.isNotEmpty()) { + // Reschedule + rescheduleTicker() + } } } } + private fun observeActiveSession() { + activeSessionSourceDisposable = sessionDataSource.stream() + .distinctUntilChanged() + .onEach { + Timber.v("Active session changed ${it.getOrNull()?.myUserId}") + it.orNull()?.let { session -> + post { + onSessionActive(session) + } + } + }.launchIn(scope) + } + + private fun onSessionActive(session: Session) { + Timber.v("onSessionActive ${session.myUserId} previous: ${activeSession?.myUserId}") + val sessionId = session.sessionId + if (sessionId == activeSession?.sessionId) { + return + } + this.activeSession?.let { previousSession -> + previousSession.removeListener(this) + previousSession.eventStreamService().removeEventStreamListener(this) + // Do we want to clear the tracked events? + } + this.activeSession = session + session.addListener(this) + session.eventStreamService().addEventStreamListener(this) + } + + override fun onSessionStopped(session: Session) { + post { + this.activeSession = null + session.addListener(this) + session.eventStreamService().addEventStreamListener(this) + } + } - private fun addDecryptionFailure(failure: DecryptionFailure) { - // de duplicate - synchronized(failures) { - if (failures.none { it.failedEventId == failure.failedEventId }) { - failures.add(failure) + // LiveEventListener callbacks + + override fun onEventDecrypted(event: Event, clearEvent: JsonDict) { + Timber.v("Event decrypted ${event.eventId}") + event.eventId?.let { + post { + handleEventDecrypted(it) } } } - private fun removeFailureForEventId(eventId: String) { - synchronized(failures) { - failures.removeIfCompat { it.failedEventId == eventId } + override fun onEventDecryptionError(event: Event, cryptoError: MXCryptoError) { + Timber.v("Decryption error for event ${event.eventId} with error $cryptoError") + val session = activeSession ?: return + // track the event + post { + trackEvent(session, event, cryptoError) } } - private fun checkFailures() { - val now = clock.epochMillis() - val aggregatedErrors: Map> - synchronized(failures) { - val toReport = mutableListOf() - failures.removeAll { failure -> - (now - failure.timeStamp > GRACE_PERIOD_MILLIS).also { - if (it) { - toReport.add(failure) - } - } + override fun onLiveToDeviceEvent(event: Event) {} + override fun onLiveEvent(roomId: String, event: Event) {} + override fun onPaginatedEvent(roomId: String, event: Event) {} + + private suspend fun trackEvent(session: Session, event: Event, error: MXCryptoError) { + Timber.v("Track event ${event.eventId}/${session.myUserId} time: ${clock.epochMillis()}") + val eventId = event.eventId + val roomId = event.roomId + if (eventId == null || roomId == null) return + if (trackedEventsMap.containsKey(eventId)) { + // already tracked + return + } + if (alreadyReported.contains(eventId)) { + // already reported + return + } + val isOwnIdentityTrusted = session.cryptoService().crossSigningService().isCrossSigningVerified() + val userHS = MatrixPatterns.extractServerNameFromId(session.myUserId) + val messageSenderHs = event.senderId?.let { MatrixPatterns.extractServerNameFromId(it) } + Timber.v("senderHs: $messageSenderHs, userHS: $userHS, isOwnIdentityTrusted: $isOwnIdentityTrusted") + + val deviceCreationTs = session.cryptoService().getMyCryptoDevice().firstTimeSeenLocalTs + Timber.v("deviceCreationTs: $deviceCreationTs") + val eventRelativeAge = deviceCreationTs?.let { deviceTs -> + event.originServerTs?.let { + it - deviceTs } + } + val failure = DecryptionFailure( + clock.epochMillis(), + roomId, + eventId, + error, + wasVisibleOnScreen = false, + ownIdentityTrustedAtTimeOfDecryptionFailure = isOwnIdentityTrusted, + isMatrixDotOrg = userHS == "matrix.org", + isFederated = messageSenderHs?.let { it != userHS }, + eventLocalAgeAtDecryptionFailure = eventRelativeAge + ) + Timber.v("Tracked failure: ${failure}") + trackedEventsMap[eventId] = failure - aggregatedErrors = toReport - .groupBy { it.error.toAnalyticsErrorName() } - .mapValues { - it.value.map { it.failedEventId } - } + if (currentTicker == null) { + rescheduleTicker() } + } - aggregatedErrors.forEach { aggregation -> - // there is now way to send the total/sum in posthog, so iterating - aggregation.value - // for now we ignore events already reported even if displayed again? - .filter { alreadyReported.contains(it).not() } - .forEach { failedEventId -> - analyticsTracker.capture(Error( - context = aggregation.key.first, - domain = Error.Domain.E2EE, - name = aggregation.key.second, - cryptoModule = currentModule - )) - alreadyReported.add(failedEventId) - } + private fun handleEventDecrypted(eventId: String) { + Timber.v("Handle event decrypted $eventId time: ${clock.epochMillis()}") + // Only consider if it was tracked as a failure + val trackedFailure = trackedEventsMap[eventId] ?: return + + // Grace event if decrypted under 4s + val now = clock.epochMillis() + val timeToDecrypt = now - trackedFailure.timeStamp + Timber.v("Handle event decrypted timeToDecrypt: $timeToDecrypt for event $eventId") + if (timeToDecrypt < GRACE_PERIOD_MILLIS) { + Timber.v("Grace event $eventId") + trackedEventsMap.remove(eventId) + return + } + // We still want to report but with the time it took + if (trackedFailure.timeToDecryptMillis == null) { + val decryptionFailure = trackedFailure.copy(timeToDecryptMillis = timeToDecrypt) + trackedEventsMap[eventId] = decryptionFailure + reportFailure(decryptionFailure) } } - private fun MXCryptoError.ErrorType.toAnalyticsErrorName(): DetailedErrorName { - val detailed = "$name | mxc_crypto_error_type" - val errorName = when (this) { - MXCryptoError.ErrorType.UNKNOWN_INBOUND_SESSION_ID, - MXCryptoError.ErrorType.KEYS_WITHHELD -> Error.Name.OlmKeysNotSentError - MXCryptoError.ErrorType.OLM -> Error.Name.OlmUnspecifiedError - MXCryptoError.ErrorType.UNKNOWN_MESSAGE_INDEX -> Error.Name.OlmIndexError - else -> Error.Name.UnknownError + fun utdDisplayedInTimeline(event: TimelineEvent) { + post { + // should be tracked (unless already reported) + val eventId = event.root.eventId ?: return@post + val trackedEvent = trackedEventsMap[eventId] ?: return@post + + trackedEventsMap[eventId] = trackedEvent.copy(wasVisibleOnScreen = true) + } + } + + // This will mutate the trackedEventsMap, so don't call it while iterating on it. + private fun reportFailure(decryptionFailure: DecryptionFailure) { + Timber.v("Report failure for event ${decryptionFailure.failedEventId}") + val error = decryptionFailure.toAnalyticsEvent() + + analyticsTracker.capture(error) + + // now remove from tracked + trackedEventsMap.remove(decryptionFailure.failedEventId) + // mark as already reported + alreadyReported.add(decryptionFailure.failedEventId) + } + + private fun checkFailures() { + val now = clock.epochMillis() + Timber.v("Check failures now $now") + // report the definitely failed + val toReport = trackedEventsMap.values.filter { + now - it.timeStamp > MAX_WAIT_MILLIS + } + toReport.forEach { + reportFailure( + it.copy(timeToDecryptMillis = -1) + ) } - return DetailedErrorName(detailed, errorName) } } diff --git a/vector/src/main/java/im/vector/app/features/analytics/impl/DefaultVectorAnalytics.kt b/vector/src/main/java/im/vector/app/features/analytics/impl/DefaultVectorAnalytics.kt index 2a7d0ac975f..acc6ebf51e8 100644 --- a/vector/src/main/java/im/vector/app/features/analytics/impl/DefaultVectorAnalytics.kt +++ b/vector/src/main/java/im/vector/app/features/analytics/impl/DefaultVectorAnalytics.kt @@ -175,7 +175,10 @@ class DefaultVectorAnalytics @Inject constructor( Timber.tag(analyticsTag.value).d("capture($event)") posthog ?.takeIf { userConsent == true } - ?.capture(event.getName(), event.getProperties()?.toPostHogProperties()) + ?.capture( + event.getName(), + event.getProperties()?.toPostHogProperties() + ) } override fun screen(screen: VectorAnalyticsScreen) { diff --git a/vector/src/main/java/im/vector/app/features/home/room/detail/TimelineViewModel.kt b/vector/src/main/java/im/vector/app/features/home/room/detail/TimelineViewModel.kt index 3793ed18d2e..9e3802101eb 100644 --- a/vector/src/main/java/im/vector/app/features/home/room/detail/TimelineViewModel.kt +++ b/vector/src/main/java/im/vector/app/features/home/room/detail/TimelineViewModel.kt @@ -1484,7 +1484,6 @@ class TimelineViewModel @AssistedInject constructor( override fun onCleared() { timeline?.dispose() timeline?.removeAllListeners() - decryptionFailureTracker.onTimeLineDisposed(initialState.roomId) if (vectorPreferences.sendTypingNotifs()) { room?.typingService()?.userStopsTyping() } diff --git a/vector/src/main/java/im/vector/app/features/home/room/detail/timeline/factory/TimelineItemFactory.kt b/vector/src/main/java/im/vector/app/features/home/room/detail/timeline/factory/TimelineItemFactory.kt index 84b71ceedfc..3482eaf4ad2 100644 --- a/vector/src/main/java/im/vector/app/features/home/room/detail/timeline/factory/TimelineItemFactory.kt +++ b/vector/src/main/java/im/vector/app/features/home/room/detail/timeline/factory/TimelineItemFactory.kt @@ -158,8 +158,8 @@ class TimelineItemFactory @Inject constructor( defaultItemFactory.create(params) } }.also { - if (it != null && event.isEncrypted()) { - decryptionFailureTracker.e2eEventDisplayedInTimeline(event) + if (it != null && event.isEncrypted() && event.root.mCryptoError != null) { + decryptionFailureTracker.utdDisplayedInTimeline(event) } } } diff --git a/vector/src/test/java/im/vector/app/features/analytics/DecryptionFailureTrackerTest.kt b/vector/src/test/java/im/vector/app/features/analytics/DecryptionFailureTrackerTest.kt new file mode 100644 index 00000000000..2f11d4c2eb1 --- /dev/null +++ b/vector/src/test/java/im/vector/app/features/analytics/DecryptionFailureTrackerTest.kt @@ -0,0 +1,760 @@ +/* + * Copyright (c) 2024 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 + +import im.vector.app.features.analytics.itf.VectorAnalyticsEvent +import im.vector.app.features.analytics.plan.Error +import im.vector.app.test.fakes.FakeActiveSessionDataSource +import im.vector.app.test.fakes.FakeAnalyticsTracker +import im.vector.app.test.fakes.FakeClock +import im.vector.app.test.fakes.FakeSession +import im.vector.app.test.shared.createTimberTestRule +import io.mockk.every +import io.mockk.just +import io.mockk.mockk +import io.mockk.runs +import io.mockk.slot +import io.mockk.verify +import kotlinx.coroutines.CoroutineScope +import kotlinx.coroutines.ExperimentalCoroutinesApi +import kotlinx.coroutines.test.advanceTimeBy +import kotlinx.coroutines.test.runCurrent +import kotlinx.coroutines.test.runTest +import org.amshove.kluent.shouldBeEqualTo +import org.amshove.kluent.shouldNotBeEqualTo +import org.junit.Before +import org.junit.Rule +import org.junit.Test +import org.matrix.android.sdk.api.auth.LoginType +import org.matrix.android.sdk.api.auth.data.Credentials +import org.matrix.android.sdk.api.auth.data.SessionParams +import org.matrix.android.sdk.api.session.crypto.MXCryptoError +import org.matrix.android.sdk.api.session.crypto.model.CryptoDeviceInfo +import org.matrix.android.sdk.api.session.events.model.Event +import org.matrix.android.sdk.api.session.room.timeline.TimelineEvent +import java.text.SimpleDateFormat + +@ExperimentalCoroutinesApi +class DecryptionFailureTrackerTest { + + @Rule + fun timberTestRule() = createTimberTestRule() + + private val fakeAnalyticsTracker = FakeAnalyticsTracker() + + private val fakeActiveSessionDataSource = FakeActiveSessionDataSource() + + private val fakeClock = FakeClock() + + private val decryptionFailureTracker = DecryptionFailureTracker( + fakeAnalyticsTracker, + fakeActiveSessionDataSource.instance, + fakeClock + ) + + private val aCredential = Credentials( + userId = "@alice:matrix.org", + deviceId = "ABCDEFGHT", + homeServer = "http://matrix.org", + accessToken = "qwerty", + refreshToken = null, + ) + + private val fakeMxOrgTestSession = FakeSession().apply { + givenSessionParams( + SessionParams( + credentials = aCredential, + homeServerConnectionConfig = mockk(relaxed = true), + isTokenValid = true, + loginType = LoginType.PASSWORD + ) + ) + fakeUserId = "@alice:matrix.org" + } + + private val aUISIError = MXCryptoError.Base( + MXCryptoError.ErrorType.UNKNOWN_INBOUND_SESSION_ID, + "", + detailedErrorDescription = "" + ) + + private val aFakeBobMxOrgEvent = Event( + originServerTs = 90_000, + eventId = "$000", + senderId = "@bob:matrix.org", + roomId = "!roomA" + ) + + @Before + fun setupTest() { + fakeMxOrgTestSession.fakeCryptoService.fakeCrossSigningService.givenIsCrossSigningVerifiedReturns(false) + } + + @Test + fun `should report late decryption to analytics tracker`() = runTest { + val fakeSession = fakeMxOrgTestSession + + every { + fakeAnalyticsTracker.capture(any()) + } just runs + + fakeClock.givenEpoch(100_000) + fakeActiveSessionDataSource.setActiveSession(fakeSession) + decryptionFailureTracker.start(CoroutineScope(coroutineContext)) + runCurrent() + + fakeSession.fakeCryptoService.fakeCrossSigningService.givenIsCrossSigningVerifiedReturns(true) + + val event = aFakeBobMxOrgEvent + + decryptionFailureTracker.onEventDecryptionError(event, aUISIError) + runCurrent() + // advance time by 5 seconds + fakeClock.givenEpoch(105_000) + + // Now simulate it's decrypted + decryptionFailureTracker.onEventDecrypted(event, emptyMap()) + runCurrent() + + // it should report + verify(exactly = 1) { fakeAnalyticsTracker.capture(any()) } + + verify { + fakeAnalyticsTracker.capture( + im.vector.app.features.analytics.plan.Error( + "mxc_crypto_error_type|", + cryptoModule = Error.CryptoModule.Rust, + domain = Error.Domain.E2EE, + name = Error.Name.OlmKeysNotSentError, + cryptoSDK = Error.CryptoSDK.Rust, + timeToDecryptMillis = 5000, + isFederated = false, + isMatrixDotOrg = true, + userTrustsOwnIdentity = true, + wasVisibleToUser = false + ), + ) + } + + // Can't do that in @Before function, it wont work as test will fail with: + // "the test coroutine is not completing, there were active child jobs" + // as the decryptionFailureTracker is setup to use the current test coroutine scope (?) + decryptionFailureTracker.stop() + } + + @Test + fun `should not report graced late decryption to analytics tracker`() = runTest { + val fakeSession = fakeMxOrgTestSession + + var currentFakeTime = 100_000L + fakeClock.givenEpoch(currentFakeTime) + fakeActiveSessionDataSource.setActiveSession(fakeSession) + decryptionFailureTracker.start(CoroutineScope(coroutineContext)) + runCurrent() + + val event = aFakeBobMxOrgEvent + + decryptionFailureTracker.onEventDecryptionError(event, aUISIError) + + runCurrent() + // advance time by 3 seconds + currentFakeTime += 3_000 + fakeClock.givenEpoch(currentFakeTime) + + // Now simulate it's decrypted + decryptionFailureTracker.onEventDecrypted( + event, + emptyMap() + ) + + runCurrent() + + // it should not have reported it + verify(exactly = 0) { fakeAnalyticsTracker.capture(any()) } + + decryptionFailureTracker.stop() + } + + @Test + fun `should report time to decrypt for late decryption`() = runTest { + val fakeSession = fakeMxOrgTestSession + + val eventSlot = slot() + + every { + fakeAnalyticsTracker.capture(event = capture(eventSlot)) + } just runs + + var currentFakeTime = 100_000L + fakeClock.givenEpoch(currentFakeTime) + fakeActiveSessionDataSource.setActiveSession(fakeSession) + decryptionFailureTracker.start(CoroutineScope(coroutineContext)) + runCurrent() + + fakeSession.fakeCryptoService.fakeCrossSigningService.givenIsCrossSigningVerifiedReturns(true) + + val event = aFakeBobMxOrgEvent + decryptionFailureTracker.onEventDecryptionError(event, aUISIError) + + runCurrent() + // advance time by 7 seconds, to be ahead of the 3 seconds grace period + currentFakeTime += 7_000 + fakeClock.givenEpoch(currentFakeTime) + + // Now simulate it's decrypted + decryptionFailureTracker.onEventDecrypted( + event, + emptyMap() + ) + + runCurrent() + + // it should report + verify(exactly = 1) { fakeAnalyticsTracker.capture(any()) } + + val error = eventSlot.captured as Error + error.timeToDecryptMillis shouldBeEqualTo 7000 + + decryptionFailureTracker.stop() + } + + @Test + fun `should report isMatrixDotOrg`() = runTest { + val fakeSession = fakeMxOrgTestSession + + val eventSlot = slot() + + every { + fakeAnalyticsTracker.capture(event = capture(eventSlot)) + } just runs + + var currentFakeTime = 100_000L + fakeClock.givenEpoch(currentFakeTime) + fakeActiveSessionDataSource.setActiveSession(fakeSession) + decryptionFailureTracker.start(CoroutineScope(coroutineContext)) + runCurrent() + + val event = aFakeBobMxOrgEvent + + decryptionFailureTracker.onEventDecryptionError(event, aUISIError) + runCurrent() + + // advance time by 7 seconds, to be ahead of the grace period + currentFakeTime += 7_000 + fakeClock.givenEpoch(currentFakeTime) + + // Now simulate it's decrypted + decryptionFailureTracker.onEventDecrypted(event, emptyMap()) + runCurrent() + + val error = eventSlot.captured as Error + error.isMatrixDotOrg shouldBeEqualTo true + + val otherSession = FakeSession().apply { + givenSessionParams( + SessionParams( + credentials = aCredential.copy(userId = "@alice:another.org"), + homeServerConnectionConfig = mockk(relaxed = true), + isTokenValid = true, + loginType = LoginType.PASSWORD + ) + ) + every { sessionId } returns "WWEERE" + fakeUserId = "@alice:another.org" + this.fakeCryptoService.fakeCrossSigningService.givenIsCrossSigningVerifiedReturns(true) + } + fakeActiveSessionDataSource.setActiveSession(otherSession) + runCurrent() + + val event2 = aFakeBobMxOrgEvent.copy(eventId = "$001") + + decryptionFailureTracker.onEventDecryptionError(event2, aUISIError) + runCurrent() + + // advance time by 7 seconds, to be ahead of the grace period + currentFakeTime += 7_000 + fakeClock.givenEpoch(currentFakeTime) + + // Now simulate it's decrypted + decryptionFailureTracker.onEventDecrypted(event2, emptyMap()) + runCurrent() + + (eventSlot.captured as Error).isMatrixDotOrg shouldBeEqualTo false + + decryptionFailureTracker.stop() + } + + @Test + fun `should report if user trusted it's identity at time of decryption`() = runTest { + val fakeSession = fakeMxOrgTestSession + + val eventSlot = slot() + + every { + fakeAnalyticsTracker.capture(event = capture(eventSlot)) + } just runs + + var currentFakeTime = 100_000L + fakeClock.givenEpoch(currentFakeTime) + fakeActiveSessionDataSource.setActiveSession(fakeSession) + decryptionFailureTracker.start(CoroutineScope(coroutineContext)) + runCurrent() + + fakeSession.fakeCryptoService.fakeCrossSigningService.givenIsCrossSigningVerifiedReturns(false) + val event = aFakeBobMxOrgEvent + + decryptionFailureTracker.onEventDecryptionError(event, aUISIError) + runCurrent() + + fakeSession.fakeCryptoService.fakeCrossSigningService.givenIsCrossSigningVerifiedReturns(true) + val event2 = aFakeBobMxOrgEvent.copy(eventId = "$001") + decryptionFailureTracker.onEventDecryptionError(event2, aUISIError) + runCurrent() + + // advance time by 7 seconds, to be ahead of the grace period + currentFakeTime += 7_000 + fakeClock.givenEpoch(currentFakeTime) + + // Now simulate it's decrypted + decryptionFailureTracker.onEventDecrypted(event, emptyMap()) + runCurrent() + + (eventSlot.captured as Error).userTrustsOwnIdentity shouldBeEqualTo false + + decryptionFailureTracker.onEventDecrypted(event2, emptyMap()) + runCurrent() + + (eventSlot.captured as Error).userTrustsOwnIdentity shouldBeEqualTo true + + verify(exactly = 2) { fakeAnalyticsTracker.capture(any()) } + + decryptionFailureTracker.stop() + } + + @Test + fun `should not report same event twice`() = runTest { + val fakeSession = fakeMxOrgTestSession + + every { + fakeAnalyticsTracker.capture(any()) + } just runs + + var currentFakeTime = 100_000L + fakeClock.givenEpoch(currentFakeTime) + fakeActiveSessionDataSource.setActiveSession(fakeSession) + decryptionFailureTracker.start(CoroutineScope(coroutineContext)) + runCurrent() + + val event = aFakeBobMxOrgEvent + + decryptionFailureTracker.onEventDecryptionError(event, aUISIError) + + runCurrent() + + // advance time by 7 seconds, to be ahead of the grace period + currentFakeTime += 7_000 + fakeClock.givenEpoch(currentFakeTime) + + // Now simulate it's decrypted + decryptionFailureTracker.onEventDecrypted(event, emptyMap()) + runCurrent() + + verify(exactly = 1) { fakeAnalyticsTracker.capture(any()) } + + decryptionFailureTracker.onEventDecryptionError(event, aUISIError) + runCurrent() + + // advance time by 7 seconds, to be ahead of the grace period + currentFakeTime += 7_000 + fakeClock.givenEpoch(currentFakeTime) + + decryptionFailureTracker.onEventDecrypted(event, emptyMap()) + runCurrent() + + verify(exactly = 1) { fakeAnalyticsTracker.capture(any()) } + + decryptionFailureTracker.stop() + } + + @Test + fun `should report if isFedrated`() = runTest { + val fakeSession = fakeMxOrgTestSession + + val eventSlot = slot() + + every { + fakeAnalyticsTracker.capture(event = capture(eventSlot)) + } just runs + + var currentFakeTime = 100_000L + fakeClock.givenEpoch(currentFakeTime) + fakeActiveSessionDataSource.setActiveSession(fakeSession) + decryptionFailureTracker.start(CoroutineScope(coroutineContext)) + runCurrent() + + val event = aFakeBobMxOrgEvent + + decryptionFailureTracker.onEventDecryptionError(event, aUISIError) + runCurrent() + + val event2 = aFakeBobMxOrgEvent.copy( + eventId = "$001", + senderId = "@bob:another.org", + ) + decryptionFailureTracker.onEventDecryptionError(event2, aUISIError) + runCurrent() + + // advance time by 7 seconds, to be ahead of the grace period + currentFakeTime += 7_000 + fakeClock.givenEpoch(currentFakeTime) + + // Now simulate it's decrypted + decryptionFailureTracker.onEventDecrypted(event, emptyMap()) + runCurrent() + + (eventSlot.captured as Error).isFederated shouldBeEqualTo false + + decryptionFailureTracker.onEventDecrypted(event2, emptyMap()) + runCurrent() + + (eventSlot.captured as Error).isFederated shouldBeEqualTo true + + verify(exactly = 2) { fakeAnalyticsTracker.capture(any()) } + + decryptionFailureTracker.stop() + } + + @Test + fun `should report if wasVisibleToUser`() = runTest { + val fakeSession = fakeMxOrgTestSession + val eventSlot = slot() + + every { + fakeAnalyticsTracker.capture(event = capture(eventSlot)) + } just runs + var currentFakeTime = 100_000L + fakeClock.givenEpoch(currentFakeTime) + fakeActiveSessionDataSource.setActiveSession(fakeSession) + decryptionFailureTracker.start(CoroutineScope(coroutineContext)) + runCurrent() + + val event = aFakeBobMxOrgEvent + + decryptionFailureTracker.onEventDecryptionError(event, aUISIError) + runCurrent() + + val event2 = aFakeBobMxOrgEvent.copy( + eventId = "$001", + senderId = "@bob:another.org", + ) + decryptionFailureTracker.onEventDecryptionError(event2, aUISIError) + runCurrent() + + decryptionFailureTracker.utdDisplayedInTimeline( + mockk(relaxed = true).apply { + every { root } returns event2 + every { eventId } returns event2.eventId.orEmpty() + } + ) + + // advance time by 7 seconds, to be ahead of the grace period + currentFakeTime += 7_000 + fakeClock.givenEpoch(currentFakeTime) + + // Now simulate it's decrypted + decryptionFailureTracker.onEventDecrypted(event, emptyMap()) + runCurrent() + + (eventSlot.captured as Error).wasVisibleToUser shouldBeEqualTo false + + decryptionFailureTracker.onEventDecrypted(event2, emptyMap()) + runCurrent() + + (eventSlot.captured as Error).wasVisibleToUser shouldBeEqualTo true + + verify(exactly = 2) { fakeAnalyticsTracker.capture(any()) } + + decryptionFailureTracker.stop() + } + + @Test + fun `should report if event relative age to session`() = runTest { + val fakeSession = fakeMxOrgTestSession + + val formatter = SimpleDateFormat("yyyy-MM-dd HH:mm:ss") + val historicalEventTimestamp = formatter.parse("2024-03-08 09:24:11")!!.time + val sessionCreationTime = formatter.parse("2024-03-09 10:00:00")!!.time + // 1mn after creation + val liveEventTimestamp = formatter.parse("2024-03-09 10:01:00")!!.time + + val eventSlot = slot() + + every { + fakeAnalyticsTracker.capture(event = capture(eventSlot)) + } just runs + + fakeSession.fakeCryptoService.cryptoDeviceInfo = CryptoDeviceInfo( + deviceId = "ABCDEFGHT", + userId = "@alice:matrix.org", + firstTimeSeenLocalTs = sessionCreationTime + ) + + var currentFakeTime = 100_000L + fakeClock.givenEpoch(currentFakeTime) + fakeActiveSessionDataSource.setActiveSession(fakeSession) + decryptionFailureTracker.start(CoroutineScope(coroutineContext)) + runCurrent() + + val event = aFakeBobMxOrgEvent.copy( + originServerTs = historicalEventTimestamp + ) + + decryptionFailureTracker.onEventDecryptionError(event, aUISIError) + runCurrent() + + val liveEvent = aFakeBobMxOrgEvent.copy( + eventId = "$001", + originServerTs = liveEventTimestamp + ) + decryptionFailureTracker.onEventDecryptionError(liveEvent, aUISIError) + runCurrent() + + // advance time by 7 seconds, to be ahead of the grace period + currentFakeTime += 7_000 + fakeClock.givenEpoch(currentFakeTime) + + // Now simulate historical event late decrypt + decryptionFailureTracker.onEventDecrypted(event, emptyMap()) + runCurrent() + + (eventSlot.captured as Error).eventLocalAgeMillis shouldBeEqualTo (historicalEventTimestamp - sessionCreationTime).toInt() + + decryptionFailureTracker.onEventDecrypted(liveEvent, emptyMap()) + runCurrent() + + (eventSlot.captured as Error).eventLocalAgeMillis shouldBeEqualTo (liveEventTimestamp - sessionCreationTime).toInt() + (eventSlot.captured as Error).eventLocalAgeMillis shouldBeEqualTo 60 * 1000 + + verify(exactly = 2) { fakeAnalyticsTracker.capture(any()) } + + decryptionFailureTracker.stop() + } + + @Test + fun `should report historical UTDs as an expected UTD if not verified`() = runTest { + val fakeSession = fakeMxOrgTestSession + + val formatter = SimpleDateFormat("yyyy-MM-dd HH:mm:ss") + val historicalEventTimestamp = formatter.parse("2024-03-08 09:24:11")!!.time + val sessionCreationTime = formatter.parse("2024-03-09 10:00:00")!!.time + + val eventSlot = slot() + + every { + fakeAnalyticsTracker.capture(event = capture(eventSlot)) + } just runs + + fakeSession.fakeCryptoService.cryptoDeviceInfo = CryptoDeviceInfo( + deviceId = "ABCDEFGHT", + userId = "@alice:matrix.org", + firstTimeSeenLocalTs = sessionCreationTime + ) + + var currentFakeTime = 100_000L + fakeClock.givenEpoch(currentFakeTime) + fakeActiveSessionDataSource.setActiveSession(fakeSession) + decryptionFailureTracker.start(CoroutineScope(coroutineContext)) + runCurrent() + + // historical event and session not verified + fakeSession.fakeCryptoService.fakeCrossSigningService.givenIsCrossSigningVerifiedReturns(false) + val event = aFakeBobMxOrgEvent.copy( + originServerTs = historicalEventTimestamp + ) + decryptionFailureTracker.onEventDecryptionError(event, aUISIError) + runCurrent() + + // advance time to be ahead of the permanent UTD period + currentFakeTime += 70_000 + fakeClock.givenEpoch(currentFakeTime) + advanceTimeBy(70_000) + runCurrent() + + (eventSlot.captured as Error).name shouldBeEqualTo Error.Name.HistoricalMessage + + decryptionFailureTracker.stop() + } + + @Test + fun `should not report historical UTDs as an expected UTD if verified`() = runTest { + val fakeSession = fakeMxOrgTestSession + + val formatter = SimpleDateFormat("yyyy-MM-dd HH:mm:ss") + val historicalEventTimestamp = formatter.parse("2024-03-08 09:24:11")!!.time + val sessionCreationTime = formatter.parse("2024-03-09 10:00:00")!!.time + + val eventSlot = slot() + + every { + fakeAnalyticsTracker.capture(event = capture(eventSlot)) + } just runs + + fakeSession.fakeCryptoService.cryptoDeviceInfo = CryptoDeviceInfo( + deviceId = "ABCDEFGHT", + userId = "@alice:matrix.org", + firstTimeSeenLocalTs = sessionCreationTime + ) + + var currentFakeTime = 100_000L + fakeClock.givenEpoch(currentFakeTime) + fakeActiveSessionDataSource.setActiveSession(fakeSession) + decryptionFailureTracker.start(CoroutineScope(coroutineContext)) + runCurrent() + + // historical event and session not verified + fakeSession.fakeCryptoService.fakeCrossSigningService.givenIsCrossSigningVerifiedReturns(true) + val event = aFakeBobMxOrgEvent.copy( + originServerTs = historicalEventTimestamp + ) + decryptionFailureTracker.onEventDecryptionError(event, aUISIError) + runCurrent() + + // advance time to be ahead of the permanent UTD period + currentFakeTime += 70_000 + fakeClock.givenEpoch(currentFakeTime) + advanceTimeBy(70_000) + runCurrent() + + (eventSlot.captured as Error).name shouldNotBeEqualTo Error.Name.HistoricalMessage + + decryptionFailureTracker.stop() + } + + @Test + fun `should not report live UTDs as an expected UTD even if not verified`() = runTest { + val fakeSession = fakeMxOrgTestSession + + val formatter = SimpleDateFormat("yyyy-MM-dd HH:mm:ss") + val sessionCreationTime = formatter.parse("2024-03-09 10:00:00")!!.time + // 1mn after creation + val liveEventTimestamp = formatter.parse("2024-03-09 10:01:00")!!.time + + val eventSlot = slot() + + every { + fakeAnalyticsTracker.capture(event = capture(eventSlot)) + } just runs + + fakeSession.fakeCryptoService.cryptoDeviceInfo = CryptoDeviceInfo( + deviceId = "ABCDEFGHT", + userId = "@alice:matrix.org", + firstTimeSeenLocalTs = sessionCreationTime + ) + + var currentFakeTime = 100_000L + fakeClock.givenEpoch(currentFakeTime) + fakeActiveSessionDataSource.setActiveSession(fakeSession) + decryptionFailureTracker.start(CoroutineScope(coroutineContext)) + runCurrent() + + // historical event and session not verified + fakeSession.fakeCryptoService.fakeCrossSigningService.givenIsCrossSigningVerifiedReturns(false) + val event = aFakeBobMxOrgEvent.copy( + originServerTs = liveEventTimestamp + ) + decryptionFailureTracker.onEventDecryptionError(event, aUISIError) + runCurrent() + + // advance time to be ahead of the permanent UTD period + currentFakeTime += 70_000 + fakeClock.givenEpoch(currentFakeTime) + advanceTimeBy(70_000) + runCurrent() + + (eventSlot.captured as Error).name shouldNotBeEqualTo Error.Name.HistoricalMessage + + decryptionFailureTracker.stop() + } + + @Test + fun `should report if permanent UTD`() = runTest { + val fakeSession = fakeMxOrgTestSession + + val eventSlot = slot() + + every { + fakeAnalyticsTracker.capture(event = capture(eventSlot)) + } just runs + + var currentFakeTime = 100_000L + fakeClock.givenEpoch(currentFakeTime) + fakeActiveSessionDataSource.setActiveSession(fakeSession) + decryptionFailureTracker.start(CoroutineScope(coroutineContext)) + runCurrent() + + val event = aFakeBobMxOrgEvent + + decryptionFailureTracker.onEventDecryptionError(event, aUISIError) + runCurrent() + + currentFakeTime += 70_000 + fakeClock.givenEpoch(currentFakeTime) + advanceTimeBy(70_000) + runCurrent() + + verify(exactly = 1) { fakeAnalyticsTracker.capture(any()) } + + (eventSlot.captured as Error).timeToDecryptMillis shouldBeEqualTo -1 + decryptionFailureTracker.stop() + } + + @Test + fun `with multiple UTD`() = runTest { + val fakeSession = fakeMxOrgTestSession + + every { + fakeAnalyticsTracker.capture(any()) + } just runs + + var currentFakeTime = 100_000L + fakeClock.givenEpoch(currentFakeTime) + fakeActiveSessionDataSource.setActiveSession(fakeSession) + decryptionFailureTracker.start(CoroutineScope(coroutineContext)) + runCurrent() + + val events = (0..10).map { + aFakeBobMxOrgEvent.copy( + eventId = "000$it", + originServerTs = 50_000 + it * 1000L + ) + } + + events.forEach { + decryptionFailureTracker.onEventDecryptionError(it, aUISIError) + } + runCurrent() + + currentFakeTime += 70_000 + fakeClock.givenEpoch(currentFakeTime) + advanceTimeBy(70_000) + runCurrent() + + verify(exactly = 11) { fakeAnalyticsTracker.capture(any()) } + + decryptionFailureTracker.stop() + } +} diff --git a/vector/src/test/java/im/vector/app/test/fakes/FakeSession.kt b/vector/src/test/java/im/vector/app/test/fakes/FakeSession.kt index 12da88d286c..9c791305b6a 100644 --- a/vector/src/test/java/im/vector/app/test/fakes/FakeSession.kt +++ b/vector/src/test/java/im/vector/app/test/fakes/FakeSession.kt @@ -53,7 +53,10 @@ class FakeSession( mockkStatic("im.vector.app.core.extensions.SessionKt") } - override val myUserId: String = "@fake:server.fake" + var fakeUserId = "@fake:server.fake" + + override val myUserId: String + get() = fakeUserId override val coroutineDispatchers = testCoroutineDispatchers diff --git a/vector/src/test/java/im/vector/app/test/fakes/FakeUri.kt b/vector/src/test/java/im/vector/app/test/fakes/FakeUri.kt index 08bfac8db15..e24f14294ec 100644 --- a/vector/src/test/java/im/vector/app/test/fakes/FakeUri.kt +++ b/vector/src/test/java/im/vector/app/test/fakes/FakeUri.kt @@ -28,6 +28,7 @@ class FakeUri(contentEquals: String? = null) { contentEquals?.let { givenEquals(it) every { instance.toString() } returns it + every { instance.scheme } returns contentEquals.substring(0, contentEquals.indexOf(':')) } }