Scylla: >10 ms reactor stalls from logalloc::segment_pool::refill_emergency_reserve / row_cache eviction
Seen in QA test using 4.5.dev-0.20210304.45471419d
Scylla version 45471419d
Here's the relevant part in the processed call graph
(using https://github.com/bhalevy/seastar/blob/stall-analyser-20210310.2/scripts/stall-analyser.py -e ~/latency/4.5.dev-0.20210304.45471419d/scylla ~/latency/4.5.dev-0.20210304.45471419d/all_stalls.txt)
Input data: https://s3.console.aws.amazon.com/s3/object/scylla-qa-public?region=us-east-1&prefix=latency_tracker/all_stalls_20210308.txt
Excerpt from
decoded_graph-refill_emergency_reserver-row_cache.txt:
++[0#1/6 57%] addr=0x101902 total=55136 count=4284 avg=13: ?? ??:0
++ - addr=0x93f8: ?? ??:0
++ - addr=0x3e9608a:
| (inlined by) seastar::posix_thread::start_routine at ./build/release/seastar/./seastar/src/core/posix.cc:60
| std::function<void ()>::operator() at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/std_function.h:622
++ - addr=0x3ee9ee8:
| (inlined by) std::_Function_handler<void (), seastar::smp::configure(boost::program_options::variables_map, seastar::reactor_config)::$_97>::_M_invoke at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/std_function.h:291
| (inlined by) std::__invoke_r<void, seastar::smp::configure(boost::program_options::variables_map, seastar::reactor_config)::$_97&> at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/invoke.h:110
| (inlined by) std::__invoke_impl<void, seastar::smp::configure(boost::program_options::variables_map, seastar::reactor_config)::$_97&> at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/invoke.h:60
| operator() at ./build/release/seastar/./seastar/src/core/reactor.cc:4014
++ - addr=0x3ecb937:
| seastar::reactor::run at ./build/release/seastar/./seastar/src/core/reactor.cc:2826
| ++[1#1/8 100%] addr=0x3eca74f total=62561 count=4846 avg=13:
| | (inlined by) seastar::reactor::run_some_tasks at ./build/release/seastar/./seastar/src/core/reactor.cc:2667
| | seastar::reactor::run_tasks at ./build/release/seastar/./seastar/src/core/reactor.cc:2258
| | ++[2#1/76 55%] addr=0x3e72b85 total=34404 count=2194 avg=16:
| | | (inlined by) seastar::lambda_task<seastar::execution_stage::flush()::$_5>::run_and_dispose at ./build/release/seastar/./seastar/include/seastar/core/make_task.hh:40
| | | (inlined by) seastar::futurize<void>::invoke<seastar::execution_stage::flush()::$_5&> at ./build/release/seastar/./seastar/include/seastar/core/future.hh:2132
| | | operator() at ./build/release/seastar/./seastar/src/core/execution_stage.cc:141
| | | ++[3#1/10 53%] addr=0x101629b total=18083 count=1002 avg=18:
| | | | (inlined by) seastar::concrete_execution_stage<seastar::future<seastar::lw_shared_ptr<query::result> >, table*, seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context>::do_flush at ././seastar/include/seastar/core/execution_stage.hh:248
| | | | (inlined by) seastar::futurize<seastar::future<seastar::lw_shared_ptr<query::result> > >::apply<seastar::noncopyable_function<seastar::future<seastar::lw_shared_ptr<query::result> > (table*, seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context)>&, table*, seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context> at ././seastar/include/seastar/core/future.hh:2102
| | | | (inlined by) std::apply<seastar::noncopyable_function<seastar::future<seastar::lw_shared_ptr<query::result> > (table*, seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context)>&, std::tuple<table*, seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context> > at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/tuple:1734
| | | | (inlined by) std::__apply_impl<seastar::noncopyable_function<seastar::future<seastar::lw_shared_ptr<query::result> > (table*, seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context)>&, std::tuple<table*, seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context>, 0ul, 1ul, 2ul, 3ul, 4ul, 5ul, 6ul, 7ul, 8ul, 9ul> at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/tuple:1723
| | | | (inlined by) std::__invoke<seastar::noncopyable_function<seastar::future<seastar::lw_shared_ptr<query::result> > (table*, seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context)>&, table*, seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context> at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/invoke.h:95
| | | | (inlined by) std::__invoke_impl<seastar::future<seastar::lw_shared_ptr<query::result> >, seastar::noncopyable_function<seastar::future<seastar::lw_shared_ptr<query::result> > (table*, seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context)>&, table*, seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context> at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/invoke.h:60
| | | | seastar::noncopyable_function<seastar::future<seastar::lw_shared_ptr<query::result> > (table*, seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context)>::operator() at ././seastar/include/seastar/util/noncopyable_function.hh:209
| | | ++ - addr=0x1047b1a:
| | | | (inlined by) seastar::noncopyable_function<seastar::future<seastar::lw_shared_ptr<query::result> > (table*, seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context)>::direct_vtable_for<seastar::inheriting_concrete_execution_stage<seastar::future<seastar::lw_shared_ptr<query::result> >, table*, seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context>::make_stage_for_group(seastar::scheduling_group)::{lambda(table*, seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context)#1}>::call at ././seastar/include/seastar/util/noncopyable_function.hh:124
| | | | (inlined by) operator() at ././seastar/include/seastar/core/execution_stage.hh:339
| | | | seastar::noncopyable_function<seastar::future<seastar::lw_shared_ptr<query::result> > (table*, seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context)>::operator() at ././seastar/include/seastar/util/noncopyable_function.hh:209
| | | ++ - addr=0x10376c0:
| | | | (inlined by) seastar::noncopyable_function<seastar::future<seastar::lw_shared_ptr<query::result> > (table*, seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context)>::direct_vtable_for<std::_Mem_fn<seastar::future<seastar::lw_shared_ptr<query::result> > (table::*)(seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context)> >::call at ././seastar/include/seastar/util/noncopyable_function.hh:124
| | | | (inlined by) std::_Mem_fn_base<seastar::future<seastar::lw_shared_ptr<query::result> > (table::*)(seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context), true>::operator()<table*, seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context> at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/functional:122
| | | | (inlined by) std::__invoke<seastar::future<seastar::lw_shared_ptr<query::result> > (table::* const&)(seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context), table*, seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context> at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/invoke.h:95
| | | | std::__invoke_impl<seastar::future<seastar::lw_shared_ptr<query::result> >, seastar::future<seastar::lw_shared_ptr<query::result> > (table::* const&)(seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context), table*, seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context> at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/invoke.h:73
| | | ++ - addr=0x10a91e8:
| | | | (inlined by) table::query at ./table.cc:1771
| | | | (inlined by) seastar::future<query::result_memory_accounter>::then<table::query(seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context)::$_51, seastar::future<seastar::lw_shared_ptr<query::result> > > at ././seastar/include/seastar/core/future.hh:1520
| | | | (inlined by) seastar::internal::call_then_impl<seastar::future<query::result_memory_accounter> >::run<table::query(seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context)::$_51> at ././seastar/include/seastar/core/future.hh:1234
| | | | (inlined by) seastar::future<query::result_memory_accounter>::then_impl<table::query(seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context)::$_51, seastar::future<seastar::lw_shared_ptr<query::result> > > at ././seastar/include/seastar/core/future.hh:1601
| | | | seastar::futurize<seastar::future<seastar::lw_shared_ptr<query::result> > >::invoke<table::query(seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context)::$_51, query::result_memory_accounter> at ././seastar/include/seastar/core/future.hh:2135
| | | ++ - addr=0x111fc6d:
| | | | (inlined by) operator() at ./table.cc:1776
| | | | (inlined by) seastar::do_until<table::query(seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context)::$_51::operator()(query::result_memory_accounter)::{lambda()#1}, std::_Bind<bool (query_state::*(std::_Bind*))() const> > at ././seastar/include/seastar/core/loop.hh:341
| | | | (inlined by) seastar::futurize_invoke<table::query(seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context)::$_51::operator()(query::result_memory_accounter)::{lambda()#1}&> at ././seastar/include/seastar/core/future.hh:2166
| | | | (inlined by) seastar::futurize<seastar::future<void> >::invoke<table::query(seastar::lw_shared_ptr<schema const>, query::read_command const&, query::query_class_config, query::result_options, std::vector<nonwrapping_interval<dht::ring_position>, std::allocator<nonwrapping_interval<dht::ring_position> > > const&, tracing::trace_state_ptr, query::result_memory_limiter&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, query::querier_cache_context)::$_51::operator()(query::result_memory_accounter)::{lambda()#1}&> at ././seastar/include/seastar/core/future.hh:2135
| | | | operator() at ./table.cc:1778
| | | | ++[4#1/2 99%] addr=0x132ebbd total=17845 count=972 avg=18:
| | | | | data_query at ./mutation_partition.cc:1985
| | | | | ++[5#1/2 100%] addr=0x132f313 total=17839 count=971 avg=18:
| | | | | | (inlined by) querier at ././querier.hh:213
| | | | | | (inlined by) querier_base at ././querier.hh:147
| | | | | | (inlined by) mutation_source::make_reader at ././mutation_reader.hh:250
| | | | | | std::function<flat_mutation_reader (seastar::lw_shared_ptr<schema const>, reader_permit, nonwrapping_interval<dht::ring_position> const&, query::partition_slice const&, seastar::io_priority_class const&, tracing::trace_state_ptr, seastar::bool_class<streamed_mutation::forwarding_tag>, seastar::bool_class<flat_mutation_reader::partition_range_forwarding_tag>)>::operator() at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/std_function.h:622
| | | | | ++ - addr=0x1126a12:
| | | | | | (inlined by) std::_Function_handler<flat_mutation_reader (seastar::lw_shared_ptr<schema const>, reader_permit, nonwrapping_interval<dht::ring_position> const&, query::partition_slice const&, seastar::io_priority_class const&, tracing::trace_state_ptr, seastar::bool_class<streamed_mutation::forwarding_tag>, seastar::bool_class<flat_mutation_reader::partition_range_forwarding_tag>), table::as_mutation_source() const::$_52>::_M_invoke at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/std_function.h:291
| | | | | | (inlined by) std::__invoke_r<flat_mutation_reader, table::as_mutation_source() const::$_52&, seastar::lw_shared_ptr<schema const>, reader_permit, nonwrapping_interval<dht::ring_position> const&, query::partition_slice const&, seastar::io_priority_class const&, tracing::trace_state_ptr, seastar::bool_class<streamed_mutation::forwarding_tag>, seastar::bool_class<flat_mutation_reader::partition_range_forwarding_tag> > at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/invoke.h:113
| | | | | | (inlined by) std::__invoke_impl<flat_mutation_reader, table::as_mutation_source() const::$_52&, seastar::lw_shared_ptr<schema const>, reader_permit, nonwrapping_interval<dht::ring_position> const&, query::partition_slice const&, seastar::io_priority_class const&, tracing::trace_state_ptr, seastar::bool_class<streamed_mutation::forwarding_tag>, seastar::bool_class<flat_mutation_reader::partition_range_forwarding_tag> > at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/invoke.h:60
| | | | | | operator() at ./table.cc:1803
| | | | | | ++[6#1/3 100%] addr=0x10775c0 total=17819 count=968 avg=18:
| | | | | | | table::make_reader at ./table.cc:189
| | | | | | ++ - addr=0x1263776:
| | | | | | | (inlined by) memtable::make_flat_reader at ./memtable.cc:655
| | | | | | | (inlined by) logalloc::allocating_section::operator()<memtable::make_flat_reader(seastar::lw_shared_ptr<schema const>, reader_permit, nonwrapping_interval<dht::ring_position> const&, query::partition_slice const&, seastar::io_priority_class const&, tracing::trace_state_ptr, seastar::bool_class<streamed_mutation::forwarding_tag>, seastar::bool_class<flat_mutation_reader::partition_range_forwarding_tag>)::$_5> at ././utils/logalloc.hh:778
| | | | | | | logalloc::allocating_section::with_reserve<logalloc::allocating_section::operator()<memtable::make_flat_reader(seastar::lw_shared_ptr<schema const>, reader_permit, nonwrapping_interval<dht::ring_position> const&, query::partition_slice const&, seastar::io_priority_class const&, tracing::trace_state_ptr, seastar::bool_class<streamed_mutation::forwarding_tag>, seastar::bool_class<flat_mutation_reader::partition_range_forwarding_tag>)::$_5>(logalloc::region&, memtable::make_flat_reader(seastar::lw_shared_ptr<schema const>, reader_permit, nonwrapping_interval<dht::ring_position> const&, query::partition_slice const&, seastar::io_priority_class const&, tracing::trace_state_ptr, seastar::bool_class<streamed_mutation::forwarding_tag>, seastar::bool_class<flat_mutation_reader::partition_range_forwarding_tag>)::$_5&&)::{lambda()#1}> at ././utils/logalloc.hh:727
| | | | | | ++ - addr=0x12afd97:
| | | | | | | (inlined by) logalloc::allocating_section::reserve at ./utils/logalloc.cc:2407
| | | | | | | logalloc::segment_pool::refill_emergency_reserve at ./utils/logalloc.cc:928
| | | | | | | ++[7#1/4 100%] addr=0x1292977 total=78369 count=7410 avg=11:
| | | | | | | | (inlined by) logalloc::segment_pool::allocate_segment at ./utils/logalloc.cc:915
| | | | | | | | logalloc::tracker::impl::compact_and_evict at ./utils/logalloc.cc:2050
| | | | | | | | ++[8#1/31 75%] addr=0x129b413 total=59118 count=4843 avg=12:
| | | | | | | | | (inlined by) logalloc::tracker::impl::compact_and_evict_locked at ./utils/logalloc.cc:2117
| | | | | | | | | (inlined by) logalloc::reclaim_from_evictable at ./utils/logalloc.cc:1922
| | | | | | | | | (inlined by) logalloc::region_impl::evict_some at ./utils/logalloc.cc:1701
| | | | | | | | | std::function<seastar::memory::reclaiming_result ()>::operator() at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/std_function.h:622
| | | | | | | | | ++[9#1/13 99%] addr=0x122aadb total=58961 count=4842 avg=12:
| | | | | | | | | | (inlined by) std::_Function_handler<seastar::memory::reclaiming_result (), cache_tracker::cache_tracker(mutation_application_stats&)::$_0>::_M_invoke at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/std_function.h:291
| | | | | | | | | | (inlined by) std::__invoke_r<seastar::memory::reclaiming_result, cache_tracker::cache_tracker(mutation_application_stats&)::$_0&> at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/invoke.h:113
| | | | | | | | | | (inlined by) std::__invoke_impl<seastar::memory::reclaiming_result, cache_tracker::cache_tracker(mutation_application_stats&)::$_0&> at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/invoke.h:60
| | | | | | | | | | (inlined by) operator() at ./row_cache.cc:65
| | | | | | | | | | (inlined by) with_allocator<cache_tracker::cache_tracker(mutation_application_stats&)::$_0::operator()() const::{lambda()#1}> at ././utils/allocation_strategy.hh:311
| | | | | | | | | | operator() at ./row_cache.cc:80
| | | | | | | | | | ++[10#1/91 47%] addr=0x11fa43c total=27605 count=2421 avg=11:
| | | | | | | | | | | (inlined by) rows_entry::on_evicted at ./row_cache.cc:1217
| | | | | | | | | | | (inlined by) intrusive_b::tree<rows_entry, &rows_entry::_link, rows_entry::tri_compare, 12ul, 20ul, (intrusive_b::key_search)0, (intrusive_b::with_debug)0>::iterator::erase_and_dispose<current_deleter<rows_entry>()::{lambda(rows_entry*)#1}> at ././utils/intrusive_btree.hh:916
| | | | | | | | | | | (inlined by) intrusive_b::node<rows_entry, &rows_entry::_link, rows_entry::tri_compare, 12ul, 20ul, (intrusive_b::key_search)0, (intrusive_b::with_debug)0>::dispose_key<current_deleter<rows_entry>()::{lambda(rows_entry*)#1}&> at ././utils/intrusive_btree.hh:1330
| | | | | | | | | | | (inlined by) operator() at ././utils/allocation_strategy.hh:242
| | | | | | | | | | | (inlined by) allocation_strategy::destroy<rows_entry> at ././utils/allocation_strategy.hh:165
| | | | | | | | | | | (inlined by) ~rows_entry at ././mutation_partition.hh:893
| | | | | | | | | | | ~deletable_row at ././mutation_partition.hh:822
| | | | | | | | | | | ++[11#1/26 93%] addr=0x1322860 total=25589 count=2239 avg=11:
| | | | | | | | | | | | (inlined by) ~row at ./mutation_partition.cc:1466
| | | | | | | | | | | | (inlined by) ~tree at ././utils/compact-radix-tree.hh:1789
| | | | | | | | | | | | (inlined by) compact_radix_tree::tree<cell_and_hash, unsigned int>::clear at ././utils/compact-radix-tree.hh:1856
| | | | | | | | | | | | (inlined by) compact_radix_tree::tree<cell_and_hash, unsigned int>::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor> at ././utils/compact-radix-tree.hh:1655
| | | | | | | | | | | | (inlined by) compact_radix_tree::tree<cell_and_hash, unsigned int>::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor>(compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor&&)::adaptor> at ././utils/compact-radix-tree.hh:1636
| | | | | | | | | | | | (inlined by) compact_radix_tree::tree<cell_and_hash, unsigned int>::node_head::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor>(compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor&&)::adaptor> at ././utils/compact-radix-tree.hh:485
| | | | | | | | | | | | (inlined by) compact_radix_tree::tree<cell_and_hash, unsigned int>::node_base<cell_and_hash, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)1, 4u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)2, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)0, 0u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)2, 8u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)1, 4u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 16u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)4, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)2, 8u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)4, 32u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)6, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 16u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::direct_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)6, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)0, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)4, 32u> >::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor>(compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor&&)::adaptor&> at ././utils/compact-radix-tree.hh:815
| | | | | | | | | | | | compact_radix_tree::tree<cell_and_hash, unsigned int>::node_base<cell_and_hash, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)1, 4u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)2, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)0, 0u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)2, 8u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)1, 4u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 16u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)4, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)2, 8u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)4, 32u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)6, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 16u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::direct_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)6, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)0, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)4, 32u> >::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor>(compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor&&)::adaptor&, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)1, 4u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)2, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)0, 0u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)2, 8u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)1, 4u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 16u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)4, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)2, 8u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)4, 32u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)6, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 16u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::direct_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)6, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)0, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)4, 32u> > at ././utils/compact-radix-tree.hh:810
| | | | | | | | | | | | ++[12#1/51 45%] addr=0x13e8e08 total=11640 count=1063 avg=11:
| | | | | | | | | | | | | (inlined by) compact_radix_tree::tree<cell_and_hash, unsigned int>::node_base<cell_and_hash, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)1, 4u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)2, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)0, 0u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)2, 8u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)1, 4u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 16u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)4, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)2, 8u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)4, 32u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)6, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 16u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::direct_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)6, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)0, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)4, 32u> >::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor>(compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor&&)::adaptor&, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)2, 8u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)1, 4u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 16u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)4, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)2, 8u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)4, 32u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)6, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 16u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::direct_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)6, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)0, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)4, 32u> > at ././utils/compact-radix-tree.hh:807
| | | | | | | | | | | | | (inlined by) compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)2, 8u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)1, 4u>::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor>(compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor&&)::adaptor&> at ././utils/compact-radix-tree.hh:1372
| | | | | | | | | | | | | (inlined by) compact_radix_tree::tree<cell_and_hash, unsigned int>::visit_slot<compact_radix_tree::tree<cell_and_hash, unsigned int>::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor>(compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor&&)::adaptor&> at ././utils/compact-radix-tree.hh:1570
| | | | | | | | | | | | | (inlined by) operator() at ././utils/compact-radix-tree.hh:1647
| | | | | | | | | | | | | (inlined by) operator() at ././utils/compact-radix-tree.hh:1844
| | | | | | | | | | | | | (inlined by) ~cell_and_hash at ././mutation_partition.hh:75
| | | | | | | | | | | | | (inlined by) ~atomic_cell_or_collection at ././atomic_cell_or_collection.hh:33
| | | | | | | | | | | | | (inlined by) ~managed_bytes at ././utils/managed_bytes.hh:194
| | | | | | | | | | | | | managed_bytes::free_chain at ././utils/managed_bytes.hh:107
| | | | | | | | | | | | |+[12#2/51 39%] addr=0x13e8e18 total=9978 count=884 avg=11:
| | | | | | | | | | | | | (inlined by) compact_radix_tree::tree<cell_and_hash, unsigned int>::node_base<cell_and_hash, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)1, 4u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)2, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)0, 0u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)2, 8u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)1, 4u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 16u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)4, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)2, 8u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)4, 32u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)6, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 16u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::direct_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)6, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)0, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)4, 32u> >::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor>(compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor&&)::adaptor&, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)2, 8u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)1, 4u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 16u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)4, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)2, 8u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)4, 32u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)6, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 16u>, compact_radix_tree::tree<cell_and_hash, unsigned int>::direct_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)6, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)0, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)4, 32u> > at ././utils/compact-radix-tree.hh:807
| | | | | | | | | | | | | (inlined by) compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)2, 8u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)1, 4u>::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor>(compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor&&)::adaptor&> at ././utils/compact-radix-tree.hh:1372
| | | | | | | | | | | | | (inlined by) compact_radix_tree::tree<cell_and_hash, unsigned int>::visit_slot<compact_radix_tree::tree<cell_and_hash, unsigned int>::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor>(compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor&&)::adaptor&> at ././utils/compact-radix-tree.hh:1570
| | | | | | | | | | | | | (inlined by) operator() at ././utils/compact-radix-tree.hh:1647
| | | | | | | | | | | | | (inlined by) operator() at ././utils/compact-radix-tree.hh:1844
| | | | | | | | | | | | | (inlined by) ~cell_and_hash at ././mutation_partition.hh:75
| | | | | | | | | | | | | (inlined by) ~atomic_cell_or_collection at ././atomic_cell_or_collection.hh:33
| | | | | | | | | | | | | (inlined by) ~managed_bytes at ././utils/managed_bytes.hh:194
| | | | | | | | | | | | | (inlined by) managed_bytes::free_chain at ././utils/managed_bytes.hh:108
| | | | | | | | | | | | | allocation_strategy::destroy<blob_storage> at ././utils/allocation_strategy.hh:166
| | | | | | | | | | | | | ++[13#1/105 18%] addr=0x12c0bf3 total=1811 count=175 avg=10:
| | | | | | | | | | | | | | (inlined by) logalloc::region_impl::free at ./utils/logalloc.cc:1558
| | | | | | | | | | | | | | logalloc::region_impl::object_descriptor::decode_backwards at ./utils/logalloc.cc:1214
latency
bhalevy
All 20 comments
cc @avikivity @tgrabiec
bhalevy
on 10 Mar 2021
@fgelcer is running an instrumented build that will show which table, which section, and what are the reservation sizes.
avikivity
on 10 Mar 2021
Instrumentation is in https://github.com/avikivity/scylla/tree/print-logalloc-stalls
avikivity
on 10 Mar 2021
it is finally running here
fgelcer
on 11 Mar 2021
👍2
Here's some logs:
Mar 11 11:06:56 perf-latency-nemesis-latency--db-node-886beea2-1 systemd-logind[689]: New session 1905 of user scyllaadm.
Mar 11 11:06:56 perf-latency-nemesis-latency--db-node-886beea2-1 scylla[3302]: [shard 3] lsa - allocating_section row_cache update_section for keyspace1:standard1: 4990us stall, std reserve 1024 lsa reserve 10: cache_flat_mutation_reader maybe_add_to_cache
A stall, coinciding with a login
Mar 11 11:06:56 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16757]: Accepted publickey for centos from 10.0.0.137 port 58566 ssh2: RSA SHA256:1YmYWh7roz4Y3FSY7N8CetmQNlK/K5FeBPITC8KF0u8
Mar 11 11:06:51 perf-latency-nemesis-latency--db-node-886beea2-1 systemd-logind[689]: Removed session 1904.
Mar 11 11:06:51 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16739]: pam_unix(sshd:session): session closed for user centos
Mar 11 11:06:50 perf-latency-nemesis-latency--db-node-886beea2-1 systemd[1]: Started Session 1904 of user scyllaadm.
Mar 11 11:06:50 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16739]: pam_unix(sshd:session): session opened for user centos by (uid=0)
Mar 11 11:06:50 perf-latency-nemesis-latency--db-node-886beea2-1 systemd-logind[689]: New session 1904 of user scyllaadm.
Mar 11 11:06:50 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16739]: Accepted publickey for centos from 10.0.0.137 port 58502 ssh2: RSA SHA256:1YmYWh7roz4Y3FSY7N8CetmQNlK/K5FeBPITC8KF0u8
Mar 11 11:06:45 perf-latency-nemesis-latency--db-node-886beea2-1 systemd-logind[689]: Removed session 1903.
Mar 11 11:06:45 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16721]: pam_unix(sshd:session): session closed for user centos
Mar 11 11:06:45 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16721]: pam_unix(sshd:session): session opened for user centos by (uid=0)
Mar 11 11:06:45 perf-latency-nemesis-latency--db-node-886beea2-1 systemd[1]: Started Session 1903 of user scyllaadm.
Mar 11 11:06:45 perf-latency-nemesis-latency--db-node-886beea2-1 systemd-logind[689]: New session 1903 of user scyllaadm.
Mar 11 11:06:45 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16721]: Accepted publickey for centos from 10.0.0.137 port 58440 ssh2: RSA SHA256:1YmYWh7roz4Y3FSY7N8CetmQNlK/K5FeBPITC8KF0u8
Mar 11 11:06:40 perf-latency-nemesis-latency--db-node-886beea2-1 systemd-logind[689]: Removed session 1902.
Mar 11 11:06:40 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16702]: pam_unix(sshd:session): session closed for user centos
Mar 11 11:06:40 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16702]: pam_unix(sshd:session): session opened for user centos by (uid=0)
Mar 11 11:06:40 perf-latency-nemesis-latency--db-node-886beea2-1 systemd[1]: Started Session 1902 of user scyllaadm.
Mar 11 11:06:40 perf-latency-nemesis-latency--db-node-886beea2-1 systemd-logind[689]: New session 1902 of user scyllaadm.
Mar 11 11:06:40 perf-latency-nemesis-latency--db-node-886beea2-1 scylla[3302]: [shard 5] lsa - allocating_section memtable allocating section for keyspace1:standard1: 7101us stall, std reserve 1024 lsa reserve 10: memtable::apply, mem usage 1510
Mar 11 11:06:40 perf-latency-nemesis-latency--db-node-886beea2-1 scylla[3302]: [shard 5] lsa - allocating_section memtable allocating section for keyspace1:standard1: 8103us stall, std reserve 1024 lsa reserve 10: memtable::apply, mem usage 1510
Mar 11 11:06:40 perf-latency-nemesis-latency--db-node-886beea2-1 scylla[3302]: [shard 5] lsa - allocating_section memtable allocating section for keyspace1:standard1: 8067us stall, std reserve 1024 lsa reserve 10: memtable::apply, mem usage 1510
Mar 11 11:06:40 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16702]: Accepted publickey for centos from 10.0.0.137
More stalls conciding with logins
```port 58378 ssh2: RSA SHA256:1YmYWh7roz4Y3FSY7N8CetmQNlK/K5FeBPITC8KF0u8
Mar 11 11:06:35 perf-latency-nemesis-latency--db-node-886beea2-1 systemd-logind[689]: Removed session 1901.
Mar 11 11:06:35 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16684]: pam_unix(sshd:session): session closed for user centos
Mar 11 11:06:35 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16684]: pam_unix(sshd:session): session opened for user centos by (uid=0)
Mar 11 11:06:35 perf-latency-nemesis-latency--db-node-886beea2-1 systemd[1]: Started Session 1901 of user scyllaadm.
Mar 11 11:06:35 perf-latency-nemesis-latency--db-node-886beea2-1 systemd-logind[689]: New session 1901 of user scyllaadm.
Mar 11 11:06:34 perf-latency-nemesis-latency--db-node-886beea2-1 scylla[3302]: [shard 4] lsa - allocating_section memtable allocating section for keyspace1:standard1: 9072us stall, std reserve 1024 lsa reserve 10: memtable::apply, mem usage 1510
Mar 11 11:06:34 perf-latency-nemesis-latency--db-node-886beea2-1 scylla[3302]: [shard 4] lsa - allocating_section row_cache read_section for keyspace1:standard1: 8114us stall, std reserve 1024 lsa reserve 10: cache_flat_mutation_reader do_fill_buffer
Mar 11 11:06:34 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16684]: Accepted publickey for centos from 10.0.0.137
port 58310 ssh2: RSA SHA256:1YmYWh7roz4Y3FSY7N8CetmQNlK/K5FeBPITC8KF0u8
Mar 11 11:06:29 perf-latency-nemesis-latency--db-node-886beea2-1 sudo[16677]: pam_unix(sudo:session): session closed for user root
Mar 11 11:06:29 perf-latency-nemesis-latency--db-node-886beea2-1 sudo[16677]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 11 11:06:29 perf-latency-nemesis-latency--db-node-886beea2-1 sudo[16677]: scyllaadm : TTY=unknown ; PWD=/home/scyllaadm ; USER=root ; COMMAND=/bin/coredumpctl --no-pager --no-legend
Mar 11 11:06:29 perf-latency-nemesis-latency--db-node-886beea2-1 systemd-logind[689]: Removed session 1900.
Mar 11 11:06:29 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16654]: pam_unix(sshd:session): session closed for user centos
Mar 11 11:06:29 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16654]: pam_unix(sshd:session): session opened for user centos by (uid=0)
Mar 11 11:06:29 perf-latency-nemesis-latency--db-node-886beea2-1 systemd[1]: Started Session 1900 of user scyllaadm.
Mar 11 11:06:29 perf-latency-nemesis-latency--db-node-886beea2-1 systemd-logind[689]: New session 1900 of user scyllaadm.
Mar 11 11:06:29 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16654]: Accepted publickey for centos from 10.0.0.137 port 58248 ssh2: RSA SHA256:1YmYWh7roz4Y3FSY7N8CetmQNlK/K5FeBPITC8KF0u8
Mar 11 11:06:24 perf-latency-nemesis-latency--db-node-886beea2-1 systemd-logind[689]: Removed session 1899.
Mar 11 11:06:24 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16635]: pam_unix(sshd:session): session closed for user centos
Mar 11 11:06:24 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16635]: pam_unix(sshd:session): session opened for user centos by (uid=0)
Mar 11 11:06:24 perf-latency-nemesis-latency--db-node-886beea2-1 systemd[1]: Started Session 1899 of user scyllaadm.
Mar 11 11:06:24 perf-latency-nemesis-latency--db-node-886beea2-1 systemd-logind[689]: New session 1899 of user scyllaadm.
Mar 11 11:06:24 perf-latency-nemesis-latency--db-node-886beea2-1 scylla[3302]: [shard 4] lsa - allocating_section memtable allocating section for keyspace1:standard1: 8068us stall, std reserve 1024 lsa reserve 10: memtable::apply, mem usage 1510
Mar 11 11:06:24 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16635]: Accepted publickey for centos from 10.0.0.137
port 58178 ssh2: RSA SHA256:1YmYWh7roz4Y3FSY7N8CetmQNlK/K5FeBPITC8KF0u8
Mar 11 11:06:24 perf-latency-nemesis-latency--db-node-886beea2-1 scylla[3302]: [shard 4] lsa - allocating_section memtable allocating section for keyspace1:standard1: 4937us stall, std reserve 1024 lsa reserve 10: memtable::apply, mem usage 1510
Mar 11 11:06:19 perf-latency-nemesis-latency--db-node-886beea2-1 systemd-logind[689]: Removed session 1898.
Mar 11 11:06:19 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16617]: pam_unix(sshd:session): session closed for user centos
Mar 11 11:06:19 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16617]: pam_unix(sshd:session): session opened for user centos by (uid=0)
Mar 11 11:06:19 perf-latency-nemesis-latency--db-node-886beea2-1 scylla[3302]: [shard 7] lsa - allocating_section memtable allocating section for keyspace1:standard1: 3233us stall, std reserve 1024 lsa reserve 10: memtable::apply, mem usage 1510
Mar 11 11:06:19 perf-latency-nemesis-latency--db-node-886beea2-1 systemd[1]: Started Session 1898 of user scyllaadm.
Mar 11 11:06:19 perf-latency-nemesis-latency--db-node-886beea2-1 systemd-logind[689]: New session 1898 of user scyllaadm.
Mar 11 11:06:18 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16617]: Accepted publickey for centos from 10.0.0.137 port 58114 ssh2: RSA SHA256:1YmYWh7roz4Y3FSY7N8CetmQNlK/K5FeBPITC8KF0u8
Mar 11 11:06:18 perf-latency-nemesis-latency--db-node-886beea2-1 scylla[3302]: [shard 2] lsa - allocating_section memtable allocating section for keyspace1:standard1: 8050us stall, std reserve 1024 lsa reserve 10: memtable::apply, mem usage 1510
Mar 11 11:06:13 perf-latency-nemesis-latency--db-node-886beea2-1 systemd-logind[689]: Removed session 1897.
Mar 11 11:06:13 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16598]: pam_unix(sshd:session): session closed for user centos
Mar 11 11:06:13 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16598]: pam_unix(sshd:session): session opened for user centos by (uid=0)
Mar 11 11:06:13 perf-latency-nemesis-latency--db-node-886beea2-1 systemd[1]: Started Session 1897 of user scyllaadm.
Mar 11 11:06:13 perf-latency-nemesis-latency--db-node-886beea2-1 systemd-logind[689]: New session 1897 of user scyllaadm.
Mar 11 11:06:13 perf-latency-nemesis-latency--db-node-886beea2-1 scylla[3302]: [shard 2] lsa - allocating_section memtable allocating section for keyspace1:standard1: 8205us stall, std reserve 1024 lsa reserve 10: memtable::apply, mem usage 1510
Mar 11 11:06:13 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16598]: Accepted publickey for centos from 10.0.0.137 port 58048 ssh2: RSA SHA256:1YmYWh7roz4Y3FSY7N8CetmQNlK/K5FeBPITC8KF0u8
Mar 11 11:06:08 perf-latency-nemesis-latency--db-node-886beea2-1 systemd-logind[689]: Removed session 1896.
Mar 11 11:06:08 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16579]: pam_unix(sshd:session): session closed for user centos
Mar 11 11:06:08 perf-latency-nemesis-latency--db-node-886beea2-1 sshd[16579]: pam_unix(sshd:session): session opened for user centos by (uid=0)
```
Of course, there are many stalls and many logins. The question is whether all stalls are associated with a login.
avikivity
on 11 Mar 2021
I reniced all threads to -15, did not help.
avikivity
on 11 Mar 2021
Let's say the login's are related to the stalls, I'm trying to think of a theory that might explain them.
Why is the stall happening where it is?
bhalevy
on 11 Mar 2021
I don't think we make any system call in that path, do we?
bhalevy
on 11 Mar 2021
Maybe someone issues a REST call that eats memory.
avikivity
on 11 Mar 2021
1 0.000000000 127.0.0.1 -> 127.0.0.1 HTTP 304 GET /storage_service/nodes/leaving HTTP/1.1
2 0.000222881 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
3 0.000241434 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=239 Ack=133 Win=511 Len=0 TSval=2046757027 TSecr=2046757027
4 0.009918613 127.0.0.1 -> 127.0.0.1 HTTP 304 GET /storage_service/nodes/joining HTTP/1.1
5 0.010264406 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
6 0.010285536 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=477 Ack=265 Win=511 Len=0 TSval=2046757037 TSecr=2046757037
7 0.019779615 127.0.0.1 -> 127.0.0.1 HTTP 221 GET /v2/config/client_encryption_options HTTP/1.1
8 0.019870326 127.0.0.1 -> 127.0.0.1 HTTP 216 HTTP/1.1 200 OK (application/json)
9 0.019879852 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=632 Ack=415 Win=511 Len=0 TSval=2046757047 TSecr=2046757047
10 0.020941002 127.0.0.1 -> 127.0.0.1 HTTP 213 GET /v2/config/broadcast_address HTTP/1.1
11 0.021074800 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
12 0.021093212 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=779 Ack=547 Win=511 Len=0 TSval=2046757048 TSecr=2046757048
13 0.021880731 127.0.0.1 -> 127.0.0.1 HTTP 217 GET /v2/config/broadcast_rpc_address HTTP/1.1
14 0.022053830 127.0.0.1 -> 127.0.0.1 HTTP 209 HTTP/1.1 200 OK (application/json)
15 0.022068278 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=930 Ack=690 Win=511 Len=0 TSval=2046757049 TSecr=2046757049
16 0.024917792 127.0.0.1 -> 127.0.0.1 HTTP 210 GET /v2/config/listen_address HTTP/1.1
17 0.025228028 127.0.0.1 -> 127.0.0.1 HTTP 209 HTTP/1.1 200 OK (application/json)
18 0.025242663 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=1074 Ack=833 Win=511 Len=0 TSval=2046757052 TSecr=2046757052
19 0.027875019 127.0.0.1 -> 127.0.0.1 HTTP 217 GET /v2/config/native_transport_port HTTP/1.1
20 0.028026634 127.0.0.1 -> 127.0.0.1 HTTP 200 HTTP/1.1 200 OK (application/json)
21 0.028040254 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=1225 Ack=967 Win=511 Len=0 TSval=2046757055 TSecr=2046757055
22 0.040032549 127.0.0.1 -> 127.0.0.1 HTTP 221 GET /v2/config/native_transport_port_ssl HTTP/1.1
23 0.040289695 127.0.0.1 -> 127.0.0.1 HTTP 200 HTTP/1.1 200 OK (application/json)
24 0.040303608 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=1380 Ack=1101 Win=511 Len=0 TSval=2046757067 TSecr=2046757067
25 0.047892664 127.0.0.1 -> 127.0.0.1 HTTP 214 GET /v2/config/prometheus_address HTTP/1.1
26 0.048022769 127.0.0.1 -> 127.0.0.1 HTTP 205 HTTP/1.1 200 OK (application/json)
27 0.055807719 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=1528 Ack=1240 Win=512 Len=0 TSval=2046757083 TSecr=2046757075
28 0.055936906 127.0.0.1 -> 127.0.0.1 HTTP 211 GET /v2/config/prometheus_port HTTP/1.1
29 0.056105764 127.0.0.1 -> 127.0.0.1 HTTP 200 HTTP/1.1 200 OK (application/json)
30 0.062820531 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=1673 Ack=1374 Win=512 Len=0 TSval=2046757090 TSecr=2046757083
31 0.062990919 127.0.0.1 -> 127.0.0.1 HTTP 207 GET /v2/config/rpc_address HTTP/1.1
32 0.063169201 127.0.0.1 -> 127.0.0.1 HTTP 209 HTTP/1.1 200 OK (application/json)
33 0.069825524 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=1814 Ack=1517 Win=512 Len=0 TSval=2046757097 TSecr=2046757090
34 0.070014041 127.0.0.1 -> 127.0.0.1 HTTP 204 GET /v2/config/rpc_port HTTP/1.1
35 0.070237022 127.0.0.1 -> 127.0.0.1 HTTP 200 HTTP/1.1 200 OK (application/json)
36 0.077806976 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=1952 Ack=1651 Win=512 Len=0 TSval=2046757105 TSecr=2046757097
37 0.077984737 127.0.0.1 -> 127.0.0.1 HTTP 214 GET /v2/config/alternator_address HTTP/1.1
38 0.078093580 127.0.0.1 -> 127.0.0.1 HTTP 205 HTTP/1.1 200 OK (application/json)
39 0.085786499 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=2100 Ack=1790 Win=512 Len=0 TSval=2046757113 TSecr=2046757105
40 0.085954610 127.0.0.1 -> 127.0.0.1 HTTP 211 GET /v2/config/alternator_port HTTP/1.1
41 0.086144455 127.0.0.1 -> 127.0.0.1 HTTP 197 HTTP/1.1 200 OK (application/json)
42 0.091790839 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=2245 Ack=1921 Win=512 Len=0 TSval=2046757119 TSecr=2046757113
43 0.091956909 127.0.0.1 -> 127.0.0.1 HTTP 217 GET /v2/config/alternator_https_port HTTP/1.1
44 0.092161048 127.0.0.1 -> 127.0.0.1 HTTP 197 HTTP/1.1 200 OK (application/json)
45 0.098807064 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=2396 Ack=2052 Win=512 Len=0 TSval=2046757126 TSecr=2046757119
46 0.098927011 127.0.0.1 -> 127.0.0.1 HTTP 209 GET /v2/config/authenticator HTTP/1.1
47 0.099149432 127.0.0.1 -> 127.0.0.1 HTTP 246 HTTP/1.1 200 OK (application/json)
48 0.105788434 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=2539 Ack=2232 Win=512 Len=0 TSval=2046757133 TSecr=2046757126
49 0.105978162 127.0.0.1 -> 127.0.0.1 HTTP 228 GET /v2/config/alternator_enforce_authorization HTTP/1.1
50 0.106104722 127.0.0.1 -> 127.0.0.1 HTTP 201 HTTP/1.1 200 OK (application/json)
51 0.108765732 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=2701 Ack=2367 Win=512 Len=0 TSval=2046757136 TSecr=2046757133
52 0.111151441 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /storage_service/host_id HTTP/1.1
53 0.111539870 127.0.0.1 -> 127.0.0.1 HTTP 411 HTTP/1.1 200 OK (application/json)
54 0.111572292 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=2933 Ack=2712 Win=521 Len=0 TSval=2046757139 TSecr=2046757139
55 15.018978212 127.0.0.1 -> 127.0.0.1 HTTP 304 GET /storage_service/nodes/joining HTTP/1.1
56 15.022948798 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
57 15.022966191 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=3171 Ack=2844 Win=529 Len=0 TSval=2046772050 TSecr=2046772050
58 15.356777929 127.0.0.1 -> 127.0.0.1 TCP 66 33208 > ndmp [ACK] Seq=1 Ack=1 Win=512 Len=0 TSval=2046772384 TSecr=2046742047
59 15.356893728 127.0.0.1 -> 127.0.0.1 TCP 66 [TCP ACKed unseen segment] ndmp > 33208 [ACK] Seq=1 Ack=2 Win=512 Len=0 TSval=2046772384 TSecr=2046742047
60 15.372056810 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /gossiper/endpoint/live/ HTTP/1.1
61 15.377925575 127.0.0.1 -> 127.0.0.1 HTTP 236 HTTP/1.1 200 OK (application/json)
62 15.377940323 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=3403 Ack=3014 Win=537 Len=0 TSval=2046772405 TSecr=2046772405
63 15.394993039 127.0.0.1 -> 127.0.0.1 HTTP 304 GET /storage_service/nodes/joining HTTP/1.1
64 15.397976754 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
65 15.397991537 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=3641 Ack=3146 Win=546 Len=0 TSval=2046772425 TSecr=2046772425
66 30.173059434 127.0.0.1 -> 127.0.0.1 HTTP 303 GET /storage_service/nodes/moving HTTP/1.1
67 30.175614581 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
68 30.175630257 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=3878 Ack=3278 Win=554 Len=0 TSval=2046787203 TSecr=2046787203
69 32.570128667 127.0.0.1 -> 127.0.0.1 TCP 74 33498 > ndmp [SYN] Seq=0 Win=65495 Len=0 MSS=65495 SACK_PERM=1 TSval=2046789597 TSecr=0 WS=128
70 32.570145506 127.0.0.1 -> 127.0.0.1 TCP 74 ndmp > 33498 [SYN, ACK] Seq=0 Ack=1 Win=65483 Len=0 MSS=65495 SACK_PERM=1 TSval=2046789597 TSecr=2046789597 WS=128
71 32.570182618 127.0.0.1 -> 127.0.0.1 TCP 66 33498 > ndmp [ACK] Seq=1 Ack=1 Win=65536 Len=0 TSval=2046789597 TSecr=2046789597
72 32.590909605 127.0.0.1 -> 127.0.0.1 HTTP 228 GET /column_family/ HTTP/1.1
73 32.590918894 127.0.0.1 -> 127.0.0.1 TCP 66 ndmp > 33498 [ACK] Seq=1 Ack=163 Win=65408 Len=0 TSval=2046789618 TSecr=2046789618
74 32.591665353 127.0.0.1 -> 127.0.0.1 HTTP 3737 HTTP/1.1 200 OK (application/json)
75 32.591681605 127.0.0.1 -> 127.0.0.1 TCP 66 33498 > ndmp [ACK] Seq=163 Ack=3672 Win=63104 Len=0 TSval=2046789619 TSecr=2046789619
76 32.741467643 127.0.0.1 -> 127.0.0.1 HTTP 229 GET /stream_manager/ HTTP/1.1
77 32.741477355 127.0.0.1 -> 127.0.0.1 TCP 66 ndmp > 33498 [ACK] Seq=3672 Ack=326 Win=65408 Len=0 TSval=2046789769 TSecr=2046789769
78 32.745466577 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
79 32.745479906 127.0.0.1 -> 127.0.0.1 TCP 66 33498 > ndmp [ACK] Seq=326 Ack=3804 Win=65408 Len=0 TSval=2046789773 TSecr=2046789773
80 42.633959220 127.0.0.1 -> 127.0.0.1 TCP 66 33498 > ndmp [FIN, ACK] Seq=326 Ack=3804 Win=65536 Len=0 TSval=2046799661 TSecr=2046789773
81 42.634146116 127.0.0.1 -> 127.0.0.1 TCP 66 ndmp > 33498 [FIN, ACK] Seq=3804 Ack=327 Win=65536 Len=0 TSval=2046799661 TSecr=2046799661
82 42.634154816 127.0.0.1 -> 127.0.0.1 TCP 66 33498 > ndmp [ACK] Seq=327 Ack=3805 Win=65536 Len=0 TSval=2046799661 TSecr=2046799661
83 45.002941646 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /storage_service/host_id HTTP/1.1
84 45.003572139 127.0.0.1 -> 127.0.0.1 HTTP 411 HTTP/1.1 200 OK (application/json)
85 45.003588762 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=4110 Ack=3623 Win=562 Len=0 TSval=2046802031 TSecr=2046802031
86 45.015881320 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /gossiper/endpoint/live/ HTTP/1.1
87 45.016572128 127.0.0.1 -> 127.0.0.1 HTTP 236 HTTP/1.1 200 OK (application/json)
88 45.016586981 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=4342 Ack=3793 Win=571 Len=0 TSval=2046802044 TSecr=2046802044
89 45.049978388 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /storage_service/host_id HTTP/1.1
90 45.052563707 127.0.0.1 -> 127.0.0.1 HTTP 411 HTTP/1.1 200 OK (application/json)
91 45.052572931 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=4574 Ack=4138 Win=579 Len=0 TSval=2046802080 TSecr=2046802080
92 45.052773263 127.0.0.1 -> 127.0.0.1 HTTP 298 [TCP Previous segment not captured] GET /storage_service/host_id HTTP/1.1
93 45.054203709 127.0.0.1 -> 127.0.0.1 HTTP 411 [TCP ACKed unseen segment] HTTP/1.1 200 OK (application/json)
94 45.054212146 127.0.0.1 -> 127.0.0.1 TCP 66 33208 > ndmp [ACK] Seq=234 Ack=346 Win=510 Len=0 TSval=2046802081 TSecr=2046802081
95 45.094850060 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /gossiper/endpoint/live/ HTTP/1.1
96 45.096546491 127.0.0.1 -> 127.0.0.1 HTTP 236 HTTP/1.1 200 OK (application/json)
97 45.096556899 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=4806 Ack=4308 Win=588 Len=0 TSval=2046802124 TSecr=2046802124
98 45.242008368 127.0.0.1 -> 127.0.0.1 HTTP 303 GET /storage_service/nodes/moving HTTP/1.1
99 45.243637817 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
100 45.243676832 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=5043 Ack=4440 Win=596 Len=0 TSval=2046802271 TSecr=2046802271
101 45.383099646 127.0.0.1 -> 127.0.0.1 HTTP 304 GET /storage_service/nodes/leaving HTTP/1.1
102 45.384586356 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
103 45.384600650 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=5281 Ack=4572 Win=604 Len=0 TSval=2046802412 TSecr=2046802412
104 45.549992322 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /storage_service/host_id HTTP/1.1
105 45.550144682 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /storage_service/host_id HTTP/1.1
106 45.550472576 127.0.0.1 -> 127.0.0.1 HTTP 411 HTTP/1.1 200 OK (application/json)
107 45.550486966 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=5513 Ack=4917 Win=613 Len=0 TSval=2046802578 TSecr=2046802578
108 45.551673752 127.0.0.1 -> 127.0.0.1 HTTP 411 HTTP/1.1 200 OK (application/json)
109 45.551681266 127.0.0.1 -> 127.0.0.1 TCP 66 33208 > ndmp [ACK] Seq=466 Ack=691 Win=510 Len=0 TSval=2046802579 TSecr=2046802579
110 45.568859776 127.0.0.1 -> 127.0.0.1 HTTP 313 GET /storage_service/scylla_release_version HTTP/1.1
111 45.569069704 127.0.0.1 -> 127.0.0.1 HTTP 228 HTTP/1.1 200 OK (application/json)
112 45.569082677 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=5760 Ack=5079 Win=621 Len=0 TSval=2046802596 TSecr=2046802596
113 59.983016073 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /storage_service/host_id HTTP/1.1
114 59.983573679 127.0.0.1 -> 127.0.0.1 HTTP 411 HTTP/1.1 200 OK (application/json)
115 59.983592524 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=5992 Ack=5424 Win=629 Len=0 TSval=2046817011 TSecr=2046817011
116 60.032011899 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /gossiper/endpoint/live/ HTTP/1.1
117 60.032533734 127.0.0.1 -> 127.0.0.1 HTTP 236 HTTP/1.1 200 OK (application/json)
118 60.032548199 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=6224 Ack=5594 Win=638 Len=0 TSval=2046817060 TSecr=2046817060
119 60.054908539 127.0.0.1 -> 127.0.0.1 HTTP 303 GET /storage_service/nodes/moving HTTP/1.1
120 60.055022021 127.0.0.1 -> 127.0.0.1 HTTP 303 GET /storage_service/nodes/moving HTTP/1.1
121 60.055593016 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
122 60.055608720 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=6461 Ack=5726 Win=646 Len=0 TSval=2046817083 TSecr=2046817083
123 60.060205499 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
124 60.060211868 127.0.0.1 -> 127.0.0.1 TCP 66 33208 > ndmp [ACK] Seq=703 Ack=823 Win=511 Len=0 TSval=2046817087 TSecr=2046817087
125 74.999968795 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /gossiper/endpoint/live/ HTTP/1.1
126 75.000143731 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /storage_service/host_id HTTP/1.1
127 75.001415154 127.0.0.1 -> 127.0.0.1 HTTP 411 HTTP/1.1 200 OK (application/json)
128 75.001432642 127.0.0.1 -> 127.0.0.1 TCP 66 33150 > ndmp [ACK] Seq=6693 Ack=6071 Win=655 Len=0 TSval=2046832029 TSecr=2046832029
129 75.002667259 127.0.0.1 -> 127.0.0.1 HTTP 236 HTTP/1.1 200 OK (application/json)
130 75.002674956 127.0.0.1 -> 127.0.0.1 TCP 66 33208 > ndmp [ACK] Seq=935 Ack=993 Win=511 Len=0 TSval=2046832030 TSecr=2046832030
131 75.050032103 127.0.0.1 -> 127.0.0.1 HTTP 304 GET /storage_service/nodes/leaving HTTP/1.1
132 75.052200868 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
133 75.052208780 127.0.0.1 -> 127.0.0.1 TCP 66 33208 > ndmp [ACK] Seq=1173 Ack=1125 Win=511 Len=0 TSval=2046832079 TSecr=2046832079
134 75.065970217 127.0.0.1 -> 127.0.0.1 HTTP 303 GET /storage_service/nodes/moving HTTP/1.1
135 75.068213298 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
136 75.108822002 127.0.0.1 -> 127.0.0.1 TCP 66 33208 > ndmp [ACK] Seq=1410 Ack=1257 Win=512 Len=0 TSval=2046832136 TSecr=2046832095
137 89.985052665 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /storage_service/host_id HTTP/1.1
138 89.986738458 127.0.0.1 -> 127.0.0.1 HTTP 411 HTTP/1.1 200 OK (application/json)
139 89.986747214 127.0.0.1 -> 127.0.0.1 TCP 66 33208 > ndmp [ACK] Seq=1642 Ack=1602 Win=510 Len=0 TSval=2046847014 TSecr=2046847014
140 90.001013144 127.0.0.1 -> 127.0.0.1 HTTP 304 GET /storage_service/nodes/joining HTTP/1.1
141 90.003727973 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
142 90.003736176 127.0.0.1 -> 127.0.0.1 TCP 66 33208 > ndmp [ACK] Seq=1880 Ack=1734 Win=511 Len=0 TSval=2046847031 TSecr=2046847031
143 90.008980100 127.0.0.1 -> 127.0.0.1 HTTP 304 GET /storage_service/nodes/leaving HTTP/1.1
144 90.010221258 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
145 90.010237004 127.0.0.1 -> 127.0.0.1 TCP 66 33208 > ndmp [ACK] Seq=2118 Ack=1866 Win=511 Len=0 TSval=2046847037 TSecr=2046847037
146 90.017973189 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /gossiper/endpoint/live/ HTTP/1.1
147 90.018721749 127.0.0.1 -> 127.0.0.1 HTTP 236 HTTP/1.1 200 OK (application/json)
148 90.022561738 127.0.0.1 -> 127.0.0.1 HTTP 303 GET /storage_service/nodes/moving HTTP/1.1
149 90.025183882 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
150 90.065824143 127.0.0.1 -> 127.0.0.1 TCP 66 33208 > ndmp [ACK] Seq=2587 Ack=2168 Win=512 Len=0 TSval=2046847093 TSecr=2046847052
151 90.096047289 127.0.0.1 -> 127.0.0.1 HTTP 303 GET /storage_service/nodes/moving HTTP/1.1
152 90.099002931 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
153 90.099010044 127.0.0.1 -> 127.0.0.1 TCP 66 33208 > ndmp [ACK] Seq=2824 Ack=2300 Win=511 Len=0 TSval=2046847126 TSecr=2046847126
55 15.018978212 127.0.0.1 -> 127.0.0.1 HTTP 304 GET /storage_service/nodes/joining HTTP/1.1
56 15.022948798 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
3.1 ms
60 15.372056810 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /gossiper/endpoint/live/ HTTP/1.1
61 15.377925575 127.0.0.1 -> 127.0.0.1 HTTP 236 HTTP/1.1 200 OK (application/json)
3.1 ms
63 15.394993039 127.0.0.1 -> 127.0.0.1 HTTP 304 GET /storage_service/nodes/joining HTTP/1.1
64 15.397976754 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
3.1 ms
66 30.173059434 127.0.0.1 -> 127.0.0.1 HTTP 303 GET /storage_service/nodes/moving HTTP/1.1
67 30.175614581 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
3.1 ms
89 45.049978388 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /storage_service/host_id HTTP/1.1
90 45.052563707 127.0.0.1 -> 127.0.0.1 HTTP 411 HTTP/1.1 200 OK (application/json)
3.1 ms
92 45.052773263 127.0.0.1 -> 127.0.0.1 HTTP 298 [TCP Previous segment not captured] GET /storage_service/host_id HTTP/1.1
93 45.054203709 127.0.0.1 -> 127.0.0.1 HTTP 411 [TCP ACKed unseen segment] HTTP/1.1 200 OK (application/json)
3.1 ms
95 45.094850060 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /gossiper/endpoint/live/ HTTP/1.1
96 45.096546491 127.0.0.1 -> 127.0.0.1 HTTP 236 HTTP/1.1 200 OK (application/json)
3.1 ms
98 45.242008368 127.0.0.1 -> 127.0.0.1 HTTP 303 GET /storage_service/nodes/moving HTTP/1.1
99 45.243637817 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
3.1 ms
101 45.383099646 127.0.0.1 -> 127.0.0.1 HTTP 304 GET /storage_service/nodes/leaving HTTP/1.1
102 45.384586356 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
3.1 ms
131 75.050032103 127.0.0.1 -> 127.0.0.1 HTTP 304 GET /storage_service/nodes/leaving HTTP/1.1
132 75.052200868 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
3.1 ms
134 75.065970217 127.0.0.1 -> 127.0.0.1 HTTP 303 GET /storage_service/nodes/moving HTTP/1.1
135 75.068213298 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
3.1 ms
137 89.985052665 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /storage_service/host_id HTTP/1.1
138 89.986738458 127.0.0.1 -> 127.0.0.1 HTTP 411 HTTP/1.1 200 OK (application/json)
3.1 ms
140 90.001013144 127.0.0.1 -> 127.0.0.1 HTTP 304 GET /storage_service/nodes/joining HTTP/1.1
141 90.003727973 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
3.1 ms
143 90.008980100 127.0.0.1 -> 127.0.0.1 HTTP 304 GET /storage_service/nodes/leaving HTTP/1.1
144 90.010221258 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
3.1 ms
148 90.022561738 127.0.0.1 -> 127.0.0.1 HTTP 303 GET /storage_service/nodes/moving HTTP/1.1
149 90.025183882 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
3.1 ms
151 90.096047289 127.0.0.1 -> 127.0.0.1 HTTP 303 GET /storage_service/nodes/moving HTTP/1.1
152 90.099002931 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
3.1 ms
55 15.018978212 127.0.0.1 -> 127.0.0.1 HTTP 304 GET /storage_service/nodes/joining HTTP/1.1 56 15.022948798 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json) 3.1 ms 60 15.372056810 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /gossiper/endpoint/live/ HTTP/1.1 61 15.377925575 127.0.0.1 -> 127.0.0.1 HTTP 236 HTTP/1.1 200 OK (application/json) 3.1 ms
5.9 ms
avikivity
on 11 Mar 2021
Maybe the logins just make things worse by eating some cpu time. Or maybe it's a red herring.
I'm looking at reducing the various emergency reserves.
avikivity
on 11 Mar 2021
And to have background reclaim respect those reserves.
avikivity
on 11 Mar 2021
👍1
55 15.018978212 127.0.0.1 -> 127.0.0.1 HTTP 304 GET /storage_service/nodes/joining HTTP/1.1 56 15.022948798 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json) 3.1 ms 60 15.372056810 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /gossiper/endpoint/live/ HTTP/1.1 61 15.377925575 127.0.0.1 -> 127.0.0.1 HTTP 236 HTTP/1.1 200 OK (application/json) 3.1 ms5.9 ms
Oops, that was supposed to be %3.1f, not 3.1...
55 15.018978212 127.0.0.1 -> 127.0.0.1 HTTP 304 GET /storage_service/nodes/joining HTTP/1.1
56 15.022948798 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
4.0 ms
60 15.372056810 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /gossiper/endpoint/live/ HTTP/1.1
61 15.377925575 127.0.0.1 -> 127.0.0.1 HTTP 236 HTTP/1.1 200 OK (application/json)
5.9 ms
63 15.394993039 127.0.0.1 -> 127.0.0.1 HTTP 304 GET /storage_service/nodes/joining HTTP/1.1
64 15.397976754 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
3.0 ms
66 30.173059434 127.0.0.1 -> 127.0.0.1 HTTP 303 GET /storage_service/nodes/moving HTTP/1.1
67 30.175614581 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
2.6 ms
89 45.049978388 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /storage_service/host_id HTTP/1.1
90 45.052563707 127.0.0.1 -> 127.0.0.1 HTTP 411 HTTP/1.1 200 OK (application/json)
2.6 ms
92 45.052773263 127.0.0.1 -> 127.0.0.1 HTTP 298 [TCP Previous segment not captured] GET /storage_service/host_id HTTP/1.1
93 45.054203709 127.0.0.1 -> 127.0.0.1 HTTP 411 [TCP ACKed unseen segment] HTTP/1.1 200 OK (application/json)
1.4 ms
95 45.094850060 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /gossiper/endpoint/live/ HTTP/1.1
96 45.096546491 127.0.0.1 -> 127.0.0.1 HTTP 236 HTTP/1.1 200 OK (application/json)
1.7 ms
98 45.242008368 127.0.0.1 -> 127.0.0.1 HTTP 303 GET /storage_service/nodes/moving HTTP/1.1
99 45.243637817 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
1.6 ms
101 45.383099646 127.0.0.1 -> 127.0.0.1 HTTP 304 GET /storage_service/nodes/leaving HTTP/1.1
102 45.384586356 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
1.5 ms
131 75.050032103 127.0.0.1 -> 127.0.0.1 HTTP 304 GET /storage_service/nodes/leaving HTTP/1.1
132 75.052200868 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
2.2 ms
134 75.065970217 127.0.0.1 -> 127.0.0.1 HTTP 303 GET /storage_service/nodes/moving HTTP/1.1
135 75.068213298 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
2.2 ms
137 89.985052665 127.0.0.1 -> 127.0.0.1 HTTP 298 GET /storage_service/host_id HTTP/1.1
138 89.986738458 127.0.0.1 -> 127.0.0.1 HTTP 411 HTTP/1.1 200 OK (application/json)
1.7 ms
140 90.001013144 127.0.0.1 -> 127.0.0.1 HTTP 304 GET /storage_service/nodes/joining HTTP/1.1
141 90.003727973 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
2.7 ms
143 90.008980100 127.0.0.1 -> 127.0.0.1 HTTP 304 GET /storage_service/nodes/leaving HTTP/1.1
144 90.010221258 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
1.2 ms
148 90.022561738 127.0.0.1 -> 127.0.0.1 HTTP 303 GET /storage_service/nodes/moving HTTP/1.1
149 90.025183882 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
2.6 ms
151 90.096047289 127.0.0.1 -> 127.0.0.1 HTTP 303 GET /storage_service/nodes/moving HTTP/1.1
152 90.099002931 127.0.0.1 -> 127.0.0.1 HTTP 198 HTTP/1.1 200 OK (application/json)
3.0 ms
Maybe ce1b1d6ec42552e30ff9cdfd12d48ab61fa2425e will help.
avikivity
on 15 Mar 2021
Possibly due to #8473. Can't tell since we don't know if this happened during bootstrap or not.
avikivity
on 13 Apr 2021
@tgrabiec regarding https://github.com/scylladb/scylla/pull/8364#issuecomment-818995032, we see many stalls on this path.
bhalevy
on 14 Apr 2021
For the record, I filtered out the stalls that happened during bootstrap in the recent QA report to disregard those that could be caused by #8473 and I still see this path as the most prominent:
++[0#1/553 15%] addr=0x1442358 total=4821 count=330 avg=15:
| managed_bytes::free_chain at ././utils/managed_bytes.hh:106
| (inlined by) ~managed_bytes at ././utils/managed_bytes.hh:194
| (inlined by) ~atomic_cell_or_collection at ././atomic_cell_or_collection.hh:33
| (inlined by) ~cell_and_hash at ././mutation_partition.hh:75
| (inlined by) operator() at ././utils/compact-radix-tree.hh:1844
| (inlined by) operator() at ././utils/compact-radix-tree.hh:1647
| (inlined by) compact_radix_tree::tree<cell_and_hash, unsigned int>::visit_slot<compact_radix_tree::tree<cell_and_hash, unsigned int>::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor>(compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visito>
| (inlined by) compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)2, 8u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)3, 0u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout>
| (inlined by) compact_radix_tree::tree<cell_and_hash, unsigned int>::node_base<cell_and_hash, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)1, 4u, (compact_radix_tree::tree<cell_and_hash, unsigned in>
++ - addr=0x137df40:
| compact_radix_tree::tree<cell_and_hash, unsigned int>::node_base<cell_and_hash, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)1, 4u, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)2,>
| (inlined by) compact_radix_tree::tree<cell_and_hash, unsigned int>::node_base<cell_and_hash, compact_radix_tree::tree<cell_and_hash, unsigned int>::indirect_layout<cell_and_hash, (compact_radix_tree::tree<cell_and_hash, unsigned int>::layout)1, 4u, (compact_radix_tree::tree<cell_and_hash, unsigned in>
| (inlined by) compact_radix_tree::tree<cell_and_hash, unsigned int>::node_head::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor>(compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_>
| (inlined by) compact_radix_tree::tree<cell_and_hash, unsigned int>::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor>(compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor&&):>
| (inlined by) compact_radix_tree::tree<cell_and_hash, unsigned int>::visit<compact_radix_tree::tree<cell_and_hash, unsigned int>::clear()::clearing_visitor> at ././utils/compact-radix-tree.hh:1655
| (inlined by) compact_radix_tree::tree<cell_and_hash, unsigned int>::clear at ././utils/compact-radix-tree.hh:1856
| (inlined by) ~tree at ././utils/compact-radix-tree.hh:1789
| (inlined by) ~row at ./mutation_partition.cc:1469
| ++[1#1/1 100%] addr=0x123c5ec total=9931 count=706 avg=14:
| | ~deletable_row at ././mutation_partition.hh:822
| | (inlined by) ~rows_entry at ././mutation_partition.hh:893
| | (inlined by) allocation_strategy::destroy<rows_entry> at ././utils/allocation_strategy.hh:165
| | (inlined by) operator() at ././utils/allocation_strategy.hh:242
| | (inlined by) intrusive_b::node<rows_entry, &rows_entry::_link, rows_entry::tri_compare, 12ul, 20ul, (intrusive_b::key_search)0, (intrusive_b::with_debug)0>::dispose_key<current_deleter<rows_entry>()::{lambda(rows_entry*)#1}&> at ././utils/intrusive_btree.hh:1331
| | (inlined by) intrusive_b::tree<rows_entry, &rows_entry::_link, rows_entry::tri_compare, 12ul, 20ul, (intrusive_b::key_search)0, (intrusive_b::with_debug)0>::iterator::erase_and_dispose<current_deleter<rows_entry>()::{lambda(rows_entry*)#1}> at ././utils/intrusive_btree.hh:917
| | (inlined by) rows_entry::on_evicted at ./row_cache.cc:1217
| ++[2#1/1 100%] addr=0x1271d4b total=10741 count=767 avg=14:
| | operator() at ./row_cache.cc:80
| | (inlined by) with_allocator<cache_tracker::cache_tracker(mutation_application_stats&)::$_0::operator()() const::{lambda()#1}> at ././utils/allocation_strategy.hh:311
| | (inlined by) operator() at ./row_cache.cc:65
| | (inlined by) std::__invoke_impl<seastar::memory::reclaiming_result, cache_tracker::cache_tracker(mutation_application_stats&)::$_0&> at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/invoke.h:60
| | (inlined by) std::__invoke_r<seastar::memory::reclaiming_result, cache_tracker::cache_tracker(mutation_application_stats&)::$_0&> at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/invoke.h:113
| | (inlined by) std::_Function_handler<seastar::memory::reclaiming_result (), cache_tracker::cache_tracker(mutation_application_stats&)::$_0>::_M_invoke at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/std_function.h:291
| ++[3#1/1 100%] addr=0x12e82d3 total=23270 count=1556 avg=15:
| | std::function<seastar::memory::reclaiming_result ()>::operator() at /usr/lib/gcc/x86_64-redhat-linux/10/../../../../include/c++/10/bits/std_function.h:622
| | (inlined by) logalloc::region_impl::evict_some at ./utils/logalloc.cc:1705
| | (inlined by) logalloc::reclaim_from_evictable at ./utils/logalloc.cc:1926
| | (inlined by) logalloc::tracker::impl::compact_and_evict_locked at ./utils/logalloc.cc:2121
| ++[4#1/1 100%] addr=0x12df837 total=23367 count=1563 avg=15:
| | logalloc::tracker::impl::compact_and_evict at ./utils/logalloc.cc:2054
| | (inlined by) logalloc::segment_pool::allocate_segment at ./utils/logalloc.cc:919
| ++[5#1/1 100%] addr=0x12fcc57 total=29424 count=2281 avg=13:
| | logalloc::segment_pool::refill_emergency_reserve at ./utils/logalloc.cc:932
| | (inlined by) logalloc::allocating_section::reserve at ./utils/logalloc.cc:2411
| ++[6#1/12 29%] addr=0x12ae399 total=8446 count=438 avg=19:
| | logalloc::allocating_section::with_reserve<logalloc::allocating_section::operator()<memtable::apply(frozen_mutation const&, seastar::lw_shared_ptr<schema const> const&, db::rp_handle&&)::$_8::operator()() const::{lambda()#1}>(logalloc::region&, memtable::apply(frozen_mutation const&, seast>
| | (inlined by) logalloc::allocating_section::operator()<memtable::apply(frozen_mutation const&, seastar::lw_shared_ptr<schema const> const&, db::rp_handle&&)::$_8::operator()() const::{lambda()#1}> at ././utils/logalloc.hh:778
| | (inlined by) operator() at ./memtable.cc:731
| | (inlined by) with_allocator<memtable::apply(frozen_mutation const&, seastar::lw_shared_ptr<schema const> const&, db::rp_handle&&)::$_8> at ././utils/allocation_strategy.hh:311
| | (inlined by) memtable::apply at ./memtable.cc:730
| ++ - addr=0x10dd4ee:
| | table::do_apply<frozen_mutation const&, seastar::lw_shared_ptr<schema const> const&> at ./table.cc:1826
| | (inlined by) table::apply at ./table.cc:1845
| | ++[7#1/1 100%] addr=0x1027a0e total=8516 count=443 avg=19:
| | | operator() at ./database.cc:1733
| | | (inlined by) seastar::futurize<void>::invoke<database::apply_in_memory(frozen_mutation const&, seastar::lw_shared_ptr<schema const>, db::rp_handle&&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >)::$_56&> at ././seastar/include/seast>
| | | (inlined by) seastar::futurize_invoke<database::apply_in_memory(frozen_mutation const&, seastar::lw_shared_ptr<schema const>, db::rp_handle&&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >)::$_56&> at ././seastar/include/seastar/core>
| | | (inlined by) logalloc::region_group::run_when_memory_available<database::apply_in_memory(frozen_mutation const&, seastar::lw_shared_ptr<schema const>, db::rp_handle&&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >)::$_56> at ././util>
| | | (inlined by) database::apply_in_memory at ./database.cc:1732
| | ++ - addr=0x102ad67:
| | | operator() at ./database.cc:1792
| | | (inlined by) seastar::futurize<seastar::future<void> >::invoke<database::apply_with_commitlog(seastar::lw_shared_ptr<schema const>, table&, utils::UUID, frozen_mutation const&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, seastar::>
| | | (inlined by) seastar::future<db::rp_handle>::then_impl<database::apply_with_commitlog(seastar::lw_shared_ptr<schema const>, table&, utils::UUID, frozen_mutation const&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, seastar::bool_cla>
| | | (inlined by) seastar::internal::call_then_impl<seastar::future<db::rp_handle> >::run<database::apply_with_commitlog(seastar::lw_shared_ptr<schema const>, table&, utils::UUID, frozen_mutation const&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l,>
| | | (inlined by) seastar::future<db::rp_handle>::then<database::apply_with_commitlog(seastar::lw_shared_ptr<schema const>, table&, utils::UUID, frozen_mutation const&, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, seastar::bool_class<fo>
| | | (inlined by) database::apply_with_commitlog at ./database.cc:1791
| | ++ - addr=0xfcbe1b:
| | | database::do_apply at ./database.cc:1815
| | ++ - addr=0x1064b6a:
| | | std::__invoke_impl<seastar::future<void>, seastar::future<void> (database::* const&)(seastar::lw_shared_ptr<schema const>, frozen_mutation const&, tracing::trace_state_ptr, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, seastar::bool>
| | | (inlined by) std::__invoke<seastar::future<void> (database::* const&)(seastar::lw_shared_ptr<schema const>, frozen_mutation const&, tracing::trace_state_ptr, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, seastar::bool_class<force_sy>
| | | (inlined by) std::_Mem_fn_base<seastar::future<void> (database::*)(seastar::lw_shared_ptr<schema const>, frozen_mutation const&, tracing::trace_state_ptr, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, seastar::bool_class<force_sync_>
| | | (inlined by) seastar::noncopyable_function<seastar::future<void> (database*, seastar::lw_shared_ptr<schema const>, frozen_mutation const&, tracing::trace_state_ptr, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, seastar::bool_class<f>
| | ++ - addr=0x1090f6c:
| | | seastar::noncopyable_function<seastar::future<void> (database*, seastar::lw_shared_ptr<schema const>, frozen_mutation const&, tracing::trace_state_ptr, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, seastar::bool_class<force_sync_tag>
| | | (inlined by) operator() at ././seastar/include/seastar/core/execution_stage.hh:339
| | | (inlined by) seastar::noncopyable_function<seastar::future<void> (database*, seastar::lw_shared_ptr<schema const>, frozen_mutation const&, tracing::trace_state_ptr, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, seastar::bool_class<f>
| | ++ - addr=0x103f99b:
| | | seastar::noncopyable_function<seastar::future<void> (database*, seastar::lw_shared_ptr<schema const>, frozen_mutation const&, tracing::trace_state_ptr, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, seastar::bool_class<force_sync_tag>
| | | (inlined by) std::__invoke_impl<seastar::future<void>, seastar::noncopyable_function<seastar::future<void> (database*, seastar::lw_shared_ptr<schema const>, frozen_mutation const&, tracing::trace_state_ptr, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::r>
| | | (inlined by) std::__invoke<seastar::noncopyable_function<seastar::future<void> (database*, seastar::lw_shared_ptr<schema const>, frozen_mutation const&, tracing::trace_state_ptr, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, seastar>
| | | (inlined by) std::__apply_impl<seastar::noncopyable_function<seastar::future<void> (database*, seastar::lw_shared_ptr<schema const>, frozen_mutation const&, tracing::trace_state_ptr, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, sea>
| | | (inlined by) std::apply<seastar::noncopyable_function<seastar::future<void> (database*, seastar::lw_shared_ptr<schema const>, frozen_mutation const&, tracing::trace_state_ptr, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, seastar::b>
| | | (inlined by) seastar::futurize<seastar::future<void> >::apply<seastar::noncopyable_function<seastar::future<void> (database*, seastar::lw_shared_ptr<schema const>, frozen_mutation const&, tracing::trace_state_ptr, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long,>
| | | (inlined by) seastar::concrete_execution_stage<seastar::future<void>, database*, seastar::lw_shared_ptr<schema const>, frozen_mutation const&, tracing::trace_state_ptr, std::chrono::time_point<seastar::lowres_clock, std::chrono::duration<long, std::ratio<1l, 1000l> > >, seastar::bool_cla>
| | ++ - addr=0x3f87735:
| | | operator() at ./build/release/seastar/./seastar/src/core/execution_stage.cc:141
| | | (inlined by) seastar::futurize<void>::invoke<seastar::execution_stage::flush()::$_5&> at ./build/release/seastar/./seastar/include/seastar/core/future.hh:2132
| | | (inlined by) seastar::lambda_task<seastar::execution_stage::flush()::$_5>::run_and_dispose at ./build/release/seastar/./seastar/include/seastar/core/make_task.hh:40
Cc @xemul
bhalevy
on 14 Apr 2021
Was this page helpful?
0 / 5 - 0 ratings
Related issues
tzach
路
3Comments
veramine
路
5Comments
Ritaja
路
3Comments
duarten
路
5Comments
vladzcloudius
路
5Comments
Most helpful comment
it is finally running here