Refactor Decryption Failure Tracker and report new properties

This commit is contained in:
Valere 2024-03-14 11:26:36 +01:00
parent 1f430a4015
commit fcc5181a28
9 changed files with 930 additions and 104 deletions

View File

@ -51,6 +51,7 @@ import im.vector.app.core.debug.LeakDetector
import im.vector.app.core.di.ActiveSessionHolder import im.vector.app.core.di.ActiveSessionHolder
import im.vector.app.core.pushers.FcmHelper import im.vector.app.core.pushers.FcmHelper
import im.vector.app.core.resources.BuildMeta 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.analytics.VectorAnalytics
import im.vector.app.features.call.webrtc.WebRtcCallManager import im.vector.app.features.call.webrtc.WebRtcCallManager
import im.vector.app.features.configuration.VectorConfiguration import im.vector.app.features.configuration.VectorConfiguration
@ -100,6 +101,7 @@ class VectorApplication :
@Inject lateinit var callManager: WebRtcCallManager @Inject lateinit var callManager: WebRtcCallManager
@Inject lateinit var invitesAcceptor: InvitesAcceptor @Inject lateinit var invitesAcceptor: InvitesAcceptor
@Inject lateinit var autoRageShaker: AutoRageShaker @Inject lateinit var autoRageShaker: AutoRageShaker
@Inject lateinit var decryptionFailureTracker: DecryptionFailureTracker
@Inject lateinit var vectorFileLogger: VectorFileLogger @Inject lateinit var vectorFileLogger: VectorFileLogger
@Inject lateinit var vectorAnalytics: VectorAnalytics @Inject lateinit var vectorAnalytics: VectorAnalytics
@Inject lateinit var flipperProxy: FlipperProxy @Inject lateinit var flipperProxy: FlipperProxy
@ -130,6 +132,7 @@ class VectorApplication :
vectorAnalytics.init() vectorAnalytics.init()
invitesAcceptor.initialize() invitesAcceptor.initialize()
autoRageShaker.initialize() autoRageShaker.initialize()
decryptionFailureTracker.start()
vectorUncaughtExceptionHandler.activate() vectorUncaughtExceptionHandler.activate()
// Remove Log handler statically added by Jitsi // Remove Log handler statically added by Jitsi

View File

