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

Add backtrace to error messages #7434

Merged
merged 12 commits into from
Sep 7, 2023
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
8 changes: 5 additions & 3 deletions datafusion-cli/src/helper.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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
),))
}
});
}
Expand Down
4 changes: 2 additions & 2 deletions datafusion/common/src/column.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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");
Expand All @@ -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(())
}
Expand Down
16 changes: 8 additions & 8 deletions datafusion/common/src/dfschema.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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(())
}
Expand All @@ -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(())
}
Expand Down Expand Up @@ -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(())
}
Expand Down Expand Up @@ -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]
Expand Down
70 changes: 53 additions & 17 deletions datafusion/common/src/error.rs
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@

//! DataFusion error types

use std::backtrace::{Backtrace, BacktraceStatus};
use std::error::Error;
use std::fmt::{Display, Formatter};
use std::io;
Expand Down Expand Up @@ -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}")
Expand All @@ -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:?}")
}
Expand All @@ -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) => {
Expand Down Expand Up @@ -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`.
Expand Down Expand Up @@ -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()))
Copy link
Contributor

Choose a reason for hiding this comment

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

this is pretty clever, to use the macro like this

}
}
}
Expand All @@ -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;
Expand All @@ -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]
Expand Down Expand Up @@ -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\""
);
}
Expand All @@ -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),)
}
}
10 changes: 8 additions & 2 deletions datafusion/common/src/scalar.rs
Original file line number Diff line number Diff line change
Expand Up @@ -3238,7 +3238,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"
Expand All @@ -3258,7 +3261,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")
}

Expand Down
2 changes: 1 addition & 1 deletion datafusion/core/src/catalog/mod.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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"),
};
}

Expand Down
6 changes: 3 additions & 3 deletions datafusion/core/src/dataframe.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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(())
}
Expand Down Expand Up @@ -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(())
}
Expand Down Expand Up @@ -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(())
}
Expand Down
3 changes: 2 additions & 1 deletion datafusion/core/src/datasource/listing/table.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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(())
}

Expand Down
22 changes: 10 additions & 12 deletions datafusion/core/src/datasource/memory.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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(())
}
Expand All @@ -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(())
}
Expand Down
4 changes: 2 additions & 2 deletions datafusion/core/src/datasource/physical_plan/csv.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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"
Expand Down Expand Up @@ -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(())
}

Expand Down
2 changes: 1 addition & 1 deletion datafusion/core/src/datasource/physical_plan/json.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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(())
}

Expand Down
2 changes: 1 addition & 1 deletion datafusion/core/src/datasource/physical_plan/parquet.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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(())
}

Expand Down
Loading