Scylla: [CDC] nodes aborting with coredump when writing large row

Created on 31 Jan 2021  路  14Comments  路  Source: scylladb/scylla

Installation details
Scylla version (or git commit hash): 4.5.dev-0.20210127.a1f93e429 with build-id f53c1cdd5bf7a862ed05cdf0396dd5725eeaddce
Cluster size: 4
OS (RHEL/CentOS/Ubuntu/AWS AMI): ami-0395803c0387e0e06 (eu-north-1)
Scenario: longevity-cdc-100gb-4h

At 2021-01-28 01:14:22,812 a AddDropColumnMonkey nemesis started (the first nemesis in this longevity). The nemesis constantly adds and drops columns from random tables in the clusters for 10 minutes. During the run of the nemesis' run 2 of the nodes experienced aborting error and produced a coredump:

node 1 (10.0.2.137):

2021-01-28T01:19:21+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-1 !WARNING | scylla: [shard 1] large_data - Writing large row cdc_test/test_table_scylla_cdc_log: 802124924924924a1431c7be48000041ce923bdc-6106-11eb-18fa-f2bd8c4fd210:0 (3221225555 bytes)
2021-01-28T01:19:21+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-1 !ERR     | scylla: [shard 1] database - cdc_test.test_table_scylla_cdc_log@84fdfa33-0e7c-3dd7-bf8f-5c7715eaba6b: column id 36 >= 36, at:    0x3caad5e#012   0x3cab1d0#012   0x3cab558#012   0x38ec16b#012   0x10e3ee2#012   0x1689c99#012   0x168bd8b#012   0x168b722#012   0x15d27b9#012   0x15d207e#012   0x3b9ec91#012   --------#012   seastar::continuation<seastar::internal::promise_base_with_type<void>, seastar::async<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62>(seastar::thread_attributes, sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62&&)::{lambda()#2}, seastar::future<void>::then_impl_nrvo<{lambda()#2}, seastar::future>(sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62&&)::{lambda(seastar::internal::promise_base_with_type<void>&&, {lambda()#2}&, seastar::future_state<seastar::internal::monostate>&&)#1}, void>#012   --------#012   seastar::continuation<seastar::internal::promise_base_with_type<void>, seastar::future<void>::finally_body<seastar::async<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62>(seastar::thread_attributes, sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62&&)::{lambda()#3}, false>, seastar::future<void>::then_wrapped_nrvo<seastar::future<void>, seastar::async<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62>(seastar::thread_attributes, sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62&&)::{lambda()#3}>(seastar::async<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62>(seastar::thread_attributes, sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62&&)::{lambda()#3}&&)::{lambda(seastar::internal::promise_base_with_type<void>&&, seastar::async<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62>(seastar::thread_attributes, auto:1&&)::{lambda()#3}&, seastar::future_state<seastar::internal::monostate>&&)#1}, void>#012   --------#012   seastar::continuation<seastar::internal::promise_base_with_type<void>, seastar::future<void>::finally_body<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_37, false>, seastar::future<void>::then_wrapped_nrvo<seastar::future<void>, seastar::future<void>::finally_body<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_37, false> >(seastar::future<void>::finally_body<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_37, false>&&)::{lambda(seastar::internal::promise_base_with_type<void>&&, seastar::future<void>::finally_body<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_37, false>&, seastar::future_state<seastar::internal::monostate>&&)#1}, void>#012   --------#012   seastar::internal::do_with_state<std::tuple<database_sstable_write_monitor>, seastar::future<void> >
2021-01-28T01:19:21+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-1 !INFO    | scylla: Aborting on shard 1.
2021-01-28T01:19:21+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-1 !INFO    | scylla: Backtrace:
2021-01-28T01:19:21+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-1 !INFO    | scylla: 0x00000000039360e4
2021-01-28T01:19:21+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-1 !INFO    | scylla: 0x0000000003940599
2021-01-28T01:19:21+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-1 !INFO    | scylla: 0x00007f8fafa211df
2021-01-28T01:19:21+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-1 !INFO    | scylla: /opt/scylladb/libreloc/libc.so.6+0x000000000003d9d4
2021-01-28T01:19:21+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-1 !INFO    | scylla: /opt/scylladb/libreloc/libc.so.6+0x00000000000268a3
2021-01-28T01:19:21+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-1 !INFO    | scylla: 0x00000000038ec18b
2021-01-28T01:19:21+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-1 !INFO    | scylla: 0x00000000010e3ee2
2021-01-28T01:19:21+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-1 !INFO    | scylla: 0x0000000001689c99
2021-01-28T01:19:21+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-1 !INFO    | scylla: 0x000000000168bd8b
2021-01-28T01:19:21+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-1 !INFO    | scylla: 0x000000000168b722
2021-01-28T01:19:21+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-1 !INFO    | scylla: 0x00000000015d27b9
2021-01-28T01:19:21+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-1 !INFO    | scylla: 0x00000000015d207e
2021-01-28T01:19:21+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-1 !INFO    | scylla: 0x0000000003b9ec91

Translated:

void seastar::backtrace<seastar::backtrace_buffer::append_backtrace()::{lambda(seastar::frame)#1}>(seastar::backtrace_buffer::append_backtrace()::{lambda(seastar::frame)#1}&&) at ./build/release/seastar/./seastar/include/seastar/util/backtrace.hh:59
 (inlined by) seastar::backtrace_buffer::append_backtrace() at ./build/release/seastar/./seastar/src/core/reactor.cc:731
 (inlined by) seastar::print_with_backtrace(seastar::backtrace_buffer&) at ./build/release/seastar/./seastar/src/core/reactor.cc:752
 (inlined by) seastar::print_with_backtrace(char const*) at ./build/release/seastar/./seastar/src/core/reactor.cc:759
seastar::sigabrt_action() at ./build/release/seastar/./seastar/src/core/reactor.cc:3550
 (inlined by) operator() at ./build/release/seastar/./seastar/src/core/reactor.cc:3532
 (inlined by) __invoke at ./build/release/seastar/./seastar/src/core/reactor.cc:3528
?? ??:0
?? ??:0
?? ??:0
seastar::on_internal_error(seastar::logger&, std::basic_string_view<char, std::char_traits<char> >) at ./build/release/seastar/./seastar/src/core/on_internal_error.cc:39
schema::column_at(ordinal_column_id) const at ./schema.cc:636
 (inlined by) schema::column_at(column_kind, unsigned int) const at ./schema.cc:630
operator() at ./sstables/mx/writer.cc:1275
 (inlined by) auto row::maybe_invoke_with_hash<sstables::mc::row_has_complex_deletion(schema const&, row const&, column_kind)::$_3, cell_and_hash const>(sstables::mc::row_has_complex_deletion(schema const&, row const&, column_kind)::$_3&, unsigned int, cell_and_hash const&) at ././mutation_partition.hh:253
 (inlined by) void row::for_each_cell_until<sstables::mc::row_has_complex_deletion(schema const&, row const&, column_kind)::$_3>(sstables::mc::row_has_complex_deletion(schema const&, row const&, column_kind)::$_3&&) const at ././mutation_partition.hh:297
 (inlined by) sstables::mc::row_has_complex_deletion(schema const&, row const&, column_kind) at ./sstables/mx/writer.cc:1274
 (inlined by) sstables::mc::writer::write_clustered(clustering_row const&, unsigned long) at ./sstables/mx/writer.cc:1344
void sstables::mc::writer::write_clustered<clustering_row>(clustering_row const&) at ./sstables/mx/writer.cc:739
sstables::mc::writer::consume(clustering_row&&) at ./sstables/mx/writer.cc:1374
flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer>::consume(clustering_row&&) at ././flat_mutation_reader.hh:205
 (inlined by) _ZNO17mutation_fragment7consumeIN20flat_mutation_reader4impl16consumer_adapterIN8sstables14sstable_writerEEEEEDcRT_ at ././mutation_fragment.hh:432
flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer>::operator()(mutation_fragment&&) at ././flat_mutation_reader.hh:199
 (inlined by) seastar::future<seastar::bool_class<seastar::stop_iteration_tag> > std::__invoke_impl<seastar::future<seastar::bool_class<seastar::stop_iteration_tag> >, flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer>&, mutation_fragment>(std::__invoke_other, flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer>&, mutation_fragment&&) at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/invoke.h:60
 (inlined by) std::__invoke_result<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer>&, mutation_fragment>::type std::__invoke<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer>&, mutation_fragment>(flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer>&, mutation_fragment&&) at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/invoke.h:95
 (inlined by) std::result_of<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer>& (mutation_fragment&&)>::type std::reference_wrapper<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer> >::operator()<mutation_fragment>(mutation_fragment&&) const at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/refwrap.h:349
 (inlined by) operator() at ././flat_mutation_reader.hh:180
 (inlined by) seastar::future<seastar::bool_class<seastar::stop_iteration_tag> > seastar::futurize<seastar::future<seastar::bool_class<seastar::stop_iteration_tag> > >::invoke<void flat_mutation_reader::impl::consume_pausable_in_thread<std::reference_wrapper<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer> >, flat_mutation_reader::no_filter>(std::reference_wrapper<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer> >, flat_mutation_reader::no_filter, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >)::{lambda()#1}>(void flat_mutation_reader::impl::consume_pausable_in_thread<std::reference_wrapper<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer> >, flat_mutation_reader::no_filter>(std::reference_wrapper<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer> >, flat_mutation_reader::no_filter, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >)::{lambda()#1}&&) at ././seastar/include/seastar/core/future.hh:2135
 (inlined by) auto seastar::futurize_invoke<void flat_mutation_reader::impl::consume_pausable_in_thread<std::reference_wrapper<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer> >, flat_mutation_reader::no_filter>(std::reference_wrapper<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer> >, flat_mutation_reader::no_filter, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >)::{lambda()#1}>(void flat_mutation_reader::impl::consume_pausable_in_thread<std::reference_wrapper<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer> >, flat_mutation_reader::no_filter>(std::reference_wrapper<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer> >, flat_mutation_reader::no_filter, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >)::{lambda()#1}&&) at ././seastar/include/seastar/core/future.hh:2166
 (inlined by) void flat_mutation_reader::impl::consume_pausable_in_thread<std::reference_wrapper<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer> >, flat_mutation_reader::no_filter>(std::reference_wrapper<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer> >, flat_mutation_reader::no_filter, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >) at ././flat_mutation_reader.hh:179
 (inlined by) auto flat_mutation_reader::impl::consume_in_thread<sstables::sstable_writer, flat_mutation_reader::no_filter>(sstables::sstable_writer, flat_mutation_reader::no_filter, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >) at ././flat_mutation_reader.hh:266
 (inlined by) auto flat_mutation_reader::consume_in_thread<sstables::sstable_writer, flat_mutation_reader::no_filter>(sstables::sstable_writer, flat_mutation_reader::no_filter, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >) at ././flat_mutation_reader.hh:377
 (inlined by) auto flat_mutation_reader::consume_in_thread<sstables::sstable_writer>(sstables::sstable_writer, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >) at ././flat_mutation_reader.hh:383
 (inlined by) operator() at ./sstables/sstables.cc:1710
 (inlined by) void std::__invoke_impl<void, sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62>(std::__invoke_other, sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62&&) at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/invoke.h:60
 (inlined by) std::__invoke_result<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62>::type std::__invoke<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62>(sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62&&) at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/invoke.h:95
 (inlined by) _ZSt12__apply_implIZN8sstables7sstable16write_componentsE20flat_mutation_readermN7seastar13lw_shared_ptrIK6schemaEERKNS0_21sstable_writer_configE14encoding_statsRKNS3_17io_priority_classEE4$_62St5tupleIJEEJEEDcOT_OT0_St16integer_sequenceImJXspT1_EEE at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/tuple:1723
 (inlined by) _ZSt5applyIZN8sstables7sstable16write_componentsE20flat_mutation_readermN7seastar13lw_shared_ptrIK6schemaEERKNS0_21sstable_writer_configE14encoding_statsRKNS3_17io_priority_classEE4$_62St5tupleIJEEEDcOT_OT0_ at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/tuple:1734
 (inlined by) seastar::future<void> seastar::futurize<void>::apply<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62>(sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62&&, std::tuple<>&&) at ././seastar/include/seastar/core/future.hh:2099
 (inlined by) operator() at ././seastar/include/seastar/core/thread.hh:258
 (inlined by) seastar::noncopyable_function<void ()>::direct_vtable_for<seastar::futurize<std::result_of<std::decay<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62>::type ()>::type>::type seastar::async<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62>(seastar::thread_attributes, sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62&&)::{lambda()#1}>::call(seastar::noncopyable_function<void ()> const*) at ././seastar/include/seastar/util/noncopyable_function.hh:124
seastar::noncopyable_function<void ()>::operator()() const at ./build/release/seastar/./seastar/include/seastar/util/noncopyable_function.hh:209
 (inlined by) seastar::thread_context::main() at ./build/release/seastar/./seastar/src/core/thread.cc:297

Coredump:

2021-01-28 01:29:55.831: (CoreDumpEvent Severity.ERROR) node=Node longevity-cdc-100gb-4h-master-db-node-50c038cd-1 [13.48.45.172 | 10.0.2.137] (seed: True)
corefile_url=https://storage.cloud.google.com/upload.scylladb.com/core.scylla.997.9624b5f033854516b0c77402a58e92b4.3361.1611796761000000/core.scylla.997.9624b5f033854516b0c77402a58e92b4.3361.1611796761000000.gz
backtrace=           PID: 3361 (scylla)
           UID: 997 (scylla)
           GID: 1001 (scylla)
        Signal: 6 (ABRT)
     Timestamp: Thu 2021-01-28 01:19:21 UTC (2min 48s ago)
  Command Line: /usr/bin/scylla --blocked-reactor-notify-ms 500 --abort-on-lsa-bad-alloc 1 --abort-on-seastar-bad-alloc --abort-on-internal-error 1 --abort-on-ebadf 1 --experimental-features cdc --log-to-syslog 1 --log-to-stdout 0 --default-log-level info --network-stack posix --io-properties-file=/etc/scylla.d/io_properties.yaml --cpuset 1-7,9-15 --lock-memory=1
    Executable: /opt/scylladb/libexec/scylla
 Control Group: /
       Boot ID: 9624b5f033854516b0c77402a58e92b4
    Machine ID: cc2c86fe566741e6a2ff6d399c5d5daa
      Hostname: longevity-cdc-100gb-4h-master-db-node-50c038cd-1
      Coredump: /var/lib/systemd/coredump/core.scylla.997.9624b5f033854516b0c77402a58e92b4.3361.1611796761000000
       Message: Process 3361 (scylla) of user 997 dumped core.

download_instructions=gsutil cp gs://upload.scylladb.com/core.scylla.997.9624b5f033854516b0c77402a58e92b4.3361.1611796761000000/core.scylla.997.9624b5f033854516b0c77402a58e92b4.3361.1611796761000000.gz .
gunzip /var/lib/systemd/coredump/core.scylla.997.9624b5f033854516b0c77402a58e92b4.3361.1611796761000000.gz

node 2 (10.0.3.12):

2021-01-28T01:22:24+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-2 !INFO    | scylla: [shard 13] query_processor - Column definitions for cdc_test.test_table_scylla_cdc_log changed, invalidating related prepared statements
2021-01-28T01:22:24+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-2 !ERR     | scylla: [shard 13] database - cdc_test.test_table_scylla_cdc_log@69453ff2-1cf3-3575-a1df-514416b06b6a: column id 33 >= 33, at:    0x3caad5e#012   0x3cab1d0#012   0x3cab558#012   0x38ec16b#012   0x10e3ee2#012   0x1689c99#012   0x168bd8b#012   0x168b722#012   0x15d27b9#012   0x15d207e#012   0x3b9ec91#012   --------#012   seastar::continuation<seastar::internal::promise_base_with_type<void>, seastar::async<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62>(seastar::thread_attributes, sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62&&)::{lambda()#2}, seastar::future<void>::then_impl_nrvo<{lambda()#2}, seastar::future>(sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62&&)::{lambda(seastar::internal::promise_base_with_type<void>&&, {lambda()#2}&, seastar::future_state<seastar::internal::monostate>&&)#1}, void>#012   --------#012   seastar::continuation<seastar::internal::promise_base_with_type<void>, seastar::future<void>::finally_body<seastar::async<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62>(seastar::thread_attributes, sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62&&)::{lambda()#3}, false>, seastar::future<void>::then_wrapped_nrvo<seastar::future<void>, seastar::async<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62>(seastar::thread_attributes, sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62&&)::{lambda()#3}>(seastar::async<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62>(seastar::thread_attributes, sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62&&)::{lambda()#3}&&)::{lambda(seastar::internal::promise_base_with_type<void>&&, seastar::async<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62>(seastar::thread_attributes, auto:1&&)::{lambda()#3}&, seastar::future_state<seastar::internal::monostate>&&)#1}, void>#012   --------#012   seastar::continuation<seastar::internal::promise_base_with_type<void>, seastar::future<void>::finally_body<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_37, false>, seastar::future<void>::then_wrapped_nrvo<seastar::future<void>, seastar::future<void>::finally_body<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_37, false> >(seastar::future<void>::finally_body<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_37, false>&&)::{lambda(seastar::internal::promise_base_with_type<void>&&, seastar::future<void>::finally_body<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_37, false>&, seastar::future_state<seastar::internal::monostate>&&)#1}, void>#012   --------#012   seastar::internal::do_with_state<std::tuple<database_sstable_write_monitor>, seastar::future<void> >
2021-01-28T01:22:24+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-2 !INFO    | scylla: Aborting on shard 13.
2021-01-28T01:22:24+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-2 !INFO    | scylla: Backtrace:
2021-01-28T01:22:24+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-2 !INFO    | scylla: 0x00000000039360e4
2021-01-28T01:22:24+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-2 !INFO    | scylla: 0x0000000003940599
2021-01-28T01:22:24+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-2 !INFO    | scylla: 0x00007f07502571df
2021-01-28T01:22:24+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-2 !INFO    | scylla: /opt/scylladb/libreloc/libc.so.6+0x000000000003d9d4
2021-01-28T01:22:24+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-2 !INFO    | scylla: /opt/scylladb/libreloc/libc.so.6+0x00000000000268a3
2021-01-28T01:22:24+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-2 !INFO    | scylla: 0x00000000038ec18b
2021-01-28T01:22:24+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-2 !INFO    | scylla: 0x00000000010e3ee2
2021-01-28T01:22:24+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-2 !INFO    | scylla: 0x0000000001689c99
2021-01-28T01:22:24+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-2 !INFO    | scylla: 0x000000000168bd8b
2021-01-28T01:22:24+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-2 !INFO    | scylla: 0x000000000168b722
2021-01-28T01:22:24+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-2 !INFO    | scylla: 0x00000000015d27b9
2021-01-28T01:22:24+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-2 !INFO    | scylla: 0x00000000015d207e
2021-01-28T01:22:24+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-2 !INFO    | scylla: 0x0000000003b9ec91

Translated:

void seastar::backtrace<seastar::backtrace_buffer::append_backtrace()::{lambda(seastar::frame)#1}>(seastar::backtrace_buffer::append_backtrace()::{lambda(seastar::frame)#1}&&) at ./build/release/seastar/./seastar/include/seastar/util/backtrace.hh:59
 (inlined by) seastar::backtrace_buffer::append_backtrace() at ./build/release/seastar/./seastar/src/core/reactor.cc:731
 (inlined by) seastar::print_with_backtrace(seastar::backtrace_buffer&) at ./build/release/seastar/./seastar/src/core/reactor.cc:752
 (inlined by) seastar::print_with_backtrace(char const*) at ./build/release/seastar/./seastar/src/core/reactor.cc:759
seastar::sigabrt_action() at ./build/release/seastar/./seastar/src/core/reactor.cc:3550
 (inlined by) operator() at ./build/release/seastar/./seastar/src/core/reactor.cc:3532
 (inlined by) __invoke at ./build/release/seastar/./seastar/src/core/reactor.cc:3528
?? ??:0
?? ??:0
?? ??:0
seastar::on_internal_error(seastar::logger&, std::basic_string_view<char, std::char_traits<char> >) at ./build/release/seastar/./seastar/src/core/on_internal_error.cc:39
schema::column_at(ordinal_column_id) const at ./schema.cc:636
 (inlined by) schema::column_at(column_kind, unsigned int) const at ./schema.cc:630
operator() at ./sstables/mx/writer.cc:1275
 (inlined by) auto row::maybe_invoke_with_hash<sstables::mc::row_has_complex_deletion(schema const&, row const&, column_kind)::$_3, cell_and_hash const>(sstables::mc::row_has_complex_deletion(schema const&, row const&, column_kind)::$_3&, unsigned int, cell_and_hash const&) at ././mutation_partition.hh:253
 (inlined by) void row::for_each_cell_until<sstables::mc::row_has_complex_deletion(schema const&, row const&, column_kind)::$_3>(sstables::mc::row_has_complex_deletion(schema const&, row const&, column_kind)::$_3&&) const at ././mutation_partition.hh:297
 (inlined by) sstables::mc::row_has_complex_deletion(schema const&, row const&, column_kind) at ./sstables/mx/writer.cc:1274
 (inlined by) sstables::mc::writer::write_clustered(clustering_row const&, unsigned long) at ./sstables/mx/writer.cc:1344
void sstables::mc::writer::write_clustered<clustering_row>(clustering_row const&) at ./sstables/mx/writer.cc:739
sstables::mc::writer::consume(clustering_row&&) at ./sstables/mx/writer.cc:1374
flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer>::consume(clustering_row&&) at ././flat_mutation_reader.hh:205
 (inlined by) _ZNO17mutation_fragment7consumeIN20flat_mutation_reader4impl16consumer_adapterIN8sstables14sstable_writerEEEEEDcRT_ at ././mutation_fragment.hh:432
flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer>::operator()(mutation_fragment&&) at ././flat_mutation_reader.hh:199
 (inlined by) seastar::future<seastar::bool_class<seastar::stop_iteration_tag> > std::__invoke_impl<seastar::future<seastar::bool_class<seastar::stop_iteration_tag> >, flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer>&, mutation_fragment>(std::__invoke_other, flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer>&, mutation_fragment&&) at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/invoke.h:60
 (inlined by) std::__invoke_result<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer>&, mutation_fragment>::type std::__invoke<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer>&, mutation_fragment>(flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer>&, mutation_fragment&&) at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/invoke.h:95
 (inlined by) std::result_of<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer>& (mutation_fragment&&)>::type std::reference_wrapper<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer> >::operator()<mutation_fragment>(mutation_fragment&&) const at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/refwrap.h:349
 (inlined by) operator() at ././flat_mutation_reader.hh:180
 (inlined by) seastar::future<seastar::bool_class<seastar::stop_iteration_tag> > seastar::futurize<seastar::future<seastar::bool_class<seastar::stop_iteration_tag> > >::invoke<void flat_mutation_reader::impl::consume_pausable_in_thread<std::reference_wrapper<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer> >, flat_mutation_reader::no_filter>(std::reference_wrapper<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer> >, flat_mutation_reader::no_filter, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >)::{lambda()#1}>(void flat_mutation_reader::impl::consume_pausable_in_thread<std::reference_wrapper<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer> >, flat_mutation_reader::no_filter>(std::reference_wrapper<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer> >, flat_mutation_reader::no_filter, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >)::{lambda()#1}&&) at ././seastar/include/seastar/core/future.hh:2135
 (inlined by) auto seastar::futurize_invoke<void flat_mutation_reader::impl::consume_pausable_in_thread<std::reference_wrapper<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer> >, flat_mutation_reader::no_filter>(std::reference_wrapper<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer> >, flat_mutation_reader::no_filter, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >)::{lambda()#1}>(void flat_mutation_reader::impl::consume_pausable_in_thread<std::reference_wrapper<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer> >, flat_mutation_reader::no_filter>(std::reference_wrapper<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer> >, flat_mutation_reader::no_filter, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >)::{lambda()#1}&&) at ././seastar/include/seastar/core/future.hh:2166
 (inlined by) void flat_mutation_reader::impl::consume_pausable_in_thread<std::reference_wrapper<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer> >, flat_mutation_reader::no_filter>(std::reference_wrapper<flat_mutation_reader::impl::consumer_adapter<sstables::sstable_writer> >, flat_mutation_reader::no_filter, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >) at ././flat_mutation_reader.hh:179
 (inlined by) auto flat_mutation_reader::impl::consume_in_thread<sstables::sstable_writer, flat_mutation_reader::no_filter>(sstables::sstable_writer, flat_mutation_reader::no_filter, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >) at ././flat_mutation_reader.hh:266
 (inlined by) auto flat_mutation_reader::consume_in_thread<sstables::sstable_writer, flat_mutation_reader::no_filter>(sstables::sstable_writer, flat_mutation_reader::no_filter, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >) at ././flat_mutation_reader.hh:377
 (inlined by) auto flat_mutation_reader::consume_in_thread<sstables::sstable_writer>(sstables::sstable_writer, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >) at ././flat_mutation_reader.hh:383
 (inlined by) operator() at ./sstables/sstables.cc:1710
 (inlined by) void std::__invoke_impl<void, sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62>(std::__invoke_other, sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62&&) at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/invoke.h:60
 (inlined by) std::__invoke_result<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62>::type std::__invoke<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62>(sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62&&) at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/invoke.h:95
 (inlined by) _ZSt12__apply_implIZN8sstables7sstable16write_componentsE20flat_mutation_readermN7seastar13lw_shared_ptrIK6schemaEERKNS0_21sstable_writer_configE14encoding_statsRKNS3_17io_priority_classEE4$_62St5tupleIJEEJEEDcOT_OT0_St16integer_sequenceImJXspT1_EEE at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/tuple:1723
 (inlined by) _ZSt5applyIZN8sstables7sstable16write_componentsE20flat_mutation_readermN7seastar13lw_shared_ptrIK6schemaEERKNS0_21sstable_writer_configE14encoding_statsRKNS3_17io_priority_classEE4$_62St5tupleIJEEEDcOT_OT0_ at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/tuple:1734
 (inlined by) seastar::future<void> seastar::futurize<void>::apply<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62>(sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62&&, std::tuple<>&&) at ././seastar/include/seastar/core/future.hh:2099
 (inlined by) operator() at ././seastar/include/seastar/core/thread.hh:258
 (inlined by) seastar::noncopyable_function<void ()>::direct_vtable_for<seastar::futurize<std::result_of<std::decay<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62>::type ()>::type>::type seastar::async<sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62>(seastar::thread_attributes, sstables::sstable::write_components(flat_mutation_reader, unsigned long, seastar::lw_shared_ptr<schema const>, sstables::sstable_writer_config const&, encoding_stats, seastar::io_priority_class const&)::$_62&&)::{lambda()#1}>::call(seastar::noncopyable_function<void ()> const*) at ././seastar/include/seastar/util/noncopyable_function.hh:124
seastar::noncopyable_function<void ()>::operator()() const at ./build/release/seastar/./seastar/include/seastar/util/noncopyable_function.hh:209
 (inlined by) seastar::thread_context::main() at ./build/release/seastar/./seastar/src/core/thread.cc:297

Coredump:

2021-01-28 01:33:33.803: (CoreDumpEvent Severity.ERROR) node=Node longevity-cdc-100gb-4h-master-db-node-50c038cd-2 [13.48.55.166 | 10.0.3.12] (seed: False)
corefile_url=https://storage.cloud.google.com/upload.scylladb.com/core.scylla.997.1f6a88ed46234b42bf2514fe55c8fc90.3729.1611796944000000/core.scylla.997.1f6a88ed46234b42bf2514fe55c8fc90.3729.1611796944000000.gz
backtrace=           PID: 3729 (scylla)
           UID: 997 (scylla)
           GID: 1001 (scylla)
        Signal: 6 (ABRT)
     Timestamp: Thu 2021-01-28 01:22:24 UTC (2min 48s ago)
  Command Line: /usr/bin/scylla --blocked-reactor-notify-ms 500 --abort-on-lsa-bad-alloc 1 --abort-on-seastar-bad-alloc --abort-on-internal-error 1 --abort-on-ebadf 1 --experimental-features cdc --log-to-syslog 1 --log-to-stdout 0 --default-log-level info --netw
ork-stack posix --io-properties-file=/etc/scylla.d/io_properties.yaml --cpuset 1-7,9-15 --lock-memory=1
    Executable: /opt/scylladb/libexec/scylla
 Control Group: /
       Boot ID: 1f6a88ed46234b42bf2514fe55c8fc90
    Machine ID: cc2c86fe566741e6a2ff6d399c5d5daa
      Hostname: longevity-cdc-100gb-4h-master-db-node-50c038cd-2
      Coredump: /var/lib/systemd/coredump/core.scylla.997.1f6a88ed46234b42bf2514fe55c8fc90.3729.1611796944000000
       Message: Process 3729 (scylla) of user 997 dumped core.
download_instructions=gsutil cp gs://upload.scylladb.com/core.scylla.997.1f6a88ed46234b42bf2514fe55c8fc90.3729.1611796944000000/core.scylla.997.1f6a88ed46234b42bf2514fe55c8fc90.3729.1611796944000000.gz .
gunzip /var/lib/systemd/coredump/core.scylla.997.1f6a88ed46234b42bf2514fe55c8fc90.3729.1611796944000000.gz

List of alterations:

< t:2021-01-28 01:14:22,964 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( A47NDZK49U boolean );'...
< t:2021-01-28 01:14:25,561 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( A47NDZK49U );'...
< t:2021-01-28 01:14:27,565 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( D91DZWPPQ6 duration, OZA7PDBWNV ascii );'...
< t:2021-01-28 01:14:30,979 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( OZA7PDBWNV, D91DZWPPQ6 );'...
< t:2021-01-28 01:14:33,159 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( LVMOWOQU3L tinyint, S4M04DZCLU int, PDTZWMZ2GO timeuuid );'...
< t:2021-01-28 01:14:36,849 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( PDTZWMZ2GO, LVMOWOQU3L, S4M04DZCLU );'...
< t:2021-01-28 01:14:39,058 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( A1O5EXLLSB blob, Y5CY7T9BM3 float, DB5970ALJB timestamp, WD795LP8P6 varchar );'...
< t:2021-01-28 01:14:41,746 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( WD795LP8P6, Y5CY7T9BM3, DB5970ALJB, A1O5EXLLSB );'...
< t:2021-01-28 01:14:43,502 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( Z6LUGFOXJ9 uuid, X5TIQ1XN8I map<time,float>, YN6X9FFMWD text );'...
< t:2021-01-28 01:14:46,532 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( YN6X9FFMWD, X5TIQ1XN8I, Z6LUGFOXJ9 );'...
< t:2021-01-28 01:14:48,484 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( JWJXPKMPHI varint, RTY89YGXN4 inet, QNDYISDFGY time );'...
< t:2021-01-28 01:14:51,676 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( JWJXPKMPHI, QNDYISDFGY );'...
< t:2021-01-28 01:14:55,091 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( ZJRIWOC8TC date, LDQ7HCH5AX bigint, QU594OVEP8 list<varint>, EAEM6SFG1P map<date,int> );'...
< t:2021-01-28 01:14:57,154 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( ZJRIWOC8TC, LDQ7HCH5AX, RTY89YGXN4 );'...
< t:2021-01-28 01:14:59,475 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( Q4Z8F8II1Y decimal, IMZ1KI8VY7 set<tinyint>, IQ6E202RLH set<timeuuid>, KRDBPNA75S smallint );'...
< t:2021-01-28 01:15:01,333 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( IQ6E202RLH, EAEM6SFG1P, QU594OVEP8, IMZ1KI8VY7, Q4Z8F8II1Y );'...
< t:2021-01-28 01:15:03,326 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( K779P5TU9L double, CLLQZFULLS double );'...
< t:2021-01-28 01:15:04,846 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( CLLQZFULLS );'...
< t:2021-01-28 01:15:07,307 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( EJB65CQIYK list<timeuuid> );'...
< t:2021-01-28 01:15:10,288 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( EJB65CQIYK, KRDBPNA75S, K779P5TU9L );'...
< t:2021-01-28 01:15:12,221 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( BM9ZMLZAKP list<float> );'...
< t:2021-01-28 01:15:15,436 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( BM9ZMLZAKP );'...
< t:2021-01-28 01:15:17,718 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( ENLCAZZEVJ map<frozen<map<timeuuid,uuid>>,boolean>, UZPJLNBRBQ set<varint> );'...
< t:2021-01-28 01:15:19,839 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( ENLCAZZEVJ, UZPJLNBRBQ );'...
< t:2021-01-28 01:15:22,101 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( EQ3OSVLQL1 set<blob>, ZLG28AXUN8 set<boolean>, OQMKRCOPCF map<varchar,double>, G6XYKN903Q set<timestamp> );'...
< t:2021-01-28 01:15:24,758 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( EQ3OSVLQL1, OQMKRCOPCF );'...
< t:2021-01-28 01:15:26,335 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( UGZJILTWKC map<boolean,blob>, MXI60PQKOT list<tinyint> );'...
< t:2021-01-28 01:15:28,328 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( UGZJILTWKC, MXI60PQKOT );'...
< t:2021-01-28 01:15:29,685 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( UIEUWMYNVO map<frozen<list<decimal>>,bigint>, PVG1TD854P map<blob,decimal>, JA1QVRECT5 list<frozen<map<frozen<map<timestamp,boolean>>,timeuuid>>> );'...
< t:2021-01-28 01:15:32,354 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( PVG1TD854P, G6XYKN903Q );'...
< t:2021-01-28 01:15:34,550 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( NZV9VXY7I6 list<varchar> );'...
< t:2021-01-28 01:15:36,362 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( JA1QVRECT5, UIEUWMYNVO, ZLG28AXUN8, NZV9VXY7I6 );'...
< t:2021-01-28 01:15:39,403 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( B41SLE67ES set<frozen<list<timeuuid>>>, ALXWIE32WQ list<int> );'...
< t:2021-01-28 01:15:42,448 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( B41SLE67ES, ALXWIE32WQ );'...
< t:2021-01-28 01:15:45,337 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( KDFK8QW8UJ list<decimal> );'...
< t:2021-01-28 01:15:47,545 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( KDFK8QW8UJ );'...
< t:2021-01-28 01:15:49,884 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( DPP13CUR2H set<frozen<list<double>>>, GJ3XFOUE3P map<frozen<map<frozen<list<inet>>,ascii>>,time>, PY1VRD8HXI map<text,timeuuid>, D62SRDCNYE map<float,smallint> );'...
< t:2021-01-28 01:15:52,863 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( PY1VRD8HXI, DPP13CUR2H, GJ3XFOUE3P, D62SRDCNYE );'...
< t:2021-01-28 01:15:55,286 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( V40VAMDW5G set<int>, IEW7Q3CR8V list<ascii>, FWV6T45K1T map<timestamp,uuid>, OWAAVSHP4S list<frozen<list<blob>>> );'...
< t:2021-01-28 01:15:57,570 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( IEW7Q3CR8V );'...
< t:2021-01-28 01:16:00,058 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( IAT5P1TFPV set<inet>, CK0X6XLHFU list<boolean>, MFLTQOC0TH map<uuid,frozen<list<decimal>>>, W9YEA52HG9 set<double> );'...
< t:2021-01-28 01:16:02,538 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( CK0X6XLHFU, W9YEA52HG9, MFLTQOC0TH, IAT5P1TFPV );'...
< t:2021-01-28 01:16:04,339 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( P4F2HVJ1RR list<frozen<list<timeuuid>>>, CVARP0H0OJ set<smallint>, PUH9O673M9 map<int,date>, X5PRJAXJUE list<frozen<map<double,frozen<list<boolean>>>>> );'...
< t:2021-01-28 01:16:06,630 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( PUH9O673M9, P4F2HVJ1RR, FWV6T45K1T );'...
< t:2021-01-28 01:16:08,502 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( IJ5ZA48N7Z list<frozen<set<tinyint>>> );'...
< t:2021-01-28 01:16:10,949 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( OWAAVSHP4S );'...
< t:2021-01-28 01:16:13,641 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( EIU8A3IHSD map<frozen<list<tinyint>>,frozen<map<float,int>>>, IKAFHHTI5S set<uuid> );'...
< t:2021-01-28 01:16:15,747 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( EIU8A3IHSD, X5PRJAXJUE, CVARP0H0OJ, IKAFHHTI5S, IJ5ZA48N7Z );'...
< t:2021-01-28 01:16:18,357 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( T1Z72AK3IH set<frozen<set<time>>> );'...
< t:2021-01-28 01:16:20,804 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( T1Z72AK3IH, V40VAMDW5G );'...
< t:2021-01-28 01:16:23,516 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( Q9DYP9AKCT set<time> );'...
< t:2021-01-28 01:16:25,556 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( Q9DYP9AKCT );'...
< t:2021-01-28 01:16:27,886 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( BTAJG0JX2W list<frozen<list<varint>>>, IZN5P14SBL map<bigint,frozen<map<int,double>>>, VA3UMX41EC list<timestamp> );'...
< t:2021-01-28 01:16:30,435 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( VA3UMX41EC, IZN5P14SBL );'...
< t:2021-01-28 01:16:32,396 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( G50HCHBPW0 list<time>, LI7N0XJNAH list<text>, RQ83M70QQP map<decimal,varchar>, IX539XAZ26 map<smallint,varint> );'...
< t:2021-01-28 01:16:34,600 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( RQ83M70QQP, BTAJG0JX2W, LI7N0XJNAH );'...
< t:2021-01-28 01:16:37,109 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( HS2EPSBKMW list<uuid> );'...
< t:2021-01-28 01:16:39,127 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( HS2EPSBKMW );'...
< t:2021-01-28 01:16:41,308 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( GPL4Y850VI set<ascii> );'...
< t:2021-01-28 01:16:43,250 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( GPL4Y850VI, G50HCHBPW0 );'...
< t:2021-01-28 01:16:45,887 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( NX36LO8MXF set<text>, W0GU78WPMX map<double,frozen<list<tinyint>>>, KRSJU47S7M map<frozen<list<blob>>,text> );'...
< t:2021-01-28 01:16:48,612 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( KRSJU47S7M );'...
< t:2021-01-28 01:16:50,231 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( XAEZX0JN0K set<bigint> );'...
< t:2021-01-28 01:16:52,066 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( IX539XAZ26, NX36LO8MXF, W0GU78WPMX, XAEZX0JN0K );'...
< t:2021-01-28 01:16:53,960 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( U6903VCG21 map<frozen<list<varchar>>,frozen<map<frozen<map<timeuuid,boolean>>,text>>> );'...
< t:2021-01-28 01:16:56,764 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( U6903VCG21 );'...
< t:2021-01-28 01:16:58,565 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( M04KURJZYA list<smallint>, NJ8T2W3WMY list<bigint>, M18R6WT860 map<inet,tinyint>, JJEPUC3LJL map<timeuuid,inet> );'...
< t:2021-01-28 01:17:00,943 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( M18R6WT860, NJ8T2W3WMY, M04KURJZYA );'...
< t:2021-01-28 01:17:02,267 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( TZQ7IVG5CP list<frozen<set<timeuuid>>>, XOO1Q6RWCF list<frozen<list<timestamp>>>, LLWYA0DMJK set<float>, K0DJE2T2BP set<frozen<list<boolean>>> );'...
< t:2021-01-28 01:17:04,414 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( JJEPUC3LJL );'...
< t:2021-01-28 01:17:05,783 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( OYPEVVQWM2 set<date>, GE5OBNMPMO set<date>, UWEUI9X3EJ list<inet>, E769YKN378 list<inet> );'...
< t:2021-01-28 01:17:07,848 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( LLWYA0DMJK, UWEUI9X3EJ, OYPEVVQWM2 );'...
< t:2021-01-28 01:17:09,610 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( RO45LA87N8 list<frozen<list<bigint>>>, H1V8NUC1Z8 set<decimal> );'...
< t:2021-01-28 01:17:12,128 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( E769YKN378, K0DJE2T2BP, TZQ7IVG5CP );'...
< t:2021-01-28 01:17:15,121 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( HDJ1BFAHMA list<blob>, A18BIA34IQ list<frozen<map<float,time>>> );'...
< t:2021-01-28 01:17:17,448 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( GE5OBNMPMO, A18BIA34IQ );'...
< t:2021-01-28 01:17:19,705 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( Z1W384VIWX list<frozen<list<inet>>>, VRHHGSM51O set<varchar>, LGGCO0P3XV set<frozen<map<frozen<set<text>>,blob>>> );'...
< t:2021-01-28 01:17:21,525 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( H1V8NUC1Z8, Z1W384VIWX );'...
< t:2021-01-28 01:17:23,557 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( S0N7C5L6ER set<frozen<set<ascii>>> );'...
< t:2021-01-28 01:17:25,885 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( HDJ1BFAHMA, LGGCO0P3XV, VRHHGSM51O );'...
< t:2021-01-28 01:17:28,154 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( W5IHSVKDYD map<ascii,frozen<map<frozen<list<timeuuid>>,tinyint>>>, UPAVUHEH64 map<frozen<list<text>>,frozen<set<text>>> );'...
< t:2021-01-28 01:17:30,482 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( RO45LA87N8, W5IHSVKDYD, S0N7C5L6ER, UPAVUHEH64, XOO1Q6RWCF );'...
< t:2021-01-28 01:17:32,791 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( ZVBMYCWWL7 list<frozen<list<double>>>, VEQGVVJTXO list<frozen<list<smallint>>>, KAYYL23DJA set<frozen<list<decimal>>>, WK8QL1ISBB list<date> );'...
< t:2021-01-28 01:17:34,411 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( ZVBMYCWWL7, WK8QL1ISBB, KAYYL23DJA );'...
< t:2021-01-28 01:17:37,657 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( M1C7FHN753 set<frozen<map<decimal,frozen<map<date,timestamp>>>>>, YZGOPHHFVW map<varint,frozen<map<time,timestamp>>> );'...
< t:2021-01-28 01:17:39,905 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( M1C7FHN753 );'...
< t:2021-01-28 01:17:42,208 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( BI9PR32XTF set<frozen<list<frozen<list<decimal>>>>>, X58FNHNJIB list<double> );'...
< t:2021-01-28 01:17:44,795 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( X58FNHNJIB, VEQGVVJTXO, BI9PR32XTF, YZGOPHHFVW );'...
< t:2021-01-28 01:17:47,005 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( VMKI10WB50 map<frozen<map<varchar,inet>>,ascii> );'...
< t:2021-01-28 01:17:49,345 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( VMKI10WB50 );'...
< t:2021-01-28 01:17:51,750 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( SSK6M69FUK set<frozen<set<date>>>, DIIFUKRM7U set<frozen<list<uuid>>> );'...
< t:2021-01-28 01:17:53,970 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( SSK6M69FUK );'...
< t:2021-01-28 01:17:56,434 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( N1XTAGANG3 list<frozen<list<ascii>>> );'...
< t:2021-01-28 01:17:58,011 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( N1XTAGANG3, DIIFUKRM7U );'...
< t:2021-01-28 01:18:00,220 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( KHQ2ZSH9AV set<frozen<set<boolean>>>, YSUMDE9I28 set<frozen<set<smallint>>>, SO3ZFO6MIS set<frozen<set<varchar>>> );'...
< t:2021-01-28 01:18:02,357 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( KHQ2ZSH9AV, SO3ZFO6MIS, YSUMDE9I28 );'...
< t:2021-01-28 01:18:04,308 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( JFRA8N0MHA map<tinyint,timestamp>, GEC4PI0KGJ list<frozen<list<boolean>>> );'...
< t:2021-01-28 01:18:06,447 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( JFRA8N0MHA );'...
< t:2021-01-28 01:18:08,928 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( OKIRHEZP6E set<frozen<map<inet,decimal>>>, OBLEWPAT2M set<frozen<map<smallint,time>>>, AKNET51JYK list<frozen<list<tinyint>>> );'...
< t:2021-01-28 01:18:11,734 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( GEC4PI0KGJ, OBLEWPAT2M, AKNET51JYK, OKIRHEZP6E );'...
< t:2021-01-28 01:18:13,570 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( N1NXPKBKK2 map<frozen<set<frozen<set<frozen<map<boolean,inet>>>>>>,frozen<map<date,uuid>>>, V6EFWH8R57 map<frozen<map<decimal,text>>,frozen<set<varchar>>>, JF5W64W6UJ list<frozen<set<smallint>>> );'...
< t:2021-01-28 01:18:15,869 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( N1NXPKBKK2, V6EFWH8R57, JF5W64W6UJ );'...
< t:2021-01-28 01:18:18,238 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( Q5KW0OM5DG map<frozen<map<double,smallint>>,frozen<set<timeuuid>>>, MER8C8UCW7 map<frozen<map<bigint,tinyint>>,frozen<list<int>>>, OU81J1W7LB list<frozen<list<float>>> );'...
< t:2021-01-28 01:18:20,078 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( MER8C8UCW7, Q5KW0OM5DG );'...
< t:2021-01-28 01:18:22,617 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( GER8G3AFAE set<frozen<list<tinyint>>>, S9DVXLGOWW map<frozen<map<inet,boolean>>,frozen<list<float>>>, WQD6S1AU1Y list<frozen<map<varchar,frozen<map<varint,float>>>>> );'...
< t:2021-01-28 01:18:25,178 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( S9DVXLGOWW, OU81J1W7LB, WQD6S1AU1Y, GER8G3AFAE );'...
< t:2021-01-28 01:18:28,249 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( A20H9G4FGG list<frozen<map<timestamp,ascii>>> );'...
< t:2021-01-28 01:18:30,012 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( A20H9G4FGG );'...
< t:2021-01-28 01:18:31,535 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( TU0QZC1BAB list<frozen<list<int>>> );'...
< t:2021-01-28 01:18:33,919 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( TU0QZC1BAB );'...
< t:2021-01-28 01:18:35,512 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( ZEJDO82G2I map<frozen<list<date>>,frozen<map<bigint,inet>>>, VN6B42Z81D list<frozen<set<varint>>>, SO8NHMOOG4 list<frozen<list<frozen<set<int>>>>> );'...
< t:2021-01-28 01:18:37,125 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( VN6B42Z81D );'...
< t:2021-01-28 01:18:39,247 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( R3OTLVUEZ4 map<frozen<set<frozen<set<frozen<list<uuid>>>>>>,frozen<set<decimal>>>, ETMNIZTDYW set<frozen<map<frozen<map<date,blob>>,text>>> );'...
< t:2021-01-28 01:18:41,767 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( SO8NHMOOG4, ETMNIZTDYW );'...
< t:2021-01-28 01:18:43,476 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( JL5746JON4 map<frozen<set<varchar>>,frozen<map<decimal,bigint>>> );'...
< t:2021-01-28 01:18:45,616 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( ZEJDO82G2I );'...
< t:2021-01-28 01:18:47,433 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( LSU41J0PH2 set<frozen<set<frozen<list<inet>>>>>, G7KY822PJ9 map<frozen<list<boolean>>,frozen<map<blob,varint>>>, R2P2ZP6E61 set<frozen<list<smallint>>>, BIW475HPMP map<frozen<set<int>>,frozen<list<varchar>>> );'...
< t:2021-01-28 01:18:49,314 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( R2P2ZP6E61, G7KY822PJ9, R3OTLVUEZ4 );'...
< t:2021-01-28 01:18:52,088 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( FP85NIWIHL set<frozen<map<boolean,uuid>>>, P1MPBGNVYY set<frozen<map<timeuuid,bigint>>>, NSPKJIKHUX map<frozen<map<blob,float>>,frozen<list<uuid>>>, KER6W1OYRI map<frozen<set<bigint>>,frozen<list<boolean>>> );'...
< t:2021-01-28 01:18:54,651 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( KER6W1OYRI, NSPKJIKHUX, LSU41J0PH2, FP85NIWIHL, BIW475HPMP );'...
< t:2021-01-28 01:18:57,180 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( J5DYAGXAFT map<frozen<map<ascii,frozen<set<blob>>>>,frozen<map<frozen<map<inet,varchar>>,boolean>>> );'...
< t:2021-01-28 01:18:59,706 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( JL5746JON4, P1MPBGNVYY );'...
< t:2021-01-28 01:19:01,532 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( Y8R3AY7OJ0 map<frozen<map<date,timestamp>>,frozen<list<bigint>>>, ZI3MPN9QH8 set<frozen<set<frozen<list<timeuuid>>>>>, ZEIUGRJ2ZU set<frozen<list<frozen<set<decimal>>>>> );'...
< t:2021-01-28 01:19:05,216 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( J5DYAGXAFT, ZI3MPN9QH8, ZEIUGRJ2ZU );'...
< t:2021-01-28 01:19:07,159 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( HQ6FF1YKZY map<frozen<set<inet>>,frozen<map<frozen<set<blob>>,varchar>>> );'...
< t:2021-01-28 01:19:08,998 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( HQ6FF1YKZY, Y8R3AY7OJ0 );'...
< t:2021-01-28 01:19:11,746 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( GEF0M08YMI list<frozen<set<int>>>, V59720YG97 map<frozen<map<text,frozen<set<double>>>>,frozen<set<inet>>> );'...
< t:2021-01-28 01:19:13,788 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( V59720YG97 );'...
< t:2021-01-28 01:19:19,327 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( Y8D65WKB15 list<frozen<map<smallint,frozen<set<int>>>>>, ONV2X4NYE8 map<frozen<map<time,frozen<list<decimal>>>>,frozen<map<timeuuid,timeuuid>>> );'...
< t:2021-01-28 01:21:10,205 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( ONV2X4NYE8, Y8D65WKB15 );'...
< t:2021-01-28 01:22:14,157 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( GDMAEHE0LQ map<frozen<map<float,time>>,frozen<map<varchar,ascii>>>, VMME8CVPON set<frozen<map<ascii,timeuuid>>>, OPIYV6GVM7 set<frozen<set<bigint>>> );'...
< t:2021-01-28 01:22:17,414 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( GEF0M08YMI, GDMAEHE0LQ );'...
< t:2021-01-28 01:22:20,712 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( YKPTV3FBYE map<frozen<map<frozen<set<blob>>,bigint>>,frozen<set<date>>>, Z1C50JVTFQ list<frozen<list<decimal>>>, L6TGCHK17C map<frozen<set<ascii>>,frozen<set<frozen<map<inet,timestamp>>>>> );'...
< t:2021-01-28 01:22:23,802 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( OPIYV6GVM7, YKPTV3FBYE, Z1C50JVTFQ, VMME8CVPON, L6TGCHK17C );'...
< t:2021-01-28 01:22:34,420 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( Z2B2XB9D0Q list<frozen<set<inet>>>, ML1PAJP1ZW map<frozen<map<frozen<map<tinyint,time>>,int>>,frozen<map<double,frozen<set<double>>>>> );'...
< t:2021-01-28 01:25:14,927 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table DROP ( Z2B2XB9D0Q, ML1PAJP1ZW );'...
< t:2021-01-28 01:25:17,390 f:common.py       l:1174 c:utils                p:DEBUG > Executing CQL 'ALTER TABLE test_table ADD ( YG6YJ2R6RY set<frozen<set<varint>>>, S44P7AWAYO list<frozen<map<frozen<set<text>>,bigint>>> );'...

Logs:

+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
|                                                                                                            Log links for testrun with test id 50c038cd-2a99-4632-82f5-e3c5a7833970                                                                                                             |
+-----------------+-------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Date            | Log type    | Link                                                                                                                                                                                                                                                           |
+-----------------+-------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| 20190101_010101 | prometheus  | https://cloudius-jenkins-test.s3.amazonaws.com/50c038cd-2a99-4632-82f5-e3c5a7833970/prometheus_snapshot_20210128_014203.tar.gz                                                                                                                                 |
| 20210128_013352 | grafana     | https://cloudius-jenkins-test.s3.amazonaws.com/50c038cd-2a99-4632-82f5-e3c5a7833970/20210128_013352/grafana-screenshot-longevity-cdc-100gb-4h-test-scylla-per-server-metrics-nemesis-20210128_013743-longevity-cdc-100gb-4h-master-monitor-node-50c038cd-1.png |
| 20210128_013352 | grafana     | https://cloudius-jenkins-test.s3.amazonaws.com/50c038cd-2a99-4632-82f5-e3c5a7833970/20210128_013352/grafana-screenshot-overview-20210128_013352-longevity-cdc-100gb-4h-master-monitor-node-50c038cd-1.png                                                      |
| 20210128_014223 | grafana     | https://cloudius-jenkins-test.s3.amazonaws.com/50c038cd-2a99-4632-82f5-e3c5a7833970/20210128_014223/grafana-screenshot-longevity-cdc-100gb-4h-test-scylla-per-server-metrics-nemesis-20210128_014539-longevity-cdc-100gb-4h-master-monitor-node-50c038cd-1.png |
| 20210128_014223 | grafana     | https://cloudius-jenkins-test.s3.amazonaws.com/50c038cd-2a99-4632-82f5-e3c5a7833970/20210128_014223/grafana-screenshot-overview-20210128_014223-longevity-cdc-100gb-4h-master-monitor-node-50c038cd-1.png                                                      |
| 20210128_015022 | db-cluster  | https://cloudius-jenkins-test.s3.amazonaws.com/50c038cd-2a99-4632-82f5-e3c5a7833970/20210128_015022/db-cluster-50c038cd.zip                                                                                                                                    |
| 20210128_015022 | loader-set  | https://cloudius-jenkins-test.s3.amazonaws.com/50c038cd-2a99-4632-82f5-e3c5a7833970/20210128_015022/loader-set-50c038cd.zip                                                                                                                                    |
| 20210128_015022 | monitor-set | https://cloudius-jenkins-test.s3.amazonaws.com/50c038cd-2a99-4632-82f5-e3c5a7833970/20210128_015022/monitor-set-50c038cd.zip                                                                                                                                   |
| 20210128_015022 | sct-runner  | https://cloudius-jenkins-test.s3.amazonaws.com/50c038cd-2a99-4632-82f5-e3c5a7833970/20210128_015022/sct-runner-50c038cd.zip                                                                                                                                    |
+-----------------+-------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
CDC bug
Source
picture ShlomiBalalis

All 14 comments

The reason is: one alteration of cdc log table's schema did not reach the SST writer. Coredump shows that sstables::mc::writer uses old schema, i.e. before the ALTER (84fdfa33):

#8  sstables::mc::row_has_complex_deletion (s=..., r=..., kind=column_kind::regular_column) at sstables/mx/writer.cc:1274
(gdb) info args

s = @0x60100876d500: {<seastar::enable_lw_shared_from_this<schema>> = {<seastar::lw_shared_ptr_counter_base> = {_count = 114}, <No data fields>}, _raw = {_id = dcf80512-6103-11eb-a924-e59e2a76ed98, _ks_name = "cdc_test", _cf_name = "test_table_scylla_cdc_log", 
    _columns = {<std::_Vector_base<column_definition, std::allocator<column_definition> >> = {
...
    _version = 84fdfa33-0e7c-3dd7-bf8f-5c7715eaba6b, _dropped_columns = {       // <------------- old schema version
...

meanwhile, scylla-gdb shows new (ALTERed) schema version (bddeced0):

(gdb) scylla column_families
...
   1 dcf80512-6103-11eb-a924-e59e2a76ed98 v=bddeced0-d799-32dd-aaa9-9e2728ec0507 "cdc_test"/"test_table_scylla_cdc_log"        (column_family*)0x60b009211800
...

And logs confirm that (I extracted only the relevant events, in order). Assert message displays the unALTERed schema version:

26501:2021-01-28T01:19:13+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-1 !INFO    | scylla: [shard 0] schema_tables - Altering cdc_test.test_table_scylla_cdc_log id=dcf80512-6103-11eb-a924-e59e2a76ed98 version=84fdfa33-0e7c-3dd7-bf8f-5c7715eaba6b
26593:2021-01-28T01:19:19+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-1 !INFO    | scylla: [shard 8] schema_tables - Altering cdc_test.test_table_scylla_cdc_log id=dcf80512-6103-11eb-a924-e59e2a76ed98 version=bddeced0-d799-32dd-aaa9-9e2728ec0507
26638:2021-01-28T01:19:21+00:00  longevity-cdc-100gb-4h-master-db-node-50c038cd-1 !ERR     | scylla: [shard 1] database - cdc_test.test_table_scylla_cdc_log@84fdfa33-0e7c-3dd7-bf8f-5c7715eaba6b: column id 36 >= 36, at: ... [abort]

I'm yet to figure out why schema in writer wasn't updated. EDIT: it's not about CDC mutations being created before ALTER - checked experimentally. Must be an interleaving at other place.

jul-stas picture jul-stas on 4 Feb 2021

The schema is not upgraded in ongoing reads/writes, this is expected. I thought that schemas are backward compatible with data written by previous schemas but looking at the code it appears this is only true for data in sstables, data in memory has to be processed with the schema it was created with. What is happening here likely resulted from the usage of the wrong schema. Instead of using the schema this data (which still has the dropped column) was written with, the new schema is used.
I'd dump the continuation chain and see who started this write and why is it using the wrong schema object.

denesb picture denesb on 9 Feb 2021
❤1

Check if the schema version of the mx::writer::_schema is the same as that of the flat_mutation_reader

tgrabiec picture tgrabiec on 19 Feb 2021

Check if the schema version of the mx::writer::_schema is the same as that of the flat_mutation_reader

Apparently, writer has the "middle" schema version and flat_mutation_reader::impl has the oldest one:

(gdb) scylla schema ((sstables::mc::writer*)(0x601000cac800))->_schema
(schema*) 0x60100876d500 ks="cdc_test" cf="test_table_scylla_cdc_log" id=dcf80512-6103-11eb-a924-e59e2a76ed98 version=84fdfa33-0e7c-3dd7-bf8f-5c7715eaba6b
...
(gdb) scylla schema ((flat_mutation_reader::impl*)(0x601000875000))->_schema
(schema*) 0x6010084eee00 ks="cdc_test" cf="test_table_scylla_cdc_log" id=dcf80512-6103-11eb-a924-e59e2a76ed98 version=20bcf58e-d499-3400-9c54-100cbcb488f3

EDIT: @bdenes Yes, memtable and CF have both the newest schema.

jul-stas picture jul-stas on 22 Feb 2021

@jul-stas That's wrong, they should use the same schema, not necessarily the newest one.

tgrabiec picture tgrabiec on 22 Feb 2021

Is the writer created on behalf of a memtable flush or compaction?

tgrabiec picture tgrabiec on 22 Feb 2021

Is the writer created on behalf of a memtable flush or compaction?

Reader's permit says that _op_name_view is "memtable-flush".

jul-stas picture jul-stas on 22 Feb 2021

I don't see how that's possible. Both the reader and writer's schema are obtained without a deferring point in the middle (see mt.make_flush_reader(mt.schema(), pc) and mt.schema())

future<>
write_memtable_to_sstable(flat_mutation_reader reader,
                          memtable& mt, sstables::shared_sstable sst,
                          sstables::write_monitor& monitor,
                          sstables::sstable_writer_config& cfg,
                          const io_priority_class& pc) {
    cfg.replay_position = mt.replay_position();
    cfg.monitor = &monitor;
    return sst->write_components(std::move(reader), mt.partition_count(), mt.schema(), cfg, mt.get_encoding_stats(), pc);
}

future<>
write_memtable_to_sstable(memtable& mt, sstables::shared_sstable sst,
                          sstables::write_monitor& monitor,
                          sstables::sstable_writer_config& cfg,
                          const io_priority_class& pc) {
    return write_memtable_to_sstable(mt.make_flush_reader(mt.schema(), pc), mt, std::move(sst), monitor, cfg, pc);
}
tgrabiec picture tgrabiec on 22 Feb 2021

What's the type of the reader impl?

tgrabiec picture tgrabiec on 22 Feb 2021

What's the type of the reader impl?

Apparently it's queue_reader. If I take the reader's address from this frame of aborted stack:

#22 flat_mutation_reader::impl::consume_in_thread<sstables::sstable_writer, flat_mutation_reader::no_filter> (this=0x601000875000, consumer=..., timeout=..., filter=...) at ./flat_mutation_reader.hh:266

Then I get this:

(gdb) x/1a 0x601000875000
0x601000875000: 0x3b8d08 <_ZTV12queue_reader+16>
(gdb) p $downcast_vptr(0x601000875000)
$2 = (queue_reader *) 0x601000875000
jul-stas picture jul-stas on 22 Feb 2021

It's probably a regression introduced in 9124a708f16a6b7644fc643456f40494a6cb5b1a

\cc @raphaelsc

tgrabiec picture tgrabiec on 22 Feb 2021

Patch sent

tgrabiec picture tgrabiec on 22 Feb 2021
🚀1

Patch sent

thanks a lot @tgrabiec

raphaelsc picture raphaelsc on 23 Feb 2021

Backported to 4.4. Older release streams are not affected.

avikivity picture avikivity on 23 Feb 2021
Was this page helpful?
0 / 5 - 0 ratings

Related issues

tgrabiec picture tgrabiec  路  6Comments
gnumoreno picture gnumoreno  路  5Comments
tarzanek picture tarzanek  路  6Comments
tzach picture tzach  路  7Comments
Ritaja picture Ritaja  路  3Comments