@ -23,7 +23,6 @@ import im.vector.app.core.pushers.UnregisterUnifiedPushUseCase
import im.vector.app.core.services.GuardServiceStarter import im.vector.app.core.services.GuardServiceStarter
import im.vector.app.core.session.ConfigureAndStartSessionUseCase import im.vector.app.core.session.ConfigureAndStartSessionUseCase
import im.vector.app.features.analytics.DecryptionFailureTracker 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.call.webrtc.WebRtcCallManager
import im.vector.app.features.crypto.keysrequest.KeyRequestHandler import im.vector.app.features.crypto.keysrequest.KeyRequestHandler
import im.vector.app.features.crypto.verification.IncomingVerificationRequestHandler import im.vector.app.features.crypto.verification.IncomingVerificationRequestHandler
@ -75,11 +74,6 @@ class ActiveSessionHolder @Inject constructor(
session.callSignalingService().addCallListener(callManager) session.callSignalingService().addCallListener(callManager)
imageManager.onSessionStarted(session) imageManager.onSessionStarted(session)
guardServiceStarter.start() guardServiceStarter.start()
decryptionFailureTracker.currentModule = if (session.cryptoService().name() == "rust-sdk") {
Error.CryptoModule.Rust
} else {
Error.CryptoModule.Native
}
} }
suspend fun clearActiveSession() { suspend fun clearActiveSession() {

View File

@ -0,0 +1,78 @@
/*
* 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
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.error.toAnalyticsErrorName(),
// this is deprecated keep for backward compatibility
cryptoModule = Error.CryptoModule.Rust
)
}
fun DecryptionFailure.toCustomProperties(): Map<String, Any> {
val properties = mutableMapOf<String, Any>()
if (timeToDecryptMillis != null) {
properties["timeToDecryptMillis"] = timeToDecryptMillis
} else {
properties["timeToDecryptMillis"] = -1
}
isFederated?.let {
properties["isFederated"] = it
}
properties["isMatrixDotOrg"] = isMatrixDotOrg
properties["wasVisibleToUser"] = wasVisibleOnScreen
properties["userTrustsOwnIdentity"] = ownIdentityTrustedAtTimeOfDecryptionFailure
eventLocalAgeAtDecryptionFailure?.let {
properties["eventLocalAgeAtDecryptionFailure"] = it
}
return properties
}
private fun MXCryptoError.toAnalyticsErrorName(): Error.Name {
return if (this is MXCryptoError.Base) {
when (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
}
}

View File

@ -16,149 +16,280 @@
package im.vector.app.features.analytics package im.vector.app.features.analytics
import im.vector.app.features.analytics.plan.Error import im.vector.app.ActiveSessionDataSource
import im.vector.lib.core.utils.compat.removeIfCompat
import im.vector.lib.core.utils.flow.tickerFlow
import im.vector.lib.core.utils.timer.Clock import im.vector.lib.core.utils.timer.Clock
import kotlinx.coroutines.CancellationException
import kotlinx.coroutines.CoroutineScope import kotlinx.coroutines.CoroutineScope
import kotlinx.coroutines.Dispatchers import kotlinx.coroutines.Dispatchers
import kotlinx.coroutines.Job
import kotlinx.coroutines.SupervisorJob 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.launchIn
import kotlinx.coroutines.flow.onEach import kotlinx.coroutines.flow.onEach
import kotlinx.coroutines.launch 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.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.session.room.timeline.TimelineEvent
import org.matrix.android.sdk.api.util.JsonDict
import timber.log.Timber
import javax.inject.Inject import javax.inject.Inject
import javax.inject.Singleton import javax.inject.Singleton
private data class DecryptionFailure( // If we can decrypt in less than 4s, we don't report
val timeStamp: Long,
val roomId: String,
val failedEventId: String,
val error: MXCryptoError.ErrorType
)
private typealias DetailedErrorName = Pair<String, Error.Name>
private const val GRACE_PERIOD_MILLIS = 4_000 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 * 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. * 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 @Singleton
class DecryptionFailureTracker @Inject constructor( class DecryptionFailureTracker @Inject constructor(
private val analyticsTracker: AnalyticsTracker, private val analyticsTracker: AnalyticsTracker,
private val sessionDataSource: ActiveSessionDataSource,
private val clock: Clock private val clock: Clock
) { ) : Session.Listener, LiveEventListener {
private val scope: CoroutineScope = CoroutineScope(SupervisorJob()) // The active session (set by the sessionDataSource)
private val failures = mutableListOf<DecryptionFailure>() 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<String, DecryptionFailure>()
// List of eventId that have been reported, to avoid double reporting
private val alreadyReported = mutableListOf<String>() private val alreadyReported = mutableListOf<String>()
var currentModule: Error.CryptoModule? = null // Mutex to ensure sequential access to internal state
private val mutex = Mutex()
init { // Used to unsubscribe from the active session data source
start() private lateinit var activeSessionSourceDisposable: Job
}
fun start() { // The ticker job, to report permanent UTD (not decrypted after MAX_WAIT_MILLIS)
tickerFlow(scope, CHECK_INTERVAL) private var currentTicker: Job? = null
.onEach {
checkFailures() /**
}.launchIn(scope) * 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() { 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) { private fun post(block: suspend () -> Unit) {
scope.launch(Dispatchers.Default) { scope.launch {
val mCryptoError = event.root.mCryptoError mutex.withLock {
if (mCryptoError != null) { block()
addDecryptionFailure(DecryptionFailure(clock.epochMillis(), event.roomId, event.eventId, mCryptoError))
} else {
removeFailureForEventId(event.eventId)
} }
} }
} }
/** private suspend fun rescheduleTicker() {
* Can be called when the timeline is disposed in order currentTicker = scope.launch {
* to grace those events as they are not anymore displayed on screen. Timber.v("Reschedule ticker")
* */ delay(CHECK_INTERVAL)
fun onTimeLineDisposed(roomId: String) { post {
scope.launch(Dispatchers.Default) { checkFailures()
synchronized(failures) { currentTicker = null
failures.removeIfCompat { it.roomId == roomId } 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)
}
}
// LiveEventListener callbacks
override fun onEventDecrypted(event: Event, clearEvent: JsonDict) {
Timber.v("Event decrypted ${event.eventId}")
event.eventId?.let {
post {
handleEventDecrypted(it)
} }
} }
} }
private fun addDecryptionFailure(failure: DecryptionFailure) { override fun onEventDecryptionError(event: Event, cryptoError: MXCryptoError) {
// de duplicate Timber.v("Decryption error for event ${event.eventId} with error $cryptoError")
synchronized(failures) { val session = activeSession ?: return
if (failures.none { it.failedEventId == failure.failedEventId }) { // track the event
failures.add(failure) post {
} trackEvent(session, event, cryptoError)
} }
} }
private fun removeFailureForEventId(eventId: String) { override fun onLiveToDeviceEvent(event: Event) {}
synchronized(failures) { override fun onLiveEvent(roomId: String, event: Event) {}
failures.removeIfCompat { it.failedEventId == eventId } 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
} }
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
if (currentTicker == null) {
rescheduleTicker()
}
}
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)
}
}
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()
val properties = decryptionFailure.toCustomProperties()
Timber.v("capture error $error with properties $properties")
analyticsTracker.capture(error, properties)
// now remove from tracked
trackedEventsMap.remove(decryptionFailure.failedEventId)
// mark as already reported
alreadyReported.add(decryptionFailure.failedEventId)
} }
private fun checkFailures() { private fun checkFailures() {
val now = clock.epochMillis() val now = clock.epochMillis()
val aggregatedErrors: Map<DetailedErrorName, List<String>> Timber.v("Check failures now $now")
synchronized(failures) { // report the definitely failed
val toReport = mutableListOf<DecryptionFailure>() val toReport = trackedEventsMap.values.filter {
failures.removeAll { failure -> now - it.timeStamp > MAX_WAIT_MILLIS
(now - failure.timeStamp > GRACE_PERIOD_MILLIS).also {
if (it) {
toReport.add(failure)
}
}
}
aggregatedErrors = toReport
.groupBy { it.error.toAnalyticsErrorName() }
.mapValues {
it.value.map { it.failedEventId }
}
} }
toReport.forEach {
aggregatedErrors.forEach { aggregation -> reportFailure(
// there is now way to send the total/sum in posthog, so iterating it.copy(timeToDecryptMillis = -1)
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 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
}
return DetailedErrorName(detailed, errorName)
}
} }

View File

@ -1484,7 +1484,6 @@ class TimelineViewModel @AssistedInject constructor(
override fun onCleared() { override fun onCleared() {
timeline?.dispose() timeline?.dispose()
timeline?.removeAllListeners() timeline?.removeAllListeners()
decryptionFailureTracker.onTimeLineDisposed(initialState.roomId)
if (vectorPreferences.sendTypingNotifs()) { if (vectorPreferences.sendTypingNotifs()) {
room?.typingService()?.userStopsTyping() room?.typingService()?.userStopsTyping()
} }

View File

@ -158,8 +158,8 @@ class TimelineItemFactory @Inject constructor(
defaultItemFactory.create(params) defaultItemFactory.create(params)
} }
}.also { }.also {
if (it != null && event.isEncrypted()) { if (it != null && event.isEncrypted() && event.root.mCryptoError != null) {
decryptionFailureTracker.e2eEventDisplayedInTimeline(event) decryptionFailureTracker.utdDisplayedInTimeline(event)
} }
} }
} }

