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

upgrade sqlparser 0.47 -> 0.48 #11453

Merged
merged 16 commits into from
Jul 16, 2024
Merged

Conversation

MohamedAbdeen21
Copy link
Contributor

@MohamedAbdeen21 MohamedAbdeen21 commented Jul 13, 2024

Which issue does this PR close?

Closes #9949
Closes #11377

Rationale for this change

Recent version of sqlparser addresses some issues with DF

What changes are included in this PR?

Upgrade sqlparser version + cleaning a few imports.

Are these changes tested?

yes, with existing tests

Are there any user-facing changes?

slightly better errors.

BREAKING trailing commas in create statements were enabled by default for all dialects, that was a bug mistaken for a feature. Trailing commas in create statements will now raise an error, unless using a dialect that supports trailing commas (currently only duckdb does that)

@github-actions github-actions bot added sql SQL Planner sqllogictest SQL Logic Tests (.slt) labels Jul 13, 2024
@MohamedAbdeen21
Copy link
Contributor Author

MohamedAbdeen21 commented Jul 14, 2024

@alamb (I don't know who else to ask for help)

I have no idea how to fix the tests. The issue seems to stem from sqllogictests + backtrace feature.

minimal command: RUST_BACKTRACE=1 cargo test --features backtrace --tests

Adding the --release flag seems to solve the issue. Skipping sqllogictests also doesn't raise an issue.

Does SQLParser 0.48 have some massive struct on the stack that needs to be boxed and isn't cleaned in debug mode? Why does it pass if backtrace feature isn't enabled or when sqllogictests are skipped?

@alamb
Copy link
Contributor

alamb commented Jul 14, 2024

@alamb (I don't know who else to ask for help)

I have no idea how to fix the tests. The issue seems to stem from sqllogictests + backtrace feature.

minimal command: RUST_BACKTRACE=1 cargo test --features backtrace --tests

Adding the --release flag seems to solve the issue. Skipping sqllogictests also doesn't raise an issue.

Does SQLParser 0.48 have some massive struct on the stack that needs to be boxed and isn't cleaned in debug mode? Why does it pass if backtrace feature isn't enabled or when sqllogictests are skipped?

Thanks @MohamedAbdeen21

I don't know why the --features backtrace is causing issues. Maybe @comphead had some idea

I think you are likely right that something in sqlparser has grown the stack space slightly so now we are hitting stack overflows. Maybe if we can find what exactly is on the stack when it overflows we can refactor datafusion (e.g. break a single large function into multiple smaller ones) to work around the issue

@MohamedAbdeen21
Copy link
Contributor Author

MohamedAbdeen21 commented Jul 14, 2024

I've been running some experiments for the past few hours. Here are some observations:

  • Main branch tests pass with default tokio stack size (2 MB) but overflows when slightly reducing the stack size to 1.9 MB.

  • Also, slightly pumping the stack size to 2.1 MB in this branch causes the tests to pass.

It doesn't look like it's a single struct/enum filling the stack, but multiple small structs/enums being copied, which kinda explains why the release build passes, but not the debug build.

Maybe we've been slightly increasing the stack usage with every change and this PR caused it to finally overflow.

I think we should temporarily increase the stack size to something > 2 MB (I'm thinking 2.5 MB) for now and try to find the problematic test in a follow-up, just to keep things moving.

To replicate, change datafusion/sqllogictest/bin/sqllogictests.rs:54 from

#[tokio::main]
#[cfg(not(target_family = "windows"))]
pub async fn main() -> Result<()> {
    run_tests().await
}

to

#[cfg(not(target_family = "windows"))]
fn main() -> Result<()> {
    tokio::runtime::Builder::new_multi_thread()
        .thread_stack_size(2 * 1024 * 1024) // 2 MB
        // .thread_stack_size(2 * 1024 * 1024 - 128 * 1024) // 1.9 MB
        // .thread_stack_size(2 * 1024 * 1024 + 128 * 1024) // 2.1 MB
        .enable_all()
        .build()
        .unwrap()
        .block_on(run_tests())
}

and run the tests RUST_BACKTRACE=1 cargo test --lib --tests --bins --features avro,json,backtrace

Also, why do we spawn a thread in the windows main function that spawns tokio threads? Is there a reason why we don't spawn the tokio threads directly? datafusion/sqllogictest/bin/sqllogictests.rs:36

#[cfg(target_family = "windows")]
pub fn main() {
    // Tests from `tpch/tpch.slt` fail with stackoverflow with the default stack size.
    thread::Builder::new()
        .stack_size(2 * 1024 * 1024) // 2 MB
        .spawn(move || {
            tokio::runtime::Builder::new_multi_thread()
                .enable_all()
                .build()
                .unwrap()
                .block_on(async { run_tests().await })
                .unwrap()
        })
        .unwrap()
        .join()
        .unwrap();
}

@alamb
Copy link
Contributor

alamb commented Jul 14, 2024

It doesn't look like it's a single struct/enum filling the stack, but multiple small structs/enums being copied, which kinda explains why the release build passes, but not the debug build.

I think Rust debug builds keep space on the stack for all local variables to make debugging easier, but that also makes for much larger stack frames in debug build

Maybe we've been slightly increasing the stack usage with every change and this PR caused it to finally overflow.

Yes, I think this is a likely explanation

@alamb
Copy link
Contributor

alamb commented Jul 14, 2024

I think we should temporarily increase the stack size to something > 2 MB (I'm thinking 2.5 MB) for now and try to find the problematic test in a follow-up, just to keep things moving.

I think that would be ok

Also, why do we spawn a thread in the windows main function that spawns tokio threads? Is there a reason why we don't spawn the tokio threads directly? datafusion/sqllogictest/bin/sqllogictests.rs:36

I don't know

@MohamedAbdeen21 MohamedAbdeen21 marked this pull request as ready for review July 14, 2024 20:49
@comphead
Copy link
Contributor

@alamb @MohamedAbdeen21 sorry for coming up late.
I dont see the original issue unfortunately.
But if speaking to memory I think the problem can be in backtraces especially for schemaError which contains many information in the stack taking a lot of memory which was solved to move the stack to the heap instead of a stack. Please let me know what is the original issue?

@MohamedAbdeen21
Copy link
Contributor Author

Hi @comphead, the original issue was a tokio stack overflow when running tests with backtrace feature enabled. That only happens in debug builds and when sqllogictests are not skipped.

The temporary fix I pushed is simply increasing tokio stack size from 2 MBs to 2.5 MBs. You can check my last comment for some observations.

If possible, we want to avoid throwing memory at our problems and instead find the test that fills its stack and break it down.

@comphead
Copy link
Contributor

We try not to hardcode the stack size in the code, if possible please do like
https://github.com/apache/datafusion/pull/8929/files#diff-43f475b102ba01b21812901330682b1c70309f0ef39865d61e84327244e5aae4R39

I see we removed the stack size recently from the yml, probably we need more investigation before this can be removed

@MohamedAbdeen21
Copy link
Contributor Author

I can't see how that benefits us. Setting an env var just to read it once in a test, which is meant to be a (hopefully) temporary fix, seems ... unnecessary.

Plus, other devs WILL run into this issue in their local envs whenever they use the full test command (with the backtrace feature), so hiding the variable in workflow env doesn't seem like a reasonable move.

@alamb
Copy link
Contributor

alamb commented Jul 15, 2024

I ran the program under lldb and here is the stack trace on my M3 mac

(lldb) target create "/Users/andrewlamb/Software/datafusion/target/debug/deps/sqllogictests-ac42652c86ad174a"
Current executable set to '/Users/andrewlamb/Software/datafusion/target/debug/deps/sqllogictests-ac42652c86ad174a' (arm64).
(lldb) run
Process 71406 launched: '/Users/andrewlamb/Software/datafusion/target/debug/deps/sqllogictests-ac42652c86ad174a' (arm64)
(lldb) bt
(lldb) thread backtrace
* thread #4, name = 'tokio-runtime-worker', stop reason = �[31mEXC_BAD_ACCESS (code=2, address=0x17021bff0)�[0m
  * frame #0: �[33m0x000000010015eaa8�[0m sqllogictests-ac42652c86ad174a`core::ptr::read_volatile::precondition_check::hf7ae97eea9784816(addr=<unavailable>, align=0) at �[36mub_checks.rs�[0m:�[33m64�[0m
    frame #1: �[33m0x000000010056a610�[0m sqllogictests-ac42652c86ad174a`alloc::alloc::alloc::h35bb2b9d1fa8d32a at �[36mub_checks.rs�[0m:�[33m73�[0m:�[33m17�[0m
    frame #2: �[33m0x000000010056a5e4�[0m sqllogictests-ac42652c86ad174a`alloc::alloc::alloc::h35bb2b9d1fa8d32a(layout=Layout @ 0x000000017021c008) at �[36malloc.rs�[0m:�[33m98�[0m:�[33m9�[0m
    frame #3: �[33m0x000000010056a73c�[0m sqllogictests-ac42652c86ad174a`alloc::alloc::Global::alloc_impl::h0457a5da59b28ec3(self=0x0000000000000001, layout=Layout @ 0x000000017021c0b0, zeroed=false) at �[36malloc.rs�[0m:�[33m183�[0m:�[33m73�[0m
    frame #4: �[33m0x000000010056a58c�[0m sqllogictests-ac42652c86ad174a`alloc::alloc::exchange_malloc::hfa50229b37808378 at �[36malloc.rs�[0m:�[33m243�[0m:�[33m9�[0m
    frame #5: �[33m0x000000010056a578�[0m sqllogictests-ac42652c86ad174a`alloc::alloc::exchange_malloc::hfa50229b37808378(size=32, align=8) at �[36malloc.rs�[0m:�[33m332�[0m:�[33m18�[0m
    frame #6: �[33m0x000000010017ff88�[0m sqllogictests-ac42652c86ad174a`datafusion_sql::expr::_$LT$impl$u20$datafusion_sql..planner..SqlToRel$LT$S$GT$$GT$::sql_expr_to_logical_expr::h2ff0e8a146a45a93(self=0x00000001703ff270, sql=<unavailable>, schema=0x00006000002a3940, planner_context=0x000000017021dc58) at �[36mmod.rs�[0m:�[33m67�[0m:�[33m25�[0m
    frame #7: �[33m0x0000000100138fb4�[0m sqllogictests-ac42652c86ad174a`datafusion_sql::expr::value::_$LT$impl$u20$datafusion_sql..planner..SqlToRel$LT$S$GT$$GT$::sql_array_literal::_$u7b$$u7b$closure$u7d$$u7d$::hd77cfb386f009aed(element=<unavailable>) at �[36mvalue.rs�[0m:�[33m144�[0m:�[33m17�[0m
    frame #8: �[33m0x00000001003b8d88�[0m sqllogictests-ac42652c86ad174a`core::iter::adapters::map::map_try_fold::_$u7b$$u7b$closure$u7d$$u7d$::hc2d7a57769576c2b(acc=<unavailable>, elt=<unavailable>) at �[36mmap.rs�[0m:�[33m96�[0m:�[33m28�[0m
    frame #9: �[33m0x000000010050ee88�[0m sqllogictests-ac42652c86ad174a`core::iter::traits::iterator::Iterator::try_fold::he6904ec7d95c9139(self=0x000000017021f258, init=<unavailable>, f={closure_env#0}<sqlparser::ast::Expr, core::result::Result<datafusion_expr::expr::Expr, datafusion_common::error::DataFusionError>, (), core::ops::control_flow::ControlFlow<core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>, ()>, datafusion_sql::expr::value::{impl#0}::sql_array_literal::{closure_env#0}<datafusion::execution::session_state::SessionContextProvider>, core::iter::adapters::{impl#0}::try_fold::{closure_env#0}<core::iter::adapters::map::Map<alloc::vec::into_iter::IntoIter<sqlparser::ast::Expr, alloc::alloc::Global>, datafusion_sql::expr::value::{impl#0}::sql_array_literal::{closure_env#0}<datafusion::execution::session_state::SessionContextProvider>>, core::result::Result<core::convert::Infallible, datafusion_common::error::DataFusionError>, (), core::iter::traits::iterator::Iterator::try_for_each::call::{closure_env#0}<datafusion_expr::expr::Expr, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>, fn(datafusion_expr::expr::Expr) -> core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>>, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>>> @ 0x000000017021e7e0) at �[36miterator.rs�[0m:�[33m2410�[0m:�[33m21�[0m
    frame #10: �[33m0x00000001003a2ae8�[0m sqllogictests-ac42652c86ad174a`_$LT$core..iter..adapters..map..Map$LT$I$C$F$GT$$u20$as$u20$core..iter..traits..iterator..Iterator$GT$::try_fold::h4735bf7f64bdaf02(self=0x000000017021f258, init=<unavailable>, g={closure_env#0}<core::iter::adapters::map::Map<alloc::vec::into_iter::IntoIter<sqlparser::ast::Expr, alloc::alloc::Global>, datafusion_sql::expr::value::{impl#0}::sql_array_literal::{closure_env#0}<datafusion::execution::session_state::SessionContextProvider>>, core::result::Result<core::convert::Infallible, datafusion_common::error::DataFusionError>, (), core::iter::traits::iterator::Iterator::try_for_each::call::{closure_env#0}<datafusion_expr::expr::Expr, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>, fn(datafusion_expr::expr::Expr) -> core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>>, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>> @ 0x000000017021e808) at �[36mmap.rs�[0m:�[33m122�[0m:�[33m9�[0m
    frame #11: �[33m0x00000001005d2f40�[0m sqllogictests-ac42652c86ad174a`_$LT$core..iter..adapters..GenericShunt$LT$I$C$R$GT$$u20$as$u20$core..iter..traits..iterator..Iterator$GT$::try_fold::h0ec4e279a8e32e3d(self=0x000000017021f258, init=<unavailable>, f={closure_env#0}<datafusion_expr::expr::Expr, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>, fn(datafusion_expr::expr::Expr) -> core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>> @ 0x000000017021e85f) at �[36mmod.rs�[0m:�[33m201�[0m:�[33m9�[0m
    frame #12: �[33m0x00000001005d0e64�[0m sqllogictests-ac42652c86ad174a`_$LT$core..iter..adapters..GenericShunt$LT$I$C$R$GT$$u20$as$u20$core..iter..traits..iterator..Iterator$GT$::next::haa640898d9ff18e1 at �[36miterator.rs�[0m:�[33m2472�[0m:�[33m9�[0m
    frame #13: �[33m0x00000001005d0e54�[0m sqllogictests-ac42652c86ad174a`_$LT$core..iter..adapters..GenericShunt$LT$I$C$R$GT$$u20$as$u20$core..iter..traits..iterator..Iterator$GT$::next::haa640898d9ff18e1(self=0x000000017021f258) at �[36mmod.rs�[0m:�[33m184�[0m:�[33m14�[0m
    frame #14: �[33m0x00000001001de2fc�[0m sqllogictests-ac42652c86ad174a`_$LT$alloc..vec..Vec$LT$T$GT$$u20$as$u20$alloc..vec..spec_from_iter_nested..SpecFromIterNested$LT$T$C$I$GT$$GT$::from_iter::h0a544a1a59bae07f(iterator=<unavailable>) at �[36mspec_from_iter_nested.rs�[0m:�[33m26�[0m:�[33m32�[0m
    frame #15: �[33m0x0000000100257f78�[0m sqllogictests-ac42652c86ad174a`alloc::vec::in_place_collect::_$LT$impl$u20$alloc..vec..spec_from_iter..SpecFromIter$LT$T$C$I$GT$$u20$for$u20$alloc..vec..Vec$LT$T$GT$$GT$::from_iter::h28bd6c3936396d49(iterator=<unavailable>) at �[36min_place_collect.rs�[0m:�[33m245�[0m:�[33m9�[0m
    frame #16: �[33m0x000000010026c63c�[0m sqllogictests-ac42652c86ad174a`_$LT$alloc..vec..Vec$LT$T$GT$$u20$as$u20$core..iter..traits..collect..FromIterator$LT$T$GT$$GT$::from_iter::hc4d35fafb59fcf91(iter=<unavailable>) at �[36mmod.rs�[0m:�[33m2972�[0m:�[33m9�[0m
    frame #17: �[33m0x000000010053ade0�[0m sqllogictests-ac42652c86ad174a`_$LT$core..result..Result$LT$V$C$E$GT$$u20$as$u20$core..iter..traits..collect..FromIterator$LT$core..result..Result$LT$A$C$E$GT$$GT$$GT$::from_iter::_$u7b$$u7b$closure$u7d$$u7d$::h11ba652124830586 at �[36miterator.rs�[0m:�[33m2004�[0m:�[33m9�[0m
    frame #18: �[33m0x000000010053addc�[0m sqllogictests-ac42652c86ad174a`_$LT$core..result..Result$LT$V$C$E$GT$$u20$as$u20$core..iter..traits..collect..FromIterator$LT$core..result..Result$LT$A$C$E$GT$$GT$$GT$::from_iter::_$u7b$$u7b$closure$u7d$$u7d$::h11ba652124830586((null)=0x000000017021f2f7, i=<unavailable>) at �[36mresult.rs�[0m:�[33m1935�[0m:�[33m51�[0m
    frame #19: �[33m0x00000001005f3aa0�[0m sqllogictests-ac42652c86ad174a`core::iter::adapters::try_process::hc02972ea3a35822f(iter=<unavailable>, f={closure_env#0}<datafusion_expr::expr::Expr, datafusion_common::error::DataFusionError, alloc::vec::Vec<datafusion_expr::expr::Expr, alloc::alloc::Global>, core::iter::adapters::map::Map<alloc::vec::into_iter::IntoIter<sqlparser::ast::Expr, alloc::alloc::Global>, datafusion_sql::expr::value::{impl#0}::sql_array_literal::{closure_env#0}<datafusion::execution::session_state::SessionContextProvider>>> @ 0x000000017021f2f7) at �[36mmod.rs�[0m:�[33m170�[0m:�[33m17�[0m
    frame #20: �[33m0x0000000100539858�[0m sqllogictests-ac42652c86ad174a`_$LT$core..result..Result$LT$V$C$E$GT$$u20$as$u20$core..iter..traits..collect..FromIterator$LT$core..result..Result$LT$A$C$E$GT$$GT$$GT$::from_iter::h192073e1a8f55489(iter=<unavailable>) at �[36mresult.rs�[0m:�[33m1935�[0m:�[33m9�[0m
    frame #21: �[33m0x00000001003ae09c�[0m sqllogictests-ac42652c86ad174a`core::iter::traits::iterator::Iterator::collect::h2a11199afaa8fa12(self=<unavailable>) at �[36miterator.rs�[0m:�[33m2004�[0m:�[33m9�[0m
    frame #22: �[33m0x0000000100174a6c�[0m sqllogictests-ac42652c86ad174a`datafusion_sql::expr::value::_$LT$impl$u20$datafusion_sql..planner..SqlToRel$LT$S$GT$$GT$::sql_array_literal::h4d44e9d8cbf97873(self=0x00000001703ff270, elements=<unavailable>, schema=0x00006000002a3940) at �[36mvalue.rs�[0m:�[33m141�[0m:�[33m22�[0m
    frame #23: �[33m0x0000000100182a2c�[0m sqllogictests-ac42652c86ad174a`datafusion_sql::expr::_$LT$impl$u20$datafusion_sql..planner..SqlToRel$LT$S$GT$$GT$::sql_expr_to_logical_expr_internal::h9b44f811d2436c9f(self=0x00000001703ff270, sql=Expr @ 0x0000000170230250, schema=0x00006000002a3940, planner_context=0x0000000170231558) at �[36mmod.rs�[0m:�[33m199�[0m:�[33m36�[0m
    frame #24: �[33m0x00000001001803fc�[0m sqllogictests-ac42652c86ad174a`datafusion_sql::expr::_$LT$impl$u20$datafusion_sql..planner..SqlToRel$LT$S$GT$$GT$::sql_expr_to_logical_expr::h2ff0e8a146a45a93(self=0x00000001703ff270, sql=Expr @ 0x0000000170231430, schema=0x00006000002a3940, planner_context=0x0000000170231558) at �[36mmod.rs�[0m:�[33m82�[0m:�[33m40�[0m
    frame #25: �[33m0x0000000100138fb4�[0m sqllogictests-ac42652c86ad174a`datafusion_sql::expr::value::_$LT$impl$u20$datafusion_sql..planner..SqlToRel$LT$S$GT$$GT$::sql_array_literal::_$u7b$$u7b$closure$u7d$$u7d$::hd77cfb386f009aed(element=<unavailable>) at �[36mvalue.rs�[0m:�[33m144�[0m:�[33m17�[0m
    frame #26: �[33m0x00000001003b8d88�[0m sqllogictests-ac42652c86ad174a`core::iter::adapters::map::map_try_fold::_$u7b$$u7b$closure$u7d$$u7d$::hc2d7a57769576c2b(acc=<unavailable>, elt=<unavailable>) at �[36mmap.rs�[0m:�[33m96�[0m:�[33m28�[0m
    frame #27: �[33m0x000000010050ee88�[0m sqllogictests-ac42652c86ad174a`core::iter::traits::iterator::Iterator::try_fold::he6904ec7d95c9139(self=0x0000000170232b58, init=<unavailable>, f={closure_env#0}<sqlparser::ast::Expr, core::result::Result<datafusion_expr::expr::Expr, datafusion_common::error::DataFusionError>, (), core::ops::control_flow::ControlFlow<core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>, ()>, datafusion_sql::expr::value::{impl#0}::sql_array_literal::{closure_env#0}<datafusion::execution::session_state::SessionContextProvider>, core::iter::adapters::{impl#0}::try_fold::{closure_env#0}<core::iter::adapters::map::Map<alloc::vec::into_iter::IntoIter<sqlparser::ast::Expr, alloc::alloc::Global>, datafusion_sql::expr::value::{impl#0}::sql_array_literal::{closure_env#0}<datafusion::execution::session_state::SessionContextProvider>>, core::result::Result<core::convert::Infallible, datafusion_common::error::DataFusionError>, (), core::iter::traits::iterator::Iterator::try_for_each::call::{closure_env#0}<datafusion_expr::expr::Expr, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>, fn(datafusion_expr::expr::Expr) -> core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>>, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>>> @ 0x00000001702320e0) at �[36miterator.rs�[0m:�[33m2410�[0m:�[33m21�[0m
    frame #28: �[33m0x00000001003a2ae8�[0m sqllogictests-ac42652c86ad174a`_$LT$core..iter..adapters..map..Map$LT$I$C$F$GT$$u20$as$u20$core..iter..traits..iterator..Iterator$GT$::try_fold::h4735bf7f64bdaf02(self=0x0000000170232b58, init=<unavailable>, g={closure_env#0}<core::iter::adapters::map::Map<alloc::vec::into_iter::IntoIter<sqlparser::ast::Expr, alloc::alloc::Global>, datafusion_sql::expr::value::{impl#0}::sql_array_literal::{closure_env#0}<datafusion::execution::session_state::SessionContextProvider>>, core::result::Result<core::convert::Infallible, datafusion_common::error::DataFusionError>, (), core::iter::traits::iterator::Iterator::try_for_each::call::{closure_env#0}<datafusion_expr::expr::Expr, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>, fn(datafusion_expr::expr::Expr) -> core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>>, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>> @ 0x0000000170232108) at �[36mmap.rs�[0m:�[33m122�[0m:�[33m9�[0m
    frame #29: �[33m0x00000001005d2f40�[0m sqllogictests-ac42652c86ad174a`_$LT$core..iter..adapters..GenericShunt$LT$I$C$R$GT$$u20$as$u20$core..iter..traits..iterator..Iterator$GT$::try_fold::h0ec4e279a8e32e3d(self=0x0000000170232b58, init=<unavailable>, f={closure_env#0}<datafusion_expr::expr::Expr, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>, fn(datafusion_expr::expr::Expr) -> core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>> @ 0x000000017023215f) at �[36mmod.rs�[0m:�[33m201�[0m:�[33m9�[0m
    frame #30: �[33m0x00000001005d0e64�[0m sqllogictests-ac42652c86ad174a`_$LT$core..iter..adapters..GenericShunt$LT$I$C$R$GT$$u20$as$u20$core..iter..traits..iterator..Iterator$GT$::next::haa640898d9ff18e1 at �[36miterator.rs�[0m:�[33m2472�[0m:�[33m9�[0m
    frame #31: �[33m0x00000001005d0e54�[0m sqllogictests-ac42652c86ad174a`_$LT$core..iter..adapters..GenericShunt$LT$I$C$R$GT$$u20$as$u20$core..iter..traits..iterator..Iterator$GT$::next::haa640898d9ff18e1(self=0x0000000170232b58) at �[36mmod.rs�[0m:�[33m184�[0m:�[33m14�[0m
    frame #32: �[33m0x00000001001de2fc�[0m sqllogictests-ac42652c86ad174a`_$LT$alloc..vec..Vec$LT$T$GT$$u20$as$u20$alloc..vec..spec_from_iter_nested..SpecFromIterNested$LT$T$C$I$GT$$GT$::from_iter::h0a544a1a59bae07f(iterator=<unavailable>) at �[36mspec_from_iter_nested.rs�[0m:�[33m26�[0m:�[33m32�[0m
    frame #33: �[33m0x0000000100257f78�[0m sqllogictests-ac42652c86ad174a`alloc::vec::in_place_collect::_$LT$impl$u20$alloc..vec..spec_from_iter..SpecFromIter$LT$T$C$I$GT$$u20$for$u20$alloc..vec..Vec$LT$T$GT$$GT$::from_iter::h28bd6c3936396d49(iterator=<unavailable>) at �[36min_place_collect.rs�[0m:�[33m245�[0m:�[33m9�[0m
    frame #34: �[33m0x000000010026c63c�[0m sqllogictests-ac42652c86ad174a`_$LT$alloc..vec..Vec$LT$T$GT$$u20$as$u20$core..iter..traits..collect..FromIterator$LT$T$GT$$GT$::from_iter::hc4d35fafb59fcf91(iter=<unavailable>) at �[36mmod.rs�[0m:�[33m2972�[0m:�[33m9�[0m
    frame #35: �[33m0x000000010053ade0�[0m sqllogictests-ac42652c86ad174a`_$LT$core..result..Result$LT$V$C$E$GT$$u20$as$u20$core..iter..traits..collect..FromIterator$LT$core..result..Result$LT$A$C$E$GT$$GT$$GT$::from_iter::_$u7b$$u7b$closure$u7d$$u7d$::h11ba652124830586 at �[36miterator.rs�[0m:�[33m2004�[0m:�[33m9�[0m
    frame #36: �[33m0x000000010053addc�[0m sqllogictests-ac42652c86ad174a`_$LT$core..result..Result$LT$V$C$E$GT$$u20$as$u20$core..iter..traits..collect..FromIterator$LT$core..result..Result$LT$A$C$E$GT$$GT$$GT$::from_iter::_$u7b$$u7b$closure$u7d$$u7d$::h11ba652124830586((null)=0x0000000170232bf7, i=<unavailable>) at �[36mresult.rs�[0m:�[33m1935�[0m:�[33m51�[0m
    frame #37: �[33m0x00000001005f3aa0�[0m sqllogictests-ac42652c86ad174a`core::iter::adapters::try_process::hc02972ea3a35822f(iter=<unavailable>, f={closure_env#0}<datafusion_expr::expr::Expr, datafusion_common::error::DataFusionError, alloc::vec::Vec<datafusion_expr::expr::Expr, alloc::alloc::Global>, core::iter::adapters::map::Map<alloc::vec::into_iter::IntoIter<sqlparser::ast::Expr, alloc::alloc::Global>, datafusion_sql::expr::value::{impl#0}::sql_array_literal::{closure_env#0}<datafusion::execution::session_state::SessionContextProvider>>> @ 0x0000000170232bf7) at �[36mmod.rs�[0m:�[33m170�[0m:�[33m17�[0m
    frame #38: �[33m0x0000000100539858�[0m sqllogictests-ac42652c86ad174a`_$LT$core..result..Result$LT$V$C$E$GT$$u20$as$u20$core..iter..traits..collect..FromIterator$LT$core..result..Result$LT$A$C$E$GT$$GT$$GT$::from_iter::h192073e1a8f55489(iter=<unavailable>) at �[36mresult.rs�[0m:�[33m1935�[0m:�[33m9�[0m
    frame #39: �[33m0x00000001003ae09c�[0m sqllogictests-ac42652c86ad174a`core::iter::traits::iterator::Iterator::collect::h2a11199afaa8fa12(self=<unavailable>) at �[36miterator.rs�[0m:�[33m2004�[0m:�[33m9�[0m
    frame #40: �[33m0x0000000100174a6c�[0m sqllogictests-ac42652c86ad174a`datafusion_sql::expr::value::_$LT$impl$u20$datafusion_sql..planner..SqlToRel$LT$S$GT$$GT$::sql_array_literal::h4d44e9d8cbf97873(self=0x00000001703ff270, elements=<unavailable>, schema=0x00006000002a3940) at �[36mvalue.rs�[0m:�[33m141�[0m:�[33m22�[0m
    frame #41: �[33m0x0000000100182a2c�[0m sqllogictests-ac42652c86ad174a`datafusion_sql::expr::_$LT$impl$u20$datafusion_sql..planner..SqlToRel$LT$S$GT$$GT$::sql_expr_to_logical_expr_internal::h9b44f811d2436c9f(self=0x00000001703ff270, sql=Expr @ 0x0000000170243b50, schema=0x00006000002a3940, planner_context=0x0000000170244e58) at �[36mmod.rs�[0m:�[33m199�[0m:�[33m36�[0m
    frame #42: �[33m0x00000001001803fc�[0m sqllogictests-ac42652c86ad174a`datafusion_sql::expr::_$LT$impl$u20$datafusion_sql..planner..SqlToRel$LT$S$GT$$GT$::sql_expr_to_logical_expr::h2ff0e8a146a45a93(self=0x00000001703ff270, sql=Expr @ 0x0000000170244d30, schema=0x00006000002a3940, planner_context=0x0000000170244e58) at �[36mmod.rs�[0m:�[33m82�[0m:�[33m40�[0m
    frame #43: �[33m0x0000000100138fb4�[0m sqllogictests-ac42652c86ad174a`datafusion_sql::expr::value::_$LT$impl$u20$datafusion_sql..planner..SqlToRel$LT$S$GT$$GT$::sql_array_literal::_$u7b$$u7b$closure$u7d$$u7d$::hd77cfb386f009aed(element=<unavailable>) at �[36mvalue.rs�[0m:�[33m144�[0m:�[33m17�[0m
    frame #44: �[33m0x00000001003b8d88�[0m sqllogictests-ac42652c86ad174a`core::iter::adapters::map::map_try_fold::_$u7b$$u7b$closure$u7d$$u7d$::hc2d7a57769576c2b(acc=<unavailable>, elt=<unavailable>) at �[36mmap.rs�[0m:�[33m96�[0m:�[33m28�[0m
    frame #45: �[33m0x000000010050ee88�[0m sqllogictests-ac42652c86ad174a`core::iter::traits::iterator::Iterator::try_fold::he6904ec7d95c9139(self=0x0000000170246458, init=<unavailable>, f={closure_env#0}<sqlparser::ast::Expr, core::result::Result<datafusion_expr::expr::Expr, datafusion_common::error::DataFusionError>, (), core::ops::control_flow::ControlFlow<core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>, ()>, datafusion_sql::expr::value::{impl#0}::sql_array_literal::{closure_env#0}<datafusion::execution::session_state::SessionContextProvider>, core::iter::adapters::{impl#0}::try_fold::{closure_env#0}<core::iter::adapters::map::Map<alloc::vec::into_iter::IntoIter<sqlparser::ast::Expr, alloc::alloc::Global>, datafusion_sql::expr::value::{impl#0}::sql_array_literal::{closure_env#0}<datafusion::execution::session_state::SessionContextProvider>>, core::result::Result<core::convert::Infallible, datafusion_common::error::DataFusionError>, (), core::iter::traits::iterator::Iterator::try_for_each::call::{closure_env#0}<datafusion_expr::expr::Expr, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>, fn(datafusion_expr::expr::Expr) -> core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>>, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>>> @ 0x00000001702459e0) at �[36miterator.rs�[0m:�[33m2410�[0m:�[33m21�[0m
    frame #46: �[33m0x00000001003a2ae8�[0m sqllogictests-ac42652c86ad174a`_$LT$core..iter..adapters..map..Map$LT$I$C$F$GT$$u20$as$u20$core..iter..traits..iterator..Iterator$GT$::try_fold::h4735bf7f64bdaf02(self=0x0000000170246458, init=<unavailable>, g={closure_env#0}<core::iter::adapters::map::Map<alloc::vec::into_iter::IntoIter<sqlparser::ast::Expr, alloc::alloc::Global>, datafusion_sql::expr::value::{impl#0}::sql_array_literal::{closure_env#0}<datafusion::execution::session_state::SessionContextProvider>>, core::result::Result<core::convert::Infallible, datafusion_common::error::DataFusionError>, (), core::iter::traits::iterator::Iterator::try_for_each::call::{closure_env#0}<datafusion_expr::expr::Expr, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>, fn(datafusion_expr::expr::Expr) -> core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>>, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>> @ 0x0000000170245a08) at �[36mmap.rs�[0m:�[33m122�[0m:�[33m9�[0m
    frame #47: �[33m0x00000001005d2f40�[0m sqllogictests-ac42652c86ad174a`_$LT$core..iter..adapters..GenericShunt$LT$I$C$R$GT$$u20$as$u20$core..iter..traits..iterator..Iterator$GT$::try_fold::h0ec4e279a8e32e3d(self=0x0000000170246458, init=<unavailable>, f={closure_env#0}<datafusion_expr::expr::Expr, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>, fn(datafusion_expr::expr::Expr) -> core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>> @ 0x0000000170245a5f) at �[36mmod.rs�[0m:�[33m201�[0m:�[33m9�[0m
    frame #48: �[33m0x00000001005d0e64�[0m sqllogictests-ac42652c86ad174a`_$LT$core..iter..adapters..GenericShunt$LT$I$C$R$GT$$u20$as$u20$core..iter..traits..iterator..Iterator$GT$::next::haa640898d9ff18e1 at �[36miterator.rs�[0m:�[33m2472�[0m:�[33m9�[0m
    frame #49: �[33m0x00000001005d0e54�[0m sqllogictests-ac42652c86ad174a`_$LT$core..iter..adapters..GenericShunt$LT$I$C$R$GT$$u20$as$u20$core..iter..traits..iterator..Iterator$GT$::next::haa640898d9ff18e1(self=0x0000000170246458) at �[36mmod.rs�[0m:�[33m184�[0m:�[33m14�[0m
    frame #50: �[33m0x00000001001de2fc�[0m sqllogictests-ac42652c86ad174a`_$LT$alloc..vec..Vec$LT$T$GT$$u20$as$u20$alloc..vec..spec_from_iter_nested..SpecFromIterNested$LT$T$C$I$GT$$GT$::from_iter::h0a544a1a59bae07f(iterator=<unavailable>) at �[36mspec_from_iter_nested.rs�[0m:�[33m26�[0m:�[33m32�[0m
    frame #51: �[33m0x0000000100257f78�[0m sqllogictests-ac42652c86ad174a`alloc::vec::in_place_collect::_$LT$impl$u20$alloc..vec..spec_from_iter..SpecFromIter$LT$T$C$I$GT$$u20$for$u20$alloc..vec..Vec$LT$T$GT$$GT$::from_iter::h28bd6c3936396d49(iterator=<unavailable>) at �[36min_place_collect.rs�[0m:�[33m245�[0m:�[33m9�[0m
    frame #52: �[33m0x000000010026c63c�[0m sqllogictests-ac42652c86ad174a`_$LT$alloc..vec..Vec$LT$T$GT$$u20$as$u20$core..iter..traits..collect..FromIterator$LT$T$GT$$GT$::from_iter::hc4d35fafb59fcf91(iter=<unavailable>) at �[36mmod.rs�[0m:�[33m2972�[0m:�[33m9�[0m
    frame #53: �[33m0x000000010053ade0�[0m sqllogictests-ac42652c86ad174a`_$LT$core..result..Result$LT$V$C$E$GT$$u20$as$u20$core..iter..traits..collect..FromIterator$LT$core..result..Result$LT$A$C$E$GT$$GT$$GT$::from_iter::_$u7b$$u7b$closure$u7d$$u7d$::h11ba652124830586 at �[36miterator.rs�[0m:�[33m2004�[0m:�[33m9�[0m
    frame #54: �[33m0x000000010053addc�[0m sqllogictests-ac42652c86ad174a`_$LT$core..result..Result$LT$V$C$E$GT$$u20$as$u20$core..iter..traits..collect..FromIterator$LT$core..result..Result$LT$A$C$E$GT$$GT$$GT$::from_iter::_$u7b$$u7b$closure$u7d$$u7d$::h11ba652124830586((null)=0x00000001702464f7, i=<unavailable>) at �[36mresult.rs�[0m:�[33m1935�[0m:�[33m51�[0m
    frame #55: �[33m0x00000001005f3aa0�[0m sqllogictests-ac42652c86ad174a`core::iter::adapters::try_process::hc02972ea3a35822f(iter=<unavailable>, f={closure_env#0}<datafusion_expr::expr::Expr, datafusion_common::error::DataFusionError, alloc::vec::Vec<datafusion_expr::expr::Expr, alloc::alloc::Global>, core::iter::adapters::map::Map<alloc::vec::into_iter::IntoIter<sqlparser::ast::Expr, alloc::alloc::Global>, datafusion_sql::expr::value::{impl#0}::sql_array_literal::{closure_env#0}<datafusion::execution::session_state::SessionContextProvider>>> @ 0x00000001702464f7) at �[36mmod.rs�[0m:�[33m170�[0m:�[33m17�[0m
    frame #56: �[33m0x0000000100539858�[0m sqllogictests-ac42652c86ad174a`_$LT$core..result..Result$LT$V$C$E$GT$$u20$as$u20$core..iter..traits..collect..FromIterator$LT$core..result..Result$LT$A$C$E$GT$$GT$$GT$::from_iter::h192073e1a8f55489(iter=<unavailable>) at �[36mresult.rs�[0m:�[33m1935�[0m:�[33m9�[0m
    frame #57: �[33m0x00000001003ae09c�[0m sqllogictests-ac42652c86ad174a`core::iter::traits::iterator::Iterator::collect::h2a11199afaa8fa12(self=<unavailable>) at �[36miterator.rs�[0m:�[33m2004�[0m:�[33m9�[0m
    frame #58: �[33m0x0000000100174a6c�[0m sqllogictests-ac42652c86ad174a`datafusion_sql::expr::value::_$LT$impl$u20$datafusion_sql..planner..SqlToRel$LT$S$GT$$GT$::sql_array_literal::h4d44e9d8cbf97873(self=0x00000001703ff270, elements=<unavailable>, schema=0x00006000002a3940) at �[36mvalue.rs�[0m:�[33m141�[0m:�[33m22�[0m
    frame #59: �[33m0x0000000100182a2c�[0m sqllogictests-ac42652c86ad174a`datafusion_sql::expr::_$LT$impl$u20$datafusion_sql..planner..SqlToRel$LT$S$GT$$GT$::sql_expr_to_logical_expr_internal::h9b44f811d2436c9f(self=0x00000001703ff270, sql=Expr @ 0x0000000170257450, schema=0x00006000002a3940, planner_context=0x0000000170258758) at �[36mmod.rs�[0m:�[33m199�[0m:�[33m36�[0m
    frame #60: �[33m0x00000001001803fc�[0m sqllogictests-ac42652c86ad174a`datafusion_sql::expr::_$LT$impl$u20$datafusion_sql..planner..SqlToRel$LT$S$GT$$GT$::sql_expr_to_logical_expr::h2ff0e8a146a45a93(self=0x00000001703ff270, sql=Expr @ 0x0000000170258630, schema=0x00006000002a3940, planner_context=0x0000000170258758) at �[36mmod.rs�[0m:�[33m82�[0m:�[33m40�[0m
    frame #61: �[33m0x0000000100138fb4�[0m sqllogictests-ac42652c86ad174a`datafusion_sql::expr::value::_$LT$impl$u20$datafusion_sql..planner..SqlToRel$LT$S$GT$$GT$::sql_array_literal::_$u7b$$u7b$closure$u7d$$u7d$::hd77cfb386f009aed(element=<unavailable>) at �[36mvalue.rs�[0m:�[33m144�[0m:�[33m17�[0m
    frame #62: �[33m0x00000001003b8d88�[0m sqllogictests-ac42652c86ad174a`core::iter::adapters::map::map_try_fold::_$u7b$$u7b$closure$u7d$$u7d$::hc2d7a57769576c2b(acc=<unavailable>, elt=<unavailable>) at �[36mmap.rs�[0m:�[33m96�[0m:�[33m28�[0m
    frame #63: �[33m0x000000010050ee88�[0m sqllogictests-ac42652c86ad174a`core::iter::traits::iterator::Iterator::try_fold::he6904ec7d95c9139(self=0x0000000170259d58, init=<unavailable>, f={closure_env#0}<sqlparser::ast::Expr, core::result::Result<datafusion_expr::expr::Expr, datafusion_common::error::DataFusionError>, (), core::ops::control_flow::ControlFlow<core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>, ()>, datafusion_sql::expr::value::{impl#0}::sql_array_literal::{closure_env#0}<datafusion::execution::session_state::SessionContextProvider>, core::iter::adapters::{impl#0}::try_fold::{closure_env#0}<core::iter::adapters::map::Map<alloc::vec::into_iter::IntoIter<sqlparser::ast::Expr, alloc::alloc::Global>, datafusion_sql::expr::value::{impl#0}::sql_array_literal::{closure_env#0}<datafusion::execution::session_state::SessionContextProvider>>, core::result::Result<core::convert::Infallible, datafusion_common::error::DataFusionError>, (), core::iter::traits::iterator::Iterator::try_for_each::call::{closure_env#0}<datafusion_expr::expr::Expr, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>, fn(datafusion_expr::expr::Expr) -> core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>>, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>>> @ 0x00000001702592e0) at �[36miterator.rs�[0m:�[33m2410�[0m:�[33m21�[0m
    frame #64: �[33m0x00000001003a2ae8�[0m sqllogictests-ac42652c86ad174a`_$LT$core..iter..adapters..map..Map$LT$I$C$F$GT$$u20$as$u20$core..iter..traits..iterator..Iterator$GT$::try_fold::h4735bf7f64bdaf02(self=0x0000000170259d58, init=<unavailable>, g={closure_env#0}<core::iter::adapters::map::Map<alloc::vec::into_iter::IntoIter<sqlparser::ast::Expr, alloc::alloc::Global>, datafusion_sql::expr::value::{impl#0}::sql_array_literal::{closure_env#0}<datafusion::execution::session_state::SessionContextProvider>>, core::result::Result<core::convert::Infallible, datafusion_common::error::DataFusionError>, (), core::iter::traits::iterator::Iterator::try_for_each::call::{closure_env#0}<datafusion_expr::expr::Expr, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>, fn(datafusion_expr::expr::Expr) -> core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>>, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>> @ 0x0000000170259308) at �[36mmap.rs�[0m:�[33m122�[0m:�[33m9�[0m
    frame #65: �[33m0x00000001005d2f40�[0m sqllogictests-ac42652c86ad174a`_$LT$core..iter..adapters..GenericShunt$LT$I$C$R$GT$$u20$as$u20$core..iter..traits..iterator..Iterator$GT$::try_fold::h0ec4e279a8e32e3d(self=0x0000000170259d58, init=<unavailable>, f={closure_env#0}<datafusion_expr::expr::Expr, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>, fn(datafusion_expr::expr::Expr) -> core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>> @ 0x000000017025935f) at �[36mmod.rs�[0m:�[33m201�[0m:�[33m9�[0m
    frame #66: �[33m0x00000001005d0e64�[0m sqllogictests-ac42652c86ad174a`_$LT$core..iter..adapters..GenericShunt$LT$I$C$R$GT$$u20$as$u20$core..iter..traits..iterator..Iterator$GT$::next::haa640898d9ff18e1 at �[36miterator.rs�[0m:�[33m2472�[0m:�[33m9�[0m
    frame #67: �[33m0x00000001005d0e54�[0m sqllogictests-ac42652c86ad174a`_$LT$core..iter..adapters..GenericShunt$LT$I$C$R$GT$$u20$as$u20$core..iter..traits..iterator..Iterator$GT$::next::haa640898d9ff18e1(self=0x0000000170259d58) at �[36mmod.rs�[0m:�[33m184�[0m:�[33m14�[0m
    frame #68: �[33m0x00000001001de2fc�[0m sqllogictests-ac42652c86ad174a`_$LT$alloc..vec..Vec$LT$T$GT$$u20$as$u20$alloc..vec..spec_from_iter_nested..SpecFromIterNested$LT$T$C$I$GT$$GT$::from_iter::h0a544a1a59bae07f(iterator=<unavailable>) at �[36mspec_from_iter_nested.rs�[0m:�[33m26�[0m:�[33m32�[0m
    frame #69: �[33m0x0000000100257f78�[0m sqllogictests-ac42652c86ad174a`alloc::vec::in_place_collect::_$LT$impl$u20$alloc..vec..spec_from_iter..SpecFromIter$LT$T$C$I$GT$$u20$for$u20$alloc..vec..Vec$LT$T$GT$$GT$::from_iter::h28bd6c3936396d49(iterator=<unavailable>) at �[36min_place_collect.rs�[0m:�[33m245�[0m:�[33m9�[0m
    frame #70: �[33m0x000000010026c63c�[0m sqllogictests-ac42652c86ad174a`_$LT$alloc..vec..Vec$LT$T$GT$$u20$as$u20$core..iter..traits..collect..FromIterator$LT$T$GT$$GT$::from_iter::hc4d35fafb59fcf91(iter=<unavailable>) at �[36mmod.rs�[0m:�[33m2972�[0m:�[33m9�[0m
    frame #71: �[33m0x000000010053ade0�[0m sqllogictests-ac42652c86ad174a`_$LT$core..result..Result$LT$V$C$E$GT$$u20$as$u20$core..iter..traits..collect..FromIterator$LT$core..result..Result$LT$A$C$E$GT$$GT$$GT$::from_iter::_$u7b$$u7b$closure$u7d$$u7d$::h11ba652124830586 at �[36miterator.rs�[0m:�[33m2004�[0m:�[33m9�[0m
    frame #72: �[33m0x000000010053addc�[0m sqllogictests-ac42652c86ad174a`_$LT$core..result..Result$LT$V$C$E$GT$$u20$as$u20$core..iter..traits..collect..FromIterator$LT$core..result..Result$LT$A$C$E$GT$$GT$$GT$::from_iter::_$u7b$$u7b$closure$u7d$$u7d$::h11ba652124830586((null)=0x0000000170259df7, i=<unavailable>) at �[36mresult.rs�[0m:�[33m1935�[0m:�[33m51�[0m
    frame #73: �[33m0x00000001005f3aa0�[0m sqllogictests-ac42652c86ad174a`core::iter::adapters::try_process::hc02972ea3a35822f(iter=<unavailable>, f={closure_env#0}<datafusion_expr::expr::Expr, datafusion_common::error::DataFusionError, alloc::vec::Vec<datafusion_expr::expr::Expr, alloc::alloc::Global>, core::iter::adapters::map::Map<alloc::vec::into_iter::IntoIter<sqlparser::ast::Expr, alloc::alloc::Global>, datafusion_sql::expr::value::{impl#0}::sql_array_literal::{closure_env#0}<datafusion::execution::session_state::SessionContextProvider>>> @ 0x0000000170259df7) at �[36mmod.rs�[0m:�[33m170�[0m:�[33m17�[0m
    frame #74: �[33m0x0000000100539858�[0m sqllogictests-ac42652c86ad174a`_$LT$core..result..Result$LT$V$C$E$GT$$u20$as$u20$core..iter..traits..collect..FromIterator$LT$core..result..Result$LT$A$C$E$GT$$GT$$GT$::from_iter::h192073e1a8f55489(iter=<unavailable>) at �[36mresult.rs�[0m:�[33m1935�[0m:�[33m9�[0m
    frame #75: �[33m0x00000001003ae09c�[0m sqllogictests-ac42652c86ad174a`core::iter::traits::iterator::Iterator::collect::h2a11199afaa8fa12(self=<unavailable>) at �[36miterator.rs�[0m:�[33m2004�[0m:�[33m9�[0m
    frame #76: �[33m0x0000000100174a6c�[0m sqllogictests-ac42652c86ad174a`datafusion_sql::expr::value::_$LT$impl$u20$datafusion_sql..planner..SqlToRel$LT$S$GT$$GT$::sql_array_literal::h4d44e9d8cbf97873(self=0x00000001703ff270, elements=<unavailable>, schema=0x00006000002a3940) at �[36mvalue.rs�[0m:�[33m141�[0m:�[33m22�[0m
    frame #77: �[33m0x0000000100182a2c�[0m sqllogictests-ac42652c86ad174a`datafusion_sql::expr::_$LT$impl$u20$datafusion_sql..planner..SqlToRel$LT$S$GT$$GT$::sql_expr_to_logical_expr_internal::h9b44f811d2436c9f(self=0x00000001703ff270, sql=Expr @ 0x000000017026ad50, schema=0x00006000002a3940, planner_context=0x000000017026c058) at �[36mmod.rs�[0m:�[33m199�[0m:�[33m36�[0m
    frame #78: �[33m0x00000001001803fc�[0m sqllogictests-ac42652c86ad174a`datafusion_sql::expr::_$LT$impl$u20$datafusion_sql..planner..SqlToRel$LT$S$GT$$GT$::sql_expr_to_logical_expr::h2ff0e8a146a45a93(self=0x00000001703ff270, sql=Expr @ 0x000000017026bf30, schema=0x00006000002a3940, planner_context=0x000000017026c058) at �[36mmod.rs�[0m:�[33m82�[0m:�[33m40�[0m
    frame #79: �[33m0x0000000100138fb4�[0m sqllogictests-ac42652c86ad174a`datafusion_sql::expr::value::_$LT$impl$u20$datafusion_sql..planner..SqlToRel$LT$S$GT$$GT$::sql_array_literal::_$u7b$$u7b$closure$u7d$$u7d$::hd77cfb386f009aed(element=<unavailable>) at �[36mvalue.rs�[0m:�[33m144�[0m:�[33m17�[0m
    frame #80: �[33m0x00000001003b8d88�[0m sqllogictests-ac42652c86ad174a`core::iter::adapters::map::map_try_fold::_$u7b$$u7b$closure$u7d$$u7d$::hc2d7a57769576c2b(acc=<unavailable>, elt=<unavailable>) at �[36mmap.rs�[0m:�[33m96�[0m:�[33m28�[0m
    frame #81: �[33m0x000000010050ee88�[0m sqllogictests-ac42652c86ad174a`core::iter::traits::iterator::Iterator::try_fold::he6904ec7d95c9139(self=0x000000017026d658, init=<unavailable>, f={closure_env#0}<sqlparser::ast::Expr, core::result::Result<datafusion_expr::expr::Expr, datafusion_common::error::DataFusionError>, (), core::ops::control_flow::ControlFlow<core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>, ()>, datafusion_sql::expr::value::{impl#0}::sql_array_literal::{closure_env#0}<datafusion::execution::session_state::SessionContextProvider>, core::iter::adapters::{impl#0}::try_fold::{closure_env#0}<core::iter::adapters::map::Map<alloc::vec::into_iter::IntoIter<sqlparser::ast::Expr, alloc::alloc::Global>, datafusion_sql::expr::value::{impl#0}::sql_array_literal::{closure_env#0}<datafusion::execution::session_state::SessionContextProvider>>, core::result::Result<core::convert::Infallible, datafusion_common::error::DataFusionError>, (), core::iter::traits::iterator::Iterator::try_for_each::call::{closure_env#0}<datafusion_expr::expr::Expr, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>, fn(datafusion_expr::expr::Expr) -> core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>>, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>>> @ 0x000000017026cbe0) at �[36miterator.rs�[0m:�[33m2410�[0m:�[33m21�[0m
    frame #82: �[33m0x00000001003a2ae8�[0m sqllogictests-ac42652c86ad174a`_$LT$core..iter..adapters..map..Map$LT$I$C$F$GT$$u20$as$u20$core..iter..traits..iterator..Iterator$GT$::try_fold::h4735bf7f64bdaf02(self=0x000000017026d658, init=<unavailable>, g={closure_env#0}<core::iter::adapters::map::Map<alloc::vec::into_iter::IntoIter<sqlparser::ast::Expr, alloc::alloc::Global>, datafusion_sql::expr::value::{impl#0}::sql_array_literal::{closure_env#0}<datafusion::execution::session_state::SessionContextProvider>>, core::result::Result<core::convert::Infallible, datafusion_common::error::DataFusionError>, (), core::iter::traits::iterator::Iterator::try_for_each::call::{closure_env#0}<datafusion_expr::expr::Expr, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>, fn(datafusion_expr::expr::Expr) -> core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>>, core::ops::control_flow::ControlFlow<datafusion_expr::expr::Expr, ()>> @ 0x000000017026cc08) at �[36mmap.rs�[0m:�[33m122�[0m:�[33m9�[0m
...
    frame #508: �[33m0x0000000103cb110c�[0m sqllogictests-ac42652c86ad174a`std::sys::pal::unix::thread::Thread::new::thread_start::h50a0ef5291b272f3 [inlined] _$LT$alloc..boxed..Box$LT$F$C$A$GT$$u20$as$u20$core..ops..function..FnOnce$LT$Args$GT$$GT$::call_once::h435242b988184cd5 at �[36mboxed.rs�[0m:�[33m2022�[0m:�[33m9�[0m [opt]
    frame #509: �[33m0x0000000103cb1100�[0m sqllogictests-ac42652c86ad174a`std::sys::pal::unix::thread::Thread::new::thread_start::h50a0ef5291b272f3 [inlined] _$LT$alloc..boxed..Box$LT$F$C$A$GT$$u20$as$u20$core..ops..function..FnOnce$LT$Args$GT$$GT$::call_once::h4e377725be3abcb1 at �[36mboxed.rs�[0m:�[33m2022�[0m:�[33m9�[0m [opt]
    frame #510: �[33m0x0000000103cb10fc�[0m sqllogictests-ac42652c86ad174a`std::sys::pal::unix::thread::Thread::new::thread_start::h50a0ef5291b272f3 at �[36mthread.rs�[0m:�[33m108�[0m:�[33m17�[0m [opt]
    frame #511: �[33m0x000000018b2eef94�[0m libsystem_pthread.dylib`_pthread_start + 136

@alamb
Copy link
Contributor

alamb commented Jul 15, 2024

Here is a smaller reproducer:

cargo test --features=backtrace --test sqllogictests -- array.slt

@alamb
Copy link
Contributor

alamb commented Jul 15, 2024

RUST_LOG=info cargo test --features=backtrace --test sqllogictests -- array.slt

Shows the issue appears to be in the handling of this query

select array_ndims(array_repeat(array_repeat(array_repeat(1, 3), 2), 1)), array_ndims([[[[[[[[[[[[[[[[[[[[[1]]]]]]]]]]]]]]]]]]]]]);
[2024-07-15T18:22:00Z INFO  datafusion_sqllogictest::engines::datafusion_engine::runner] [array.slt] Running query: "drop table array_ndims_table;"
[2024-07-15T18:22:00Z INFO  datafusion_sqllogictest::engines::datafusion_engine::runner] [array.slt] Running query: "drop table large_array_ndims_table"
[2024-07-15T18:22:00Z INFO  datafusion_sqllogictest::engines::datafusion_engine::runner] [array.slt] Running query: "select array_ndims(arrow_cast([null], 'List(List(List(Int64)))'));"
[2024-07-15T18:22:00Z INFO  datafusion_sqllogictest::engines::datafusion_engine::runner] [array.slt] Running query: "select array_ndims(array_repeat(array_repeat(array_repeat(1, 3), 2), 1)), array_ndims([[[[[[[[[[[[[[[[[[[[[1]]]]]]]]]]]]]]]]]]]]]);"

thread 'tokio-runtime-worker' has overflowed its stack
fatal runtime error: stack overflow
error: test failed, to rerun pass `-p datafusion-sqllogictest --test sqllogictests`

@alamb
Copy link
Contributor

alamb commented Jul 15, 2024

🤔 the comments suggest this is not a new problem:

// IMPORTANT: Keep sql_array_literal's function body small to prevent stack overflow
// This function is recursively called, potentially leading to deep call stacks.

@alamb
Copy link
Contributor

alamb commented Jul 15, 2024

What I suggest we do is:

  1. File a ticket to reduce the stack size more on debug builds somehow
  2. Merge this PR

Copy link
Contributor

@alamb alamb left a comment

Choose a reason for hiding this comment

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

Thank you @MohamedAbdeen21 -- I think this PR's code looks good to me.

The stack overflow is somewhat concerning. We should probably figure out how to handle that better (as a follow on PR).

I will wait to hear @comphead 's thoughts before merging this PR

@comphead
Copy link
Contributor

Thanks @alamb for your analysis, I think this PR is good to go, but we need to think on recursive calls.

Copy link
Contributor

@comphead comphead left a comment

Choose a reason for hiding this comment

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

lgtm thanks @MohamedAbdeen21

@alamb
Copy link
Contributor

alamb commented Jul 16, 2024

I plan to file the follow on ticket / description and then merge this later today

@alamb
Copy link
Contributor

alamb commented Jul 16, 2024

Filed #11499 to track looking into the stack overflow.

Thanks everyone

@alamb alamb merged commit 382bf4f into apache:main Jul 16, 2024
25 checks passed
xinlifoobar pushed a commit to xinlifoobar/datafusion that referenced this pull request Jul 17, 2024
* upgrade sqlparser 0.47 -> 0.48

* clean imports and qualified imports

* update df-cli cargo lock

* fix trailing commas in slt tests

* update slt tests results

* restore rowsort in slt tests

* fix slt tests

* rerun CI

* reset unchanged slt files

* Revert "clean imports and qualified imports"

This reverts commit 7be2263.

* update non-windows systems stack size

* update windows stack size

* remove windows-only unused import

* use same test main for all systems

* Reapply "clean imports and qualified imports"

This reverts commit 4fc036a.
xinlifoobar pushed a commit to xinlifoobar/datafusion that referenced this pull request Jul 18, 2024
* upgrade sqlparser 0.47 -> 0.48

* clean imports and qualified imports

* update df-cli cargo lock

* fix trailing commas in slt tests

* update slt tests results

* restore rowsort in slt tests

* fix slt tests

* rerun CI

* reset unchanged slt files

* Revert "clean imports and qualified imports"

This reverts commit 7be2263.

* update non-windows systems stack size

* update windows stack size

* remove windows-only unused import

* use same test main for all systems

* Reapply "clean imports and qualified imports"

This reverts commit 4fc036a.
wiedld pushed a commit to influxdata/arrow-datafusion that referenced this pull request Jul 31, 2024
* upgrade sqlparser 0.47 -> 0.48

* clean imports and qualified imports

* update df-cli cargo lock

* fix trailing commas in slt tests

* update slt tests results

* restore rowsort in slt tests

* fix slt tests

* rerun CI

* reset unchanged slt files

* Revert "clean imports and qualified imports"

This reverts commit 7be2263.

* update non-windows systems stack size

* update windows stack size

* remove windows-only unused import

* use same test main for all systems

* Reapply "clean imports and qualified imports"

This reverts commit 4fc036a.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
sql SQL Planner sqllogictest SQL Logic Tests (.slt)
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Trailing comma output misleading error message
3 participants