verification: Add more debug log

src/session/verification/identity_verification.rs

@@ -7,8 +7,7 @@ use crate::spawn_tokio;
 use crate::Error;
 use gettextrs::gettext;
 use gtk::{glib, glib::clone, prelude::*, subclass::prelude::*};
-use log::error;
-use log::warn;
+use log::{debug, error, warn};
 use matrix_sdk::{
     encryption::{
         identities::RequestVerificationError,
@@ -915,6 +914,7 @@ impl Context {
 
     async fn start(mut self) -> Result<State, RequestVerificationError> {
         if self.request.we_started() {
+            debug!("Wait for ready state");
             wait![self, self.request.is_ready()];
         } else {
             // Check if it was started by somebody else already
@@ -922,6 +922,7 @@ impl Context {
                 return Ok(State::Passive);
             }
 
+            debug!("Wait for user action accept or cancel");
             // Wait for the user to accept or cancel the request
             wait![self];
 
@@ -966,6 +967,7 @@ impl Context {
             self.send_state(State::QrV1Scan);
 
             // Wait for scanned data
+            debug!("Wait for user to scan a qr-code");
             wait![self];
 
             unreachable!();
@@ -976,6 +978,7 @@ impl Context {
         // FIXME: we should automatically confirm
         request.confirm().await?;
 
+        debug!("Wait for done state");
         wait![self, request.is_done()];
 
         Ok(State::Completed)
@@ -994,6 +997,7 @@ impl Context {
         // FIXME: we should automatically confirm
         request.confirm().await?;
 
+        debug!("Wait for done state");
         wait_without_scanning_sas![self, request.is_done()];
 
         Ok(State::Completed)
@@ -1016,6 +1020,7 @@ impl Context {
     ) -> Result<State, RequestVerificationError> {
         request.accept().await?;
 
+        debug!("Wait for emojis to be ready");
         wait_without_scanning_sas![self, request.can_be_presented()];
 
         let sas_data = if let Some(emoji) = request.emoji() {
@@ -1030,10 +1035,12 @@ impl Context {
         self.send_state(State::SasV1);
 
         // Wait for match user action
+        debug!("Wait for user action match or missmatch");
         wait_without_scanning_sas![self];
 
         request.confirm().await?;
 
+        debug!("Wait for done state");
         wait_without_scanning_sas![self, request.is_done()];
 
         Ok(State::Completed)

src/session/verification/verification_list.rs

@@ -4,7 +4,7 @@ use crate::session::{
     Session,
 };
 use gtk::{gio, glib, glib::clone, prelude::*, subclass::prelude::*};
-use log::warn;
+use log::{debug, warn};
 use matrix_sdk::ruma::{
     api::client::r0::sync::sync_events::ToDevice, events::AnyToDeviceEvent, identifiers::UserId,
 };
@@ -115,6 +115,7 @@ impl VerificationList {
 
     pub fn handle_response_to_device(&self, to_device: ToDevice) {
         for event in to_device.events.iter().filter_map(|e| e.deserialize().ok()) {
+            debug!("Received verification event: {:?}", event);
             let request = match event {
                 AnyToDeviceEvent::KeyVerificationRequest(e) => {
                     let flow_id = FlowId::new(e.sender, e.content.transaction_id);
@@ -125,6 +126,7 @@ impl VerificationList {
                         let user = session.user().unwrap();
                         // ToDevice verifications can only be send by us
                         if &flow_id.user_id != user.user_id() {
+                            warn!("Received a device verification event from a different user, which isn't allowed");
                             continue;
                         }
 
@@ -132,6 +134,7 @@ impl VerificationList {
                         let start_time = if let Some(time) = e.content.timestamp.to_system_time() {
                             if let Ok(duration) = time.elapsed() {
                                 if duration > VERIFICATION_CREATION_TIMEOUT {
+                                    debug!("Received verification event that already timedout");
                                     continue;
                                 }
 
@@ -142,14 +145,15 @@ impl VerificationList {
                                 {
                                     time
                                 } else {
-                                    warn!("Ignor verification request because getting a correct timestamp failed");
+                                    warn!("Ignore verification request because getting a correct timestamp failed");
                                     continue;
                                 }
                             } else {
-                                warn!("Ignoring verification request because it was sent in the future. The system time of the server or the local machine is probably wrong.");
+                                warn!("Ignore verification request because it was sent in the future. The system time of the server or the local machine is probably wrong.");
                                 continue;
                             }
                         } else {
+                            warn!("Ignore verification request because getting a correct timestamp failed");
                             continue;
                         };