View File

@ -0,0 +1,617 @@
/*
* 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 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.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(), 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(), any()) }
verify {
fakeAnalyticsTracker.capture(
Error(
"mxc_crypto_error_type|",
Error.CryptoModule.Rust,
Error.Domain.E2EE,
Error.Name.OlmKeysNotSentError
),
any()
)
}
// 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(), any()) }
decryptionFailureTracker.stop()
}
@Test
fun `should report time to decrypt for late decryption`() = runTest {
val fakeSession = fakeMxOrgTestSession
val propertiesSlot = slot<Map<String, Any>>()
every {
fakeAnalyticsTracker.capture(any(), customProperties = capture(propertiesSlot))
} 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(), any()) }
val properties = propertiesSlot.captured
properties["timeToDecryptMillis"] shouldBeEqualTo 7000L
decryptionFailureTracker.stop()
}
@Test
fun `should report isMatrixDotOrg`() = runTest {
val fakeSession = fakeMxOrgTestSession
val propertiesSlot = slot<Map<String, Any>>()
every {
fakeAnalyticsTracker.capture(any(), customProperties = capture(propertiesSlot))
} 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()
propertiesSlot.captured["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()
propertiesSlot.captured["isMatrixDotOrg"] shouldBeEqualTo false
decryptionFailureTracker.stop()
}
@Test
fun `should report if user trusted it's identity at time of decryption`() = runTest {
val fakeSession = fakeMxOrgTestSession
val propertiesSlot = slot<Map<String, Any>>()
every {
fakeAnalyticsTracker.capture(any(), customProperties = capture(propertiesSlot))
} 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()
propertiesSlot.captured["userTrustsOwnIdentity"] shouldBeEqualTo false
decryptionFailureTracker.onEventDecrypted(event2, emptyMap())
runCurrent()
propertiesSlot.captured["userTrustsOwnIdentity"] shouldBeEqualTo true
verify(exactly = 2) { fakeAnalyticsTracker.capture(any(), any()) }
decryptionFailureTracker.stop()
}
@Test
fun `should not report same event twice`() = runTest {
val fakeSession = fakeMxOrgTestSession
every {
fakeAnalyticsTracker.capture(any(), 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(), any()) }
decryptionFailureTracker.onEventDecryptionError(event, aUISIError)
runCurrent()
decryptionFailureTracker.onEventDecrypted(event, emptyMap())
runCurrent()
verify(exactly = 1) { fakeAnalyticsTracker.capture(any(), any()) }
decryptionFailureTracker.stop()
}
@Test
fun `should report if isFedrated`() = runTest {
val fakeSession = fakeMxOrgTestSession
val propertiesSlot = slot<Map<String, Any>>()
every {
fakeAnalyticsTracker.capture(any(), customProperties = capture(propertiesSlot))
} 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()
propertiesSlot.captured["isFederated"] shouldBeEqualTo false
decryptionFailureTracker.onEventDecrypted(event2, emptyMap())
runCurrent()
propertiesSlot.captured["isFederated"] shouldBeEqualTo true
verify(exactly = 2) { fakeAnalyticsTracker.capture(any(), any()) }
decryptionFailureTracker.stop()
}
@Test
fun `should report if wasVisibleToUser`() = runTest {
val fakeSession = fakeMxOrgTestSession
val propertiesSlot = slot<Map<String, Any>>()
every {
fakeAnalyticsTracker.capture(any(), customProperties = capture(propertiesSlot))
} 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<TimelineEvent>(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()
propertiesSlot.captured["wasVisibleToUser"] shouldBeEqualTo false
decryptionFailureTracker.onEventDecrypted(event2, emptyMap())
runCurrent()
propertiesSlot.captured["wasVisibleToUser"] shouldBeEqualTo true
verify(exactly = 2) { fakeAnalyticsTracker.capture(any(), any()) }
decryptionFailureTracker.stop()
}
@Test
fun `should report if event relative age to session`() = runTest {
val fakeSession = fakeMxOrgTestSession
val propertiesSlot = slot<Map<String, Any>>()
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
every {
fakeAnalyticsTracker.capture(any(), customProperties = capture(propertiesSlot))
} 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()
propertiesSlot.captured["eventLocalAgeAtDecryptionFailure"] shouldBeEqualTo (historicalEventTimestamp - sessionCreationTime)
decryptionFailureTracker.onEventDecrypted(liveEvent, emptyMap())
runCurrent()
propertiesSlot.captured["eventLocalAgeAtDecryptionFailure"] shouldBeEqualTo (liveEventTimestamp - sessionCreationTime)
propertiesSlot.captured["eventLocalAgeAtDecryptionFailure"] shouldBeEqualTo 60 * 1000L
verify(exactly = 2) { fakeAnalyticsTracker.capture(any(), any()) }
decryptionFailureTracker.stop()
}
@Test
fun `should report if permanent UTD`() = runTest {
val fakeSession = fakeMxOrgTestSession
val propertiesSlot = slot<Map<String, Any>>()
every {
fakeAnalyticsTracker.capture(any(), customProperties = capture(propertiesSlot))
} 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(), any()) }
propertiesSlot.captured["timeToDecryptMillis"] shouldBeEqualTo -1L
decryptionFailureTracker.stop()
}
@Test
fun `with multiple UTD`() = runTest {
val fakeSession = fakeMxOrgTestSession
val propertiesSlot = slot<Map<String, Any>>()
every {
fakeAnalyticsTracker.capture(any(), customProperties = capture(propertiesSlot))
} 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(), any()) }
decryptionFailureTracker.stop()
}
}

View File

@ -53,7 +53,10 @@ class FakeSession(
mockkStatic("im.vector.app.core.extensions.SessionKt") 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 override val coroutineDispatchers = testCoroutineDispatchers

View File

@ -28,6 +28,7 @@ class FakeUri(contentEquals: String? = null) {
contentEquals?.let { contentEquals?.let {
givenEquals(it) givenEquals(it)
every { instance.toString() } returns it every { instance.toString() } returns it
every { instance.scheme } returns contentEquals.substring(0, contentEquals.indexOf(':'))
} }
} }