refactor(error): enhance error logging and output formatting

Signed-off-by: simonsan <[email protected]>

crates/backend/src/local.rs

@@ -312,7 +312,7 @@ impl ReadBackend for LocalBackend {
             })
             .inspect(|r| {
                 if let Err(err) = r {
-                    error!("Error while listing files: {err:?}");
+                    error!("Error while listing files: {}", err.to_log_output());
                 }
             })
             .filter_map(RusticResult::ok);
@@ -563,7 +563,7 @@ impl WriteBackend for LocalBackend {
 
         if let Some(command) = &self.post_create_command {
             if let Err(err) = Self::call_command(tpe, id, &filename, command) {
-                warn!("post-create: {err}");
+                warn!("post-create: {}", err.to_log_output());
             }
         }
         Ok(())
@@ -593,7 +593,7 @@ impl WriteBackend for LocalBackend {
         )?;
         if let Some(command) = &self.post_delete_command {
             if let Err(err) = Self::call_command(tpe, id, &filename, command) {
-                warn!("post-delete: {err}");
+                warn!("post-delete: {}", err.to_log_output());
             }
         }
         Ok(())

crates/backend/src/opendal.rs

@@ -328,7 +328,7 @@ impl ReadBackend for OpenDALBackend {
             })
             .inspect(|r| {
                 if let Err(err) = r {
-                    error!("Error while listing files: {err:?}");
+                    error!("Error while listing files: {}", err.to_log_output());
                 }
             })
             .filter_map(RusticResult::ok)

crates/core/src/archiver.rs

