Add backtrace to error messages (#7434)

* Adding back trace

* fmt

* fmt

* tests

* tests

* tests

* clippy

* strip_backtrace

* tests

* moved backtrace

* tests

* tests

Author: comphead

datafusion-cli/src/helper.rs

@@ -18,6 +18,7 @@
 //! Helper that helps with interactive editing, including multi-line parsing and validation,
 //! and auto-completion for file name during creating external table.
 
+use datafusion::common::sql_err;
 use datafusion::error::DataFusionError;
 use datafusion::sql::parser::{DFParser, Statement};
 use datafusion::sql::sqlparser::dialect::dialect_from_str;
@@ -162,9 +163,10 @@ pub fn unescape_input(input: &str) -> datafusion::error::Result<String> {
                     't' => '\t',
                     '\\' => '\\',
                     _ => {
-                        return Err(DataFusionError::SQL(ParserError::TokenizerError(
-                            format!("unsupported escape char: '\\{}'", next_char),
-                        )))
+                        return sql_err!(ParserError::TokenizerError(format!(
+                            "unsupported escape char: '\\{}'",
+                            next_char
+                        ),))
                     }
                 });
             }

datafusion/common/src/column.rs

@@ -428,7 +428,7 @@ mod tests {
             )
             .expect_err("should've failed to find field");
         let expected = r#"Schema error: No field named z. Valid fields are t1.a, t1.b, t2.c, t2.d, t3.a, t3.b, t3.c, t3.d, t3.e."#;
-        assert_eq!(err.to_string(), expected);
+        assert_eq!(err.strip_backtrace(), expected);
 
         // ambiguous column reference
         let col = Column::from_name("a");
@@ -439,7 +439,7 @@ mod tests {
             )
             .expect_err("should've found ambiguous field");
         let expected = "Schema error: Ambiguous reference to unqualified field a";
-        assert_eq!(err.to_string(), expected);
+        assert_eq!(err.strip_backtrace(), expected);
 
         Ok(())
     }

datafusion/common/src/dfschema.rs

@@ -812,8 +812,8 @@ mod tests {
         // lookup with unqualified name "t1.c0"
         let err = schema.index_of_column(&col).unwrap_err();
         assert_eq!(
-            err.to_string(),
-            "Schema error: No field named \"t1.c0\". Valid fields are t1.c0, t1.c1.",
+            err.strip_backtrace(),
+            "Schema error: No field named \"t1.c0\". Valid fields are t1.c0, t1.c1."
         );
         Ok(())
     }
@@ -832,8 +832,8 @@ mod tests {
         // lookup with unqualified name "t1.c0"
         let err = schema.index_of_column(&col).unwrap_err();
         assert_eq!(
-            err.to_string(),
-            "Schema error: No field named \"t1.c0\". Valid fields are t1.\"CapitalColumn\", t1.\"field.with.period\".",
+            err.strip_backtrace(),
+            "Schema error: No field named \"t1.c0\". Valid fields are t1.\"CapitalColumn\", t1.\"field.with.period\"."
         );
         Ok(())
     }
@@ -916,8 +916,8 @@ mod tests {
         let right = DFSchema::try_from(test_schema_1())?;
         let join = left.join(&right);
         assert_eq!(
-            join.unwrap_err().to_string(),
-            "Schema error: Schema contains duplicate unqualified field name c0",
+            join.unwrap_err().strip_backtrace(),
+            "Schema error: Schema contains duplicate unqualified field name c0"
         );
         Ok(())
     }
@@ -993,12 +993,12 @@ mod tests {
 
         let col = Column::from_qualified_name("t1.c0");
         let err = schema.index_of_column(&col).unwrap_err();
-        assert_eq!(err.to_string(), "Schema error: No field named t1.c0.");
+        assert_eq!(err.strip_backtrace(), "Schema error: No field named t1.c0.");
 
         // the same check without qualifier
         let col = Column::from_name("c0");
         let err = schema.index_of_column(&col).err().unwrap();
-        assert_eq!("Schema error: No field named c0.", err.to_string());
+        assert_eq!(err.strip_backtrace(), "Schema error: No field named c0.");
     }
 
     #[test]

datafusion/common/src/error.rs

@@ -17,6 +17,7 @@
 
 //! DataFusion error types
 
+use std::backtrace::{Backtrace, BacktraceStatus};
 use std::error::Error;
 use std::fmt::{Display, Formatter};
 use std::io;
@@ -278,7 +279,9 @@ impl From<GenericError> for DataFusionError {
 impl Display for DataFusionError {
     fn fmt(&self, f: &mut Formatter) -> std::fmt::Result {
         match *self {
-            DataFusionError::ArrowError(ref desc) => write!(f, "Arrow error: {desc}"),
+            DataFusionError::ArrowError(ref desc) => {
+                write!(f, "Arrow error: {desc}")
+            }
             #[cfg(feature = "parquet")]
             DataFusionError::ParquetError(ref desc) => {
                 write!(f, "Parquet error: {desc}")
@@ -287,7 +290,9 @@ impl Display for DataFusionError {
             DataFusionError::AvroError(ref desc) => {
                 write!(f, "Avro error: {desc}")
             }
-            DataFusionError::IoError(ref desc) => write!(f, "IO error: {desc}"),
+            DataFusionError::IoError(ref desc) => {
+                write!(f, "IO error: {desc}")
+            }
             DataFusionError::SQL(ref desc) => {
                 write!(f, "SQL error: {desc:?}")
             }
@@ -298,7 +303,7 @@ impl Display for DataFusionError {
                 write!(f, "This feature is not implemented: {desc}")
             }
             DataFusionError::Internal(ref desc) => {
-                write!(f, "Internal error: {desc}. This was likely caused by a bug in DataFusion's \
+                write!(f, "Internal error: {desc}.\nThis was likely caused by a bug in DataFusion's \
                     code and we would welcome that you file an bug report in our issue tracker")
             }
             DataFusionError::Plan(ref desc) => {
@@ -404,6 +409,24 @@ impl DataFusionError {
     pub fn context(self, description: impl Into<String>) -> Self {
         Self::Context(description.into(), Box::new(self))
     }
+
+    pub fn strip_backtrace(&self) -> String {
+        self.to_string()
+            .split("\n\nbacktrace: ")
+            .collect::<Vec<&str>>()
+            .first()
+            .unwrap_or(&"")
+            .to_string()
+    }
+
+    pub fn get_back_trace() -> String {
+        let back_trace = Backtrace::capture();
+        if back_trace.status() == BacktraceStatus::Captured {
+            return format!("\n\nbacktrace: {}", back_trace);
+        }
+
+        "".to_string()
+    }
 }
 
 /// Unwrap an `Option` if possible. Otherwise return an `DataFusionError::Internal`.
@@ -444,7 +467,7 @@ macro_rules! make_error {
                 #[macro_export]
                 macro_rules! $NAME {
                     ($d($d args:expr),*) => {
-                        Err(DataFusionError::$ERR(format!($d($d args),*).into()))
+                        Err(DataFusionError::$ERR(format!("{}{}", format!($d($d args),*), DataFusionError::get_back_trace()).into()))
                     }
                 }
             }
@@ -464,6 +487,14 @@ make_error!(not_impl_err, NotImplemented);
 // Exposes a macro to create `DataFusionError::Execution`
 make_error!(exec_err, Execution);
 
+// Exposes a macro to create `DataFusionError::SQL`
+#[macro_export]
+macro_rules! sql_err {
+    ($ERR:expr) => {
+        Err(DataFusionError::SQL($ERR))
+    };
+}
+
 // To avoid compiler error when using macro in the same crate:
 // macros from the current crate cannot be referred to by absolute paths
 pub use exec_err as _exec_err;
@@ -478,18 +509,17 @@ mod test {
     use arrow::error::ArrowError;
 
     #[test]
-    fn arrow_error_to_datafusion() {
+    fn datafusion_error_to_arrow() {
         let res = return_arrow_error().unwrap_err();
-        assert_eq!(
-            res.to_string(),
-            "External error: Error during planning: foo"
-        );
+        assert!(res
+            .to_string()
+            .starts_with("External error: Error during planning: foo"));
     }
 
     #[test]
-    fn datafusion_error_to_arrow() {
+    fn arrow_error_to_datafusion() {
         let res = return_datafusion_error().unwrap_err();
-        assert_eq!(res.to_string(), "Arrow error: Schema error: bar");
+        assert_eq!(res.strip_backtrace(), "Arrow error: Schema error: bar");
     }
 
     #[test]
@@ -552,31 +582,37 @@ mod test {
     fn test_make_error_parse_input() {
         let res: Result<(), DataFusionError> = plan_err!("Err");
         let res = res.unwrap_err();
-        assert_eq!(res.to_string(), "Error during planning: Err");
+        assert_eq!(res.strip_backtrace(), "Error during planning: Err");
 
         let extra1 = "extra1";
         let extra2 = "extra2";
 
         let res: Result<(), DataFusionError> = plan_err!("Err {} {}", extra1, extra2);
         let res = res.unwrap_err();
-        assert_eq!(res.to_string(), "Error during planning: Err extra1 extra2");
+        assert_eq!(
+            res.strip_backtrace(),
+            "Error during planning: Err extra1 extra2"
+        );
 
         let res: Result<(), DataFusionError> =
             plan_err!("Err {:?} {:#?}", extra1, extra2);
         let res = res.unwrap_err();
         assert_eq!(
-            res.to_string(),
+            res.strip_backtrace(),
             "Error during planning: Err \"extra1\" \"extra2\""
         );
 
         let res: Result<(), DataFusionError> = plan_err!("Err {extra1} {extra2}");
         let res = res.unwrap_err();
-        assert_eq!(res.to_string(), "Error during planning: Err extra1 extra2");
+        assert_eq!(
+            res.strip_backtrace(),
+            "Error during planning: Err extra1 extra2"
+        );
 
         let res: Result<(), DataFusionError> = plan_err!("Err {extra1:?} {extra2:#?}");
         let res = res.unwrap_err();
         assert_eq!(
-            res.to_string(),
+            res.strip_backtrace(),
             "Error during planning: Err \"extra1\" \"extra2\""
         );
     }
@@ -599,7 +635,7 @@ mod test {
         let e = e.find_root();
 
         // DataFusionError does not implement Eq, so we use a string comparison + some cheap "same variant" test instead
-        assert_eq!(e.to_string(), exp.to_string(),);
+        assert_eq!(e.strip_backtrace(), exp.strip_backtrace());
         assert_eq!(std::mem::discriminant(e), std::mem::discriminant(&exp),)
     }
 }

datafusion/common/src/scalar.rs

@@ -3265,7 +3265,10 @@ mod tests {
     fn scalar_sub_trait_int32_overflow_test() {
         let int_value = ScalarValue::Int32(Some(i32::MAX));
         let int_value_2 = ScalarValue::Int32(Some(i32::MIN));
-        let err = int_value.sub_checked(&int_value_2).unwrap_err().to_string();
+        let err = int_value
+            .sub_checked(&int_value_2)
+            .unwrap_err()
+            .strip_backtrace();
         assert_eq!(
             err,
             "Arrow error: Compute error: Overflow happened on: 2147483647 - -2147483648"
@@ -3285,7 +3288,10 @@ mod tests {
     fn scalar_sub_trait_int64_overflow_test() {
         let int_value = ScalarValue::Int64(Some(i64::MAX));
         let int_value_2 = ScalarValue::Int64(Some(i64::MIN));
-        let err = int_value.sub_checked(&int_value_2).unwrap_err().to_string();
+        let err = int_value
+            .sub_checked(&int_value_2)
+            .unwrap_err()
+            .strip_backtrace();
         assert_eq!(err, "Arrow error: Compute error: Overflow happened on: 9223372036854775807 - -9223372036854775808")
     }
 

datafusion/core/src/catalog/mod.rs

@@ -237,7 +237,7 @@ mod tests {
 
         match catalog.register_schema("foo", schema) {
             Ok(_) => panic!("unexpected OK"),
-            Err(e) => assert_eq!(e.to_string(), "This feature is not implemented: Registering new schemas is not supported"),
+            Err(e) => assert_eq!(e.strip_backtrace(), "This feature is not implemented: Registering new schemas is not supported"),
         };
     }
 

datafusion/core/src/dataframe.rs

@@ -1502,7 +1502,7 @@ mod tests {
             // try to sort on some value not present in input to distinct
             .sort(vec![col("c2").sort(true, true)])
             .unwrap_err();
-        assert_eq!(err.to_string(), "Error during planning: For SELECT DISTINCT, ORDER BY expressions c2 must appear in select list");
+        assert_eq!(err.strip_backtrace(), "Error during planning: For SELECT DISTINCT, ORDER BY expressions c2 must appear in select list");
 
         Ok(())
     }
@@ -1560,7 +1560,7 @@ mod tests {
             .join_on(right, JoinType::Inner, [col("c1").eq(col("c1"))])
             .expect_err("join didn't fail check");
         let expected = "Schema error: Ambiguous reference to unqualified field c1";
-        assert_eq!(join.to_string(), expected);
+        assert_eq!(join.strip_backtrace(), expected);
 
         Ok(())
     }
@@ -1917,7 +1917,7 @@ mod tests {
             .with_column_renamed("c2", "AAA")
             .unwrap_err();
         let expected_err = "Schema error: Ambiguous reference to unqualified field c2";
-        assert_eq!(actual_err.to_string(), expected_err);
+        assert_eq!(actual_err.strip_backtrace(), expected_err);
 
         Ok(())
     }

datafusion/core/src/datasource/listing/table.rs

@@ -1862,7 +1862,8 @@ mod tests {
         )
         .await
         .expect_err("Example should fail!");
-        assert_eq!("Invalid or Unsupported Configuration: zstd compression requires specifying a level such as zstd(4)", format!("{e}"));
+        assert_eq!(e.strip_backtrace(), "Invalid or Unsupported Configuration: zstd compression requires specifying a level such as zstd(4)");
+
         Ok(())
     }
 

datafusion/core/src/datasource/memory.rs

@@ -435,12 +435,11 @@ mod tests {
             ],
         )?;
 
-        match MemTable::try_new(schema2, vec![vec![batch]]) {
-            Err(DataFusionError::Plan(e)) => {
-                assert_eq!("\"Mismatch between schema and batches\"", format!("{e:?}"))
-            }
-            _ => panic!("MemTable::new should have failed due to schema mismatch"),
-        }
+        let e = MemTable::try_new(schema2, vec![vec![batch]]).unwrap_err();
+        assert_eq!(
+            "Error during planning: Mismatch between schema and batches",
+            e.strip_backtrace()
+        );
 
         Ok(())
     }
@@ -466,12 +465,11 @@ mod tests {
             ],
         )?;
 
-        match MemTable::try_new(schema2, vec![vec![batch]]) {
-            Err(DataFusionError::Plan(e)) => {
-                assert_eq!("\"Mismatch between schema and batches\"", format!("{e:?}"))
-            }
-            _ => panic!("MemTable::new should have failed due to schema mismatch"),
-        }
+        let e = MemTable::try_new(schema2, vec![vec![batch]]).unwrap_err();
+        assert_eq!(
+            "Error during planning: Mismatch between schema and batches",
+            e.strip_backtrace()
+        );
 
         Ok(())
     }

datafusion/core/src/datasource/physical_plan/csv.rs

@@ -835,7 +835,7 @@ mod tests {
 
         // errors due to https://github.com/apache/arrow-datafusion/issues/4918
         let mut it = csv.execute(0, task_ctx)?;
-        let err = it.next().await.unwrap().unwrap_err().to_string();
+        let err = it.next().await.unwrap().unwrap_err().strip_backtrace();
         assert_eq!(
             err,
             "Arrow error: Csv error: incorrect number of fields for line 1, expected 14 got 13"
@@ -1075,7 +1075,7 @@ mod tests {
             .write_csv(out_dir_url, DataFrameWriteOptions::new(), None)
             .await
             .expect_err("should fail because input file does not match inferred schema");
-        assert_eq!("Arrow error: Parser error: Error while parsing value d for column 0 at line 4", format!("{e}"));
+        assert_eq!(e.strip_backtrace(), "Arrow error: Parser error: Error while parsing value d for column 0 at line 4");
         Ok(())
     }
 

datafusion/core/src/datasource/physical_plan/json.rs

@@ -794,7 +794,7 @@ mod tests {
             .write_json(out_dir_url, DataFrameWriteOptions::new())
             .await
             .expect_err("should fail because input file does not match inferred schema");
-        assert_eq!("Arrow error: Parser error: Error while parsing value d for column 0 at line 4", format!("{e}"));
+        assert_eq!(e.strip_backtrace(), "Arrow error: Parser error: Error while parsing value d for column 0 at line 4");
         Ok(())
     }
 

datafusion/core/src/datasource/physical_plan/parquet.rs

@@ -936,7 +936,7 @@ mod tests {
             .write_parquet(out_dir_url, DataFrameWriteOptions::new(), None)
             .await
             .expect_err("should fail because input file does not match inferred schema");
-        assert_eq!("Arrow error: Parser error: Error while parsing value d for column 0 at line 4", format!("{e}"));
+        assert_eq!(e.strip_backtrace(), "Arrow error: Parser error: Error while parsing value d for column 0 at line 4");
         Ok(())
     }