Re: [pbs-devel] [PATCH proxmox-backup rebased 2/9] pbs-client: replace print with log macro

[Wolfgang Bumiller <w.bumiller@proxmox.com>]

On Tue, May 10, 2022 at 09:01:51AM +0000, Hannes Laimer wrote:
> --- a/pbs-client/src/backup_writer.rs
> +++ b/pbs-client/src/backup_writer.rs
> @@ -335,23 +332,19 @@ 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 {
> -            archive_name
> -        } else {
> -            pbs_tools::format::strip_server_file_extension(archive_name)
> -        };
> +        let archive = pbs_tools::format::strip_server_file_extension(archive_name);

I think it would be better to keep the conditional naming using
`log::log_enabled!(log::Level::Debug)` as condition

>          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::debug!("{}", archive_name);

^ Then we don't need the extra line here.

> +            log::info!(
>                  "{}: had to backup {} of {} (compressed {}) in {:.2}s",
>                  archive,
>                  size_dirty,
> @@ -359,32 +352,32 @@ 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
>              );
>          }
> -        if self.verbose && upload_stats.chunk_count > 0 {

^ Could check `log_enabled!` here as well.

> -            println!(
> +        if upload_stats.chunk_count > 0 {
> +            log::debug!(
>                  "{}: Reused {} from {} chunks.",
> -                archive, upload_stats.chunk_reused, upload_stats.chunk_count
> +                archive_name, upload_stats.chunk_reused, upload_stats.chunk_count

^ not sure why we would want to change the `archive` to `archive_name`
here?

>              );
> -            println!(
> +            log::debug!(
>                  "{}: Average chunk size was {}.",
> -                archive,
> +                archive_name,
>                  HumanByte::from(upload_stats.size / upload_stats.chunk_count)
>              );
> -            println!(
> +            log::debug!(
>                  "{}: Average time per request: {} microseconds.",
> -                archive,
> +                archive_name,
>                  (upload_stats.duration.as_micros()) / (upload_stats.chunk_count as u128)
>              );
>          }
(...)
> diff --git a/pbs-client/src/pxar/fuse.rs b/pbs-client/src/pxar/fuse.rs
> index 594930ef..27e741c1 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::debug!("an IO error occurred: {}", err);

^ I think this can be `log::error`

>                  }
>  
>                  // 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::debug!("internal error: {}, bailing out", err);

^ I think this can be `log::error`

>                  Err(err)
>              }
>          };
> @@ -385,9 +383,7 @@ impl SessionImpl {
>                  }
>              }
>              other => {
> -                if self.verbose {
> -                    eprintln!("Received unexpected fuse request");
> -                }
> +                log::debug!("Received unexpected fuse request");

^ I think this can be `log::error`

>                  other.fail(libc::ENOSYS).map_err(Error::from)
>              }
>          };