Minor logging updates

CHANGELOG.md

@@ -1,3 +1,11 @@
+# v0.7.1
+## Fixes
+- Suppress warning when `SALVAGE_ARCHIVE_COMPRESSION_LEVEL` is not provided
+- Changed level of some logging messages to match intention
+
+## Minor Changes
+- Added duration timers for logging
+
 # v0.7.0
 ## Features
 - Added Zstandard to valid compression types.

Cargo.toml

@@ -1,6 +1,6 @@
 [package]
 name = "salvage"
-version = "0.7.0"
+version = "0.7.1"
 authors = ["Kevin Wheelans <kevin.wheelans@proton.me>"]
 edition = "2021"
 rust-version = "1.70"

src/configuration.rs

@@ -11,6 +11,7 @@ use log::{debug, warn};
 use std::env;
 use std::fmt::{Display, Formatter};
 use std::fs::Permissions;
+use std::num::IntErrorKind;
 use std::os::unix::fs::PermissionsExt;
 use std::path::PathBuf;
 use std::str::FromStr;
@@ -145,7 +146,9 @@ impl ArchiveCompression {
                 }
             }
             Err(error) => {
-                warn!(target: LOG_TARGET, "Using default because compression level conversion to u32 failed: {}", error);
+                if error.kind().ne(&IntErrorKind::Empty) {
+                    warn!(target: LOG_TARGET, "Using default because compression level conversion to u32 failed: {}", error);
+                }
                 self.default_level()
             }
         }

src/docker.rs

@@ -10,17 +10,19 @@ use bollard::Docker;
 use log::{debug, info, trace, warn};
 use std::collections::HashMap;
 use std::string::ToString;
+use std::time::Instant;
 
 pub async fn post_archive_container_processing(
     container_ids: Option<Vec<String>>,
 ) -> Result<(), Error> {
+    let start_time = Instant::now();
     let docker = connect_docker()?;
     match container_ids {
         None => debug!(target: LOG_TARGET, "No containers to restart"),
         Some(ids) => start_containers(&docker, ids.as_slice()).await?,
     }
 
-    info!(target: LOG_TARGET, "Post-archive container processing complete");
+    debug!(target: LOG_TARGET, "Post-archive container processing complete after {} milliseconds", start_time.elapsed().as_millis());
     Ok(())
 }
 
@@ -29,6 +31,7 @@ pub async fn post_archive_container_processing(
 pub async fn pre_archive_container_processing(
     config: &Configuration,
 ) -> Result<Vec<String>, Error> {
+    let start_time = Instant::now();
     let docker = connect_docker()?;
     let salvage = find_salvage_container(&docker).await?;
     trace!(target: LOG_TARGET ,"Salvage container: {:?}", salvage);
@@ -51,7 +54,7 @@ pub async fn pre_archive_container_processing(
 
     stop_containers(&docker, containers.as_slice()).await?;
 
-    info!(target: LOG_TARGET, "Pre-archive container processing complete");
+    debug!(target: LOG_TARGET, "Pre-archive container processing complete after {} milliseconds", start_time.elapsed().as_millis());
     Ok(containers)
 }
 

src/main.rs

@@ -12,6 +12,7 @@ use std::io::Write;
 use std::path::{Path, PathBuf};
 use std::process::ExitCode;
 use std::str::FromStr;
+use std::time::Instant;
 use time::macros::format_description;
 use time::OffsetDateTime;
 use xz2::write::XzEncoder;
@@ -98,6 +99,7 @@ fn set_logging_level() -> LevelFilter {
 }
 
 fn archive(config: Configuration) -> Result<(), Error> {
+    let start_time = Instant::now();
     info!(target: LOG_TARGET, "Archive process started");
     let runtime = tokio::runtime::Builder::new_current_thread()
         .enable_all()
@@ -138,7 +140,7 @@ fn archive(config: Configuration) -> Result<(), Error> {
         runtime.block_on(post_archive_container_processing(pre_archive))?;
     }
 
-    info!(target: LOG_TARGET, "Archive process finished");
+    info!(target: LOG_TARGET, "Archive process finished after {} milliseconds", start_time.elapsed().as_millis());
     Ok(())
 }
 
@@ -151,6 +153,7 @@ fn single_archive(
     directories: Vec<(OsString, PathBuf)>,
     config: &Configuration,
 ) -> Result<(), Error> {
+    let start_time = Instant::now();
     let timestamp = timestamp()?;
     let archive_name = format!(
         "{}_{}.tar.{}",
@@ -170,6 +173,7 @@ fn single_archive(
         tar.append_dir_all(name, path)?;
     }
     std::fs::set_permissions(archive_path.as_path(), config.archive_permission())?;
+    debug!(target: LOG_TARGET, "Archive {} took {} milliseconds", archive_name, start_time.elapsed().as_millis());
     Ok(())
 }
 
@@ -179,6 +183,7 @@ fn multiple_archive(
 ) -> Result<(), Error> {
     let timestamp = timestamp()?;
     for (name, path) in directories {
+        let start_time = Instant::now();
         let archive_name = format!(
             "{}_{}_{}.tar.{}",
             config.archive_prefix,
@@ -196,6 +201,7 @@ fn multiple_archive(
         tar.append_dir_all(name, path)?;
         tar.finish()?;
         std::fs::set_permissions(archive_path.as_path(), config.archive_permission())?;
+        debug!(target: LOG_TARGET, "Archive {} took {} milliseconds", archive_name, start_time.elapsed().as_millis());
     }
 
     Ok(())