Skip to content

Test flake in explain_analyze.slt #21850

@neilconway

Description

@neilconway

Describe the bug

https://github.com/apache/datafusion/actions/runs/24933184034/job/73014229851?pr=21845

     Running bin/sqllogictests.rs (target/ci/deps/sqllogictests-5935843a9c47cdf8)
Running with 3 test threads (available parallelism: 3)
Progress: 46/463 files completed (10%)
Progress: 50/463 files completed (11%)
Progress: 92/463 files completed (20%)
Progress: 100/463 files completed (22%)
Progress: 138/463 files completed (30%)
Progress: 150/463 files completed (32%)
Progress: 184/463 files completed (40%)
Progress: 200/463 files completed (43%)
Progress: 230/463 files completed (50%)
Progress: 250/463 files completed (54%)
Progress: 276/463 files completed (60%)
Progress: 300/463 files completed (65%)
Progress: 322/463 files completed (70%)
Progress: 350/463 files completed (76%)
Progress: 368/463 files completed (79%)
Progress: 400/463 files completed (86%)
Progress: 414/463 files completed (89%)
Progress: 450/463 files completed (97%)
Progress: 460/463 files completed (99%)
Progress: 463/463 files completed (100%)
External error: 1 errors in file /Users/runner/work/datafusion/datafusion/datafusion/sqllogictest/test_files/explain_analyze.slt

1. query result mismatch:
[SQL] EXPLAIN ANALYZE SELECT * FROM skew_parquet;
[Diff] (-expected|+actual)
-   Plan with Metrics DataSourceExec: <slt:ignore>output_rows_skew=84.31%<slt:ignore>
+   Plan with Metrics DataSourceExec: file_groups={4 groups: [[WORKSPACE_ROOT/datafusion/sqllogictest/test_files/scratch/explain_analyze/output_rows_skew/f1.parquet], [WORKSPACE_ROOT/datafusion/sqllogictest/test_files/scratch/explain_analyze/output_rows_skew/f2.parquet], [WORKSPACE_ROOT/datafusion/sqllogictest/test_files/scratch/explain_analyze/output_rows_skew/f3.parquet], [WORKSPACE_ROOT/datafusion/sqllogictest/test_files/scratch/explain_analyze/output_rows_skew/f4.parquet]]}, projection=[x], file_type=parquet, metrics=[output_rows=5, elapsed_compute=14.55µs, output_bytes=40.0 B, output_batches=2, files_ranges_pruned_statistics=4 total → 4 matched, row_groups_pruned_statistics=2 total → 2 matched, row_groups_pruned_bloom_filter=2 total → 2 matched, page_index_pages_pruned=0 total → 0 matched, page_index_rows_pruned=0 total → 0 matched, limit_pruned_row_groups=0 total → 0 matched, batches_split=0, bytes_scanned=74, file_open_errors=0, file_scan_errors=0, files_opened=4, files_processed=4, num_predicate_creation_errors=0, predicate_evaluation_errors=0, pushdown_rows_matched=0, pushdown_rows_pruned=0, predicate_cache_inner_records=0, predicate_cache_records=0, bloom_filter_eval_time=421ns, metadata_load_time=79.55µs, page_index_eval_time=8ns, row_pushdown_eval_time=8ns, statistics_eval_time=8ns, time_elapsed_opening=296.42µs, time_elapsed_processing=902.88µs, time_elapsed_scanning_total=624.63µs, time_elapsed_scanning_until_data=188.09µs, output_rows_skew=100%, scan_efficiency_ratio=27.41% (74/270)]
at /Users/runner/work/datafusion/datafusion/datafusion/sqllogictest/test_files/explain_analyze.slt:103



