fix: display the failed sqllogictest file and query that failed in case of a panic #18785

rluvaton · 2025-11-17T19:41:36Z

Which issue does this PR close?

Closes panic in DataFusion is propegated but no failed query and file is logged in sqllogictest #18784.

Rationale for this change

To be able to the failed tests

What changes are included in this PR?

Are these changes tested?

Manually, by adding panic in the join like in the issue linked PR and saw that it working for datafusion

Added panic in sort_merge_join and run:

RUST_BACKTRACE=1 cargo test --test sqllogictests -- join

Logs for running join slt tests (7 files)

  Running bin/sqllogictests.rs (target/debug/deps/sqllogictests-0092c8e14262530a)
[00:00:00] #####################-------------------       3/6       "join_lists.slt"
[00:00:00] #################-----------------------      12/30      "join_is_not_distinct_from.slt"
[00:00:00] ######----------------------------------      11/81      "sort_merge_join.slt"
[00:00:00] ##--------------------------------------       7/224     "join_disable_repartition_joins.slt"
[00:00:00] ######----------------------------------      11/81      "sort_merge_join.slt"
[00:00:00] #####-----------------------------------      27/224     "join_disable_repartition_joins.slt"
[00:00:00] #####-----------------------------------      26/217     "join_only.slt"
[00:00:00] ##--------------------------------------      19/531     "joins.slt"                                                                                                                                                                                   0: __rustc::rust_begin_unwind
             at /rustc/f8297e351a40c1439a467bbbb6879088047f50b3/library/std/src/panicking.rs:698:5
   1: core::panicking::panic_fmt
             at /rustc/f8297e351a40c1439a467bbbb6879088047f50b3/library/core/src/panicking.rs:75:14
   2: datafusion_physical_plan::joins::sort_merge_join::stream::SortMergeJoinStream::filter_record_batch_by_join_type
             at /Users/rluvaton/dev/open-source/apache/datafusion/datafusion/physical-plan/src/joins/sort_merge_join/stream.rs:1573:17
   3: datafusion_physical_plan::joins::sort_merge_join::stream::SortMergeJoinStream::filter_joined_batch
             at /Users/rluvaton/dev/open-source/apache/datafusion/datafusion/physical-plan/src/joins/sort_merge_join/stream.rs:1536:14
   4: <datafusion_physical_plan::joins::sort_merge_join::stream::SortMergeJoinStream as futures_core::stream::Stream>::poll_next
             at /Users/rluvaton/dev/open-source/apache/datafusion/datafusion/physical-plan/src/joins/sort_merge_join/stream.rs:603:54
   5: <core::pin::Pin<P> as futures_core::stream::Stream>::poll_next
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-core-0.3.31/src/stream.rs:130:33
   6: <S as futures_core::stream::TryStream>::try_poll_next
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-core-0.3.31/src/stream.rs:206:14
   7: <futures_util::stream::try_stream::try_collect::TryCollect<St,C> as core::future::future::Future>::poll
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-util-0.3.31/src/stream/try_stream/try_collect.rs:46:47
   8: datafusion_physical_plan::common::collect::{{closure}}
             at /Users/rluvaton/dev/open-source/apache/datafusion/datafusion/physical-plan/src/common.rs:43:36
   9: datafusion_sqllogictest::engines::datafusion_engine::runner::run_query::{{closure}}
             at ./src/engines/datafusion_engine/runner.rs:151:53
  10: <datafusion_sqllogictest::engines::datafusion_engine::runner::DataFusion as sqllogictest::runner::AsyncDB>::run::{{closure}}
             at ./src/engines/datafusion_engine/runner.rs:101:84
  11: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /rustc/f8297e351a40c1439a467bbbb6879088047f50b3/library/core/src/future/future.rs:133:9
  12: sqllogictest::runner::Runner<D,M>::apply_record::{{closure}}
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/sqllogictest-0.28.4/src/runner.rs:893:62
  13: sqllogictest::runner::Runner<D,M>::run_async_no_retry::{{closure}}
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/sqllogictest-0.28.4/src/runner.rs:1031:56
  14: sqllogictest::runner::Runner<D,M>::run_async::{{closure}}
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/sqllogictest-0.28.4/src/runner.rs:1007:52
  15: sqllogictests::run_file_in_runner::{{closure}}
             at ./bin/sqllogictests.rs:386:52
  16: sqllogictests::run_test_file::{{closure}}
             at ./bin/sqllogictests.rs:365:60
  17: sqllogictests::run_tests::{{closure}}::{{closure}}::{{closure}}
             at ./bin/sqllogictests.rs:189:26
  18: datafusion_common_runtime::trace_utils::trace_future::{{closure}}
             at /Users/rluvaton/dev/open-source/apache/datafusion/datafusion/common-runtime/src/trace_utils.rs:137:29
  19: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /rustc/f8297e351a40c1439a467bbbb6879088047f50b3/library/core/src/future/future.rs:133:9
  20: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-util-0.3.31/src/future/future/map.rs:55:44
  21: <futures_util::future::future::Map<Fut,F> as core::future::future::Future>::poll
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/futures-util-0.3.31/src/lib.rs:86:35
  22: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /rustc/f8297e351a40c1439a467bbbb6879088047f50b3/library/core/src/future/future.rs:133:9
  23: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/task/core.rs:365:24
  24: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/loom/std/unsafe_cell.rs:16:9
  25: tokio::runtime::task::core::Core<T,S>::poll
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/task/core.rs:354:30
  26: tokio::runtime::task::harness::poll_future::{{closure}}
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/task/harness.rs:535:30
  27: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/f8297e351a40c1439a467bbbb6879088047f50b3/library/core/src/panic/unwind_safe.rs:274:9
  28: std::panicking::catch_unwind::do_call
             at /rustc/f8297e351a40c1439a467bbbb6879088047f50b3/library/std/src/panicking.rs:590:40
  29: ___rust_try
  30: std::panicking::catch_unwind
             at /rustc/f8297e351a40c1439a467bbbb6879088047f50b3/library/std/src/panicking.rs:553:19
  31: std::panic::catch_unwind
             at /rustc/f8297e351a40c1439a467bbbb6879088047f50b3/library/std/src/panic.rs:359:14
  32: tokio::runtime::task::harness::poll_future
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/task/harness.rs:523:18
  33: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/task/harness.rs:210:27
  34: tokio::runtime::task::harness::Harness<T,S>::poll
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/task/harness.rs:155:20
  35: tokio::runtime::task::raw::poll
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/task/raw.rs:325:13
  36: tokio::runtime::task::raw::RawTask::poll
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/task/raw.rs:255:18
  37: tokio::runtime::task::LocalNotified<S>::run
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/task/mod.rs:509:13
  38: tokio::runtime::scheduler::multi_thread::worker::Context::run_task::{{closure}}
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/scheduler/multi_thread/worker.rs:600:18
  39: tokio::task::coop::with_budget
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/task/coop/mod.rs:167:5
  40: tokio::task::coop::budget
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/task/coop/mod.rs:133:5
  41: tokio::runtime::scheduler::multi_thread::worker::Context::run_task
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/scheduler/multi_thread/worker.rs:591:9
  42: tokio::runtime::scheduler::multi_thread::worker::Context::run
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/scheduler/multi_thread/worker.rs:539:29
  43: tokio::runtime::scheduler::multi_thread::worker::run::{{closure}}::{{closure}}
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/scheduler/multi_thread/worker.rs:504:24
  44: tokio::runtime::context::scoped::Scoped<T>::set
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/context/scoped.rs:40:9
  45: tokio::runtime::context::set_scheduler::{{closure}}
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/context.rs:176:38
  46: std::thread::local::LocalKey<T>::try_with
             at /rustc/f8297e351a40c1439a467bbbb6879088047f50b3/library/std/src/thread/local.rs:315:12
  47: std::thread::local::LocalKey<T>::with
             at /rustc/f8297e351a40c1439a467bbbb6879088047f50b3/library/std/src/thread/local.rs:279:20
  48: tokio::runtime::context::set_scheduler
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/context.rs:176:17
  49: tokio::runtime::scheduler::multi_thread::worker::run::{{closure}}
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/scheduler/multi_thread/worker.rs:499:9
  50: tokio::runtime::context::runtime::enter_runtime
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/context/runtime.rs:65:16
  51: tokio::runtime::scheduler::multi_thread::worker::run
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/scheduler/multi_thread/worker.rs:491:5
  52: tokio::runtime::scheduler::multi_thread::worker::Launch::launch::{{closure}}
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/scheduler/multi_thread/worker.rs:457:45
  53: <tokio::runtime::blocking::task::BlockingTask<T> as core::future::future::Future>::poll
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/blocking/task.rs:42:21
  54: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/task/core.rs:365:24
  55: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/loom/std/unsafe_cell.rs:16:9
  56: tokio::runtime::task::core::Core<T,S>::poll
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/task/core.rs:354:30
  57: tokio::runtime::task::harness::poll_future::{{closure}}
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/task/harness.rs:535:30
  58: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/f8297e351a40c1439a467bbbb6879088047f50b3/library/core/src/panic/unwind_safe.rs:274:9
  59: std::panicking::catch_unwind::do_call
             at /rustc/f8297e351a40c1439a467bbbb6879088047f50b3/library/std/src/panicking.rs:590:40
  60: ___rust_try
  61: std::panicking::catch_unwind
             at /rustc/f8297e351a40c1439a467bbbb6879088047f50b3/library/std/src/panicking.rs:553:19
  62: std::panic::catch_unwind
             at /rustc/f8297e351a40c1439a467bbbb6879088047f50b3/library/std/src/panic.rs:359:14
  63: tokio::runtime::task::harness::poll_future
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/task/harness.rs:523:18
  64: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/task/harness.rs:210:27
  65: tokio::runtime::task::harness::Harness<T,S>::poll
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/task/harness.rs:155:20
  66: tokio::runtime::task::raw::poll
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/task/raw.rs:325:13
  67: tokio::runtime::task::raw::RawTask::poll
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/task/raw.rs:255:18
  68: tokio::runtime::task::UnownedTask<S>::run
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/task/mod.rs:546:13
  69: tokio::runtime::blocking::pool::Task::run
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/blocking/pool.rs:161:19
  70: tokio::runtime::blocking::pool::Inner::run
             at /Users/rluvaton/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.48.0/src/runtime/blocking/pool.rs:516:22
Completed 7 test files in 2 seconds
failure in sort_merge_join.slt for sql SELECT * FROM t1 RIGHT JOIN t2 ON t1.a = t2.a AND t2.b * 50 <= t1.b
caused by
External error: task 19 panicked with message "test"
Error: Execution("1 failures")
error: test failed, to rerun pass `-p datafusion-sqllogictest --test sqllogictests`

Caused by:
  process didn't exit successfully: `/Users/rluvaton/dev/open-source/apache/datafusion/target/debug/deps/sqllogictests-0092c8e14262530a join` (exit status: 1)

Are there any user-facing changes?

Yes, added new struct for tracking running sql

…se of a panic

datafusion/sqllogictest/src/engines/postgres_engine/mod.rs

datafusion/sqllogictest/src/engines/currently_executed_sql.rs

martin-g · 2025-11-17T20:55:23Z

datafusion/sqllogictest/src/engines/currently_executed_sql.rs

+            .fetch_add(1, std::sync::atomic::Ordering::Relaxed);
+        let mut lock = self.currently_executed_sqls.lock().unwrap();
+        lock.insert(index, sql.into());
+        drop(lock);


Is this explicit drop() needed ? I think it is not really needed.

nope, removed

Jefffrey · 2025-11-18T00:58:22Z

