DecryptionTracker: Permanent vs Temporary UTD

Riot/Modules/Analytics/Analytics.swift

@@ -215,7 +215,7 @@ import AnalyticsEvents
 
 @objc
 protocol E2EAnalytics {
-    func trackE2EEError(_ reason: DecryptionFailureReason, context: String)
+    func trackE2EEError(_ failure: DecryptionFailure)
 }
 
 
@@ -225,21 +225,8 @@ protocol E2EAnalytics {
     /// - Parameters:
     ///   - reason: The error that occurred.
     ///   - context: Additional context of the error that occured
-    func trackE2EEError(_ reason: DecryptionFailureReason, context: String) {
-        let event = AnalyticsEvent.Error(
-            context: context,
-            cryptoModule: .Rust,
-            cryptoSDK: AnalyticsEvent.Error.CryptoSDK.Rust,
-            domain: .E2EE,
-            // XXX not yet supported.
-            eventLocalAgeMillis: nil,
-            isFederated: nil,
-            isMatrixDotOrg: nil,
-            name: reason.errorName,
-            timeToDecryptMillis: nil,
-            userTrustsOwnIdentity: nil,
-            wasVisibleToUser: nil
-        )
+    func trackE2EEError(_ failure: DecryptionFailure) {
+        let event = failure.toAnalyticsEvent()
         capture(event: event)
     }
     

Riot/Modules/Analytics/DecryptionFailure+Analytics.swift

@@ -0,0 +1,44 @@
+// 
+// Copyright 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.
+//
+
+import Foundation
+import AnalyticsEvents
+
+extension DecryptionFailure {
+    
+    public func toAnalyticsEvent() -> AnalyticsEvent.Error {
+        
+        let timeToDecryptMillis: Int = if self.timeToDecrypt != nil {
+            Int(self.timeToDecrypt! * 1000)
+        } else {
+            -1
+        }
+        return AnalyticsEvent.Error(
+            context: self.context,
+            cryptoModule: .Rust,
+            cryptoSDK: .Rust,
+            domain: .E2EE,
+            
+            eventLocalAgeMillis: nil,
+            isFederated: nil,
+            isMatrixDotOrg: nil,
+            name: self.reason.errorName,
+            timeToDecryptMillis: timeToDecryptMillis,
+            userTrustsOwnIdentity: nil,
+            wasVisibleToUser: nil
+        )
+    }
+}

Riot/Modules/Analytics/DecryptionFailure.swift

@@ -44,6 +44,9 @@ import AnalyticsEvents
     /// Additional context of failure
     let context: String
     
+    /// UTDs can be permanent or temporary. If temporary, this field will contain the time it took to decrypt the message in milliseconds. If permanent should be nil
+    var timeToDecrypt: TimeInterval?
+    
     init(failedEventId: String, reason: DecryptionFailureReason, context: String, ts: TimeInterval) {
         self.failedEventId = failedEventId
         self.reason = reason

Riot/Modules/Analytics/DecryptionFailureTracker.swift

@@ -36,7 +36,10 @@ class DecryptionFailureTracker: NSObject {
     
     let GRACE_PERIOD: TimeInterval = 4
     // Call `checkFailures` every `CHECK_INTERVAL`
-    let CHECK_INTERVAL: TimeInterval = 2
+    let CHECK_INTERVAL: TimeInterval = 15
+    
+    // The maximum time to wait for a late decryption before reporting as permanent UTD
+    let MAX_WAIT_FOR_LATE_DECRYPTION: TimeInterval = 60
     
     @objc weak var delegate: E2EAnalytics?
     
@@ -60,9 +63,6 @@ class DecryptionFailureTracker: NSObject {
                                                name: .mxEventDidDecrypt,
                                                object: nil)
         
-        Timer.scheduledTimer(withTimeInterval: CHECK_INTERVAL, repeats: true) { [weak self] _ in
-            self?.checkFailures()
-        }
     }
     
     @objc
@@ -93,6 +93,14 @@ class DecryptionFailureTracker: NSObject {
         let context = String(format: "code: %ld, description: %@", error.code, event.decryptionError.localizedDescription)
 
         reportedFailures[failedEventId] = DecryptionFailure(failedEventId: failedEventId, reason: reason, context: context, ts: self.timeProvider.nowTs())
+        
+        // Start the ticker if needed. There is no need to have a ticker if no failures are tracked
+        if checkFailuresTimer == nil {
+            self.checkFailuresTimer = Timer.scheduledTimer(withTimeInterval: CHECK_INTERVAL, repeats: true) { [weak self] _ in
+                self?.checkFailures()
+            }
+        }
+        
     }
     
     @objc
@@ -104,8 +112,30 @@ class DecryptionFailureTracker: NSObject {
     func eventDidDecrypt(_ notification: Notification) {
         guard let event = notification.object as? MXEvent else { return }
 
-        // Could be an event in the reportedFailures, remove it
+        guard let reportedFailure = self.reportedFailures[event.eventId] else { return }
+        
+        let now = self.timeProvider.nowTs()
+        let ellapsedTime = now - reportedFailure.ts
+        
+        if ellapsedTime < 4 {
+            // event is graced
+            reportedFailures.removeValue(forKey: event.eventId)
+        } else {
+            // It's a late decrypt must be reported as a late decrypt
+            reportedFailure.timeToDecrypt = ellapsedTime
+            self.delegate?.trackE2EEError(reportedFailure)
+        }
+        // Remove from reported failures
+        self.trackedEvents.insert(event.eventId)
         reportedFailures.removeValue(forKey: event.eventId)
+        
+        // Check if we still need the ticker timer
+        if reportedFailures.isEmpty {
+            // Invalidate the current timer, nothing to check for
+            self.checkFailuresTimer?.invalidate()
+            self.checkFailuresTimer = nil
+        }
+        
     }
     
     /**
@@ -116,23 +146,29 @@ class DecryptionFailureTracker: NSObject {
     func checkFailures() {
         guard let delegate = self.delegate else {return}
         
-        
         let tsNow = self.timeProvider.nowTs()
         var failuresToCheck = [DecryptionFailure]()
         
         for reportedFailure in self.reportedFailures.values {
             let ellapsed = tsNow - reportedFailure.ts
-            if ellapsed > GRACE_PERIOD {
+            if ellapsed > MAX_WAIT_FOR_LATE_DECRYPTION {
                 failuresToCheck.append(reportedFailure)
+                reportedFailure.timeToDecrypt = nil
                 reportedFailures.removeValue(forKey: reportedFailure.failedEventId)
                 trackedEvents.insert(reportedFailure.failedEventId)
             }
         }
         
         for failure in failuresToCheck {
-            delegate.trackE2EEError(failure.reason, context: failure.context)
+            delegate.trackE2EEError(failure)
         }
         
+        // Check if we still need the ticker timer
+        if reportedFailures.isEmpty {
+            // Invalidate the current timer, nothing to check for
+            self.checkFailuresTimer?.invalidate()
+            self.checkFailuresTimer = nil
+        }
     }
     
 }

RiotTests/DecryptionFailureTrackerTests.swift

@@ -32,10 +32,9 @@ class DecryptionFailureTrackerTests: XCTestCase {
     }
     
     class AnalyticsDelegate : E2EAnalytics {
-        var reportedFailure: Element.DecryptionFailureReason?;
+        var reportedFailure: Element.DecryptionFailure?;
         
-        func trackE2EEError(_ reason: Element.DecryptionFailureReason, context: String) {
-            print("Error Tracked: ", reason)
+        func trackE2EEError(_ reason: Element.DecryptionFailure) {
             reportedFailure = reason
         }
         
@@ -66,6 +65,9 @@ class DecryptionFailureTrackerTests: XCTestCase {
        
         timeShifter.timestamp = TimeInterval(2)
         
+        // simulate decrypted in the grace period
+        NotificationCenter.default.post(name: .mxEventDidDecrypt, object: fakeEvent)
+        
         decryptionFailureTracker.checkFailures();
         
         XCTAssertNil(testDelegate.reportedFailure);
@@ -74,10 +76,70 @@ class DecryptionFailureTrackerTests: XCTestCase {
         timeShifter.timestamp = TimeInterval(5)
         
         decryptionFailureTracker.checkFailures();
+        XCTAssertNil(testDelegate.reportedFailure);
         
-        XCTAssertEqual(testDelegate.reportedFailure, DecryptionFailureReason.olmKeysNotSent);
     }
     
+    func test_report_ratcheted_key_utd() {
+        
+        let myUser = "test@example.com";
+        
+        let decryptionFailureTracker = DecryptionFailureTracker();
+        decryptionFailureTracker.timeProvider = timeShifter;
+        
+        let testDelegate = AnalyticsDelegate();
+        
+        decryptionFailureTracker.delegate = testDelegate;
+        
+        timeShifter.timestamp = TimeInterval(0)
+        
+        let fakeEvent = FakeEvent(id: "$0000");
+        fakeEvent.decryptionError = NSError(domain: MXDecryptingErrorDomain, code: Int(MXDecryptingErrorOlmCode.rawValue))
+        
+        
+        let fakeRoomState = FakeRoomState();
+        fakeRoomState.mockMembers = FakeRoomMembers(joined: [myUser])
+        decryptionFailureTracker.reportUnableToDecryptError(forEvent: fakeEvent, withRoomState: fakeRoomState, myUser: myUser);
+        
+        // Pass the max period
+        timeShifter.timestamp = TimeInterval(70)
+        
+        decryptionFailureTracker.checkFailures();
+        
+        XCTAssertEqual(testDelegate.reportedFailure?.reason, DecryptionFailureReason.olmIndexError);
+    }
+    
+    func test_report_unspecified_error() {
+        
+        let myUser = "test@example.com";
+        
+        let decryptionFailureTracker = DecryptionFailureTracker();
+        decryptionFailureTracker.timeProvider = timeShifter;
+        
+        let testDelegate = AnalyticsDelegate();
+        
+        decryptionFailureTracker.delegate = testDelegate;
+        
+        timeShifter.timestamp = TimeInterval(0)
+        
+        let fakeEvent = FakeEvent(id: "$0000");
+        fakeEvent.decryptionError = NSError(domain: MXDecryptingErrorDomain, code: Int(MXDecryptingErrorBadRoomCode.rawValue))
+        
+        
+        let fakeRoomState = FakeRoomState();
+        fakeRoomState.mockMembers = FakeRoomMembers(joined: [myUser])
+        decryptionFailureTracker.reportUnableToDecryptError(forEvent: fakeEvent, withRoomState: fakeRoomState, myUser: myUser);
+        
+        // Pass the max period
+        timeShifter.timestamp = TimeInterval(70)
+        
+        decryptionFailureTracker.checkFailures();
+        
+        XCTAssertEqual(testDelegate.reportedFailure?.reason, DecryptionFailureReason.unspecified);
+    }
+    
+    
+    
     func test_do_not_double_report() {
         
         let myUser = "test@example.com";
@@ -100,12 +162,12 @@ class DecryptionFailureTrackerTests: XCTestCase {
         
         decryptionFailureTracker.reportUnableToDecryptError(forEvent: fakeEvent, withRoomState: fakeRoomState, myUser: myUser);
         
-        // Pass the grace period
-        timeShifter.timestamp = TimeInterval(5)
+        // Pass the max period
+        timeShifter.timestamp = TimeInterval(70)
         
         decryptionFailureTracker.checkFailures();
         
-        XCTAssertEqual(testDelegate.reportedFailure, DecryptionFailureReason.olmKeysNotSent);
+        XCTAssertEqual(testDelegate.reportedFailure?.reason, DecryptionFailureReason.olmKeysNotSent);
         
         // Try to report again the same event
         testDelegate.reportedFailure = nil
@@ -192,5 +254,77 @@ class DecryptionFailureTrackerTests: XCTestCase {
         XCTAssertNil(testDelegate.reportedFailure);
     }
     
+    
+    func test_should_report_late_decrypt() {
+        
+        let myUser = "test@example.com";
+        
+        let decryptionFailureTracker = DecryptionFailureTracker();
+        decryptionFailureTracker.timeProvider = timeShifter;
+        
+        let testDelegate = AnalyticsDelegate();
+        
+        decryptionFailureTracker.delegate = testDelegate;
+        
+        timeShifter.timestamp = TimeInterval(0)
+        
+        let fakeEvent = FakeEvent(id: "$0000");
+        fakeEvent.decryptionError = NSError(domain: MXDecryptingErrorDomain, code: Int(MXDecryptingErrorUnknownInboundSessionIdCode.rawValue))
+        
+        
+        let fakeRoomState = FakeRoomState();
+        fakeRoomState.mockMembers = FakeRoomMembers(joined: [myUser])
+        
+        decryptionFailureTracker.reportUnableToDecryptError(forEvent: fakeEvent, withRoomState: fakeRoomState, myUser: myUser);
+        
+        // Simulate succesful decryption after grace period but before max wait
+        timeShifter.timestamp = TimeInterval(20)
+        
+        // Simulate event gets decrypted
+        NotificationCenter.default.post(name: .mxEventDidDecrypt, object: fakeEvent)
+        
+        
+        decryptionFailureTracker.checkFailures();
+      
+        // Event should have been reported as a late decrypt
+        XCTAssertEqual(testDelegate.reportedFailure?.reason, DecryptionFailureReason.olmKeysNotSent);
+        XCTAssertEqual(testDelegate.reportedFailure?.timeToDecrypt, TimeInterval(20));
+        
+    }
+    
+    
+    
+    func test_should_report_permanent_decryption_error() {
+        
+        let myUser = "test@example.com";
+        
+        let decryptionFailureTracker = DecryptionFailureTracker();
+        decryptionFailureTracker.timeProvider = timeShifter;
+        
+        let testDelegate = AnalyticsDelegate();
+        
+        decryptionFailureTracker.delegate = testDelegate;
+        
+        timeShifter.timestamp = TimeInterval(0)
+        
+        let fakeEvent = FakeEvent(id: "$0000");
+        fakeEvent.decryptionError = NSError(domain: MXDecryptingErrorDomain, code: Int(MXDecryptingErrorUnknownInboundSessionIdCode.rawValue))
+        
+        
+        let fakeRoomState = FakeRoomState();
+        fakeRoomState.mockMembers = FakeRoomMembers(joined: [myUser])
+        
+        decryptionFailureTracker.reportUnableToDecryptError(forEvent: fakeEvent, withRoomState: fakeRoomState, myUser: myUser);
+        
+        // Simulate succesful decryption after max wait
+        timeShifter.timestamp = TimeInterval(70)
+        
+        decryptionFailureTracker.checkFailures();
+      
+        // Event should have been reported as a late decrypt
+        XCTAssertEqual(testDelegate.reportedFailure?.reason, DecryptionFailureReason.olmKeysNotSent);
+        XCTAssertNil(testDelegate.reportedFailure?.timeToDecrypt);
+        
+    }
 }