Skip to content

Improve error reporting by printing error chain sources #1277

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

Open
wants to merge 1 commit into
base: main
Choose a base branch
from
Open
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
5 changes: 5 additions & 0 deletions cli/src/main.rs
Original file line number Diff line number Diff line change
Expand Up @@ -37,6 +37,11 @@ fn main() {
// This code just captures any errors.
if let Err(e) = run() {
tracing::error!("{:#}", e);
e.chain().skip(1).enumerate().for_each(|(idx, error)| {
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'd find it helpful to understand this change with a concrete example. We could probably do this by:

  • Stop using tracing::error! for logging here (not sure it's helpful)
  • Move our error printing to a helper function that takes an impl Write
  • Add a unit test for it

or so?

There's...a lot of stuff in this space. For example https://lib.rs/crates/color-eyre

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

OK I typed this up just as a reference

diff --git i/Cargo.lock w/Cargo.lock
index a68cb12d..a177130e 100644
--- i/Cargo.lock
+++ w/Cargo.lock
@@ -179,6 +179,7 @@ dependencies = [
  "bootc-lib",
  "bootc-utils",
  "log",
+ "similar-asserts",
  "tokio",
  "tracing",
 ]
diff --git i/cli/Cargo.toml w/cli/Cargo.toml
index 374e89ab..d62dc966 100644
--- i/cli/Cargo.toml
+++ w/cli/Cargo.toml
@@ -21,5 +21,8 @@ tokio = { workspace = true, features = ["macros"] }
 log = "0.4.21"
 tracing = { workspace = true }
 
+[dev-dependencies]
+similar-asserts = { workspace = true }
+
 [lints]
 workspace = true
diff --git i/cli/src/main.rs w/cli/src/main.rs
index d9429aa3..48feea8f 100644
--- i/cli/src/main.rs
+++ w/cli/src/main.rs
@@ -1,5 +1,7 @@
 //! The main entrypoint for bootc, which just performs global initialization, and then
 //! calls out into the library.
+use std::io::Write;
+
 use anyhow::Result;
 
 /// The code called after we've done process global init and created
@@ -17,6 +19,9 @@ async fn async_main() -> Result<()> {
 /// Perform process global initialization, then create an async runtime
 /// and do the rest of the work there.
 fn run() -> Result<()> {
+    if std::env::var_os("FOO").is_some() {
+        return Err(anyhow::anyhow!("FOO is set").context("Checking env"));
+    }
     // Initialize global state before we've possibly created other threads, etc.
     bootc_lib::cli::global_init()?;
     // We only use the "current thread" runtime because we don't perform
@@ -31,12 +36,34 @@ fn run() -> Result<()> {
     runtime.block_on(async move { async_main().await })
 }
 
+fn print_error(mut w: impl Write, e: anyhow::Error) {
+    // Ignore recursive errors when writing errors
+    let _ = write!(w, "{e:#}\n");
+}
+
 fn main() {
     // In order to print the error in a custom format (with :#) our
     // main simply invokes a run() where all the work is done.
     // This code just captures any errors.
     if let Err(e) = run() {
-        tracing::error!("{:#}", e);
+        print_error(std::io::stderr(), e);
         std::process::exit(1);
     }
 }
+
+#[cfg(test)]
+mod tests {
+    use super::*;
+
+    #[test]
+    fn test_print_error() {
+        use std::io::Cursor;
+
+        let mut buf = Cursor::new(Vec::new());
+        let err = anyhow::anyhow!("test error").context("some context");
+        print_error(&mut buf, err);
+        let output = String::from_utf8(buf.into_inner()).unwrap();
+
+        similar_asserts::assert_eq!(output, "some context: test error\n");
+    }
+}

(missing color support, and honestly the more I look at this the cooler https://docs.rs/color-eyre/latest/color_eyre/ looks, especially that support for capturing tracing spans)

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I spent a few minutes looking deeper at eyre and ran into eyre-rs/eyre#31 which seems to currently make a partial conversion not viable because we lose the .context() that we heavily rely on and we'd have to port to use tracing spans I think?

Which would probably be an improvement in some cases but again a codebase-wide impact.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm sorry for leaving this hanging. Hopefully I'll find time to pick this up sometime later this week

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No worries at all! There's higher priority things going on.

I think my bottom line on this is I believe it's fixing a real bug, but what bothers me is basically as far as I understand it our way of printing errors is at least semi-standard and I am a bit confused why it's not doing the right thing here.

Or at least it seems to me we should be matching what other tools are doing.

What specifically just confuses me is why the error source isn't printed by default.

if let Some(e) = error.source() {
eprintln!("{idx}: {e:#?}",)
}
});
std::process::exit(1);
}
}