Materialize: Panic on INSERT INTO with JSONB: entered unreachable code: Expr::Nested not desugared

[franchb]

What version of Materialize are you using?

$ materialized -v

v0.5.0-dev (5be2ad71c)

How did you install Materialize?

• [x] Docker image
• [ ] Linux release tarball
• [ ] APT package
• [ ] macOS release tarball
• [ ] Homebrew tap
• [ ] Built from source

Pulled latest unstable version docker pull materialize/materialized:unstable ( v0.5.0-dev (5be2ad71c) )

What was the issue?

Panic on INSERT INTO. PostgreSQL v.12.4 with the same schema ingests this row without error.

Is the issue reproducible? If so, please provide reproduction instructions.

CREATE TABLE IF NOT EXISTS sample
(
    producer INTEGER     NOT NULL,
    j1       JSONB,
    j2       JSONB,
    j3       JSONB,
    count    INTEGER     NOT NULL,
    port     INTEGER     NOT NULL,
    ip       TEXT,
    c1       TEXT        NOT NULL,
    c2       TEXT        NOT NULL,
    t        TEXT        NOT NULL,
    jid      TEXT        NOT NULL,
    sid      TEXT        NOT NULL,
    an       TEXT        NOT NULL,
    raw      TEXT        NOT NULL,
    c_time   TIMESTAMP   NOT NULL,
    w_time   TIMESTAMP   NOT NULL,
    g_time   TIMESTAMP   NOT NULL,
    tid      INTEGER     NOT NULL,
    sl       INTEGER     NOT NULL,
    key      VARCHAR(32) NOT NULL,
    custom   JSONB
);

INSERT INTO sample
VALUES (1,
        '["10.0.4.96"]',
        '[12,234,33]',
        '[789,342,33]', 
        0,
        '1124', 
        '10.0.4.96', 
        '0',
        'syslog',
        '0',
        '0',
        '0',
        '0',
        'raw event',
        (TIMESTAMP '2011-05-16 15:36:38'), 
        (TIMESTAMP '2011-05-16 15:36:38'),
        (TIMESTAMP '2011-05-16 15:36:38'),
        715,
        657, 
        '1598283073-000000c7-0000003a', 
        '{"foo":"bar"}'
       );

Please attach any applicable log files.

Console log:

❯ docker run -p 6875:6875 materialize/materialized:unstable --workers=1 --experimental
Aug 28 16:38:01.090  INFO materialized: materialized version: v0.5.0-dev (5be2ad71c)
invoked as: materialized --log-file=stderr --workers=1 --experimental
environment:    
=======================================================================
Thank you for trying Materialize!

We are interested in any and all feedback you have, which may be able
to improve both our software and your queries! Please reach out at:

    Web: https://materialize.io
    GitHub issues: https://github.com/MaterializeInc/materialize/issues
    Email: [email protected]
    Twitter: @MaterializeInc
=======================================================================

!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
                               WARNING!
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Starting Materialize in experimental mode means:

- This node's catalog of views and sources are unstable.

If you use any version of Materialize besides this one, you might
not be able to start the Materialize node. To fix this, you'll have
to remove all of Materialize's data (e.g. rm -rf mzdata) and start
the node anew.

- You must always start this node in experimental mode; it can no
longer be started in non-experimental/regular mode.

For more details, see https://materialize.io/docs/cli#experimental-mode
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!

