From 86c18fb3ae6bb629b590087bd07f64ae3f8dba79 Mon Sep 17 00:00:00 2001
From: Floris Bruynooghe <flub@devork.be>
Date: Tue, 4 Apr 2023 18:11:45 +0200
Subject: [PATCH] ref: More logging for ongoing and get_backup (#4289)

This adds a few log items for imex::transfer::get_backup and the
ongoing process to give some more insights.

IO is now also paused after the ongoing process is allocated in
get_backup to avoid needlessly pausing IO.
---
 src/context.rs       | 13 +++++++++----
 src/imex/transfer.rs | 10 +++++++---
 2 files changed, 16 insertions(+), 7 deletions(-)

diff --git a/src/context.rs b/src/context.rs
index a9bbd01ad1..cfa026d671 100644
--- a/src/context.rs
+++ b/src/context.rs
@@ -260,7 +260,7 @@ enum RunningState {
     Running { cancel_sender: Sender<()> },
 
     /// Cancel signal has been sent, waiting for ongoing process to be freed.
-    ShallStop,
+    ShallStop { request: Instant },
 
     /// There is no ongoing process, a new one can be allocated.
     Stopped,
@@ -530,6 +530,9 @@ impl Context {
 
     pub(crate) async fn free_ongoing(&self) {
         let mut s = self.running_state.write().await;
+        if let RunningState::ShallStop { request } = *s {
+            info!(self, "Ongoing stopped in {:?}", request.elapsed());
+        }
         *s = RunningState::Stopped;
     }
 
@@ -542,9 +545,11 @@ impl Context {
                     warn!(self, "could not cancel ongoing: {:#}", err);
                 }
                 info!(self, "Signaling the ongoing process to stop ASAP.",);
-                *s = RunningState::ShallStop;
+                *s = RunningState::ShallStop {
+                    request: Instant::now(),
+                };
             }
-            RunningState::ShallStop | RunningState::Stopped => {
+            RunningState::ShallStop { .. } | RunningState::Stopped => {
                 info!(self, "No ongoing process to stop.",);
             }
         }
@@ -554,7 +559,7 @@ impl Context {
     pub(crate) async fn shall_stop_ongoing(&self) -> bool {
         match &*self.running_state.read().await {
             RunningState::Running { .. } => false,
-            RunningState::ShallStop | RunningState::Stopped => true,
+            RunningState::ShallStop { .. } | RunningState::Stopped => true,
         }
     }
 
diff --git a/src/imex/transfer.rs b/src/imex/transfer.rs
index f4d6939228..174e83519c 100644
--- a/src/imex/transfer.rs
+++ b/src/imex/transfer.rs
@@ -50,7 +50,7 @@ use crate::blob::BlobDirContents;
 use crate::chat::{add_device_msg, delete_and_reset_all_device_msgs};
 use crate::context::Context;
 use crate::message::{Message, Viewtype};
-use crate::qr::Qr;
+use crate::qr::{self, Qr};
 use crate::stock_str::backup_transfer_msg_body;
 use crate::{e2ee, EventType};
 
@@ -393,10 +393,14 @@ pub async fn get_backup(context: &Context, qr: Qr) -> Result<()> {
         !context.is_configured().await?,
         "Cannot import backups to accounts in use."
     );
-    let _guard = context.scheduler.pause(context.clone()).await;
-
     // Acquire global "ongoing" mutex.
     let cancel_token = context.alloc_ongoing().await?;
+    let _guard = context.scheduler.pause(context.clone()).await;
+    info!(
+        context,
+        "Running get_backup for {}",
+        qr::format_backup(&qr)?
+    );
     let res = tokio::select! {
         biased;
         res = get_backup_inner(context, qr) => res,