/* Copyright 2018 New Vector Ltd Copyright (c) 2021 BWI GmbH 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 "DecryptionFailureTracker.h" #import "GeneratedInterface-Swift.h" // Call `checkFailures` every `CHECK_INTERVAL` #define CHECK_INTERVAL 2 // bwi: 5265 // Call 'checkDidDecrypt' every 'CHECK_SUCCESS_INTERVAL' #define CHECK_DECRYPTED_EVENT_INTERVAL 10 // Give events a chance to be decrypted by waiting `GRACE_PERIOD` before counting // and reporting them as failures #define GRACE_PERIOD 4 // E2E failures analytics category. NSString *const kDecryptionFailureTrackerAnalyticsCategory = @"e2e.failure"; @interface DecryptionFailureTracker() { // Reported failures // Every `CHECK_INTERVAL`, this list is checked for failures that happened // more than`GRACE_PERIOD` ago. Those that did are reported to the delegate. NSMutableDictionary *reportedFailures; // bwi: 5265 // Reported temporary failures that did decrypt // Every 'CHECK_DECRYPTED_EVENT_INTERVAL', this list is checked for temporary (inbound_session_id only) failures that did decrypt. // Those that did will be aggregated and reported to the delegate. NSMutableDictionary *decryptedEvents; // Reported temporary failures NSMutableDictionary *temporaryFailures; // Event ids of failures that were tracked previously NSMutableSet *trackedEvents; // Timer for periodic check NSTimer *checkFailuresTimer; // bwi: 5265 NSTimer *checkDecryptedEventsTimer; } @end @implementation DecryptionFailureTracker + (instancetype)sharedInstance { static DecryptionFailureTracker *sharedInstance = nil; static dispatch_once_t onceToken; dispatch_once(&onceToken, ^{ sharedInstance = [[DecryptionFailureTracker alloc] init]; }); return sharedInstance; } - (instancetype)init { self = [super init]; if (self) { reportedFailures = [NSMutableDictionary dictionary]; trackedEvents = [NSMutableSet set]; // bwi: 5265 decryptedEvents = [NSMutableDictionary dictionary]; temporaryFailures = [NSMutableDictionary dictionary]; [[NSNotificationCenter defaultCenter] addObserver:self selector:@selector(eventDidDecrypt:) name:kMXEventDidDecryptNotification object:nil]; checkFailuresTimer = [NSTimer scheduledTimerWithTimeInterval:CHECK_INTERVAL target:self selector:@selector(checkFailures) userInfo:nil repeats:YES]; // bwi: 5265 add tracking for decryption duration (only for MXDecryptingErrorUnknownInboundSessionIdCode) checkDecryptedEventsTimer = [NSTimer scheduledTimerWithTimeInterval:CHECK_DECRYPTED_EVENT_INTERVAL target:self selector:@selector(checkDecryptedEvents) userInfo:nil repeats:YES]; } return self; } - (void)reportUnableToDecryptErrorForEvent:(MXEvent *)event withRoomState:(MXRoomState *)roomState myUser:(NSString *)userId roomDeviceCount:(NSInteger)deviceCount { if (reportedFailures[event.eventId] || [trackedEvents containsObject:event.eventId]) { return; } // Filter out "expected" UTDs // We cannot decrypt messages sent before the user joined the room MXRoomMember *myUser = [roomState.members memberWithUserId:userId]; if (!myUser || myUser.membership != MXMembershipJoin) { return; } NSString *failedEventId = event.eventId; DecryptionFailureReason reason; // Categorise the error switch (event.decryptionError.code) { case MXDecryptingErrorUnknownInboundSessionIdCode: reason = DecryptionFailureReasonOlmKeysNotSent; break; case MXDecryptingErrorOlmCode: reason = DecryptionFailureReasonOlmIndexError; break; default: // All other error codes will be tracked as `OlmUnspecifiedError` and will include `context` containing // the actual error code and localized description reason = DecryptionFailureReasonUnspecified; break; } NSString *context = [NSString stringWithFormat:@"code: %ld, description: %@", event.decryptionError.code, event.decryptionError.localizedDescription]; reportedFailures[event.eventId] = [[DecryptionFailure alloc] initWithFailedEventId:failedEventId reason:reason context:context errorCode:event.decryptionError.code deviceCount:deviceCount unspecifiedErrorMessage:event.decryptionError.localizedDescription]; // bwi: 5265 add tracking for decryption duration (only for MXDecryptingErrorUnknownInboundSessionIdCode) if (!temporaryFailures[event.eventId] && event.decryptionError.code == MXDecryptingErrorUnknownInboundSessionIdCode) { temporaryFailures[event.eventId] = [[DecryptionFailure alloc] initWithFailedEventId:failedEventId reason:reason context:context errorCode:event.decryptionError.code deviceCount:deviceCount unspecifiedErrorMessage:event.decryptionError.localizedDescription]; } } - (void)dispatch { [self checkFailures]; [self checkDecryptedEvents]; } #pragma mark - Private methods /** Mark reported failures that occured before tsNow - GRACE_PERIOD as failures that should be tracked. */ - (void)checkFailures { if (!_delegate) { return; } NSTimeInterval tsNow = [NSDate date].timeIntervalSince1970; NSMutableArray *failuresToTrack = [NSMutableArray array]; for (DecryptionFailure *reportedFailure in reportedFailures.allValues) { if (reportedFailure.ts < tsNow - GRACE_PERIOD) { [failuresToTrack addObject:reportedFailure]; [reportedFailures removeObjectForKey:reportedFailure.failedEventId]; [trackedEvents addObject:reportedFailure.failedEventId]; } } if (failuresToTrack.count) { // Sort failures by error reason NSMutableDictionary *failuresCounts = [NSMutableDictionary dictionary]; for (DecryptionFailure *failure in failuresToTrack) { if (failure.reason == DecryptionFailureReasonUnspecified) { [BWIAnalytics.sharedTracker trackE2EEErrorWithDimension:failure.errorCode deviceCount:[[BWIAnalyticsHelper shared] dimensionForDeviceCount: failure.deviceCount] unspecifiedErrorMessage:failure.unspecifiedErrorMessage]; } else { failuresCounts[@(failure.reason)] = @(failuresCounts[@(failure.reason)].unsignedIntegerValue + 1); } } MXLogDebug(@"[DecryptionFailureTracker] trackFailures: %@", failuresCounts); for (NSNumber *reason in failuresCounts) { [BWIAnalytics.sharedTracker trackE2EEErrors:reason.integerValue count:failuresCounts[reason].integerValue]; } } } // bwi: 5265 add tracking for decryption duration (only for MXDecryptingErrorUnknownInboundSessionIdCode) - (void)checkDecryptedEvents { if (!_delegate) { return; } if (decryptedEvents.count > 0) { NSInteger eventsCount = decryptedEvents.count; NSTimeInterval eventMaxTimeToDecrypt = 0; NSTimeInterval eventAvgTimeToDecrypt = 0; for (DecryptedEvent *decryptedEvent in decryptedEvents.allValues) { if (decryptedEvent.decryptedAt > 0 && decryptedEvent.ts > 0) { NSTimeInterval timeToDecrypt = decryptedEvent.decryptedAt - decryptedEvent.ts; if (timeToDecrypt > eventMaxTimeToDecrypt) { eventMaxTimeToDecrypt = timeToDecrypt; } eventAvgTimeToDecrypt += timeToDecrypt; } else { eventsCount = eventsCount - 1; } } eventAvgTimeToDecrypt = eventAvgTimeToDecrypt / eventsCount; [BWIAnalytics.sharedTracker trackE2EEDecryptionTimeWithCount:eventsCount max: (eventMaxTimeToDecrypt) avg: (eventAvgTimeToDecrypt)]; [decryptedEvents removeAllObjects]; } } - (void)eventDidDecrypt:(NSNotification *)notif { // Could be an event in the reportedFailures, remove it MXEvent *event = notif.object; // bwi: 5265 add tracking for decryption duration (only for MXDecryptingErrorUnknownInboundSessionIdCode) if (temporaryFailures[event.eventId]) { NSString *eventId = temporaryFailures[event.eventId].failedEventId; NSTimeInterval ts = temporaryFailures[event.eventId].ts; decryptedEvents[event.eventId] = [[DecryptedEvent alloc] initWithEventId:eventId ts:ts]; [temporaryFailures removeObjectForKey:event.eventId]; } [reportedFailures removeObjectForKey:event.eventId]; } @end