panic: error while handling EXPLAIN statement: internal error: panic at the `local` optimization stage - Githubissues

MaterializeInc / materialize

The Cloud Operational Data Store: use SQL to transform, deliver, and act on fast-changing data.

https://materialize.com

Other

5.7k stars 465 forks source link

panic: error while handling EXPLAIN statement: internal error: panic at the `local` optimization stage #22189

Open nrainer-materialize opened 10 months ago

nrainer-materialize commented 10 months ago

What version of Materialize are you using?

1b9f75927b87959d1e8f4709eabdca60156a7da0

What is the issue?

This panic occurred in two consequent builds in "Fast SQL logic tests" on main:

It did not occur one build later, so some flakiness might be involved.

forced panic[2m2023-10-04T19:29:40.205479Z[0m [31mERROR[0m [2mmz_adapter::coord::sequencer::inner[0m[2m:[0m error while handling EXPLAIN statement: internal error: panic at the `local` optimization stage
[2m2023-10-04T19:29:40.194261Z[0m [33m WARN[0m [1moptimize[0m[2m:[0m [2mmz_adapter::coord::sequencer::inner[0m[2m:[0m EXPLAIN ... BROKEN <query> is known to leak memory, use with caution
thread 'coordinator' panicked at 'forced panic', src/expr/src/scalar/func/impls/string.rs:1060:9
stack backtrace:
   0: rust_begin_unwind
   1: core::panicking::panic_fmt
   2: <mz_expr::scalar::func::impls::string::Panic as mz_expr::scalar::func::LazyUnaryFunc>::eval
   3: <mz_expr::scalar::func::UnaryFunc>::eval
   4: <mz_expr::scalar::MirScalarExpr>::eval
   5: <mz_expr::scalar::MirScalarExpr>::reduce::{closure#2}
   6: <mz_expr::scalar::MirScalarExpr>::reduce
   7: <mz_transform::fold_constants::FoldConstants>::action::<core::iter::adapters::map::Map<core::slice::iter::Iter<mz_repr::relation::RelationType>, <mz_transform::fold_constants::FoldConstants as mz_transform::Transform>::transform::{closure#0}::{closure#0}>>
   8: <mz_transform::fold_constants::FoldConstants as mz_transform::Transform>::transform::{closure#0}
   9: <mz_expr::relation::MirRelationExpr as mz_expr::visit::Visit>::try_visit_mut_post::<<mz_transform::fold_constants::FoldConstants as mz_transform::Transform>::transform::{closure#0}, mz_transform::TransformError>
  10: <mz_transform::fold_constants::FoldConstants as mz_transform::Transform>::transform
  11: <mz_transform::FuseAndCollapse as mz_transform::Transform>::transform
  12: <tracing::span::Span>::in_scope::<<mz_transform::Fixpoint as mz_transform::Transform>::transform::{closure#1}, core::result::Result<(), mz_transform::TransformError>>
  13: <mz_transform::Fixpoint as mz_transform::Transform>::transform
  14: <mz_transform::Optimizer>::optimize
  15: <core::panic::unwind_safe::AssertUnwindSafe<<mz_adapter::coord::Coordinator>::explain_query_optimizer_pipeline::{closure#0}::{closure#0}::{closure#2}> as core::ops::function::FnOnce<()>>::call_once
  16: mz_ore::panic::catch_unwind::<core::panic::unwind_safe::AssertUnwindSafe<<mz_adapter::coord::Coordinator>::explain_query_optimizer_pipeline::{closure#0}::{closure#0}::{closure#2}>, core::result::Result<mz_expr::OptimizedMirRelationExpr, mz_adapter::error::AdapterError>>
  17: mz_adapter::coord::sequencer::inner::catch_unwind::<mz_expr::OptimizedMirRelationExpr, mz_adapter::error::AdapterError, <mz_adapter::coord::Coordinator>::explain_query_optimizer_pipeline::{closure#0}::{closure#0}::{closure#2}>
  18: <mz_adapter::coord::Coordinator>::explain_query_optimizer_pipeline::{closure#0}::{closure#0}
  19: <mz_adapter::coord::Coordinator>::sequence_explain_plan::{closure#0}
  20: <mz_adapter::coord::Coordinator>::sequence_plan::{closure#0}::{closure#0}
  21: <mz_adapter::coord::Coordinator>::sequence_plan::{closure#0}
  22: <mz_adapter::coord::Coordinator>::handle_execute_inner::{closure#0}::{closure#0}
  23: <mz_adapter::coord::Coordinator>::handle_execute_inner::{closure#0}
  24: <mz_adapter::coord::Coordinator>::handle_execute::{closure#0}::{closure#0}
  25: <mz_adapter::coord::Coordinator>::handle_command::{closure#0}
  26: <mz_adapter::coord::Coordinator>::message_command::{closure#0}::{closure#0}
  27: <mz_adapter::coord::Coordinator>::handle_message::{closure#0}
  28: <tracing::instrument::Instrumented<<mz_adapter::coord::Coordinator>::handle_message::{closure#0}> as core::future::future::Future>::poll
  29: <mz_ore::metrics::WallTimeFuture<tracing::instrument::Instrumented<<mz_adapter::coord::Coordinator>::handle_message::{closure#0}>, prometheus::histogram::Histogram> as core::future::future::Future>::poll
  30: <tracing::instrument::Instrumented<<mz_adapter::coord::Coordinator>::serve::{closure#0}> as core::future::future::Future>::poll
  31: <tokio::runtime::park::CachedParkThread>::block_on::<tracing::instrument::Instrumented<<mz_adapter::coord::Coordinator>::serve::{closure#0}>>
  32: <tokio::runtime::handle::Handle>::block_on::<<mz_adapter::coord::Coordinator>::serve::{closure#0}>
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
forced panic[2m2023-10-04T19:29:40.205479Z[0m [31mERROR[0m [2mmz_adapter::coord::sequencer::inner[0m[2m:[0m error while handling EXPLAIN statement: internal error: panic at the `local` optimization stage
[2m2023-10-04T19:29:40.206493Z[0m [33m WARN[0m [1moptimize[0m[2m:[0m [2mmz_adapter::coord::sequencer::inner[0m[2m:[0m EXPLAIN ... BROKEN <query> is known to leak memory, use with caution
thread 'coordinator' panicked at 'forced panic', src/expr/src/scalar/func/impls/string.rs:1060:9
stack backtrace:
   0: rust_begin_unwind
   1: core::panicking::panic_fmt
   2: <mz_expr::scalar::func::impls::string::Panic as mz_expr::scalar::func::LazyUnaryFunc>::eval
   3: <mz_expr::scalar::func::UnaryFunc>::eval
   4: <mz_expr::scalar::MirScalarExpr>::eval
   5: <mz_expr::scalar::MirScalarExpr>::reduce::{closure#2}
   6: <mz_expr::scalar::MirScalarExpr>::reduce
   7: <mz_transform::fold_constants::FoldConstants>::action::<core::iter::adapters::map::Map<core::slice::iter::Iter<mz_repr::relation::RelationType>, <mz_transform::fold_constants::FoldConstants as mz_transform::Transform>::transform::{closure#0}::{closure#0}>>
   8: <mz_transform::fold_constants::FoldConstants as mz_transform::Transform>::transform::{closure#0}
   9: <mz_expr::relation::MirRelationExpr as mz_expr::visit::Visit>::try_visit_mut_post::<<mz_transform::fold_constants::FoldConstants as mz_transform::Transform>::transform::{closure#0}, mz_transform::TransformError>
  10: <mz_transform::fold_constants::FoldConstants as mz_transform::Transform>::transform
  11: <mz_transform::FuseAndCollapse as mz_transform::Transform>::transform
  12: <tracing::span::Span>::in_scope::<<mz_transform::Fixpoint as mz_transform::Transform>::transform::{closure#1}, core::result::Result<(), mz_transform::TransformError>>
  13: <mz_transform::Fixpoint as mz_transform::Transform>::transform
  14: <mz_transform::Optimizer>::optimize
  15: <core::panic::unwind_safe::AssertUnwindSafe<<mz_adapter::coord::Coordinator>::explain_query_optimizer_pipeline::{closure#0}::{closure#0}::{closure#2}> as core::ops::function::FnOnce<()>>::call_once
  16: mz_ore::panic::catch_unwind::<core::panic::unwind_safe::AssertUnwindSafe<<mz_adapter::coord::Coordinator>::explain_query_optimizer_pipeline::{closure#0}::{closure#0}::{closure#2}>, core::result::Result<mz_expr::OptimizedMirRelationExpr, mz_adapter::error::AdapterError>>
  17: mz_adapter::coord::sequencer::inner::catch_unwind::<mz_expr::OptimizedMirRelationExpr, mz_adapter::error::AdapterError, <mz_adapter::coord::Coordinator>::explain_query_optimizer_pipeline::{closure#0}::{closure#0}::{closure#2}>
  18: <mz_adapter::coord::Coordinator>::explain_query_optimizer_pipeline::{closure#0}::{closure#0}
  19: <mz_adapter::coord::Coordinator>::sequence_explain_plan::{closure#0}
  20: <mz_adapter::coord::Coordinator>::sequence_plan::{closure#0}::{closure#0}
  21: <mz_adapter::coord::Coordinator>::sequence_plan::{closure#0}
  22: <mz_adapter::coord::Coordinator>::handle_execute_inner::{closure#0}::{closure#0}
  23: <mz_adapter::coord::Coordinator>::handle_execute_inner::{closure#0}
  24: <mz_adapter::coord::Coordinator>::handle_execute::{closure#0}::{closure#0}
  25: <mz_adapter::coord::Coordinator>::handle_command::{closure#0}
  26: <mz_adapter::coord::Coordinator>::message_command::{closure#0}::{closure#0}
  27: <mz_adapter::coord::Coordinator>::handle_message::{closure#0}
  28: <tracing::instrument::Instrumented<<mz_adapter::coord::Coordinator>::handle_message::{closure#0}> as core::future::future::Future>::poll
  29: <mz_ore::metrics::WallTimeFuture<tracing::instrument::Instrumented<<mz_adapter::coord::Coordinator>::handle_message::{closure#0}>, prometheus::histogram::Histogram> as core::future::future::Future>::poll
  30: <tracing::instrument::Instrumented<<mz_adapter::coord::Coordinator>::serve::{closure#0}> as core::future::future::Future>::poll
  31: <tokio::runtime::park::CachedParkThread>::block_on::<tracing::instrument::Instrumented<<mz_adapter::coord::Coordinator>::serve::{closure#0}>>
  32: <tokio::runtime::handle::Handle>::block_on::<<mz_adapter::coord::Coordinator>::serve::{closure#0}>
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
forced panic[2m2023-10-04T19:29:40.207407Z[0m [31mERROR[0m [2mmz_adapter::coord::sequencer::inner[0m[2m:[0m error while handling EXPLAIN statement: internal error: panic at the `local` optimization stage

aalexandrov commented 10 months ago

Well, the optimization tried to constant-fold an mz_panic call. Without knowing the input query it's a bit hard to figure out if this is "things working as expected" or not. Let's keep an eye for further incarnations of that flake.

BTW, it's strange that we're seeing this now because we have not make changes to the optimizer transforms in a while.