[RFC PATCH proxmox-backup 6/6] fix #7024: cli: add option to enable verbose logs

[Shan Shaji <s.shaji@proxmox.com>]

earlier, there was no option to enable verbose logging inside the CLI.
By default only info level logs were only logged.

To get more information, users had to enable debug logs by setting the
PBS_LOG environment variable, but that was too much information. To fix
this, accept a verbose option and log only necessary information in info
level when the flag is set as true.

Signed-off-by: Shan Shaji <s.shaji@proxmox.com>
---
 pbs-client/src/backup_writer.rs               | 38 +++++++++++++------
 pbs-client/src/pxar/create.rs                 | 30 +++++++++++++--
 pbs-client/src/pxar/tools.rs                  | 10 ++++-
 proxmox-backup-client/src/main.rs             | 11 ++++++
 .../src/proxmox_restore_daemon/api.rs         |  1 +
 pxar-bin/src/main.rs                          |  1 +
 6 files changed, 74 insertions(+), 17 deletions(-)

diff --git a/pbs-client/src/backup_writer.rs b/pbs-client/src/backup_writer.rs
index 68379f725..15a9bccde 100644
--- a/pbs-client/src/backup_writer.rs
+++ b/pbs-client/src/backup_writer.rs
@@ -29,6 +29,7 @@ use proxmox_log::{Level, debug, enabled, info, trace, warn};
 use proxmox_time::TimeSpan;
 
 use crate::pxar::PxarArchiverProgressStats;
+use crate::pxar::tools::log_message;
 
 use super::backup_stats::{BackupStats, UploadProgress, UploadStats};
 use super::inject_reused_chunks::{InjectChunks, InjectReusedChunks, InjectedChunksInfo};
@@ -56,6 +57,7 @@ pub struct UploadOptions {
     pub encrypt: bool,
     pub index_type: IndexType,
     pub is_metadata_mode: bool,
+    pub verbose: bool,
 }
 
 /// Index type for upload options.
@@ -525,20 +527,32 @@ impl BackupWriter {
                 archive, reused, reused_percent
             );
         }
-        if enabled!(Level::DEBUG) && upload_stats.chunk_count > 0 {
-            debug!(
-                "{}: Reused {} from {} chunks.",
-                archive, upload_stats.chunk_reused, upload_stats.chunk_count
+
+        if (options.verbose || enabled!(Level::DEBUG)) && upload_stats.chunk_count > 0 {
+            log_message(
+                &format!(
+                    "{}: Reused {} from {} chunks.",
+                    archive, upload_stats.chunk_reused, upload_stats.chunk_count
+                ),
+                options.verbose,
             );
-            debug!(
-                "{}: Average chunk size was {}.",
-                archive,
-                HumanByte::from(upload_stats.size / upload_stats.chunk_count)
+
+            log_message(
+                &format!(
+                    "{}: Average chunk size was {}.",
+                    archive,
+                    HumanByte::from(upload_stats.size / upload_stats.chunk_count)
+                ),
+                options.verbose,
             );
-            debug!(
-                "{}: Average time per request: {} microseconds.",
-                archive,
-                (upload_stats.duration.as_micros()) / (upload_stats.chunk_count as u128)
+
+            log_message(
+                &format!(
+                    "{}: Average time per request: {} microseconds.",
+                    archive,
+                    (upload_stats.duration.as_micros()) / (upload_stats.chunk_count as u128)
+                ),
+                options.verbose,
             );
         }
 
diff --git a/pbs-client/src/pxar/create.rs b/pbs-client/src/pxar/create.rs
index 2d2dfbb3f..85f03d662 100644
--- a/pbs-client/src/pxar/create.rs
+++ b/pbs-client/src/pxar/create.rs
@@ -39,7 +39,7 @@ use crate::inject_reused_chunks::InjectChunks;
 use crate::pxar::Flags;
 use crate::pxar::look_ahead_cache::{CacheEntry, CacheEntryData, PxarLookaheadCache};
 use crate::pxar::metadata::errno_is_unsupported;
-use crate::pxar::tools::assert_single_path_component;
+use crate::pxar::tools::{assert_single_path_component, log_message};
 
 const CHUNK_PADDING_THRESHOLD: f64 = 0.1;
 
@@ -60,6 +60,8 @@ pub struct PxarCreateOptions {
     pub previous_ref: Option<PxarPrevRef>,
     /// Maximum number of lookahead cache entries
     pub max_cache_size: Option<usize>,
+    /// Enable verbose loging
+    pub verbose: bool,
 }
 
 pub type MetadataArchiveReader = Arc<dyn ReadAt + Send + Sync + 'static>;
@@ -225,6 +227,7 @@ struct Archiver {
     last_reusable_offset: Option<u64>,
     progress_stats: Arc<PxarArchiverProgressStats>,
     split_archive: bool,
+    verbose: bool,
 }
 
 type Encoder<'a, T> = pxar::encoder::aio::Encoder<'a, T>;
@@ -337,6 +340,7 @@ where
         last_reusable_offset: None,
         progress_stats: archiver_progress_stats.unwrap_or_default(),
         split_archive,
+        verbose: options.verbose,
     };
 
     archiver
@@ -511,18 +515,35 @@ impl Archiver {
                         }
                         let range =
                             *offset..*offset + size + size_of::<pxar::format::Header>() as u64;
+
+                        if self.verbose {
+                            info!("reusable: {file_name:?}");
+                        }
+
                         debug!(
                             "reusable: {file_name:?} at range {range:?} has unchanged metadata."
                         );
                         return Ok(Some(range));
                     }
-                    debug!("re-encode: {file_name:?} not a regular file.");
+
+                    log_message(
+                        &format!("re-encode: {file_name:?} not a regular file."),
+                        self.verbose,
+                    );
                     return Ok(None);
                 }
-                debug!("re-encode: {file_name:?} metadata did not match.");
+
+                log_message(
+                    &format!("re-encode: {file_name:?} metadata did not match."),
+                    self.verbose,
+                );
                 return Ok(None);
             }
-            debug!("re-encode: {file_name:?} not found in previous archive.");
+
+            log_message(
+                &format!("re-encode: {file_name:?} not found in previous archive."),
+                self.verbose,
+            );
         }
 
         Ok(None)
@@ -2136,6 +2157,7 @@ mod tests {
                 last_reusable_offset: None,
                 progress_stats: Arc::new(PxarArchiverProgressStats::default()),
                 split_archive: true,
+                verbose: false,
             };
 
             let accessor = Accessor::new(pxar::PxarVariant::Unified(reader), metadata_size)
diff --git a/pbs-client/src/pxar/tools.rs b/pbs-client/src/pxar/tools.rs
index 0c8c2927e..67d6a740b 100644
--- a/pbs-client/src/pxar/tools.rs
+++ b/pbs-client/src/pxar/tools.rs
@@ -21,7 +21,7 @@ use pbs_datastore::BackupManifest;
 use pbs_datastore::dynamic_index::{BufferedDynamicReader, LocalDynamicReadAt};
 use pbs_datastore::index::IndexFile;
 use pbs_tools::crypt_config::CryptConfig;
-use proxmox_log::{debug, info};
+use proxmox_log::{Level, debug, enabled, info};
 
 use crate::{BackupReader, RemoteChunkReader};
 
@@ -485,3 +485,11 @@ pub async fn pxar_metadata_catalog_find<'future, T: Clone + Send + Sync + ReadAt
     }
     Ok(())
 }
+
+pub(crate) fn log_message(msg: &str, verbose: bool) {
+    if verbose && !enabled!(Level::DEBUG) {
+        info!("{msg}");
+    } else {
+        debug!("{msg}");
+    }
+}
diff --git a/proxmox-backup-client/src/main.rs b/proxmox-backup-client/src/main.rs
index 1036ec7e9..52bdbe798 100644
--- a/proxmox-backup-client/src/main.rs
+++ b/proxmox-backup-client/src/main.rs
@@ -805,6 +805,12 @@ fn spawn_catalog_upload(
                 optional: true,
                 default: false,
             },
+            "verbose": {
+                type: Boolean,
+                description: "Enable verbose logs.",
+                optional: true,
+                default: false,
+            }
         }
     }
  )]
@@ -848,6 +854,8 @@ async fn create_backup(
 
     let include_dev = param["include-dev"].as_array();
 
+    let verbose = param["verbose"].as_bool().unwrap_or_default();
+
     let entries_max = param["entries-max"]
         .as_u64()
         .unwrap_or(pbs_client::pxar::ENCODER_MAX_ENTRIES as u64);
@@ -1245,6 +1253,7 @@ async fn create_backup(
                     skip_e2big_xattr,
                     previous_ref,
                     max_cache_size,
+                    verbose: verbose,
                 };
 
                 let upload_options = UploadOptions {
@@ -1252,6 +1261,7 @@ async fn create_backup(
                     compress: true,
                     encrypt: crypto.mode == CryptMode::Encrypt,
                     is_metadata_mode: detection_mode.is_metadata(),
+                    verbose,
                     ..UploadOptions::default()
                 };
 
@@ -1292,6 +1302,7 @@ async fn create_backup(
                     compress: true,
                     encrypt: crypto.mode == CryptMode::Encrypt,
                     is_metadata_mode: false,
+                    verbose,
                 };
 
                 let stats =
diff --git a/proxmox-restore-daemon/src/proxmox_restore_daemon/api.rs b/proxmox-restore-daemon/src/proxmox_restore_daemon/api.rs
index b7f4fd141..e890681fc 100644
--- a/proxmox-restore-daemon/src/proxmox_restore_daemon/api.rs
+++ b/proxmox-restore-daemon/src/proxmox_restore_daemon/api.rs
@@ -364,6 +364,7 @@ fn extract(
                         skip_e2big_xattr: false,
                         previous_ref: None,
                         max_cache_size: None,
+                        verbose: false
                     };
 
                     let pxar_writer = pxar::PxarVariant::Unified(TokioWriter::new(writer));
diff --git a/pxar-bin/src/main.rs b/pxar-bin/src/main.rs
index 953c6e756..385f54a0d 100644
--- a/pxar-bin/src/main.rs
+++ b/pxar-bin/src/main.rs
@@ -383,6 +383,7 @@ async fn create_archive(
         skip_e2big_xattr: false,
         previous_ref: None,
         max_cache_size: None,
+        verbose: false,
     };
 
     let source = PathBuf::from(source);
-- 
2.47.3