materialized v0.5.0-dev (5be2ad71c) listening on 0.0.0.0:6875...
Aug 28 16:38:01.524  INFO coord::catalog: create source mz_catalog.mz_dataflow_operators (s1000)    
Aug 28 16:38:01.525  INFO coord::catalog: create index mz_catalog.mz_dataflow_operators_primary_idx (s1001)    
Aug 28 16:38:01.525  INFO coord::catalog: create source mz_catalog.mz_dataflow_operator_addresses (s1002)    
Aug 28 16:38:01.525  INFO coord::catalog: create index mz_catalog.mz_dataflow_operator_addresses_primary_idx (s1003)    
Aug 28 16:38:01.525  INFO coord::catalog: create source mz_catalog.mz_dataflow_channels (s1004)    
Aug 28 16:38:01.525  INFO coord::catalog: create index mz_catalog.mz_dataflow_channels_primary_idx (s1005)    
Aug 28 16:38:01.525  INFO coord::catalog: create source mz_catalog.mz_scheduling_elapsed (s1006)    
Aug 28 16:38:01.525  INFO coord::catalog: create index mz_catalog.mz_scheduling_elapsed_primary_idx (s1007)    
Aug 28 16:38:01.525  INFO coord::catalog: create source mz_catalog.mz_scheduling_histogram (s1008)    
Aug 28 16:38:01.525  INFO coord::catalog: create index mz_catalog.mz_scheduling_histogram_primary_idx (s1009)    
Aug 28 16:38:01.525  INFO coord::catalog: create source mz_catalog.mz_scheduling_parks (s1010)    
Aug 28 16:38:01.525  INFO coord::catalog: create index mz_catalog.mz_scheduling_parks_primary_idx (s1011)    
Aug 28 16:38:01.525  INFO coord::catalog: create source mz_catalog.mz_arrangement_sizes (s1012)    
Aug 28 16:38:01.525  INFO coord::catalog: create index mz_catalog.mz_arrangement_sizes_primary_idx (s1013)    
Aug 28 16:38:01.525  INFO coord::catalog: create source mz_catalog.mz_arrangement_sharing (s1014)    
Aug 28 16:38:01.525  INFO coord::catalog: create index mz_catalog.mz_arrangement_sharing_primary_idx (s1015)    
Aug 28 16:38:01.525  INFO coord::catalog: create source mz_catalog.mz_materializations (s1016)    
Aug 28 16:38:01.525  INFO coord::catalog: create index mz_catalog.mz_materializations_primary_idx (s1017)    
Aug 28 16:38:01.525  INFO coord::catalog: create source mz_catalog.mz_materialization_dependencies (s1018)    
Aug 28 16:38:01.525  INFO coord::catalog: create index mz_catalog.mz_materialization_dependencies_primary_idx (s1019)    
Aug 28 16:38:01.525  INFO coord::catalog: create source mz_catalog.mz_worker_materialization_frontiers (s1020)    
Aug 28 16:38:01.525  INFO coord::catalog: create index mz_catalog.mz_worker_materialization_frontiers_primary_idx (s1021)    
Aug 28 16:38:01.525  INFO coord::catalog: create source mz_catalog.mz_peek_active (s1022)    
Aug 28 16:38:01.525  INFO coord::catalog: create index mz_catalog.mz_peek_active_primary_idx (s1023)    
Aug 28 16:38:01.525  INFO coord::catalog: create source mz_catalog.mz_peek_durations (s1024)    
Aug 28 16:38:01.525  INFO coord::catalog: create index mz_catalog.mz_peek_durations_primary_idx (s1025)    
Aug 28 16:38:01.525  INFO coord::catalog: create table mz_catalog.mz_view_keys (s2001)    
Aug 28 16:38:01.525  INFO coord::catalog: create index mz_catalog.mz_view_keys_primary_idx (s2002)    
Aug 28 16:38:01.525  INFO coord::catalog: create table mz_catalog.mz_view_foreign_keys (s2003)    
Aug 28 16:38:01.525  INFO coord::catalog: create index mz_catalog.mz_view_foreign_keys_primary_idx (s2004)    
Aug 28 16:38:01.525  INFO coord::catalog: create table mz_catalog.mz_catalog_names (s2005)    
Aug 28 16:38:01.525  INFO coord::catalog: create index mz_catalog.mz_catalog_names_primary_idx (s2006)    
Aug 28 16:38:01.525  INFO coord::catalog: create table mz_catalog.mz_kafka_sinks (s2007)    
Aug 28 16:38:01.526  INFO coord::catalog: create index mz_catalog.mz_kafka_sinks_primary_idx (s2008)    
Aug 28 16:38:01.526  INFO coord::catalog: create table mz_catalog.mz_avro_ocf_sinks (s2009)    
Aug 28 16:38:01.526  INFO coord::catalog: create index mz_catalog.mz_avro_ocf_sinks_primary_idx (s2010)    
Aug 28 16:38:01.526  INFO coord::catalog: create table mz_catalog.mz_databases (s2011)    
Aug 28 16:38:01.526  INFO coord::catalog: create index mz_catalog.mz_databases_primary_idx (s2012)    
Aug 28 16:38:01.526  INFO coord::catalog: create table mz_catalog.mz_schemas (s2013)    
Aug 28 16:38:01.526  INFO coord::catalog: create index mz_catalog.mz_schemas_primary_idx (s2014)    
Aug 28 16:38:01.526  INFO coord::catalog: create view mz_catalog.mz_addresses_with_unit_length (s3000)    
Aug 28 16:38:01.527  INFO coord::catalog: create view mz_catalog.mz_dataflow_names (s3001)    
Aug 28 16:38:01.528  INFO coord::catalog: create view mz_catalog.mz_dataflow_operator_dataflows (s3002)    
Aug 28 16:38:01.528  INFO coord::catalog: create view mz_catalog.mz_materialization_frontiers (s3003)    
Aug 28 16:38:01.529  INFO coord::catalog: create view mz_catalog.mz_records_per_dataflow_operator (s3004)    
Aug 28 16:38:01.529  INFO coord::catalog: create view mz_catalog.mz_records_per_dataflow (s3005)    
Aug 28 16:38:01.529  INFO coord::catalog: create view mz_catalog.mz_records_per_dataflow_global (s3006)    
Aug 28 16:38:01.530  INFO coord::catalog: create view mz_catalog.mz_perf_arrangement_records (s3007)    
Aug 28 16:38:01.531  INFO coord::catalog: create view mz_catalog.mz_perf_peek_durations_core (s3008)    
Aug 28 16:38:01.531  INFO coord::catalog: create view mz_catalog.mz_perf_peek_durations_bucket (s3009)    
Aug 28 16:38:01.532  INFO coord::catalog: create view mz_catalog.mz_perf_peek_durations_aggregates (s3010)    
Aug 28 16:38:01.533  INFO coord::catalog: create view mz_catalog.mz_perf_dependency_frontiers (s3011)    
Aug 28 16:38:01.534  INFO coord::timestamp: Starting Timestamping Thread. Frequency: 10 ms.    
Aug 28 16:50:53.981  INFO coord::catalog: create table materialize.public.events (u1)    
Aug 28 16:50:53.982  INFO coord::catalog: create index materialize.public.events_primary_idx (u2)    
Aug 28 16:51:14.277 ERROR panic: <unnamed>: internal error: entered unreachable code: Expr::Nested not desugared
   0: materialized::handle_panic
             at var/lib/buildkite-agent/builds/buildkite-builders-i-0ddba882a5e3f3c19-1/materialize/tests/src/materialized/src/bin/materialized.rs:431
   1: core::ops::function::Fn::call
             at usr/local/lib/rustlib/src/rust/src/libcore/ops/function.rs:72
   2: std::panicking::rust_panic_with_hook
             at rustc/5c1f21c3b82297671ad3ae1e8c942d2ca92e84f2/src/libstd/panicking.rs:490
   3: rust_begin_unwind
             at rustc/5c1f21c3b82297671ad3ae1e8c942d2ca92e84f2/src/libstd/panicking.rs:388
   4: std::panicking::begin_panic_fmt
             at rustc/5c1f21c3b82297671ad3ae1e8c942d2ca92e84f2/src/libstd/panicking.rs:342
   5: sql::plan::query::plan_expr
   6: sql::plan::query::plan_homogeneous_exprs
             at var/lib/buildkite-agent/builds/buildkite-builders-i-0ddba882a5e3f3c19-1/materialize/tests/src/sql/src/plan/query.rs:1742
   7: sql::plan::query::plan_values
             at var/lib/buildkite-agent/builds/buildkite-builders-i-0ddba882a5e3f3c19-1/materialize/tests/src/sql/src/plan/query.rs:478
   8: sql::plan::query::plan_insert_query
             at var/lib/buildkite-agent/builds/buildkite-builders-i-0ddba882a5e3f3c19-1/materialize/tests/src/sql/src/plan/query.rs:512
   9: sql::plan::statement::handle_insert
             at var/lib/buildkite-agent/builds/buildkite-builders-i-0ddba882a5e3f3c19-1/materialize/tests/src/sql/src/plan/statement.rs:1882
      sql::plan::statement::handle_statement
             at var/lib/buildkite-agent/builds/buildkite-builders-i-0ddba882a5e3f3c19-1/materialize/tests/src/sql/src/plan/statement.rs:319
  10: sql::plan::plan
             at var/lib/buildkite-agent/builds/buildkite-builders-i-0ddba882a5e3f3c19-1/materialize/tests/src/sql/src/plan.rs:243
  11: coord::coord::Coordinator<C>::handle_statement
             at var/lib/buildkite-agent/builds/buildkite-builders-i-0ddba882a5e3f3c19-1/materialize/tests/src/coord/src/coord.rs:800
      coord::coord::Coordinator<C>::serve_core::{{closure}}
             at var/lib/buildkite-agent/builds/buildkite-builders-i-0ddba882a5e3f3c19-1/materialize/tests/src/coord/src/coord.rs:568
      core::result::Result<T,E>::and_then
             at usr/local/lib/rustlib/src/rust/src/libcore/result.rs:729
      coord::coord::Coordinator<C>::serve_core
             at var/lib/buildkite-agent/builds/buildkite-builders-i-0ddba882a5e3f3c19-1/materialize/tests/src/coord/src/coord.rs:568
  12: coord::coord::Coordinator<C>::serve::{{closure}}
             at var/lib/buildkite-agent/builds/buildkite-builders-i-0ddba882a5e3f3c19-1/materialize/tests/src/coord/src/coord.rs:457
      tokio::runtime::context::enter
             at cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.22/src/runtime/context.rs:72
  13: tokio::runtime::handle::Handle::enter
             at cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.22/src/runtime/handle.rs:76
  14: coord::coord::Coordinator<C>::serve
             at var/lib/buildkite-agent/builds/buildkite-builders-i-0ddba882a5e3f3c19-1/materialize/tests/src/coord/src/coord.rs:457
      materialized::serve::{{closure}}
             at var/lib/buildkite-agent/builds/buildkite-builders-i-0ddba882a5e3f3c19-1/materialize/tests/src/materialized/src/lib.rs:292
      std::sys_common::backtrace::__rust_begin_short_backtrace
             at usr/local/lib/rustlib/src/rust/src/libstd/sys_common/backtrace.rs:130
  15: std::thread::Builder::spawn_unchecked::{{closure}}::{{closure}}
             at usr/local/lib/rustlib/src/rust/src/libstd/thread/mod.rs:475
      <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at usr/local/lib/rustlib/src/rust/src/libstd/panic.rs:318
      std::panicking::try::do_call
             at usr/local/lib/rustlib/src/rust/src/libstd/panicking.rs:297
      std::panicking::try
             at usr/local/lib/rustlib/src/rust/src/libstd/panicking.rs:274
      std::panic::catch_unwind
             at usr/local/lib/rustlib/src/rust/src/libstd/panic.rs:394
      std::thread::Builder::spawn_unchecked::{{closure}}
             at usr/local/lib/rustlib/src/rust/src/libstd/thread/mod.rs:474
      core::ops::function::FnOnce::call_once{{vtable.shim}}
             at usr/local/lib/rustlib/src/rust/src/libcore/ops/function.rs:232
  16: <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once
             at rustc/5c1f21c3b82297671ad3ae1e8c942d2ca92e84f2/src/liballoc/boxed.rs:1076
      <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once
             at rustc/5c1f21c3b82297671ad3ae1e8c942d2ca92e84f2/src/liballoc/boxed.rs:1076
      std::sys::unix::thread::Thread::new::thread_start
             at rustc/5c1f21c3b82297671ad3ae1e8c942d2ca92e84f2/src/libstd/sys/unix/thread.rs:87
  17: start_thread
  18: __clone

materialized encountered an internal error and crashed.

[benesch]

Thanks for the report! I see the issue and will have a fix out later this evening. In the meantime, if you remove the parentheses around your TIMESTAMP literals, that should be sufficient to work around the bug.

[JLDLaughlin]

@franchb I just merged the fix to this (#4100) -- thank you for bringing it to our attention!

[franchb]

Much appreciations for such rapid response!

I performed this check again with materialized v0.5.0-dev (b58133f48) and it works!

Can't wait to explore how would Materialize perform for our real-time streaming pipeline!

[JLDLaughlin]

Awesome, please feel free to reach back out with any other questions (or bug reports 😄 )!