From e5431d9fb445cb52cbff32e816be4af1b82cb439 Mon Sep 17 00:00:00 2001 From: Valere Date: Wed, 5 Jan 2022 10:24:08 +0100 Subject: [PATCH 1/2] Track decryption failures --- changelog.d/4719.feature | 1 + .../algorithms/megolm/MXMegolmDecryption.kt | 5 + .../analytics/DecryptionFailureTracker.kt | 149 ++++++++++++++++++ .../home/room/detail/RoomDetailViewModel.kt | 3 + .../timeline/factory/TimelineItemFactory.kt | 6 + 5 files changed, 164 insertions(+) create mode 100644 changelog.d/4719.feature create mode 100644 vector/src/main/java/im/vector/app/features/analytics/DecryptionFailureTracker.kt diff --git a/changelog.d/4719.feature b/changelog.d/4719.feature new file mode 100644 index 0000000000..b926613d03 --- /dev/null +++ b/changelog.d/4719.feature @@ -0,0 +1 @@ +Analytics: Track Errors \ No newline at end of file diff --git a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/crypto/algorithms/megolm/MXMegolmDecryption.kt b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/crypto/algorithms/megolm/MXMegolmDecryption.kt index 8bbc71543c..441b501360 100644 --- a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/crypto/algorithms/megolm/MXMegolmDecryption.kt +++ b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/crypto/algorithms/megolm/MXMegolmDecryption.kt @@ -133,6 +133,11 @@ internal class MXMegolmDecryption(private val userId: String, if (requestKeysOnFail) { requestKeysForEvent(event, false) } + + throw MXCryptoError.Base( + MXCryptoError.ErrorType.UNKNOWN_MESSAGE_INDEX, + throwable.olmException.message ?: "", + throwable.olmException.message) } val reason = String.format(MXCryptoError.OLM_REASON, throwable.olmException.message) 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 new file mode 100644 index 0000000000..c74a65c8ed --- /dev/null +++ b/vector/src/main/java/im/vector/app/features/analytics/DecryptionFailureTracker.kt @@ -0,0 +1,149 @@ +/* + * 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 + +import im.vector.app.core.flow.tickerFlow +import im.vector.app.features.analytics.plan.Error +import kotlinx.coroutines.CoroutineScope +import kotlinx.coroutines.Dispatchers +import kotlinx.coroutines.SupervisorJob +import kotlinx.coroutines.cancel +import kotlinx.coroutines.flow.launchIn +import kotlinx.coroutines.flow.onEach +import kotlinx.coroutines.launch +import org.matrix.android.sdk.api.session.crypto.MXCryptoError +import javax.inject.Inject +import javax.inject.Singleton + +data class DecryptionFailure( + val timeStamp: Long = System.currentTimeMillis(), + val roomId: String, + val failedEventId: String, + val error: MXCryptoError.ErrorType +) + +private const val GRACE_PERIOD_MILLIS = 20_000 + +/** + * Tracks decryption errors that are visible to the user. + * 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. + */ +@Singleton +class DecryptionFailureTracker @Inject constructor( + private val vectorAnalytics: VectorAnalytics +) { + + private val scope: CoroutineScope = CoroutineScope(SupervisorJob()) + private val failures = mutableListOf() + private val alreadyReported = mutableListOf() + + init { + start() + } + + fun start() { + tickerFlow(scope, 5_000) + .onEach { + checkFailures() + }.launchIn(scope) + } + + fun stop() { + scope.cancel() + } + + fun e2eEventDisplayedInTimeline(roomId: String, eventId: String, error: MXCryptoError.ErrorType?) { + scope.launch(Dispatchers.Default) { + if (error != null) { + addDecryptionFailure(DecryptionFailure(roomId = roomId, failedEventId = eventId, error = error)) + } else { + removeFailureForEventId(eventId) + } + } + } + + /** + * 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.removeIf { it.roomId == roomId } + } + } + } + + private fun addDecryptionFailure(failure: DecryptionFailure) { + // de duplicate + synchronized(failures) { + if (failures.indexOfFirst { it.failedEventId == failure.failedEventId } == -1) { + failures.add(failure) + } + } + } + + private fun removeFailureForEventId(eventId: String) { + synchronized(failures) { + failures.removeIf { it.failedEventId == eventId } + } + } + + private fun checkFailures() { + val now = System.currentTimeMillis() + val aggregatedErrors: Map> + synchronized(failures) { + val toReport = mutableListOf() + failures.removeAll { failure -> + (now - failure.timeStamp > GRACE_PERIOD_MILLIS).also { + if (it) { + toReport.add(failure) + } + } + } + + aggregatedErrors = toReport + .groupBy { it.error.toAnalyticsErrorName() } + .mapValues { + it.value.map { it.failedEventId } + } + } + + 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 -> + vectorAnalytics.capture(Error(failedEventId, Error.Domain.E2EE, aggregation.key)) + alreadyReported.add(failedEventId) + } + } + } + + private fun MXCryptoError.ErrorType.toAnalyticsErrorName(): Error.Name { + return when (this) { + MXCryptoError.ErrorType.UNKNOWN_INBOUND_SESSION_ID -> Error.Name.OlmKeysNotSentError + MXCryptoError.ErrorType.OLM -> { + Error.Name.OlmUnspecifiedError + } + MXCryptoError.ErrorType.UNKNOWN_MESSAGE_INDEX -> Error.Name.OlmIndexError + else -> Error.Name.UnknownError + } + } +} diff --git a/vector/src/main/java/im/vector/app/features/home/room/detail/RoomDetailViewModel.kt b/vector/src/main/java/im/vector/app/features/home/room/detail/RoomDetailViewModel.kt index aecc65b25e..583810b915 100644 --- a/vector/src/main/java/im/vector/app/features/home/room/detail/RoomDetailViewModel.kt +++ b/vector/src/main/java/im/vector/app/features/home/room/detail/RoomDetailViewModel.kt @@ -38,6 +38,7 @@ import im.vector.app.core.mvrx.runCatchingToAsync import im.vector.app.core.platform.VectorViewModel import im.vector.app.core.resources.StringProvider import im.vector.app.core.utils.BehaviorDataSource +import im.vector.app.features.analytics.DecryptionFailureTracker import im.vector.app.features.call.conference.ConferenceEvent import im.vector.app.features.call.conference.JitsiActiveConferenceHolder import im.vector.app.features.call.conference.JitsiService @@ -112,6 +113,7 @@ class RoomDetailViewModel @AssistedInject constructor( private val directRoomHelper: DirectRoomHelper, private val jitsiService: JitsiService, private val activeConferenceHolder: JitsiActiveConferenceHolder, + private val decryptionFailureTracker: DecryptionFailureTracker, timelineFactory: TimelineFactory ) : VectorViewModel(initialState), Timeline.Listener, ChatEffectManager.Delegate, CallProtocolsChecker.Listener { @@ -1083,6 +1085,7 @@ class RoomDetailViewModel @AssistedInject constructor( override fun onCleared() { timeline.dispose() timeline.removeAllListeners() + decryptionFailureTracker.onTimeLineDisposed(room.roomId) if (vectorPreferences.sendTypingNotifs()) { room.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 4af3c69aa3..a8c578a58a 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 @@ -19,6 +19,7 @@ package im.vector.app.features.home.room.detail.timeline.factory import im.vector.app.core.epoxy.TimelineEmptyItem import im.vector.app.core.epoxy.TimelineEmptyItem_ import im.vector.app.core.epoxy.VectorEpoxyModel +import im.vector.app.features.analytics.DecryptionFailureTracker import im.vector.app.features.home.room.detail.timeline.helper.TimelineEventVisibilityHelper import org.matrix.android.sdk.api.session.events.model.EventType import org.matrix.android.sdk.api.session.room.timeline.TimelineEvent @@ -34,6 +35,7 @@ class TimelineItemFactory @Inject constructor(private val messageItemFactory: Me private val widgetItemFactory: WidgetItemFactory, private val verificationConclusionItemFactory: VerificationItemFactory, private val callItemFactory: CallItemFactory, + private val decryptionFailureTracker: DecryptionFailureTracker, private val timelineEventVisibilityHelper: TimelineEventVisibilityHelper) { /** @@ -122,6 +124,10 @@ class TimelineItemFactory @Inject constructor(private val messageItemFactory: Me Timber.v("Type ${event.root.getClearType()} not handled") defaultItemFactory.create(params) } + }.also { + if (it != null && event.isEncrypted()) { + decryptionFailureTracker.e2eEventDisplayedInTimeline(event.roomId, event.eventId, event.root.mCryptoError) + } } } } catch (throwable: Throwable) { From b275546a8ac57cf7722c032e55a22225775f0210 Mon Sep 17 00:00:00 2001 From: Valere Date: Wed, 5 Jan 2022 16:42:45 +0100 Subject: [PATCH 2/2] Code review + reduce grace period --- .../algorithms/megolm/MXMegolmDecryption.kt | 4 +-- .../analytics/DecryptionFailureTracker.kt | 27 +++++++++++-------- .../timeline/factory/TimelineItemFactory.kt | 2 +- 3 files changed, 19 insertions(+), 14 deletions(-) diff --git a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/crypto/algorithms/megolm/MXMegolmDecryption.kt b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/crypto/algorithms/megolm/MXMegolmDecryption.kt index 441b501360..ceceedc802 100644 --- a/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/crypto/algorithms/megolm/MXMegolmDecryption.kt +++ b/matrix-sdk-android/src/main/java/org/matrix/android/sdk/internal/crypto/algorithms/megolm/MXMegolmDecryption.kt @@ -136,8 +136,8 @@ internal class MXMegolmDecryption(private val userId: String, throw MXCryptoError.Base( MXCryptoError.ErrorType.UNKNOWN_MESSAGE_INDEX, - throwable.olmException.message ?: "", - throwable.olmException.message) + "UNKNOWN_MESSAGE_INDEX", + null) } val reason = String.format(MXCryptoError.OLM_REASON, throwable.olmException.message) 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 c74a65c8ed..cd98356445 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 @@ -17,6 +17,7 @@ package im.vector.app.features.analytics import im.vector.app.core.flow.tickerFlow +import im.vector.app.core.time.Clock import im.vector.app.features.analytics.plan.Error import kotlinx.coroutines.CoroutineScope import kotlinx.coroutines.Dispatchers @@ -26,17 +27,19 @@ import kotlinx.coroutines.flow.launchIn import kotlinx.coroutines.flow.onEach import kotlinx.coroutines.launch import org.matrix.android.sdk.api.session.crypto.MXCryptoError +import org.matrix.android.sdk.api.session.room.timeline.TimelineEvent import javax.inject.Inject import javax.inject.Singleton -data class DecryptionFailure( - val timeStamp: Long = System.currentTimeMillis(), +private data class DecryptionFailure( + val timeStamp: Long, val roomId: String, val failedEventId: String, val error: MXCryptoError.ErrorType ) -private const val GRACE_PERIOD_MILLIS = 20_000 +private const val GRACE_PERIOD_MILLIS = 4_000 +private const val CHECK_INTERVAL = 2_000L /** * Tracks decryption errors that are visible to the user. @@ -45,7 +48,8 @@ private const val GRACE_PERIOD_MILLIS = 20_000 */ @Singleton class DecryptionFailureTracker @Inject constructor( - private val vectorAnalytics: VectorAnalytics + private val vectorAnalytics: VectorAnalytics, + private val clock: Clock ) { private val scope: CoroutineScope = CoroutineScope(SupervisorJob()) @@ -57,7 +61,7 @@ class DecryptionFailureTracker @Inject constructor( } fun start() { - tickerFlow(scope, 5_000) + tickerFlow(scope, CHECK_INTERVAL) .onEach { checkFailures() }.launchIn(scope) @@ -67,12 +71,13 @@ class DecryptionFailureTracker @Inject constructor( scope.cancel() } - fun e2eEventDisplayedInTimeline(roomId: String, eventId: String, error: MXCryptoError.ErrorType?) { + fun e2eEventDisplayedInTimeline(event: TimelineEvent) { scope.launch(Dispatchers.Default) { - if (error != null) { - addDecryptionFailure(DecryptionFailure(roomId = roomId, failedEventId = eventId, error = error)) + val mCryptoError = event.root.mCryptoError + if (mCryptoError != null) { + addDecryptionFailure(DecryptionFailure(clock.epochMillis(), event.roomId, event.eventId, mCryptoError)) } else { - removeFailureForEventId(eventId) + removeFailureForEventId(event.eventId) } } } @@ -92,7 +97,7 @@ class DecryptionFailureTracker @Inject constructor( private fun addDecryptionFailure(failure: DecryptionFailure) { // de duplicate synchronized(failures) { - if (failures.indexOfFirst { it.failedEventId == failure.failedEventId } == -1) { + if (failures.none { it.failedEventId == failure.failedEventId }) { failures.add(failure) } } @@ -105,7 +110,7 @@ class DecryptionFailureTracker @Inject constructor( } private fun checkFailures() { - val now = System.currentTimeMillis() + val now = clock.epochMillis() val aggregatedErrors: Map> synchronized(failures) { val toReport = mutableListOf() 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 a8c578a58a..dfe1cc1d9b 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 @@ -126,7 +126,7 @@ class TimelineItemFactory @Inject constructor(private val messageItemFactory: Me } }.also { if (it != null && event.isEncrypted()) { - decryptionFailureTracker.e2eEventDisplayedInTimeline(event.roomId, event.eventId, event.root.mCryptoError) + decryptionFailureTracker.e2eEventDisplayedInTimeline(event) } } }