Error: Execution("1 failures\n\nbacktrace:    0: std::backtrace_rs::backtrace::libunwind::trace\n             at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/../../backtrace/src/backtrace/libunwind.rs:117:9\n   1: std::backtrace_rs::backtrace::trace_unsynchronized\n             at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/../../backtrace/src/backtrace/mod.rs:66:14\n   2: std::backtrace::Backtrace::create\n             at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/backtrace.rs:331:13\n   3: get_back_trace\n             at /Users/runner/work/datafusion/datafusion/datafusion/common/src/error.rs:487:30\n   4: {async_fn#0}\n             at ./bin/sqllogictests.rs:393:9\n   5: {closure#0}<sqllogictests::run_tests::{async_fn_env#0}>\n             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.1/src/runtime/park.rs:284:71\n   6: with_budget<core::task::poll::Poll<core::result::Result<(), datafusion_common::error::DataFusionError>>, tokio::runtime::park::{impl#4}::block_on::{closure_env#0}<sqllogictests::run_tests::{async_fn_env#0}>>\n             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.1/src/task/coop/mod.rs:167:5\n   7: budget<core::task::poll::Poll<core::result::Result<(), datafusion_common::error::DataFusionError>>, tokio::runtime::park::{impl#4}::block_on::{closure_env#0}<sqllogictests::run_tests::{async_fn_env#0}>>\n             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.1/src/task/coop/mod.rs:133:5\n   8: block_on<sqllogictests::run_tests::{async_fn_env#0}>\n             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.1/src/runtime/park.rs:284:31\n   9: block_on<sqllogictests::run_tests::{async_fn_env#0}>\n             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.1/src/runtime/context/blocking.rs:66:14\n  10: {closure#0}<sqllogictests::run_tests::{async_fn_env#0}>\n             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.1/src/runtime/scheduler/multi_thread/mod.rs:92:22\n  11: enter_runtime<tokio::runtime::scheduler::multi_thread::{impl#0}::block_on::{closure_env#0}<sqllogictests::run_tests::{async_fn_env#0}>, core::result::Result<(), datafusion_common::error::DataFusionError>>\n             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.1/src/runtime/context/runtime.rs:65:16\n  12: block_on<sqllogictests::run_tests::{async_fn_env#0}>\n             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.1/src/runtime/scheduler/multi_thread/mod.rs:91:9\n  13: block_on_inner<sqllogictests::run_tests::{async_fn_env#0}>\n             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.1/src/runtime/runtime.rs:373:50\n  14: block_on<sqllogictests::run_tests::{async_fn_env#0}>\n             at /Users/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.1/src/runtime/runtime.rs:345:18\n  15: main\n             at ./bin/sqllogictests.rs:90:10\n  16: call_once<fn() -> core::result::Result<(), datafusion_common::error::DataFusionError>, ()>\n             at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/core/src/ops/function.rs:250:5\n  17: __rust_begin_short_backtrace<fn() -> core::result::Result<(), datafusion_common::error::DataFusionError>, core::result::Result<(), datafusion_common::error::DataFusionError>>\n             at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/sys/backtrace.rs:166:18\n  18: {closure#0}<core::result::Result<(), datafusion_common::error::DataFusionError>>\n             at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/rt.rs:206:18\n  19: core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once\n             at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/core/src/ops/function.rs:287:21\n  20: std::panicking::catch_unwind::do_call\n             at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panicking.rs:581:40\n  21: std::panicking::catch_unwind\n             at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panicking.rs:544:19\n  22: std::panic::catch_unwind\n             at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panic.rs:359:14\n  23: std::rt::lang_start_internal::{{closure}}\n             at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/rt.rs:175:24\n  24: std::panicking::catch_unwind::do_call\n             at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panicking.rs:581:40\n  25: std::panicking::catch_unwind\n             at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panicking.rs:544:19\n  26: std::panic::catch_unwind\n             at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panic.rs:359:14\n  27: std::rt::lang_start_internal\n             at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/rt.rs:171:5\n  28: lang_start<core::result::Result<(), datafusion_common::error::DataFusionError>>\n             at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/rt.rs:205:5\n  29: _main\n")
error: test failed, to rerun pass `-p datafusion-sqllogictest --test sqllogictests`

To Reproduce

No response

Expected behavior

No response

Additional context

Perhaps related to the morsel / dynamic work scheduling stuff?

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Type

    No fields configured for Bug.

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions