backtrace when writing different integer schema

[jdstrand]

Compiled using cargo build --target-dir ../target --target=x86_64-unknown-linux-musl --workspace --release from checkout of commit 6f3d6b1b7eaed72a51113ed504b34776e4758000.

Create some line protocol files:

$ cat > i.lp <<EOM
t0,t0_tag0=initTag t0_f0=0i 1715694000
t0,t0_tag0=initTag t0_f0=1i 1715694001
t0,t0_tag1=initTag t0_f0=0i 1715694000
EOM

$ cat > u.lp <<EOM
t0,t0_tag0=initTag t0_f0=0u 1715694000
t0,t0_tag0=initTag t0_f0=1u 1715694001
t0,t0_tag1=initTag t0_f0=0u 1715694000
EOM

In one terminal, start server with RUST_BACKTRACE=1 ./influxdb3 serve --object-store file --data-dir ./.influxdb3

In another terminal, write in the files:

$ ./influxdb3 write --dbname test -f ./i.lp   # write 'i' integers
success

$ ./influxdb3 write --dbname test -f ./u.lp   # write 'u' integers
Write command failed: failed to send /api/v3/write_lp request: error sending request for url (http://127.0.0.1:8181/api/v3/write_lp?db=test): connection closed before message completed
[1]

Observe the trace in the server terminal:

$ RUST_BACKTRACE=1 ./influxdb3 serve --object-store file --data-dir ./.influxdb3
2024-05-15T14:34:12.916877Z  INFO influxdb3::commands::serve: InfluxDB3 Edge server starting git_hash=v2.5.0-14031-g6f3d6b1b7eaed72a51113ed504b34776e4758000 version=0.1.0 uuid=cf52af55-fe0b-4d69-bf37-7ddad080ca91 num_cpus=20 build_malloc_conf=
2024-05-15T14:34:12.916991Z  INFO clap_blocks::object_store: Object Store db_dir="./.influxdb3" object_store_type="Directory"
2024-05-15T14:34:12.917075Z  INFO influxdb3::commands::serve: Creating shared query executor num_threads=20
2024-05-15T14:35:07.584471Z  INFO influxdb3_server::http: write_lp to test
2024-05-15T14:35:07.584508Z  INFO influxdb3_write::catalog: return new db test
2024-05-15T14:35:07.584552Z  INFO influxdb3_write::catalog: inserted/updated database in catalog: test
2024-05-15T14:35:07.592739Z  INFO influxdb3_write::catalog: db_schema test
2024-05-15T14:35:12.595484Z  INFO influxdb3_server::http: write_lp to test
2024-05-15T14:35:12.595568Z  INFO influxdb3_write::catalog: return existing db test
2024-05-15T14:35:12.602802Z ERROR panic_logging: Thread panic panic_type="unknown" panic_message="unexpected field type" panic_file="influxdb3_write/src/write_buffer/table_buffer.rs" panic_line=143 panic_column=29
thread 'tokio-runtime-worker' panicked at influxdb3_write/src/write_buffer/table_buffer.rs:143:29:
unexpected field type
stack backtrace:
   0: rust_begin_unwind
   1: core::panicking::panic_fmt
   2: influxdb3_write::write_buffer::table_buffer::TableBuffer::add_rows
   3: influxdb3_write::write_buffer::buffer_segment::DatabaseBuffer::buffer_table_batch
   4: influxdb3_write::write_buffer::flusher::WriteBufferFlusher::new::{{closure}}
   5: tokio::runtime::task::core::Core<T,S>::poll
   6: tokio::runtime::task::raw::poll
   7: tokio::runtime::scheduler::multi_thread::worker::Context::run_task
   8: tokio::runtime::task::raw::poll
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
2024-05-15T14:35:12.611008Z ERROR panic_logging: Thread panic panic_type="unknown" panic_message="wal op buffer thread is dead: RecvError(())" panic_file="/home/debian/influxdb/influxdb3_write/src/write_buffer/flusher.rs" panic_line=98 panic_column=41
thread 'tokio-runtime-worker' panicked at /home/debian/influxdb/influxdb3_write/src/write_buffer/flusher.rs:98:41:
wal op buffer thread is dead: RecvError(())
stack backtrace:
   0: rust_begin_unwind
   1: core::panicking::panic_fmt
   2: core::result::unwrap_failed
   3: <influxdb3_write::write_buffer::WriteBufferImpl<W,T> as influxdb3_write::Bufferer>::write_lp::{{closure}}
   4: influxdb3_server::http::HttpApi<W,Q,T>::write_lp_inner::{{closure}}
   5: influxdb3_server::http::route_request::{{closure}}
   6: <influxdb3_server::service::HybridFuture<RestFuture,GrpcFuture> as core::future::future::Future>::poll
   7: hyper::proto::h1::dispatch::Dispatcher<D,Bs,I,T>::poll_catch
   8: <hyper::server::server::new_svc::NewSvcTask<I,N,S,E,W> as core::future::future::Future>::poll
   9: tokio::runtime::task::core::Core<T,S>::poll
  10: tokio::runtime::task::raw::poll
  11: tokio::runtime::scheduler::multi_thread::worker::Context::run_task
  12: tokio::runtime::task::raw::poll
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

[hiltontj]

The function that is issuing the first panic (unexpected field type) is here:

influxdb/influxdb3_write/src/write_buffer/table_buffer.rs

Line 50 in 8f72bf0

pub fn add_rows(&mut self, rows: Vec<Row>) {

add_rows is infallible, which will need to change in order to respond with an error in the API response and to prevent the wal op buffer thread from dying; unless we can validate the data types upstream and respond with error from there.

[jdstrand]

Fyi, Clustered (and presumably Dedicated) handles this fine:

$ curl -H "Authorization: Basic $V1AUTH" -X POST "$URL/write?db=test&precision=s" --data-binary @./i.lp
$ curl -H "Authorization: Basic $V1AUTH" -X POST "$URL/write?db=test&precision=s" --data-binary @./u.lp
{"code":"invalid","message":"dml handler error: schema conflict: table t0, already exists: column t0_f0 is type i64 but schema update has type u64"}

[pauldix]

@hiltontj the write should never have gotten to that point. It should have failed validation and returned an error to the user. That function should only get called after successful validation.

[hiltontj]

I have a reproducer up in #25022