crypto: Store newly created Olm sessions immediately

This fixes a bug where we would try to create a new Olm session, even if
we already created one, because we didn't yet add the new one to the
store.

This would be triggered every time two or more Olm pre-key messages
arrive that don't yet have an Olm session. This leads to decryption
failures for every message that arrived in the same sync after the
first one which created the new Olm session.

matrix_sdk_crypto/src/olm/account.rs

@@ -116,13 +116,17 @@ impl Account {
         &self,
         event: &ToDeviceEvent<EncryptedToDeviceEventContent>,
     ) -> OlmResult<OlmDecryptionInfo> {
-        debug!("Decrypting to-device event");
+        debug!(sender = event.sender.as_str(), "Decrypting a to-device event");
 
         let content = if let EncryptedEventScheme::OlmV1Curve25519AesSha2(c) = &event.content.scheme
         {
             c
         } else {
-            warn!("Error, unsupported encryption algorithm");
+            warn!(
+                sender = event.sender.as_str(),
+                algorithm =? event.content.scheme,
+                "Error, unsupported encryption algorithm"
+            );
             return Err(EventError::UnsupportedAlgorithm.into());
         };
 
@@ -156,6 +160,10 @@ impl Account {
                     Ok(d) => d,
                     Err(OlmError::SessionWedged(user_id, sender_key)) => {
                         if self.store.is_message_known(&message_hash).await? {
+                            warn!(
+                                sender = event.sender.as_str(),
+                                "An Olm message got replayed, decryption failed"
+                            );
                             return Err(OlmError::ReplayedMessage(user_id, sender_key));
                         } else {
                             return Err(OlmError::SessionWedged(user_id, sender_key));
@@ -164,8 +172,6 @@ impl Account {
                     Err(e) => return Err(e),
                 };
 
-            debug!("Decrypted a to-device event {:?}", event);
-
             Ok(OlmDecryptionInfo {
                 session,
                 message_hash,
@@ -176,7 +182,10 @@ impl Account {
                 inbound_group_session: None,
             })
         } else {
-            warn!("Olm event doesn't contain a ciphertext for our key");
+            warn!(
+                sender = event.sender.as_str(),
+                "Olm event doesn't contain a ciphertext for our key"
+            );
             Err(EventError::MissingCiphertext.into())
         }
     }
@@ -264,9 +273,10 @@ impl Account {
                     // likely wedged and needs to be rotated.
                     if matches {
                         warn!(
-                            "Found a matching Olm session yet decryption failed
+                            sender = sender.as_str(),
-                              for sender {} and sender_key {} {:?}",
+                            sender_key = sender_key,
-                            sender, sender_key, e
+                            error =? e,
+                            "Found a matching Olm session yet decryption failed",
                         );
                         return Err(OlmError::SessionWedged(
                             sender.to_owned(),
@@ -302,9 +312,10 @@ impl Account {
                 // return with an error if it isn't one.
                 OlmMessage::Message(_) => {
                     warn!(
+                        sender = sender.as_str(),
+                        sender_key = sender_key,
                         "Failed to decrypt a non-pre-key message with all \
-                          available sessions {} {}",
+                        available sessions",
-                        sender, sender_key
                     );
                     return Err(OlmError::SessionWedged(sender.to_owned(), sender_key.to_owned()));
                 }
@@ -316,9 +327,11 @@ impl Account {
                             Ok(s) => s,
                             Err(e) => {
                                 warn!(
-                                    "Failed to create a new Olm session for {} {}
+                                    sender = sender.as_str(),
-                                      from a prekey message: {}",
+                                    sender_key = sender_key,
-                                    sender, sender_key, e
+                                    error =? e,
+                                    "Failed to create a new Olm session from a \
+                                    prekey message",
                                 );
                                 return Err(OlmError::SessionWedged(
                                     sender.to_owned(),
@@ -334,10 +347,26 @@ impl Account {
             // Decrypt our message, this shouldn't fail since we're using a
             // newly created Session.
             let plaintext = session.decrypt(message).await?;
+
+            // We need to add the new session to the session cache, otherwise
+            // we might try to create the same session again.
+            // TODO separate the session cache from the storage so we only add
+            // it to the cache but don't store it.
+            let changes = Changes {
+                account: Some(self.inner.clone()),
+                sessions: vec![session.clone()],
+                ..Default::default()
+            };
+            self.store.save_changes(changes).await?;
+
             (SessionType::New(session), plaintext)
         };
 
-        trace!("Successfully decrypted an Olm message: {}", plaintext);
+        trace!(
+            sender = sender.as_str(),
+            sender_key = sender_key,
+            "Successfully decrypted an Olm message"
+        );
 
         let (event, signing_key) = match self.parse_decrypted_to_device_event(sender, &plaintext) {
             Ok(r) => r,