[pbs-devel] [PATCH proxmox-backup v3 02/10] pbs-client: replace print with log macro

[Hannes Laimer <h.laimer@proxmox.com>]

Signed-off-by: Hannes Laimer <h.laimer@proxmox.com>
---
 pbs-client/Cargo.toml                |   1 +
 pbs-client/src/backup_writer.rs      | 103 +++++++++++----------------
 pbs-client/src/catalog_shell.rs      |   4 +-
 pbs-client/src/http_client.rs        |  14 ++--
 pbs-client/src/pxar/create.rs        |   2 -
 pbs-client/src/pxar/extract.rs       |  70 +++++-------------
 pbs-client/src/pxar/fuse.rs          |  18 ++---
 pbs-client/src/pxar/metadata.rs      |   4 +-
 pbs-client/src/pxar_backup_stream.rs |   6 +-
 pbs-client/src/task_log.rs           |   8 +--
 pbs-client/src/tools/key_source.rs   |   2 +-
 11 files changed, 87 insertions(+), 145 deletions(-)

diff --git a/pbs-client/Cargo.toml b/pbs-client/Cargo.toml
index 70d04caf..e2226db9 100644
--- a/pbs-client/Cargo.toml
+++ b/pbs-client/Cargo.toml
@@ -17,6 +17,7 @@ hyper = { version = "0.14", features = [ "full" ] }
 lazy_static = "1.4"
 libc = "0.2"
 nix = "0.24"
+log = "0.4"
 openssl = "0.10"
 percent-encoding = "2.1"
 pin-project-lite = "0.2"
diff --git a/pbs-client/src/backup_writer.rs b/pbs-client/src/backup_writer.rs
index a976bd43..6cf3543c 100644
--- a/pbs-client/src/backup_writer.rs
+++ b/pbs-client/src/backup_writer.rs
@@ -28,7 +28,6 @@ use super::{H2Client, HttpClient};
 pub struct BackupWriter {
     h2: H2Client,
     abort: AbortHandle,
-    verbose: bool,
     crypt_config: Option<Arc<CryptConfig>>,
 }
 
