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

SQL parameter error when querying risingwave via Postgres FDW #17661

Closed
DarthVagen opened this issue Jul 11, 2024 · 7 comments · Fixed by #19043
Closed

SQL parameter error when querying risingwave via Postgres FDW #17661

DarthVagen opened this issue Jul 11, 2024 · 7 comments · Fixed by #19043
Assignees
Labels
type/bug Something isn't working
Milestone

Comments

@DarthVagen
Copy link

Describe the bug

I build some tables in risingwave, and import them as foreign tables to postgres via FDW (postgres_fdw plugin), then I query postgres foreign tables using SpringData JPA (which uses Hibernate inside). I execute one same query for 10 times, for the first 9 times everything woks fine, but at the last time, risingwave throws error as shown in Error messge/log below.
I inspected all this 10 times query SQL statement genereated by hibernate and I found they are same. I dumped risingwave's query log and I found that postgres_fdw deliver a wrong SQL to risingwave at the last time which is:

DECLARE c1 CURSOR FOR  SELECT id, trading_date, volume FROM public.tb_cjg_1 WHERE ((id = CAST($1 AS INT)))

I show the detailes in Error message/log and To Reproduce block below.

Error message/log

RisingWave docker container log:
2024-07-10T10:06:49.482192542Z  INFO rw-batch-local local_execute{query_id="0c77a7cd-8b6f-44d1-a6c8-39c1bfcd8b1f" epoch=BatchQueryEpoch { epoch: Some(Committed(6774509286981632)) }}:batch_executor{otel.name="BatchExchange-0"}: risingwave_common_metrics::monitor::connection: monitoring connector hyper::client::connect::http::HttpConnector<risingwave_common_metrics::monitor::connection::MonitoredGaiResolver> with type grpc-compute-client
thread 'rw-main' panicked at src/frontend/src/optimizer/plan_expr_rewriter/const_eval_rewriter.rs:46:43:
internal error: entered unreachable code: Parameter should not appear here. It will be replaced by a literal before this step.
stack backtrace:
   0: rust_begin_unwind
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/std/src/panicking.rs:645:5
   1: core::panicking::panic_fmt
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/core/src/panicking.rs:72:14
   2: <risingwave_frontend::optimizer::plan_expr_rewriter::const_eval_rewriter::ConstEvalRewriter as risingwave_frontend::expr::expr_rewriter::ExprRewriter>::rewrite_expr
             at ./risingwave/src/frontend/src/optimizer/plan_expr_rewriter/const_eval_rewriter.rs:46:43
   3: risingwave_frontend::expr::expr_rewriter::ExprRewriter::rewrite_window_function::{{closure}}
             at ./risingwave/src/frontend/src/expr/expr_rewriter.rs:126:25
   4: core::iter::adapters::map::map_try_fold::{{closure}}
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/core/src/iter/adapters/map.rs:92:28
   5: core::iter::traits::iterator::Iterator::try_fold
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/core/src/iter/traits/iterator.rs:2462:21
   6: <core::iter::adapters::map::Map<I,F> as core::iter::traits::iterator::Iterator>::try_fold
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/core/src/iter/adapters/map.rs:118:9
   7: <I as alloc::vec::in_place_collect::SpecInPlaceCollect<T,I>>::collect_in_place
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/alloc/src/vec/in_place_collect.rs:361:13
   8: alloc::vec::in_place_collect::<impl alloc::vec::spec_from_iter::SpecFromIter<T,I> for alloc::vec::Vec<T>>::from_iter
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/alloc/src/vec/in_place_collect.rs:249:28
   9: <alloc::vec::Vec<T> as core::iter::traits::collect::FromIterator<T>>::from_iter
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/alloc/src/vec/mod.rs:2791:9
  10: core::iter::traits::iterator::Iterator::collect
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/core/src/iter/traits/iterator.rs:2054:9
  11: risingwave_frontend::expr::expr_rewriter::ExprRewriter::rewrite_function_call
             at ./risingwave/src/frontend/src/expr/expr_rewriter.rs:49:14
  12: <risingwave_frontend::optimizer::plan_expr_rewriter::const_eval_rewriter::ConstEvalRewriter as risingwave_frontend::expr::expr_rewriter::ExprRewriter>::rewrite_expr
             at ./risingwave/src/frontend/src/optimizer/plan_expr_rewriter/const_eval_rewriter.rs:38:50
  13: <risingwave_frontend::optimizer::plan_node::batch_hop_window::BatchHopWindow as risingwave_frontend::optimizer::plan_node::expr_rewritable::ExprRewritable>::rewrite_exprs::{{closure}}
             at ./risingwave/src/frontend/src/optimizer/plan_node/batch_hop_window.rs:153:26
  14: core::iter::adapters::map::map_try_fold::{{closure}}
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/core/src/iter/adapters/map.rs:92:28
  15: core::iter::traits::iterator::Iterator::try_fold
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/core/src/iter/traits/iterator.rs:2462:21
  16: <core::iter::adapters::map::Map<I,F> as core::iter::traits::iterator::Iterator>::try_fold
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/core/src/iter/adapters/map.rs:118:9
  17: <I as alloc::vec::in_place_collect::SpecInPlaceCollect<T,I>>::collect_in_place
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/alloc/src/vec/in_place_collect.rs:361:13
  18: alloc::vec::in_place_collect::<impl alloc::vec::spec_from_iter::SpecFromIter<T,I> for alloc::vec::Vec<T>>::from_iter
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/alloc/src/vec/in_place_collect.rs:249:28
  19: <alloc::vec::Vec<T> as core::iter::traits::collect::FromIterator<T>>::from_iter
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/alloc/src/vec/mod.rs:2791:9
  20: core::iter::traits::iterator::Iterator::collect
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/core/src/iter/traits/iterator.rs:2054:9
  21: risingwave_frontend::utils::condition::Condition::rewrite_expr
             at ./risingwave/src/frontend/src/utils/condition.rs:826:18
  22: risingwave_frontend::optimizer::plan_node::generic::table_scan::TableScan::rewrite_exprs
             at ./risingwave/src/frontend/src/optimizer/plan_node/generic/table_scan.rs:71:26
  23: <risingwave_frontend::optimizer::plan_node::logical_scan::LogicalScan as risingwave_frontend::optimizer::plan_node::expr_rewritable::ExprRewritable>::rewrite_exprs
             at ./risingwave/src/frontend/src/optimizer/plan_node/logical_scan.rs:371:9
  24: <risingwave_frontend::optimizer::plan_node::PlanRef as risingwave_frontend::optimizer::plan_node::expr_rewritable::ExprRewritable>::rewrite_exprs
             at ./risingwave/src/frontend/src/optimizer/plan_node/expr_rewritable.rs:42:13
  25: <risingwave_frontend::optimizer::plan_node::PlanRef as risingwave_frontend::optimizer::plan_node::RewriteExprsRecursive>::rewrite_exprs_recursive
             at ./risingwave/src/frontend/src/optimizer/plan_node/mod.rs:298:19
  26: risingwave_frontend::optimizer::const_eval_exprs
             at ./risingwave/src/frontend/src/optimizer/mod.rs:1008:16
  27: risingwave_frontend::optimizer::PlanRoot::gen_batch_plan
             at ./risingwave/src/frontend/src/optimizer/mod.rs:319:16
  28: risingwave_frontend::handler::query::gen_batch_query_plan
             at ./risingwave/src/frontend/src/handler/query.rs:175:22
  29: risingwave_frontend::handler::query::gen_batch_plan_by_statement
             at ./risingwave/src/frontend/src/handler/query.rs:109:5
  30: risingwave_frontend::handler::declare_cursor::create_stream_for_cursor_stmt::{{closure}}
             at ./risingwave/src/frontend/src/handler/declare_cursor.rs:132:27
  31: risingwave_frontend::handler::declare_cursor::handle_declare_query_cursor::{{closure}}
             at ./risingwave/src/frontend/src/handler/declare_cursor.rs:116:85
  32: risingwave_frontend::handler::declare_cursor::handle_declare_cursor::{{closure}}
             at ./risingwave/src/frontend/src/handler/declare_cursor.rs:34:79
  33: risingwave_frontend::handler::handle::{{closure}}
             at ./risingwave/src/frontend/src/handler/mod.rs:369:71
  34: risingwave_frontend::handler::extended_handle::handle_execute::{{closure}}
             at ./risingwave/src/frontend/src/handler/extended_handle.rs:192:48
  35: <risingwave_frontend::session::SessionImpl as pgwire::pg_server::Session>::execute::{{closure}}
             at ./risingwave/src/frontend/src/session.rs:1242:48
  36: pgwire::pg_protocol::PgProtocol<S,SM>::process_execute_msg::{{closure}}
             at ./risingwave/src/utils/pgwire/src/pg_protocol.rs:824:58
  37: pgwire::pg_protocol::PgProtocol<S,SM>::do_process_inner::{{closure}}
             at ./risingwave/src/utils/pgwire/src/pg_protocol.rs:429:63
  38: <core::pin::Pin<P> as core::future::future::Future>::poll
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/core/src/future/future.rs:124:9
  39: <tokio::task::task_local::TaskLocalFuture<T,F> as core::future::future::Future>::poll::{{closure}}
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/task/task_local.rs:391:31
  40: tokio::task::task_local::LocalKey<T>::scope_inner
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/task/task_local.rs:217:19
  41: <tokio::task::task_local::TaskLocalFuture<T,F> as core::future::future::Future>::poll
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/task/task_local.rs:387:19
  42: pgwire::pg_protocol::PgProtocol<S,SM>::do_process::{{closure}}::{{closure}}
             at ./risingwave/src/utils/pgwire/src/pg_protocol.rs:270:53
  43: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::future::future::Future>::poll
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/core/src/panic/unwind_safe.rs:297:9
  44: <futures_util::future::future::catch_unwind::CatchUnwind<Fut> as core::future::future::Future>::poll::{{closure}}
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.30/src/future/future/catch_unwind.rs:36:42
  45: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/core/src/panic/unwind_safe.rs:272:9
  46: std::panicking::try::do_call
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/std/src/panicking.rs:552:40
  47: std::panicking::try
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/std/src/panicking.rs:516:19
  48: std::panic::catch_unwind
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/std/src/panic.rs:142:14
  49: <futures_util::future::future::catch_unwind::CatchUnwind<Fut> as core::future::future::Future>::poll
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.30/src/future/future/catch_unwind.rs:36:9
  50: <tokio::task::task_local::TaskLocalFuture<T,F> as core::future::future::Future>::poll::{{closure}}
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/task/task_local.rs:391:31
  51: tokio::task::task_local::LocalKey<T>::scope_inner
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/task/task_local.rs:217:19
  52: <tokio::task::task_local::TaskLocalFuture<T,F> as core::future::future::Future>::poll
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/task/task_local.rs:387:19
  53: pgwire::pg_protocol::PgProtocol<S,SM>::do_process::{{closure}}::{{closure}}
             at ./risingwave/src/utils/pgwire/src/pg_protocol.rs:280:18
  54: <core::pin::Pin<P> as core::future::future::Future>::poll
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/core/src/future/future.rs:124:9
  55: <&mut F as core::future::future::Future>::poll
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/core/src/future/future.rs:112:9
  56: <tokio::time::timeout::Timeout<T> as core::future::future::Future>::poll
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/time/timeout.rs:202:33
  57: pgwire::pg_protocol::PgProtocol<S,SM>::do_process::{{closure}}::{{closure}}
             at ./risingwave/src/utils/pgwire/src/pg_protocol.rs:296:62
  58: pgwire::pg_protocol::PgProtocol<S,SM>::do_process::{{closure}}::{{closure}}
             at ./risingwave/src/utils/pgwire/src/pg_protocol.rs:313:30
  59: <tracing::instrument::Instrumented<T> as core::future::future::Future>::poll
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tracing-0.1.40/src/instrument.rs:321:9
  60: pgwire::pg_protocol::PgProtocol<S,SM>::do_process::{{closure}}
             at ./risingwave/src/utils/pgwire/src/pg_protocol.rs:340:19
  61: pgwire::pg_protocol::PgProtocol<S,SM>::process::{{closure}}
             at ./risingwave/src/utils/pgwire/src/pg_protocol.rs:220:30
  62: pgwire::pg_server::handle_connection::{{closure}}
             at ./risingwave/src/utils/pgwire/src/pg_server.rs:326:41
  63: <tracing::instrument::Instrumented<T> as core::future::future::Future>::poll
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tracing-0.1.40/src/instrument.rs:321:9
  64: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/core.rs:328:17
  65: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/loom/std/unsafe_cell.rs:16:9
  66: tokio::runtime::task::core::Core<T,S>::poll
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/core.rs:317:13
  67: tokio::runtime::task::harness::poll_future::{{closure}}
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:485:19
  68: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/core/src/panic/unwind_safe.rs:272:9
  69: std::panicking::try::do_call
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/std/src/panicking.rs:552:40
  70: std::panicking::try
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/std/src/panicking.rs:516:19
  71: std::panic::catch_unwind
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/std/src/panic.rs:142:14
  72: tokio::runtime::task::harness::poll_future
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:473:18
  73: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:208:27
  74: tokio::runtime::task::harness::Harness<T,S>::poll
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:153:15
  75: tokio::runtime::task::raw::poll
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/raw.rs:271:5
  76: tokio::runtime::task::raw::RawTask::poll
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/raw.rs:201:18
  77: tokio::runtime::task::LocalNotified<S>::run
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/mod.rs:427:9
  78: tokio::runtime::scheduler::multi_thread::worker::Context::run_task::{{closure}}
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/multi_thread/worker.rs:576:18
  79: tokio::runtime::coop::with_budget
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/coop.rs:107:5
  80: tokio::runtime::coop::budget
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/coop.rs:73:5
  81: tokio::runtime::scheduler::multi_thread::worker::Context::run_task
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/multi_thread/worker.rs:575:9
  82: tokio::runtime::scheduler::multi_thread::worker::Context::run
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/multi_thread/worker.rs:526:24
  83: tokio::runtime::scheduler::multi_thread::worker::run::{{closure}}::{{closure}}
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/multi_thread/worker.rs:491:21
  84: tokio::runtime::context::scoped::Scoped<T>::set
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/context/scoped.rs:40:9
  85: tokio::runtime::scheduler::multi_thread::worker::run::{{closure}}
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/multi_thread/worker.rs:486:9
  86: tokio::runtime::context::runtime::enter_runtime
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/context/runtime.rs:65:16
  87: tokio::runtime::scheduler::multi_thread::worker::run
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/multi_thread/worker.rs:478:5
  88: tokio::runtime::scheduler::multi_thread::worker::Launch::launch::{{closure}}
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/multi_thread/worker.rs:447:45
  89: <tokio::runtime::blocking::task::BlockingTask<T> as core::future::future::Future>::poll
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/blocking/task.rs:42:21
  90: <tracing::instrument::Instrumented<T> as core::future::future::Future>::poll
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tracing-0.1.40/src/instrument.rs:321:9
  91: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/core.rs:328:17
  92: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/loom/std/unsafe_cell.rs:16:9
  93: tokio::runtime::task::core::Core<T,S>::poll
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/core.rs:317:13
  94: tokio::runtime::task::harness::poll_future::{{closure}}
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:485:19
  95: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/core/src/panic/unwind_safe.rs:272:9
  96: std::panicking::try::do_call
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/std/src/panicking.rs:552:40
  97: std::panicking::try
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/std/src/panicking.rs:516:19
  98: std::panic::catch_unwind
             at ./rustc/e4c626dd9a17a23270bf8e7158e59cf2b9c04840/library/std/src/panic.rs:142:14
  99: tokio::runtime::task::harness::poll_future
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:473:18
 100: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:208:27
 101: tokio::runtime::task::harness::Harness<T,S>::poll
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:153:15
 102: tokio::runtime::task::raw::RawTask::poll
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/raw.rs:201:18
 103: tokio::runtime::task::UnownedTask<S>::run
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/mod.rs:464:9
 104: tokio::runtime::blocking::pool::Task::run
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/blocking/pool.rs:159:9
 105: tokio::runtime::blocking::pool::Inner::run
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/blocking/pool.rs:513:17
 106: tokio::runtime::blocking::pool::Spawner::spawn_thread::{{closure}}
             at ./root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/blocking/pool.rs:471:13
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
2024-07-10T10:06:53.56236599Z ERROR        rw-main handle_query{mode="extended query execute" session_id=9 sql=DECLARE c1 CURSOR FOR  SELECT id, trading_date, volume FROM public.tb_cjg_1 WHERE ((id = CAST($1 AS INT)))}: pgwire::pg_protocol: error when process message error=Panicked when handling the request: internal error: entered unreachable code: Parameter should not appear here. It will be replaced by a literal before this step.


RisingWave query.log :
2024-07-10T10:06:49.858986883Z        rw-main ThreadId(28) handle_query{mode="simple query" session_id=9 sql=START TRANSACTION ISOLATION LEVEL REPEATABLE READ}: status="ok" time=0ms
2024-07-10T10:06:49.900772908Z        rw-main ThreadId(28) handle_query{mode="extended query parse" session_id=9 sql=DECLARE c1 CURSOR FOR  SELECT id, trading_date, volume FROM public.tb_cjg_1 WHERE ((id = 1))}: status="ok" time=0ms
2024-07-10T10:06:49.901179156Z        rw-main ThreadId(28) handle_query{mode="extended query execute" session_id=9 sql=DECLARE c1 CURSOR FOR  SELECT id, trading_date, volume FROM public.tb_cjg_1 WHERE ((id = 1))}: status="ok" time=0ms
2024-07-10T10:06:49.944030826Z        rw-main ThreadId(27) handle_query{mode="simple query" session_id=9 sql=FETCH 100 FROM  c1}: status="ok" time=0ms
2024-07-10T10:06:49.986837188Z        rw-main ThreadId(28) handle_query{mode="simple query" session_id=9 sql=CLOSE c1}: status="ok" time=0ms
2024-07-10T10:06:50.025512976Z        rw-main ThreadId(31) handle_query{mode="simple query" session_id=9 sql=COMMIT}: status="ok" time=0ms
[REPEATED FOR 8 MORE TIMES]
2024-07-10T10:06:53.156812493Z        rw-main ThreadId(31) handle_query{mode="simple query" session_id=9 sql=START TRANSACTION ISOLATION LEVEL REPEATABLE READ}: status="ok" time=0ms
2024-07-10T10:06:53.197522425Z        rw-main ThreadId(31) handle_query{mode="extended query parse" session_id=9 sql=DECLARE c1 CURSOR FOR  SELECT id, trading_date, volume FROM public.tb_cjg_1 WHERE ((id = CAST($1 AS INT)))}: status="ok" time=0ms
2024-07-10T10:06:53.562408455Z        rw-main ThreadId(31) handle_query{mode="extended query execute" session_id=9 sql=DECLARE c1 CURSOR FOR  SELECT id, trading_date, volume FROM public.tb_cjg_1 WHERE ((id = CAST($1 AS INT)))}: status="err" time=364ms

