Add more logs when encrypting messages

MatrixSDK/Data/MXRoom.m

@@ -548,6 +548,8 @@ - (MXHTTPOperation*)sendEventOfType:(MXEventTypeString)eventTypeString
                             success:(void (^)(NSString *eventId))success
                             failure:(void (^)(NSError *error))failure
 {
+
+    MXLogDebug(@"[MXRoom] sendEventOfType: %@ in room %@", eventTypeString, self.roomId);
 
     __block MXRoomOperation *roomOperation;
 
@@ -611,16 +613,15 @@ - (MXHTTPOperation*)sendEventOfType:(MXEventTypeString)eventTypeString
         [self handleNextOperationAfter:roomOperation];
     };
 
-    [self checkEncryptionState];
-
-    // Check whether the content must be encrypted before sending
-    if (mxSession.crypto
-        && self.summary.isEncrypted
-        && [self isEncryptionRequiredForEventType:eventTypeString])
+    if ([self shouldEncryptEventOfType:eventTypeString])
     {
+        MXLogDebug(@"[MXRoom] sendEventOfType(MXCrypto): Processing as encrypted event");
+
         // Check whether the provided content is already encrypted
         if ([eventTypeString isEqualToString:kMXEventTypeStringRoomEncrypted])
         {
+            MXLogDebug(@"[MXRoom] sendEventOfType(MXCrypto): Event already encrypted");
+
             // We handle here the case where we have to resent an encrypted message event.
             if (event)
             {
@@ -763,6 +764,8 @@ - (MXHTTPOperation*)sendEventOfType:(MXEventTypeString)eventTypeString
     }
     else
     {
+        MXLogDebug(@"[MXRoom] sendEventOfType: Processing as unencrypted event");
+
         // Check whether a local echo is required
         if ([eventTypeString isEqualToString:kMXEventTypeStringRoomMessage]
             || [eventTypeString isEqualToString:kMXEventTypeStringSticker])
@@ -1006,7 +1009,7 @@ - (MXHTTPOperation*)sendImage:(NSData*)imageData
 {
     __block MXRoomOperation *roomOperation;
 
-    [self checkEncryptionState];
+    [self validateEncryptionStateConsistency];
 
     double endRange = 1.0;
 
@@ -1271,7 +1274,7 @@ - (MXHTTPOperation*)sendVideoAsset:(AVAsset*)videoAsset
     NSData *videoThumbnailData = [newRep representationUsingType:NSJPEGFileType properties: @{NSImageCompressionFactor: @0.8}];
 #endif
 
-    [self checkEncryptionState];
+    [self validateEncryptionStateConsistency];
 
     // Use the uploader id as fake URL for this image data
     // The URL does not need to be valid as the MediaManager will get the data
@@ -1622,7 +1625,7 @@ - (MXHTTPOperation*)_sendFile:(NSURL*)fileLocalURL
 {
     __block MXRoomOperation *roomOperation;
 
-    [self checkEncryptionState];
+    [self validateEncryptionStateConsistency];
 
     NSData *fileData = [NSData dataWithContentsOfFile:fileLocalURL.path];
 
@@ -3634,15 +3637,67 @@ - (BOOL)isEncryptionRequiredForEventType:(MXEventTypeString)eventType
  This method ensures that the MXCryptoStore and the MXStore are aligned. If the bug happens, it should be autofixed
  by this code.
  */
-- (void)checkEncryptionState
+- (void)validateEncryptionStateConsistency
 {
-    if ([mxSession.crypto isRoomEncrypted:self.roomId]
-            && !self.summary.isEncrypted)
+    MXCrypto *crypto = mxSession.crypto;
+    if (!crypto)
+    {
+#ifdef MX_CRYPTO
+        MXLogFailure(@"[MXRoom] checkEncryptionState: Crypto module is not present");
+#endif
+        return;
+    }
+
+    BOOL isEncryptedInStore = [crypto isRoomEncrypted:self.roomId];
+    if (isEncryptedInStore && !self.summary.isEncrypted)
     {
         MXLogError(@"[MXRoom] checkEncryptionState: summary.isEncrypted is wrong for room %@. Fix it.", self.roomId);
         self.summary.isEncrypted = YES;
         [self.summary save:YES];
     }
+    else if (!isEncryptedInStore)
+    {
+        if (self.summary.isEncrypted)
+        {
+            MXLogFailure(@"[MXRoom] checkEncryptionState: Crypto and state store do not match");
+        }
+        else
+        {
+            MXLogDebug(@"[MXRoom] checkEncryptionState: Room is not encrypted");
+        }
+    }
+}
+
+/**
+ Check whether the content must be encrypted before sending
+ */
+- (BOOL)shouldEncryptEventOfType:(MXEventTypeString)eventTypeString
+{
+    // Ensures that state between summary and crypto store is consistent,
+    // otherwise log an error
+    [self validateEncryptionStateConsistency];
+
+    if (!mxSession.crypto)
+    {
+#ifdef MX_CRYPTO
+        MXLogError(@"[MXRoom] shouldEncryptEventOfType: Not encrypting, crypto module not present");
+#endif
+        return NO;
+    }
+
+    if (!self.summary.isEncrypted)
+    {
+        MXLogDebug(@"[MXRoom] shouldEncryptEventOfType: Not encrypting, room not encrypted");
+        return NO;
+    }
+
+    if (![self isEncryptionRequiredForEventType:eventTypeString])
+    {
+        MXLogDebug(@"[MXRoom] shouldEncryptEventOfType: Not encrypting, %@ does not require encryption", eventTypeString);
+        return NO;
+    }
+
+    return YES;
 }
 
 - (void)membersTrustLevelSummaryWithForceDownload:(BOOL)forceDownload success:(void (^)(MXUsersTrustLevelSummary *usersTrustLevelSummary))success failure:(void (^)(NSError *error))failure

MatrixSDKTests/MXCryptoTests.m

@@ -448,6 +448,140 @@ - (void)testAliceInACryptedRoom
     }];
 }
 
+// Test various scenarios in which encryption of a room is disabled, incl:
+// - event is not a message, but a reaction
+// - crypto module is not present
+// - room encryption is not set but is fixed
+// - room encryption is not set in neither crypto nor summary store
+- (void)testAliceInACryptedRoomWithoutEncryption
+{
+    [matrixSDKTestsE2EData doE2ETestWithAliceInARoom:self
+                                         readyToTest:^(MXSession *session, NSString *roomId, XCTestExpectation *expectation)
+     {
+        // Prepare room and event to be sent
+        MXCrypto *crypto = session.crypto;
+        MXRoom *room = [session roomWithRoomId:roomId];
+        NSString *message = @"Hello myself!";
+        NSDictionary *content = @{
+            kMXMessageTypeKey: kMXMessageTypeText,
+            kMXMessageBodyKey: message
+        };
+
+        void (^failureBlock)(NSError *) = ^(NSError *error)
+        {
+            XCTFail("Test failure - %@", error);
+            [expectation fulfill];
+        };
+
+        // A few helper methods that enable or disable aspects of state which is usually
+        // not mutable in production code, but could happen as a result of data race,
+        // or memory / state corruption
+        void (^enableCryptoModule)(BOOL) = ^(BOOL isCryptoEnabled){
+            [session setValue:isCryptoEnabled ? crypto : nil forKey:@"crypto"];
+        };
+
+        void (^enableRoomAlgorithm)(BOOL) = ^(BOOL isAlgorithmEnabled){
+            [crypto.store storeAlgorithmForRoom:roomId algorithm:isAlgorithmEnabled ? @"abc" : nil];
+        };
+
+        void (^enableSummaryEncryption)(BOOL) = ^(BOOL isSummaryEncrypted){
+            [room.summary setValue:@(isSummaryEncrypted) forKey:@"_isEncrypted"];
+        };
+
+        // Room is encrypted by default
+        XCTAssertTrue(room.summary.isEncrypted);
+
+        // 1. Send the first event as message
+        [self sendEventOfType:kMXEventTypeStringRoomMessage
+                      content:content
+                         room:room
+                      success:^(MXEvent *event) {
+
+            // At this point we expect the message to be properly encrypted
+            XCTAssertEqual(event.wireEventType, MXEventTypeRoomEncrypted);
+            XCTAssertEqual(0, [self checkEncryptedEvent:event roomId:roomId clearMessage:message senderSession:session]);
+
+            // 2. Send an event of reaction type, which does not require encryption
+            [self sendEventOfType:kMXEventTypeStringReaction
+                          content:content
+                             room:room
+                          success:^(MXEvent *event) {
+
+                // Event is indeed not encrypted
+                XCTAssertTrue(room.summary.isEncrypted);
+                XCTAssertNotEqual(event.wireEventType, MXEventTypeRoomEncrypted);
+
+                // 3. Send the third message whilst simulating the loss of crypto module
+                // (e.g. some corruption or memory deallocation)
+                enableCryptoModule(NO);
+                [self sendEventOfType:kMXEventTypeStringRoomMessage
+                              content:content
+                                 room:room
+                              success:^(MXEvent *event) {
+
+                    // Event is not encrypted, even though it should be (error logs will be printed)
+                    XCTAssertTrue(room.summary.isEncrypted);
+                    XCTAssertNotEqual(event.wireEventType, MXEventTypeRoomEncrypted);
+
+                    // 4. Re-enable crypto module but erase the encryption for the room (both in crypto store and summary).
+                    // This is not possible in production code, but simulates data corruption or memory less
+                    enableCryptoModule(YES);
+                    enableRoomAlgorithm(NO);
+                    enableSummaryEncryption(NO);
+                    [self sendEventOfType:kMXEventTypeStringRoomMessage
+                                  content:content
+                                     room:room
+                                  success:^(MXEvent *event) {
+
+                        // Event indeed not encrypted
+                        XCTAssertFalse(room.summary.isEncrypted);
+                        XCTAssertNotEqual(event.wireEventType, MXEventTypeRoomEncrypted);
+
+                        // 5. This time we store an algoritm in crypto store but keep summary as not encrypted. We expect
+                        // the state of the summary to be restored and for the event to be encrypted again
+                        enableRoomAlgorithm(YES);
+                        enableSummaryEncryption(NO);
+                        [self sendEventOfType:kMXEventTypeStringRoomMessage
+                                      content:content
+                                         room:room
+                                      success:^(MXEvent *event) {
+
+                            // The system detects that there is an inconsistency between crypto and summary store,
+                            // and restores the encryption
+                            XCTAssertTrue(room.summary.isEncrypted);
+                            XCTAssertEqual(event.wireEventType, MXEventTypeRoomEncrypted);
+                            XCTAssertEqual(0, [self checkEncryptedEvent:event roomId:roomId clearMessage:message senderSession:session]);
+                            [expectation fulfill];
+
+                        } failure:failureBlock];
+                    } failure:failureBlock];
+                } failure:failureBlock];
+            } failure:failureBlock];
+        } failure:failureBlock];
+    }];
+}
+
+- (void)sendEventOfType:(MXEventTypeString)eventTypeString
+                content:(NSDictionary *)content
+                   room:(MXRoom *)room
+                success:(void(^)(MXEvent *))success
+                failure:(void(^)(NSError *error))failure
+{
+    __block id listener = [room listenToEventsOfTypes:@[eventTypeString]
+                                              onEvent:^(MXEvent * _Nonnull event, MXTimelineDirection direction, MXRoomState * _Nullable roomState)
+    {
+        [room removeListener:listener];
+        success(event);
+    }];
+
+    [room sendEventOfType:eventTypeString
+                  content:content
+                 threadId:nil
+                localEcho:nil
+                  success:nil
+                  failure:failure];
+}
+
 - (void)testAliceInACryptedRoomAfterInitialSync
 {
     [matrixSDKTestsE2EData doE2ETestWithAliceInARoom:self readyToTest:^(MXSession *aliceSession, NSString *roomId, XCTestExpectation *expectation) {

changelog.d/pr-1476.misc

@@ -0,0 +1 @@
+Crypto: Add more logs when encrypting messages