@@ -66,17 +65,11 @@ type UploadQueueSender = mpsc::Sender<(MergedChunkInfo, Option<h2::client::Respo
 type UploadResultReceiver = oneshot::Receiver<Result<(), Error>>;
 
 impl BackupWriter {
-    fn new(
-        h2: H2Client,
-        abort: AbortHandle,
-        crypt_config: Option<Arc<CryptConfig>>,
-        verbose: bool,
-    ) -> Arc<Self> {
+    fn new(h2: H2Client, abort: AbortHandle, crypt_config: Option<Arc<CryptConfig>>) -> Arc<Self> {
         Arc::new(Self {
             h2,
             abort,
             crypt_config,
-            verbose,
         })
     }
 
@@ -117,7 +110,7 @@ impl BackupWriter {
             .start_h2_connection(req, String::from(PROXMOX_BACKUP_PROTOCOL_ID_V1!()))
             .await?;
 
-        Ok(BackupWriter::new(h2, abort, crypt_config, debug))
+        Ok(BackupWriter::new(h2, abort, crypt_config))
     }
 
     pub async fn get(&self, path: &str, param: Option<Value>) -> Result<Value, Error> {
@@ -338,23 +331,23 @@ impl BackupWriter {
                 None
             },
             options.compress,
-            self.verbose,
         )
         .await?;
 
         let size_dirty = upload_stats.size - upload_stats.size_reused;
         let size: HumanByte = upload_stats.size.into();
-        let archive = if self.verbose {
+        let archive = if log::log_enabled!(log::Level::Debug) {
             archive_name
         } else {
             pbs_tools::format::strip_server_file_extension(archive_name)
         };
+
         if archive_name != CATALOG_NAME {
             let speed: HumanByte =
                 ((size_dirty * 1_000_000) / (upload_stats.duration.as_micros() as usize)).into();
             let size_dirty: HumanByte = size_dirty.into();
             let size_compressed: HumanByte = upload_stats.size_compressed.into();
-            println!(
+            log::info!(
                 "{}: had to backup {} of {} (compressed {}) in {:.2}s",
                 archive,
                 size_dirty,
@@ -362,30 +355,34 @@ impl BackupWriter {
                 size_compressed,
                 upload_stats.duration.as_secs_f64()
             );
-            println!("{}: average backup speed: {}/s", archive, speed);
+            log::info!("{}: average backup speed: {}/s", archive, speed);
         } else {
-            println!("Uploaded backup catalog ({})", size);
+            log::info!("Uploaded backup catalog ({})", size);
         }
 
         if upload_stats.size_reused > 0 && upload_stats.size > 1024 * 1024 {
             let reused_percent = upload_stats.size_reused as f64 * 100. / upload_stats.size as f64;
             let reused: HumanByte = upload_stats.size_reused.into();
-            println!(
+            log::info!(
                 "{}: backup was done incrementally, reused {} ({:.1}%)",
-                archive, reused, reused_percent
+                archive,
+                reused,
+                reused_percent
             );
         }
-        if self.verbose && upload_stats.chunk_count > 0 {
-            println!(
+        if log::log_enabled!(log::Level::Debug) && upload_stats.chunk_count > 0 {
+            log::debug!(
                 "{}: Reused {} from {} chunks.",
-                archive, upload_stats.chunk_reused, upload_stats.chunk_count
+                archive,
+                upload_stats.chunk_reused,
+                upload_stats.chunk_count
             );
-            println!(
+            log::debug!(
                 "{}: Average chunk size was {}.",
                 archive,
                 HumanByte::from(upload_stats.size / upload_stats.chunk_count)
             );
-            println!(
+            log::debug!(
                 "{}: Average time per request: {} microseconds.",
                 archive,
                 (upload_stats.duration.as_micros()) / (upload_stats.chunk_count as u128)
@@ -405,9 +402,7 @@ impl BackupWriter {
         })
     }
 
-    fn response_queue(
-        verbose: bool,
-    ) -> (
+    fn response_queue() -> (
         mpsc::Sender<h2::client::ResponseFuture>,
         oneshot::Receiver<Result<(), Error>>,
     ) {
@@ -435,11 +430,7 @@ impl BackupWriter {
                     response
                         .map_err(Error::from)
                         .and_then(H2Client::h2api_response)
-                        .map_ok(move |result| {
-                            if verbose {
-                                println!("RESPONSE: {:?}", result)
-                            }
-                        })
+                        .map_ok(move |result| log::debug!("RESPONSE: {:?}", result))
                         .map_err(|err| format_err!("pipelined request failed: {}", err))
                 })
                 .map(|result| {
@@ -454,7 +445,6 @@ impl BackupWriter {
         h2: H2Client,
         wid: u64,
         path: String,
-        verbose: bool,
     ) -> (UploadQueueSender, UploadResultReceiver) {
         let (verify_queue_tx, verify_queue_rx) = mpsc::channel(64);
         let (verify_result_tx, verify_result_rx) = oneshot::channel();
@@ -491,7 +481,7 @@ impl BackupWriter {
                                 digest_list.push(hex::encode(&digest));
                                 offset_list.push(offset);
                             }
-                            if verbose { println!("append chunks list len ({})", digest_list.len()); }
+                            log::debug!("append chunks list len ({})", digest_list.len());
                             let param = json!({ "wid": wid, "digest-list": digest_list, "offset-list": offset_list });
                             let request = H2Client::request_builder("localhost", "PUT", &path, None, Some("application/json")).unwrap();
                             let param_data = bytes::Bytes::from(param.to_string().into_bytes());
@@ -547,13 +537,11 @@ impl BackupWriter {
             known_chunks.insert(*index.index_digest(i).unwrap());
         }
 
-        if self.verbose {
-            println!(
-                "{}: known chunks list length is {}",
-                archive_name,
-                index.index_count()
-            );
-        }
+        log::debug!(
+            "{}: known chunks list length is {}",
+            archive_name,
+            index.index_count()
+        );
 
         Ok(index)
     }
@@ -588,13 +576,11 @@ impl BackupWriter {
             known_chunks.insert(*index.index_digest(i).unwrap());
         }
 
-        if self.verbose {
-            println!(
-                "{}: known chunks list length is {}",
-                archive_name,
-                index.index_count()
-            );
-        }
+        log::debug!(
+            "{}: known chunks list length is {}",
+            archive_name,
+            index.index_count()
+        );
 
         Ok(index)
     }
@@ -641,7 +627,6 @@ impl BackupWriter {
         known_chunks: Arc<Mutex<HashSet<[u8; 32]>>>,
         crypt_config: Option<Arc<CryptConfig>>,
         compress: bool,
-        verbose: bool,
     ) -> impl Future<Output = Result<UploadStats, Error>> {
         let total_chunks = Arc::new(AtomicUsize::new(0));
         let total_chunks2 = total_chunks.clone();
@@ -660,7 +645,7 @@ impl BackupWriter {
         let is_fixed_chunk_size = prefix == "fixed";
 
         let (upload_queue, upload_result) =
-            Self::append_chunk_queue(h2.clone(), wid, append_chunk_path, verbose);
+            Self::append_chunk_queue(h2.clone(), wid, append_chunk_path);
 
         let start_time = std::time::Instant::now();
 
@@ -721,12 +706,12 @@ impl BackupWriter {
                     let digest = chunk_info.digest;
                     let digest_str = hex::encode(&digest);
 
-                    /* too verbose, needs finer verbosity setting granularity
-                    if verbose {
-                        println!("upload new chunk {} ({} bytes, offset {})", digest_str,
-                                 chunk_info.chunk_len, offset);
-                    }
-                    */
+                    log::trace!(
+                        "upload new chunk {} ({} bytes, offset {})",
+                        digest_str,
+                        chunk_info.chunk_len,
+                        offset
+                    );
 
                     let chunk_data = chunk_info.chunk.into_inner();
                     let param = json!({
@@ -793,7 +778,7 @@ impl BackupWriter {
     }
 
     /// Upload speed test - prints result to stderr
-    pub async fn upload_speedtest(&self, verbose: bool) -> Result<f64, Error> {
+    pub async fn upload_speedtest(&self) -> Result<f64, Error> {
         let mut data = vec![];
         // generate pseudo random byte sequence
         for i in 0..1024 * 1024 {
@@ -807,7 +792,7 @@ impl BackupWriter {
 
         let mut repeat = 0;
 
-        let (upload_queue, upload_result) = Self::response_queue(verbose);
+        let (upload_queue, upload_result) = Self::response_queue();
 
         let start_time = std::time::Instant::now();
 
@@ -817,9 +802,7 @@ impl BackupWriter {
                 break;
             }
 
-            if verbose {
-                eprintln!("send test data ({} bytes)", data.len());
-            }
+            log::debug!("send test data ({} bytes)", data.len());
             let request =
                 H2Client::request_builder("localhost", "POST", "speedtest", None, None).unwrap();
             let request_future = self
@@ -834,13 +817,13 @@ impl BackupWriter {
 
         let _ = upload_result.await?;
 
-        eprintln!(
+        log::info!(
             "Uploaded {} chunks in {} seconds.",
             repeat,
             start_time.elapsed().as_secs()
         );
         let speed = ((item_len * (repeat as usize)) as f64) / start_time.elapsed().as_secs_f64();
-        eprintln!(
+        log::info!(
             "Time per request: {} microseconds.",
             (start_time.elapsed().as_micros()) / (repeat as u128)
         );
diff --git a/pbs-client/src/catalog_shell.rs b/pbs-client/src/catalog_shell.rs
index 85508891..c401e434 100644
--- a/pbs-client/src/catalog_shell.rs
+++ b/pbs-client/src/catalog_shell.rs
@@ -101,7 +101,7 @@ fn complete_path(complete_me: &str, _map: &HashMap<String, String>) -> Vec<Strin
     match shell.complete_path(complete_me) {
         Ok(list) => list,
         Err(err) => {
-            eprintln!("error during completion: {}", err);
+            log::error!("error during completion: {}", err);
             Vec::new()
         }
     }
@@ -456,7 +456,7 @@ impl Shell {
             let args = match cli::shellword_split(&line) {
                 Ok(args) => args,
                 Err(err) => {
-                    println!("Error: {}", err);
+                    log::error!("Error: {}", err);
                     continue;
                 }
             };
diff --git a/pbs-client/src/http_client.rs b/pbs-client/src/http_client.rs
index c9104a03..6d5d9ad5 100644
--- a/pbs-client/src/http_client.rs
+++ b/pbs-client/src/http_client.rs
@@ -347,14 +347,14 @@ impl HttpClient {
                             if let Err(err) =
                                 store_fingerprint(prefix.as_ref().unwrap(), &server, &fingerprint)
                             {
-                                eprintln!("{}", err);
+                                log::error!("{}", err);
                             }
                         }
                         *verified_fingerprint.lock().unwrap() = Some(fingerprint);
                         true
                     }
                     Err(err) => {
-                        eprintln!("certificate validation failed - {}", err);
+                        log::error!("certificate validation failed - {}", err);
                         false
                     }
                 },
@@ -457,7 +457,7 @@ impl HttpClient {
                         *auth2.write().unwrap() = auth;
                     }
                     Err(err) => {
-                        eprintln!("re-authentication failed: {}", err);
+                        log::error!("re-authentication failed: {}", err);
                         return;
                     }
                 }
@@ -580,14 +580,14 @@ impl HttpClient {
             if expected_fingerprint == fp_string {
                 return Ok(Some(fp_string));
             } else {
-                eprintln!("WARNING: certificate fingerprint does not match expected fingerprint!");
-                eprintln!("expected:    {}", expected_fingerprint);
+                log::warn!("WARNING: certificate fingerprint does not match expected fingerprint!");
+                log::warn!("expected:    {}", expected_fingerprint);
             }
         }
 
         // If we're on a TTY, query the user
         if interactive && tty::stdin_isatty() {
-            eprintln!("fingerprint: {}", fp_string);
+            log::info!("fingerprint: {}", fp_string);
             loop {
                 eprint!("Are you sure you want to continue connecting? (y/n): ");
                 let _ = std::io::stdout().flush();
@@ -775,7 +775,7 @@ impl HttpClient {
             .handshake(upgraded)
             .await?;
 
-        let connection = connection.map_err(|_| eprintln!("HTTP/2.0 connection failed"));
+        let connection = connection.map_err(|_| log::error!("HTTP/2.0 connection failed"));
 
         let (connection, abort) = futures::future::abortable(connection);
         // A cancellable future returns an Option which is None when cancelled and
diff --git a/pbs-client/src/pxar/create.rs b/pbs-client/src/pxar/create.rs
index d58bab20..5df324cc 100644
--- a/pbs-client/src/pxar/create.rs
+++ b/pbs-client/src/pxar/create.rs
@@ -43,8 +43,6 @@ pub struct PxarCreateOptions {
     pub entries_max: usize,
     /// Skip lost+found directory
     pub skip_lost_and_found: bool,
-    /// Verbose output
-    pub verbose: bool,
 }
 
 fn detect_fs_type(fd: RawFd) -> Result<i64, Error> {
diff --git a/pbs-client/src/pxar/extract.rs b/pbs-client/src/pxar/extract.rs
index 9a8854c0..95530e48 100644
--- a/pbs-client/src/pxar/extract.rs
+++ b/pbs-client/src/pxar/extract.rs
@@ -532,12 +532,7 @@ where
 }
 
 /// Creates a tar file from `path` and writes it into `output`
-pub async fn create_tar<T, W, P>(
-    output: W,
-    accessor: Accessor<T>,
-    path: P,
-    verbose: bool,
-) -> Result<(), Error>
+pub async fn create_tar<T, W, P>(output: W, accessor: Accessor<T>, path: P) -> Result<(), Error>
 where
     T: Clone + pxar::accessor::ReadAt + Unpin + Send + Sync + 'static,
     W: tokio::io::AsyncWrite + Unpin + Send + 'static,
@@ -596,9 +591,7 @@ where
                         let metadata = realfile.entry().metadata();
                         let realpath = Path::new(link);
 
-                        if verbose {
-                            eprintln!("adding '{}' to tar", path.display());
-                        }
+                        log::debug!("adding '{}' to tar", path.display());
 
                         let stripped_path = match realpath.strip_prefix(prefix) {
                             Ok(path) => path,
@@ -632,9 +625,7 @@ where
                     }
                 }
                 EntryKind::Symlink(link) if !link.data.is_empty() => {
-                    if verbose {
-                        eprintln!("adding '{}' to tar", path.display());
-                    }
+                    log::debug!("adding '{}' to tar", path.display());
                     let realpath = Path::new(link);
                     let mut header = tar::Header::new_gnu();
                     header.set_entry_type(tar::EntryType::Symlink);
@@ -646,9 +637,7 @@ where
                         .map_err(|err| format_err!("could not send symlink entry: {}", err))?;
                 }
                 EntryKind::Fifo => {
-                    if verbose {
-                        eprintln!("adding '{}' to tar", path.display());
-                    }
+                    log::debug!("adding '{}' to tar", path.display());
                     let mut header = tar::Header::new_gnu();
                     header.set_entry_type(tar::EntryType::Fifo);
                     add_metadata_to_header(&mut header, metadata);
@@ -662,9 +651,7 @@ where
                         .map_err(|err| format_err!("could not send fifo entry: {}", err))?;
                 }
                 EntryKind::Directory => {
-                    if verbose {
-                        eprintln!("adding '{}' to tar", path.display());
-                    }
+                    log::debug!("adding '{}' to tar", path.display());
                     // we cannot add the root path itself
                     if path != Path::new("/") {
                         let mut header = tar::Header::new_gnu();
@@ -679,9 +666,7 @@ where
                     }
                 }
                 EntryKind::Device(device) => {
-                    if verbose {
-                        eprintln!("adding '{}' to tar", path.display());
-                    }
+                    log::debug!("adding '{}' to tar", path.display());
                     let entry_type = if metadata.stat.is_chardev() {
                         tar::EntryType::Char
                     } else {
@@ -704,18 +689,13 @@ where
     }
 
     tarencoder.finish().await.map_err(|err| {
-        eprintln!("error during finishing of zip: {}", err);
+        log::error!("error during finishing of zip: {}", err);
         err
     })?;
     Ok(())
 }
 
-pub async fn create_zip<T, W, P>(
-    output: W,
-    accessor: Accessor<T>,
-    path: P,
-    verbose: bool,
-) -> Result<(), Error>
+pub async fn create_zip<T, W, P>(output: W, accessor: Accessor<T>, path: P) -> Result<(), Error>
 where
     T: Clone + pxar::accessor::ReadAt + Unpin + Send + Sync + 'static,
     W: tokio::io::AsyncWrite + Unpin + Send + 'static,
@@ -758,9 +738,7 @@ where
 
             match entry.kind() {
                 EntryKind::File { .. } => {
-                    if verbose {
-                        eprintln!("adding '{}' to zip", path.display());
-                    }
+                    log::debug!("adding '{}' to zip", path.display());
                     let entry = ZipEntry::new(
                         path,
                         metadata.stat.mtime.secs,
@@ -778,9 +756,7 @@ where
                         .ok_or(format_err!("error looking up '{:?}'", path))?;
                     let realfile = accessor.follow_hardlink(&entry).await?;
                     let metadata = realfile.entry().metadata();
-                    if verbose {
-                        eprintln!("adding '{}' to zip", path.display());
-                    }
+                    log::debug!("adding '{}' to zip", path.display());
                     let entry = ZipEntry::new(
                         path,
                         metadata.stat.mtime.secs,
@@ -792,9 +768,7 @@ where
                         .map_err(|err| format_err!("could not send file entry: {}", err))?;
                 }
                 EntryKind::Directory => {
-                    if verbose {
-                        eprintln!("adding '{}' to zip", path.display());
-                    }
+                    log::debug!("adding '{}' to zip", path.display());
                     let entry = ZipEntry::new(
                         path,
                         metadata.stat.mtime.secs,
@@ -851,7 +825,6 @@ pub async fn extract_sub_dir<T, DEST, PATH>(
     destination: DEST,
     decoder: Accessor<T>,
     path: PATH,
-    verbose: bool,
 ) -> Result<(), Error>
 where
     T: Clone + pxar::accessor::ReadAt + Unpin + Send + Sync + 'static,
@@ -870,13 +843,12 @@ where
         .await?
         .ok_or(format_err!("error opening '{:?}'", path.as_ref()))?;
 
-    recurse_files_extractor(&mut extractor, file, verbose).await
+    recurse_files_extractor(&mut extractor, file).await
 }
 
 pub async fn extract_sub_dir_seq<S, DEST>(
     destination: DEST,
     mut decoder: Decoder<S>,
-    verbose: bool,
 ) -> Result<(), Error>
 where
     S: pxar::decoder::SeqRead + Unpin + Send + 'static,
@@ -891,8 +863,8 @@ where
 
     let mut extractor = get_extractor(destination, root.metadata().clone())?;
 
-    if let Err(err) = seq_files_extractor(&mut extractor, decoder, verbose).await {
-        eprintln!("error extracting pxar archive: {}", err);
+    if let Err(err) = seq_files_extractor(&mut extractor, decoder).await {
+        log::error!("error extracting pxar archive: {}", err);
     }
 
     Ok(())
@@ -948,7 +920,6 @@ fn get_filename(entry: &Entry) -> Result<(OsString, CString), Error> {
 async fn recurse_files_extractor<'a, T>(
     extractor: &'a mut Extractor,
     file: FileEntry<T>,
-    verbose: bool,
 ) -> Result<(), Error>
 where
     T: Clone + pxar::accessor::ReadAt + Unpin + Send + Sync + 'static,
@@ -957,9 +928,7 @@ where
     let metadata = entry.metadata();
     let (file_name_os, file_name) = get_filename(entry)?;
 
-    if verbose {
-        eprintln!("extracting: {}", file.path().display());
-    }
+    log::debug!("extracting: {}", file.path().display());
 
     match file.kind() {
         EntryKind::Directory => {
@@ -970,7 +939,7 @@ where
             let dir = file.enter_directory().await?;
             let mut seq_decoder = dir.decode_full().await?;
             seq_decoder.enable_goodbye_entries(true);
-            seq_files_extractor(extractor, seq_decoder, verbose).await?;
+            seq_files_extractor(extractor, seq_decoder).await?;
             extractor.leave_directory()?;
         }
         EntryKind::File { size, .. } => {
@@ -994,7 +963,6 @@ where
 async fn seq_files_extractor<'a, T>(
     extractor: &'a mut Extractor,
     mut decoder: pxar::decoder::aio::Decoder<T>,
-    verbose: bool,
 ) -> Result<(), Error>
 where
     T: pxar::decoder::SeqRead,
@@ -1009,8 +977,8 @@ where
         let metadata = entry.metadata();
         let (file_name_os, file_name) = get_filename(&entry)?;
 
-        if verbose && !matches!(entry.kind(), EntryKind::GoodbyeTable) {
-            eprintln!("extracting: {}", entry.path().display());
+        if !matches!(entry.kind(), EntryKind::GoodbyeTable) {
+            log::debug!("extracting: {}", entry.path().display());
         }
 
         if let Err(err) = async {
@@ -1044,7 +1012,7 @@ where
         .await
         {
             let display = entry.path().display().to_string();
-            eprintln!(
+            log::error!(
                 "error extracting {}: {}",
                 if matches!(entry.kind(), EntryKind::GoodbyeTable) {
                     "<directory>"
diff --git a/pbs-client/src/pxar/fuse.rs b/pbs-client/src/pxar/fuse.rs
index 594930ef..e9e1b6f3 100644
--- a/pbs-client/src/pxar/fuse.rs
+++ b/pbs-client/src/pxar/fuse.rs
@@ -240,8 +240,8 @@ impl SessionImpl {
 
     /// Here's how we deal with errors:
     ///
-    /// Any error will be printed if the verbose flag was set, otherwise the message will be
-    /// silently dropped.
+    /// Any error will be logged if a log level of at least 'debug' was set, otherwise the
+    /// message will be silently dropped.
     ///
     /// Opaque errors will cause the fuse main loop to bail out with that error.
     ///
@@ -255,8 +255,8 @@ impl SessionImpl {
     ) {
         let final_result = match err.downcast::<io::Error>() {
             Ok(err) => {
-                if err.kind() == io::ErrorKind::Other && self.verbose {
-                    eprintln!("an IO error occurred: {}", err);
+                if err.kind() == io::ErrorKind::Other {
+                    log::error!("an IO error occurred: {}", err);
                 }
 
                 // fail the request
@@ -264,9 +264,7 @@ impl SessionImpl {
             }
             Err(err) => {
                 // `bail` (non-`io::Error`) is used for fatal errors which should actually cancel:
-                if self.verbose {
-                    eprintln!("internal error: {}, bailing out", err);
-                }
+                log::error!("internal error: {}, bailing out", err);
                 Err(err)
             }
         };
@@ -297,7 +295,7 @@ impl SessionImpl {
                 },
                 err = err_recv.next() => match err {
                     Some(err) => if self.verbose {
-                        eprintln!("cancelling fuse main loop due to error: {}", err);
+                        log::error!("cancelling fuse main loop due to error: {}", err);
                         return Err(err);
                     },
                     None => panic!("error channel was closed unexpectedly"),
@@ -385,9 +383,7 @@ impl SessionImpl {
                 }
             }
             other => {
-                if self.verbose {
-                    eprintln!("Received unexpected fuse request");
-                }
+                log::error!("Received unexpected fuse request");
                 other.fail(libc::ENOSYS).map_err(Error::from)
             }
         };
diff --git a/pbs-client/src/pxar/metadata.rs b/pbs-client/src/pxar/metadata.rs
index 415922ef..22bc5f9d 100644
--- a/pbs-client/src/pxar/metadata.rs
+++ b/pbs-client/src/pxar/metadata.rs
@@ -208,7 +208,7 @@ fn apply_xattrs(
         }
 
         if !xattr::is_valid_xattr_name(xattr.name()) {
-            eprintln!("skipping invalid xattr named {:?}", xattr.name());
+            log::info!("skipping invalid xattr named {:?}", xattr.name());
             continue;
         }
 
@@ -269,7 +269,7 @@ fn apply_acls(
             acl.add_entry_full(acl::ACL_GROUP_OBJ, None, mode)?;
 
             if !metadata.acl.users.is_empty() || !metadata.acl.groups.is_empty() {
-                eprintln!(
+                log::warn!(
                     "Warning: {:?}: Missing GROUP_OBJ entry in ACL, resetting to value of MASK",
                     path_info,
                 );
diff --git a/pbs-client/src/pxar_backup_stream.rs b/pbs-client/src/pxar_backup_stream.rs
index 8ffcf36e..22a6ffdc 100644
--- a/pbs-client/src/pxar_backup_stream.rs
+++ b/pbs-client/src/pxar_backup_stream.rs
@@ -53,17 +53,13 @@ impl PxarBackupStream {
                 StdChannelWriter::new(tx),
             ));
 
-            let verbose = options.verbose;
-
             let writer = pxar::encoder::sync::StandardWriter::new(writer);
             if let Err(err) = crate::pxar::create_archive(
                 dir,
                 writer,
                 crate::pxar::Flags::DEFAULT,
                 move |path| {
-                    if verbose {
-                        println!("{:?}", path);
-                    }
+                    log::debug!("{:?}", path);
                     Ok(())
                 },
                 Some(catalog),
diff --git a/pbs-client/src/task_log.rs b/pbs-client/src/task_log.rs
index b38ae10c..a396a451 100644
--- a/pbs-client/src/task_log.rs
+++ b/pbs-client/src/task_log.rs
@@ -31,10 +31,10 @@ pub async fn display_task_log(
 
     let abort_future = async move {
         while signal_stream.recv().await.is_some() {
-            println!("got shutdown request (SIGINT)");
+            log::info!("got shutdown request (SIGINT)");
             let prev_count = abort_count2.fetch_add(1, Ordering::SeqCst);
             if prev_count >= 1 {
-                println!("forced exit (task still running)");
+                log::info!("forced exit (task still running)");
                 break;
             }
         }
@@ -77,9 +77,9 @@ pub async fn display_task_log(
                 }
                 if strip_date && t.len() > 27 && &t[25..27] == ": " {
                     let line = &t[27..];
-                    println!("{}", line);
+                    log::info!("{}", line);
                 } else {
-                    println!("{}", t);
+                    log::info!("{}", t);
                 }
                 start += 1;
             }
diff --git a/pbs-client/src/tools/key_source.rs b/pbs-client/src/tools/key_source.rs
index 3ff592e1..f7a8c7fb 100644
--- a/pbs-client/src/tools/key_source.rs
+++ b/pbs-client/src/tools/key_source.rs
@@ -231,7 +231,7 @@ fn do_crypto_parameters(param: &Value, keep_keyfd_open: bool) -> Result<CryptoPa
             (None, master_pubkey) => match read_optional_default_encryption_key()? {
                 None => bail!("--crypt-mode without --keyfile and no default key file available"),
                 enc_key => {
-                    eprintln!("Encrypting with default encryption key!");
+                    log::info!("Encrypting with default encryption key!");
                     let master_pubkey = match master_pubkey {
                         None => read_optional_default_master_pubkey()?,
                         master_pubkey => master_pubkey,
-- 
2.30.2