To Reproduce

  1. create table in RisingWave
create table tb_cjg_1(id int , trading_date date, volume int, primary key(id));
insert into tb_cjg_1 values (1, '2024-07-10', 23);
  1. import this table to postgres as FDW
create server rw foreign data wrapper postgres_fdw options (host 'XXX', port 'XXX', dbname 'XXX'); 
create user mapping for postgres server rw options (user 'XXX', password 'XXX');
import foreign schema public from server rw into public;
  1. query postgres foreign table via SpingDate JPA
// Cjg.java
import jakarta.persistence.Entity;
import jakarta.persistence.Id;
import jakarta.persistence.Table;
import java.time.LocalDate;
import lombok.Data;

@Data
@Entity
@Table(name = "tb_cjg_1")
public class Cjg {

  @Id
  private Integer id;

  private LocalDate tradingDate;
  private Integer volume;
}

// CjgRepository.java
import java.util.Optional;
import org.springframework.data.jpa.repository.JpaRepository;

public interface CjgRepository extends JpaRepository<Cjg, Integer> {

  Optional<Cjg> findById(Integer id);
}

// App.java
import jakarta.annotation.Resource;
import org.springframework.boot.CommandLineRunner;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.context.annotation.Bean;
import play.repository.pg.CjgRepository;

@SpringBootApplication
public class App {

  @Resource
  private CjgRepository cjgRepository;

  public static void main(String[] args) {
    SpringApplication.run(App.class, args);
  }

  @Bean
  public CommandLineRunner runOffline() {
    return (args) -> {
      for (int i = 0; i < 10; ++i) {
        System.out.println(cjgRepository.findById(1));
      }
      System.exit(0);
    };
  }
}

Expected behavior

For the first 9 times, everything works fine, and you can see the correct SQL in RisingWave's query.log. And at the 10th time, query failed.

How did you deploy RisingWave?

via Docker Compose, one machine for all node, standalone mode. My docker-compose.yml is

---
version: "3"
x-image: &image
  image: nexus2.ipa.zs:5000/risingwavelabs/risingwave:v1.9.2
services:
  risingwave-standalone:
    <<: *image
    command: "standalone --meta-opts=\" \
                    --listen-addr 0.0.0.0:5690 \
                    --advertise-addr 0.0.0.0:5690 \
                    --dashboard-host 0.0.0.0:5691 \
                    --prometheus-host 0.0.0.0:1250 \
                    --prometheus-endpoint http://prometheus-0:9500 \
                    --backend sql \
                    --sql-endpoint postgres://postgres:@postgres-0:5432/metadata \
                    --state-store hummock+minio://hummockadmin:hummockadmin@minio-0:9301/hummock001 \
                    --data-directory hummock_001 \
                    --config-path /risingwave.toml\" \
                 --compute-opts=\" \
                    --config-path /risingwave.toml \
                    --listen-addr 0.0.0.0:5688 \
                    --prometheus-listener-addr 0.0.0.0:1250 \
                    --advertise-addr 0.0.0.0:5688 \
                    --async-stack-trace verbose \
                    # --parallelism 8 \
                    --total-memory-bytes 107374182400 \
                    --role both \
                    --meta-address http://0.0.0.0:5690\" \
                 --frontend-opts=\" \
                   --config-path /risingwave.toml \
                   --listen-addr 0.0.0.0:4566 \
                   --advertise-addr 0.0.0.0:4566 \
                   --prometheus-listener-addr 0.0.0.0:1250 \
                   --health-check-listener-addr 0.0.0.0:6786 \
                   --meta-addr http://0.0.0.0:5690\" \
                 --compactor-opts=\" \
                   --listen-addr 0.0.0.0:6660 \
                   --prometheus-listener-addr 0.0.0.0:1250 \
                   --advertise-addr 0.0.0.0:6660 \
                   --meta-address http://0.0.0.0:5690\""
    expose:
      - "6660"
      - "4566"
      - "5688"
      - "5690"
      - "1250"
      - "5691"
    ports:
      - "4566:4566"
      - "5690:5690"
      - "5691:5691"
      - "1250:1250"
    depends_on:
      - postgres-0
      - minio-0
    volumes:
      - "./risingwave.toml:/risingwave.toml"
      - "./logs:/logs"
    environment:
      RUST_BACKTRACE: "1"
      # If ENABLE_TELEMETRY is not set, telemetry will start by default
      ENABLE_TELEMETRY: ${ENABLE_TELEMETRY:-false}
      RW_QUERY_LOG_PATH: "/logs"
    container_name: risingwave-standalone
    healthcheck:
      test:
        - CMD-SHELL
        - bash -c 'printf \"GET / HTTP/1.1\n\n\" > /dev/tcp/127.0.0.1/6660; exit $$?;'
        - bash -c 'printf \"GET / HTTP/1.1\n\n\" > /dev/tcp/127.0.0.1/5688; exit $$?;'
        - bash -c 'printf \"GET / HTTP/1.1\n\n\" > /dev/tcp/127.0.0.1/4566; exit $$?;'
        - bash -c 'printf \"GET / HTTP/1.1\n\n\" > /dev/tcp/127.0.0.1/5690; exit $$?;'
      interval: 1s
      timeout: 5s
    restart: always
    deploy:
      resources:
        limits:
          cpus: '32'
          memory: 144G
        reservations:
          memory: 32G

  postgres-0:
    image: "nexus2.ipa.zs:5000/postgres:15-alpine"
    environment:
      - POSTGRES_HOST_AUTH_METHOD=trust
      - POSTGRES_USER=postgres
      - POSTGRES_DB=metadata
      - POSTGRES_INITDB_ARGS=--encoding=UTF-8 --lc-collate=C --lc-ctype=C
    expose:
      - "5432"
    ports:
      - "8432:5432"
    volumes:
      - "postgres-0:/var/lib/postgresql/data"
    healthcheck:
      test: [ "CMD-SHELL", "pg_isready -U postgres" ]
      interval: 2s
      timeout: 5s
      retries: 5
    restart: always

  grafana-0:
    image: "nexus2.ipa.zs:5000/grafana/grafana-oss:latest"
    command: []
    expose:
      - "3001"
    ports:
      - "3001:3001"
    depends_on: []
    volumes:
      - "grafana-0:/var/lib/grafana"
      - "./grafana.ini:/etc/grafana/grafana.ini"
      - "./grafana-risedev-datasource.yml:/etc/grafana/provisioning/datasources/grafana-risedev-datasource.yml"
      - "./grafana-risedev-dashboard.yml:/etc/grafana/provisioning/dashboards/grafana-risedev-dashboard.yml"
      - "./dashboards:/dashboards"
    environment: {}
    container_name: grafana-0
    healthcheck:
      test:
        - CMD-SHELL
        - bash -c 'printf \"GET / HTTP/1.1\n\n\" > /dev/tcp/127.0.0.1/3001; exit $$?;'
      interval: 1s
      timeout: 5s
      retries: 5
    restart: always

  minio-0:
    image: "nexus2.ipa.zs:5000/minio/minio:latest"
    command:
      - server
      - "--address"
      - "0.0.0.0:9301"
      - "--console-address"
      - "0.0.0.0:9400"
      - /data
    expose:
      - "9301"
      - "9400"
    ports:
      - "9301:9301"
      - "9400:9400"
    depends_on: []
    volumes:
      - "minio-0:/data"
    entrypoint: "

      /bin/sh -c '

      set -e

      mkdir -p \"/data/hummock001\"

      /usr/bin/docker-entrypoint.sh \"$$0\" \"$$@\"

      '"
    environment:
      MINIO_CI_CD: "1"
      MINIO_PROMETHEUS_AUTH_TYPE: public
      MINIO_PROMETHEUS_URL: "http://prometheus-0:9500"
      MINIO_ROOT_PASSWORD: hummockadmin
      MINIO_ROOT_USER: hummockadmin
      MINIO_DOMAIN: "minio-0"
    container_name: minio-0
    healthcheck:
      test:
        - CMD-SHELL
        - bash -c 'printf \"GET / HTTP/1.1\n\n\" > /dev/tcp/127.0.0.1/9301; exit $$?;'
      interval: 1s
      timeout: 5s
      retries: 5
    restart: always

  prometheus-0:
    image: "nexus2.ipa.zs:5000/prom/prometheus:latest"
    command:
      - "--config.file=/etc/prometheus/prometheus.yml"
      - "--storage.tsdb.path=/prometheus"
      - "--web.console.libraries=/usr/share/prometheus/console_libraries"
      - "--web.console.templates=/usr/share/prometheus/consoles"
      - "--web.listen-address=0.0.0.0:9500"
      - "--storage.tsdb.retention.time=30d"
    expose:
      - "9500"
    ports:
      - "9500:9500"
    depends_on: []
    volumes:
      - "prometheus-0:/prometheus"
      - "./prometheus.yaml:/etc/prometheus/prometheus.yml"
    environment: {}
    container_name: prometheus-0
    healthcheck:
      test:
        - CMD-SHELL
        - sh -c 'printf "GET /-/healthy HTTP/1.0\n\n" | nc localhost 9500; exit $$?;'
      interval: 1s
      timeout: 5s
      retries: 5
    restart: always