@@ -144,15 +144,15 @@ impl<'a, BE: DecryptFullBackend, I: ReadGlobalIndex> Archiver<'a, BE, I> {
                     match src.size() {
                         Ok(Some(size)) => p.set_length(size),
                         Ok(None) => {}
-                        Err(err) => warn!("error determining backup size: {err}"),
+                        Err(err) => warn!("error determining backup size: {}", err.to_log_output()),
                     }
                 }
             });
 
             // filter out errors and handle as_path
             let iter = src.entries().filter_map(|item| match item {
-                Err(e) => {
-                    warn!("ignoring error {e}\n");
+                Err(err) => {
+                    warn!("ignoring error: {}", err.to_log_output());
                     None
                 }
                 Ok(ReadSourceEntry { path, node, open }) => {
@@ -197,7 +197,7 @@ impl<'a, BE: DecryptFullBackend, I: ReadGlobalIndex> Archiver<'a, BE, I> {
                 .filter_map(|item| match item {
                     Ok(item) => Some(item),
                     Err(err) => {
-                        warn!("ignoring error: {err:?}");
+                        warn!("ignoring error: {}", err.to_log_output());
                         None
                     }
                 })

crates/core/src/archiver/parent.rs

@@ -98,7 +98,10 @@ impl Parent {
         let tree = tree_id.and_then(|tree_id| match Tree::from_backend(be, index, tree_id) {
             Ok(tree) => Some(tree),
             Err(err) => {
-                warn!("ignoring error when loading parent tree {tree_id}: {err}");
+                warn!(
+                    "ignoring error when loading parent tree {tree_id}: {}",
+                    err.to_log_output()
+                );
                 None
             }
         });
@@ -202,7 +205,10 @@ impl Parent {
                 |tree_id| match Tree::from_backend(be, index, tree_id) {
                     Ok(tree) => Some(tree),
                     Err(err) => {
-                        warn!("ignoring error when loading parent tree {tree_id}: {err}");
+                        warn!(
+                            "ignoring error when loading parent tree {tree_id}: {}",
+                            err.to_log_output()
+                        );
                         None
                     }
                 },
@@ -274,8 +280,9 @@ impl Parent {
                             ParentResult::Matched(())
                         } else {
                             warn!(
-                            "missing blobs in index for unchanged file {path:?}; re-reading file",
-                        );
+                                "missing blobs in index for unchanged file {}; re-reading file",
+                                path.display()
+                            );
                             ParentResult::NotFound
                         }
                     }

crates/core/src/backend/cache.rs

@@ -69,7 +69,10 @@ impl ReadBackend for CachedBackend {
 
         if tpe.is_cacheable() {
             if let Err(err) = self.cache.remove_not_in_list(tpe, &list) {
-                warn!("Error in cache backend removing files {tpe:?}: {err}");
+                warn!(
+                    "Error in cache backend removing files {tpe:?}: {}",
+                    err.to_log_output()
+                );
             }
         }
 
@@ -95,12 +98,18 @@ impl ReadBackend for CachedBackend {
             match self.cache.read_full(tpe, id) {
                 Ok(Some(data)) => return Ok(data),
                 Ok(None) => {}
-                Err(err) => warn!("Error in cache backend reading {tpe:?},{id}: {err}"),
+                Err(err) => warn!(
+                    "Error in cache backend reading {tpe:?},{id}: {}",
+                    err.to_log_output()
+                ),
             }
             let res = self.be.read_full(tpe, id);
             if let Ok(data) = &res {
                 if let Err(err) = self.cache.write_bytes(tpe, id, data) {
-                    warn!("Error in cache backend writing {tpe:?},{id}: {err}");
+                    warn!(
+                        "Error in cache backend writing {tpe:?},{id}: {}",
+                        err.to_log_output()
+                    );
                 }
             }
             res
@@ -138,14 +147,20 @@ impl ReadBackend for CachedBackend {
             match self.cache.read_partial(tpe, id, offset, length) {
                 Ok(Some(data)) => return Ok(data),
                 Ok(None) => {}
-                Err(err) => warn!("Error in cache backend reading {tpe:?},{id}: {err}"),
+                Err(err) => warn!(
+                    "Error in cache backend reading {tpe:?},{id}: {}",
+                    err.to_log_output()
+                ),
             };
             // read full file, save to cache and return partial content
             match self.be.read_full(tpe, id) {
                 Ok(data) => {
                     let range = offset as usize..(offset + length) as usize;
                     if let Err(err) = self.cache.write_bytes(tpe, id, &data) {
-                        warn!("Error in cache backend writing {tpe:?},{id}: {err}");
+                        warn!(
+                            "Error in cache backend writing {tpe:?},{id}: {}",
+                            err.to_log_output()
+                        );
                     }
                     Ok(Bytes::copy_from_slice(&data.slice(range)))
                 }
@@ -183,7 +198,10 @@ impl WriteBackend for CachedBackend {
     fn write_bytes(&self, tpe: FileType, id: &Id, cacheable: bool, buf: Bytes) -> RusticResult<()> {
         if cacheable || tpe.is_cacheable() {
             if let Err(err) = self.cache.write_bytes(tpe, id, &buf) {
-                warn!("Error in cache backend writing {tpe:?},{id}: {err}");
+                warn!(
+                    "Error in cache backend writing {tpe:?},{id}: {}",
+                    err.to_log_output()
+                );
             }
         }
         self.be.write_bytes(tpe, id, cacheable, buf)
@@ -200,7 +218,10 @@ impl WriteBackend for CachedBackend {
     fn remove(&self, tpe: FileType, id: &Id, cacheable: bool) -> RusticResult<()> {
         if cacheable || tpe.is_cacheable() {
             if let Err(err) = self.cache.remove(tpe, id) {
-                warn!("Error in cache backend removing {tpe:?},{id}: {err}");
+                warn!(
+                    "Error in cache backend removing {tpe:?},{id}: {}",
+                    err.to_log_output()
+                );
             }
         }
         self.be.remove(tpe, id, cacheable)

crates/core/src/backend/ignore.rs

@@ -358,10 +358,10 @@ impl ReadSource for LocalSource {
     fn size(&self) -> RusticResult<Option<u64>> {
         let mut size = 0;
         for entry in self.builder.build() {
-            if let Err(e) = entry.and_then(|e| e.metadata()).map(|m| {
+            if let Err(err) = entry.and_then(|e| e.metadata()).map(|m| {
                 size += if m.is_dir() { 0 } else { m.len() };
             }) {
-                warn!("ignoring error {}", e);
+                warn!("ignoring error {err}");
             }
         }
         Ok(Some(size))
@@ -656,8 +656,8 @@ fn map_entry(
     let links = if m.is_dir() { 0 } else { m.nlink() };
 
     let extended_attributes = match list_extended_attributes(entry.path()) {
-        Err(e) => {
-            warn!("ignoring error: {e}\n");
+        Err(err) => {
+            warn!("ignoring error: {err}");
             vec![]
         }
         Ok(xattr_list) => xattr_list,

crates/core/src/commands/backup.rs

@@ -267,7 +267,7 @@ pub(crate) fn backup<P: ProgressBars, S: IndexedIds>(
     let (parent_id, parent) = opts.parent_opts.get_parent(repo, &snap, backup_stdin);
     match parent_id {
         Some(id) => {
-            info!("using parent {}", id);
+            info!("using parent {id}");
             snap.parent = Some(id);
         }
         None => {
@@ -276,7 +276,7 @@ pub(crate) fn backup<P: ProgressBars, S: IndexedIds>(
     };
 
     let be = DryRunBackend::new(repo.dbe().clone(), opts.dry_run);
-    info!("starting to backup {source}...");
+    info!("starting to backup {source} ...");
     let archiver = Archiver::new(be, index, repo.config(), parent, snap)?;
     let p = repo.pb.progress_bytes("backing up...");
 

crates/core/src/commands/check.rs

@@ -274,7 +274,10 @@ pub(crate) fn check_repository<P: ProgressBars, S: Open>(
             .map(|(id, size)| (**id, *size))
             .collect();
         if let Err(err) = cache.remove_not_in_list(FileType::Pack, &ids) {
-            warn!("Error in cache backend removing pack files: {err}");
+            warn!(
+                "Error in cache backend removing pack files: {}",
+                err.to_log_output()
+            );
         }
         p.finish();
 
@@ -309,21 +312,13 @@ pub(crate) fn check_repository<P: ProgressBars, S: Open>(
             let data = match be.read_full(FileType::Pack, &id) {
                 Ok(data) => data,
                 Err(err) => {
-                    // FIXME: This needs different handling, now it prints a full display of RusticError
-                    // Instead we should actually collect and return a list of errors on the happy path
-                    // for `Check`, as this is a non-critical operation and we want to show all errors
-                    // to the user.
-                    error!("Error reading data for pack {id} : {err}");
+                    error!("Error reading data for pack {id} : {}", err.to_log_output());
                     return;
                 }
             };
             match check_pack(be, pack, data, &p) {
                 Ok(()) => {}
-                // FIXME: This needs different handling, now it prints a full display of RusticError
-                // Instead we should actually collect and return a list of errors on the happy path
-                // for `Check`, as this is a non-critical operation and we want to show all errors
-                // to the user.
-                Err(err) => error!("Pack {id} is not valid: {err}",),
+                Err(err) => error!("Pack {id} is not valid: {}", err.to_log_output()),
             }
         });
         p.finish();
@@ -362,7 +357,6 @@ fn check_hot_files(
         match files.remove(&id) {
             None => error!("hot file Type: {file_type:?}, Id: {id} does not exist in repo"),
             Some(size) if size != size_hot => {
-                // TODO: This should be an actual error not a log entry
                 error!("Type: {file_type:?}, Id: {id}: hot size: {size_hot}, actual size: {size}");
             }
             _ => {} //everything ok
@@ -415,10 +409,16 @@ fn check_cache_files(
                 be.read_full(file_type, &id),
             ) {
                 (Err(err), _) => {
-                    error!("Error reading cached file Type: {file_type:?}, Id: {id} : {err}");
+                    error!(
+                        "Error reading cached file Type: {file_type:?}, Id: {id} : {}",
+                        err.to_log_output()
+                    );
                 }
                 (_, Err(err)) => {
-                    error!("Error reading file Type: {file_type:?}, Id: {id} : {err}");
+                    error!(
+                        "Error reading file Type: {file_type:?}, Id: {id} : {}",
+                        err.to_log_output()
+                    );
                 }
                 (Ok(Some(data_cached)), Ok(data)) if data_cached != data => {
                     error!(

crates/core/src/commands/repair/index.rs

@@ -90,7 +90,10 @@ pub(crate) fn repair_index<P: ProgressBars, S: Open>(
         debug!("reading pack {id}...");
         match PackHeader::from_file(be, id, size_hint, packsize) {
             Err(err) => {
-                warn!("error reading pack {id} (-> removing from index): {err}");
+                warn!(
+                    "error reading pack {id} (-> removing from index): {}",
+                    err.to_log_output()
+                );
             }
             Ok(header) => {
                 let pack = IndexPack {

crates/core/src/commands/repair/snapshots.rs

@@ -213,8 +213,8 @@ pub(crate) fn repair_tree<BE: DecryptWriteBackend>(
             }
 
             let (tree, mut changed) = Tree::from_backend(be, index, id).map_or_else(
-                |_err| {
-                    warn!("tree {id} could not be loaded.");
+                |err| {
+                    warn!("tree {id} could not be loaded: {}", err.to_log_output());
                     (Tree::new(), Changed::This)
                 },
                 |tree| (tree, Changed::None),

crates/core/src/error.rs

@@ -19,7 +19,7 @@
 //! `Result<T, RusticError> (==RusticResult<T>)` or nested results like `RusticResult<Result<T, ArchiverErrorKind>>`.
 //! So even if the visibility of that function is `fn` or `pub(crate) fn` it should return a `RusticResult` containing a `RusticError`.
 //!
-//! If we `map_err` or `and_then` a `RusticError`, we don't want to create a new RusticError from it, but just attach some context
+//! If we `map_err` or `and_then` a `RusticError`, we don't want to create a new `RusticError` from it, but just attach some context
 //! to it, e.g. `map_err(|e| e.attach_context("key", "value"))`, so we don't lose the original error. We can also change the error
 //! kind with `map_err(|e| e.overwrite_kind(ErrorKind::NewKind))`. If we want to pre- or append to the guidance, we can use
 //! `map_err(|e| e.append_guidance_line("new line"))` or `map_err(|e| e.prepend_guidance_line("new line"))`.
@@ -48,11 +48,6 @@
 //! All types that we want to attach to an error should implement `Display` and `Debug` to provide a good error message and a nice way
 //! to display the error.
 
-// FIXME: Remove when 'displaydoc' has fixed/recommended further treatment upstream: https://github.com/yaahc/displaydoc/issues/48
-#![allow(clippy::doc_markdown)]
-// use std::error::Error as StdError;
-// use std::fmt;
-
 use derive_more::derive::Display;
 use ecow::{EcoString, EcoVec};
 use std::{
@@ -293,7 +288,7 @@ impl Display for RusticError {
             writeln!(f, "Caused by:")?;
             writeln!(f, "{cause}")?;
             if let Some(source) = cause.source() {
-                write!(f, " : (source: {source:?})")?;
+                write!(f, " : (source: {source})")?;
             }
             writeln!(f)?;
         }
@@ -375,6 +370,53 @@ impl RusticError {
     ) -> Box<Self> {
         Self::with_source(kind, error.to_string(), error)
     }
+
+    /// Returns a String representation for logging purposes.
+    /// This is a more concise version of the error message.
+    pub fn to_log_output(&self) -> String {
+        let guidance = if self.context.is_empty() {
+            self.guidance.to_string()
+        } else {
+            // If there is context, we want to iterate over it
+            // use the key to replace the placeholder in the guidance.
+            let mut guidance = self.guidance.to_string();
+
+            self.context
+                .iter()
+                // remove context which has been used in the guidance
+                .for_each(|(key, value)| {
+                    let pattern = "{".to_owned() + key + "}";
+                    guidance = guidance.replace(&pattern, value);
+                });
+
+            guidance
+        };
+
+        let kind = format!("related to {}", self.kind);
+
+        let error_code = self
+            .error_code
+            .as_ref()
+            .map_or(String::new(), |code| format!(", code: {code}"));
+
+        let output = self.source.as_ref().map_or_else(
+            || {
+                format!("Error: {guidance} (kind: {kind}{error_code})")
+            },
+            |cause| {
+                cause.source().map_or_else(
+                    || {
+                        format!("Error: {guidance} (kind: {kind}{error_code}): caused by: {cause}")
+                    },
+                    |source| {
+                        format!("Error: {guidance} (kind: {kind}{error_code}): caused by: {cause} : (source: {source})")
+                    },
+                )
+            },
+        );
+
+        output
+    }
 }
 
 // Setters for anything we do want to expose publicly.