add support for propagating backtraces on fatal errors.

Author: raulk

fvm/src/call_manager/backtrace.rs

@@ -53,6 +53,15 @@ impl Backtrace {
         self.frames.clear();
     }
 
+    /// Sets the cause of a backtrace.
+    ///
+    /// This is useful to stamp a backtrace with its cause after the frames
+    /// have been collected, such as when we ultimately handle a fatal error at
+    /// the top of its propagation chain.
+    pub fn set_cause(&mut self, cause: Cause) {
+        self.cause = Some(cause);
+    }
+
     /// Push a "frame" (actor exit) onto the backtrace.
     ///
     /// This should be called every time an actor exits.
@@ -89,7 +98,8 @@ impl Display for Frame {
     }
 }
 
-struct SyscallCause {
+#[derive(Clone, Debug)]
+pub struct SyscallCause {
     /// The syscall "module".
     pub module: &'static str,
     /// The syscall function name.
@@ -100,13 +110,24 @@ struct SyscallCause {
     pub message: String,
 }
 
+#[derive(Clone, Debug)]
+pub struct FatalCause {
+    /// The error message from the error.
+    pub error_msg: String,
+    /// The original cause that initiated the error chain.
+    pub root_cause: String,
+    /// The backtrace, captured if the relevant
+    /// [environment variables](https://doc.rust-lang.org/std/backtrace/index.html#environment-variables) are enabled.
+    pub backtrace: String,
+}
+
 /// The ultimate "cause" of a failed message.
 #[derive(Clone, Debug)]
 pub enum Cause {
     /// The original cause was a syscall error.
     Syscall(SyscallCause),
     /// The original cause was a fatal error.
-    Fatal(String),
+    Fatal(FatalCause),
 }
 
 impl Cause {
@@ -122,7 +143,11 @@ impl Cause {
 
     /// Records a fatal error as the cause of a backtrace.
     pub fn from_fatal(err: anyhow::Error) -> Self {
-        Self::Fatal(err.into())
+        Self::Fatal(FatalCause {
+            error_msg: err.to_string(),
+            root_cause: err.root_cause().to_string(),
+            backtrace: err.backtrace().to_string(),
+        })
     }
 }
 
@@ -137,7 +162,11 @@ impl Display for Cause {
                 )
             }
             Cause::Fatal(msg) => {
-                write!(f, "[FATAL] {}", msg)
+                write!(
+                    f,
+                    "[FATAL] Root cause: {}, Stacktrace: {}",
+                    msg.root_cause, msg.backtrace
+                )
             }
         }
     }

fvm/src/call_manager/default.rs

@@ -392,13 +392,8 @@ where
             let ret = match result {
                 Ok(value) => Ok(InvocationResult::Return(value)),
                 Err(abort) => {
-                    let cause = match abort {
-                        Abort::Exit(_, _) => {}
-                        Abort::OutOfGas => {}
-                        Abort::Fatal(_) => {}
-                    };
                     if let Some(err) = last_error {
-                        cm.backtrace.set_cause(err);
+                        cm.backtrace.begin(err);
                     }
 
                     let (code, message, res) = match abort {

fvm/src/executor/default.rs

@@ -137,17 +137,22 @@ where
                     gas_used,
                 }
             }
-            Err(ExecutionError::Fatal(e)) => {
-                // Annotate the error with the message context.
-                let _err = e.context(format!(
-                    "[from={}, to={}, seq={}, m={}, h={}] fatal error",
-                    msg.from,
-                    msg.to,
-                    msg.sequence,
-                    msg.method_num,
-                    self.context().epoch
-                ));
-                // TODO backtrace
+            Err(ExecutionError::Fatal(err)) => {
+                // // Annotate the error with the message context.
+                // let err = {
+                //     let backtrace = String::from("foo"); //e.backtrace().to_string();
+                //                                          // e.context(format!(
+                //                                          //     "[from={}, to={}, seq={}, m={}, h={}] fatal error; backtrace: {}",
+                //                                          //     msg.from,
+                //                                          //     msg.to,
+                //                                          //     msg.sequence,
+                //                                          //     msg.method_num,
+                //                                          //     self.context().epoch,
+                //                                          //     backtrace,
+                //                                          // ))
+                // };
+                backtrace.set_cause(backtrace::Cause::from_fatal(err));
+                // Produce a receipt that consumes the full gas amount.
                 Receipt {
                     exit_code: ExitCode::SYS_ASSERTION_FAILED,
                     return_data: Default::default(),

fvm/src/syscalls/bind.rs

@@ -141,7 +141,7 @@ macro_rules! impl_bind_syscalls {
                             Ok(Err(err)) => {
                                 let code = err.1;
                                 log::trace!("syscall {}::{}: fail ({})", module, name, code as u32);
-                                data.last_error = Some(backtrace::Cause::new(module, name, err));
+                                data.last_error = Some(backtrace::Cause::from_syscall(module, name, err));
                                 Ok(code as u32)
                             },
                             Err(e) => Err(e.into()),
@@ -163,7 +163,7 @@ macro_rules! impl_bind_syscalls {
                         if (ret as u64) > (memory.len() as u64)
                             || memory.len() - (ret as usize) < mem::size_of::<Ret::Value>() {
                             let code = ErrorNumber::IllegalArgument;
-                            data.last_error = Some(backtrace::Cause::new(module, name, SyscallError(format!("no space for return value"), code)));
+                            data.last_error = Some(backtrace::Cause::from_syscall(module, name, SyscallError(format!("no space for return value"), code)));
                             return Ok(code as u32);
                         }
 
@@ -178,7 +178,7 @@ macro_rules! impl_bind_syscalls {
                             Ok(Err(err)) => {
                                 let code = err.1;
                                 log::trace!("syscall {}::{}: fail ({})", module, name, code as u32);
-                                data.last_error = Some(backtrace::Cause::new(module, name, err));
+                                data.last_error = Some(backtrace::Cause::from_syscall(module, name, err));
                                 Ok(code as u32)
                             },
                             Err(e) => Err(e.into()),

testing/integration/tests/lib.rs

@@ -206,6 +206,8 @@ fn out_of_stack() {
 
 #[test]
 fn backtraces() {
+    // Note: this test **does not actually assert anything**, but it's useful to
+    // let us peep into FVM backtrace generation under different scenarios.
     const WAT_ABORT: &str = r#"
     (module
       ;; ipld::open
@@ -300,8 +302,7 @@ fn backtraces() {
         .execute_message(message, ApplyKind::Explicit, 100)
         .unwrap();
 
-    println!("abort backtrace:");
-    dbg!(res.failure_info);
+    println!("abort backtrace: {}", res.failure_info.unwrap());
 
     // Send message
     let message = Message {
@@ -320,8 +321,7 @@ fn backtraces() {
         .execute_message(message, ApplyKind::Explicit, 100)
         .unwrap();
 
-    println!("fatal backtrace:");
-    dbg!(res.failure_info);
+    println!("fatal backtrace: {}", res.failure_info.unwrap());
 }
 
 #[derive(Default)]