volumes:
  postgres-0:
    external: false
  grafana-0:
    external: false
  minio-0:
    external: false
  prometheus-0:
    external: false

The version of RisingWave

RisingWave version (select version();):
PostgreSQL 13.14.0-RisingWave-1.9.2 (fbf1343627e9bc018930efb7f72f7fd19c15d2d0)

Postgres version (select version();):
PostgreSQL 14.1 (Debian 14.1-1.pgdg110+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit

SpringBoot version: 3.2.1,
SpringData JPA version: 3.2.1,
Spring version 6.1.2
Postgresql driver version: 42.6.0,
hibernate core version: 6.4.1

Additional context

@ke

@DarthVagen DarthVagen added the type/bug Something isn't working label Jul 11, 2024
@github-actions github-actions bot added this to the release-1.11 milestone Jul 11, 2024
@KeXiangWang KeXiangWang self-assigned this Jul 12, 2024
@KeXiangWang
Copy link
Contributor

Thanks for your feedback! Will take a look soon.

Copy link
Contributor

This issue has been open for 60 days with no activity.

If you think it is still relevant today, and needs to be done in the near future, you can comment to update the status, or just manually remove the no-issue-activity label.

You can also confidently close this issue as not planned to keep our backlog clean.
Don't worry if you think the issue is still valuable to continue in the future.
It's searchable and can be reopened when it's time. 😄

@fuyufjh
Copy link
Member

fuyufjh commented Oct 17, 2024

Ping @KeXiangWang

@KeXiangWang
Copy link
Contributor

🥵 Will take a look soon

@KeXiangWang
Copy link
Contributor

cjgRepository.findById(1) will be transfered as an extended query, i.e., query with paramaters like $1, to postgres. Postgres sometimes will relay the extended parts to it's FDW engine(RW in this case). Previously, RW does not support declaring a cursor with extended parts, we can see the above error. In #19043, we added supported extended DECLARE CURSOR with query.

@DarthVagen
Copy link
Author

cjgRepository.findById(1) will be transfered as an extended query, i.e., query with paramaters like $1, to postgres. Postgres sometimes will relay the extended parts to it's FDW engine(RW in this case). Previously, RW does not support declaring a cursor with extended parts, we can see the above error. In #19043, we added supported extended DECLARE CURSOR with query.

Thanks for your work! But I was wondering "Postgres sometimes will relay the extended parts to it's FDW engine", why "sometimes"? This is an undeterministic behavior?

@KeXiangWang
Copy link
Contributor

KeXiangWang commented Oct 25, 2024

This is an undeterministic behavior?

I'm not entirely sure about this, but it appears to be somewhat deterministic since it consistently sends an extended (parameterized) query on the 10th attempt.

But in general, the ForeignPaths (ref) in postgres is dynamically generated, based on historical statistics of previous execution. So the same queries in one session may have different execution paths.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
type/bug Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants