Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

refactor(error): enhance error logging and output formatting #361

Merged
merged 4 commits into from
Nov 18, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
6 changes: 3 additions & 3 deletions crates/backend/src/local.rs
Original file line number Diff line number Diff line change
Expand Up @@ -315,7 +315,7 @@ impl ReadBackend for LocalBackend {
})
.inspect(|r| {
if let Err(err) = r {
error!("Error while listing files: {err:?}");
error!("Error while listing files: {}", err.display_log());
}
})
.filter_map(RusticResult::ok);
Expand Down Expand Up @@ -557,7 +557,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.display_log());
}
}
Ok(())
Expand Down Expand Up @@ -587,7 +587,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.display_log());
}
}
Ok(())
Expand Down
2 changes: 1 addition & 1 deletion crates/backend/src/opendal.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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.display_log());
}
})
.filter_map(RusticResult::ok)
Expand Down
8 changes: 4 additions & 4 deletions crates/core/src/archiver.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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.display_log()),
}
}
});

// 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.display_log());
None
}
Ok(ReadSourceEntry { path, node, open }) => {
Expand Down Expand Up @@ -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.display_log());
None
}
})
Expand Down
15 changes: 11 additions & 4 deletions crates/core/src/archiver/parent.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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.display_log()
);
None
}
});
Expand Down Expand Up @@ -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.display_log()
);
None
}
},
Expand Down Expand Up @@ -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
}
}
Expand Down
35 changes: 28 additions & 7 deletions crates/core/src/backend/cache.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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.display_log()
);
}
}

Expand All @@ -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.display_log()
),
}
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.display_log()
);
}
}
res
Expand Down Expand Up @@ -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.display_log()
),
};
// 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.display_log()
);
}
Ok(Bytes::copy_from_slice(&data.slice(range)))
}
Expand Down Expand Up @@ -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.display_log()
);
}
}
self.be.write_bytes(tpe, id, cacheable, buf)
Expand All @@ -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.display_log()
);
}
}
self.be.remove(tpe, id, cacheable)
Expand Down
8 changes: 4 additions & 4 deletions crates/core/src/backend/ignore.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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))
Expand Down Expand Up @@ -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,
Expand Down
4 changes: 2 additions & 2 deletions crates/core/src/commands/backup.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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 => {
Expand All @@ -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...");

Expand Down
28 changes: 14 additions & 14 deletions crates/core/src/commands/check.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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.display_log()
);
}
p.finish();

Expand Down Expand Up @@ -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.display_log());
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}",),
simonsan marked this conversation as resolved.
Show resolved Hide resolved
Err(err) => error!("Pack {id} is not valid: {}", err.display_log()),
}
});
p.finish();
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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.display_log()
);
}
(_, Err(err)) => {
error!("Error reading file Type: {file_type:?}, Id: {id} : {err}");
error!(
"Error reading file Type: {file_type:?}, Id: {id} : {}",
err.display_log()
);
}
(Ok(Some(data_cached)), Ok(data)) if data_cached != data => {
error!(
Expand Down
5 changes: 4 additions & 1 deletion crates/core/src/commands/repair/index.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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.display_log()
);
}
Ok(header) => {
let pack = IndexPack {
Expand Down
4 changes: 2 additions & 2 deletions crates/core/src/commands/repair/snapshots.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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.display_log());
(Tree::new(), Changed::This)
},
|tree| (tree, Changed::None),
Expand Down
56 changes: 49 additions & 7 deletions crates/core/src/error.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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"))`.
Expand Down Expand Up @@ -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::{
Expand Down Expand Up @@ -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)?;
}
Expand Down Expand Up @@ -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 display_log(&self) -> String {
use std::fmt::Write;

let mut fmt = String::new();

_ = write!(fmt, "Error: ");

if self.context.is_empty() {
_ = write!(fmt, "{}", self.guidance);
} 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);
});

_ = write!(fmt, "{guidance}");
};

_ = write!(fmt, " (kind: related to {}", self.kind);

if let Some(code) = &self.error_code {
_ = write!(fmt, ", code: {code}");
}

_ = write!(fmt, ")");

if let Some(cause) = &self.source {
_ = write!(fmt, ": caused by: {cause}");

if let Some(source) = cause.source() {
_ = write!(fmt, " : (source: {source})");
}
}

fmt
}
}

// Setters for anything we do want to expose publicly.
Expand Down
Loading
Loading