In the example test in the PR body, are we meant to be able to see which query panicked in which SLT file? I can't seem to find those details in the panic trace unless I'm overlooking it 🤔

rluvaton · 2025-11-18T17:35:24Z

updated

Jefffrey

This is a nice improvement 👍

(Is it possible to get the line number of the SQL as well?)

rluvaton · 2025-11-20T18:14:07Z

(Is it possible to get the line number of the SQL as well?)

Not that I know of, but I don't have much knowledge of this part of the codebase

fix: display the failed sqllogictest file and query that failed in ca…

b20ace9

…se of a panic

github-actions bot added the sqllogictest SQL Logic Tests (.slt) label Nov 17, 2025

rluvaton added 4 commits November 17, 2025 22:05

extract tracking to struct and allow for concurrent running sql

9d16958

add license

4ccde92

format and lint

22aac84

Merge branch 'main' into show-which-file-and-query-failed-in-sqltest

179630b

rluvaton marked this pull request as ready for review November 17, 2025 20:09

rluvaton added 2 commits November 17, 2025 22:10

rename

f398064

fix postgres

c660b4f

martin-g reviewed Nov 17, 2025

View reviewed changes

fix postgres and lock

f24c3d8

Jefffrey approved these changes Nov 18, 2025

View reviewed changes

rluvaton added this pull request to the merge queue Nov 20, 2025

Merged via the queue into apache:main with commit dc6e7cf Nov 20, 2025
29 checks passed

rluvaton deleted the show-which-file-and-query-failed-in-sqltest branch November 20, 2025 18:14

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

fix: display the failed sqllogictest file and query that failed in case of a panic #18785

fix: display the failed sqllogictest file and query that failed in case of a panic #18785

rluvaton commented Nov 17, 2025 •

edited

Loading

Uh oh!

Uh oh!

Uh oh!

Uh oh!

martin-g Nov 17, 2025

Uh oh!

rluvaton Nov 17, 2025

Uh oh!

Jefffrey commented Nov 18, 2025

Uh oh!

rluvaton commented Nov 18, 2025

Uh oh!

Jefffrey left a comment

Uh oh!

rluvaton commented Nov 20, 2025

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

fix: display the failed sqllogictest file and query that failed in case of a panic #18785

fix: display the failed sqllogictest file and query that failed in case of a panic #18785

Conversation

rluvaton commented Nov 17, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Which issue does this PR close?

Rationale for this change

What changes are included in this PR?

Are these changes tested?

Are there any user-facing changes?

Uh oh!

Uh oh!

Uh oh!

Uh oh!

martin-g Nov 17, 2025

Choose a reason for hiding this comment

Uh oh!

rluvaton Nov 17, 2025

Choose a reason for hiding this comment

Uh oh!

Jefffrey commented Nov 18, 2025

Uh oh!

rluvaton commented Nov 18, 2025

Uh oh!

Jefffrey left a comment

Choose a reason for hiding this comment

Uh oh!

rluvaton commented Nov 20, 2025

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

rluvaton commented Nov 17, 2025 •

edited

Loading