From a87705b4ffb00ba585e928d3d92622d39e9dcdce Mon Sep 17 00:00:00 2001 From: Lin Huang Date: Sun, 2 Apr 2023 13:30:22 -0400 Subject: [PATCH 1/4] Correct transient trx time summary due to read-only trxs can run in both read and write window --- plugins/producer_plugin/producer_plugin.cpp | 12 ++++++++++-- 1 file changed, 10 insertions(+), 2 deletions(-) diff --git a/plugins/producer_plugin/producer_plugin.cpp b/plugins/producer_plugin/producer_plugin.cpp index 2a1c8c481c..a779856d78 100644 --- a/plugins/producer_plugin/producer_plugin.cpp +++ b/plugins/producer_plugin/producer_plugin.cpp @@ -2306,7 +2306,11 @@ producer_plugin_impl::handle_push_result( const transaction_metadata_ptr& trx, auto end = fc::time_point::now(); push_result pr; if( trace->except ) { - if ( chain.is_on_main_thread() ) { + // Transient trxs are dry-run or read-only. + // Dry-run trxs only run in write window. Read-only trxs can run in + // both write and read windows; time spent in read window is counted + // by read window summary. + if ( app().executor().is_write_window() ) { auto dur = end - start; _time_tracker.add_fail_time(dur, trx->is_transient()); } @@ -2349,7 +2353,11 @@ producer_plugin_impl::handle_push_result( const transaction_metadata_ptr& trx, } else { fc_tlog( _log, "Subjective bill for success ${a}: ${b} elapsed ${t}us, time ${r}us", ("a",first_auth)("b",sub_bill)("t",trace->elapsed)("r", end - start)); - if ( chain.is_on_main_thread() ) { + // Transient trxs are dry-run or read-only. + // Dry-run trxs only run in write window. Read-only trxs can run in + // both write and read windows; time spent in read window is counted + // by read window summary. + if ( app().executor().is_write_window() ) { auto dur = end - start; _time_tracker.add_success_time(dur, trx->is_transient()); } From c6d5b13f1293e67b6bfb02d9b5eb1cd8d1fc4c59 Mon Sep 17 00:00:00 2001 From: Lin Huang Date: Sun, 2 Apr 2023 13:49:41 -0400 Subject: [PATCH 2/4] remove unneeded is_on_main_thread from controller.hpp --- libraries/chain/controller.cpp | 4 ---- libraries/chain/include/eosio/chain/controller.hpp | 1 - 2 files changed, 5 deletions(-) diff --git a/libraries/chain/controller.cpp b/libraries/chain/controller.cpp index 17a1092c18..4759ad7967 100644 --- a/libraries/chain/controller.cpp +++ b/libraries/chain/controller.cpp @@ -3687,10 +3687,6 @@ void controller::init_thread_local_data() { my->init_thread_local_data(); } -bool controller::is_on_main_thread() const { - return my->is_on_main_thread(); -} - /// Protocol feature activation handlers: template<> diff --git a/libraries/chain/include/eosio/chain/controller.hpp b/libraries/chain/include/eosio/chain/controller.hpp index c764b9560f..3862c27db5 100644 --- a/libraries/chain/include/eosio/chain/controller.hpp +++ b/libraries/chain/include/eosio/chain/controller.hpp @@ -373,7 +373,6 @@ namespace eosio { namespace chain { void set_db_read_only_mode(); void unset_db_read_only_mode(); void init_thread_local_data(); - bool is_on_main_thread() const; private: friend class apply_context; From 61f3e7e81803174dc4df400d683ddb853429f0f3 Mon Sep 17 00:00:00 2001 From: Lin Huang Date: Sun, 2 Apr 2023 16:48:20 -0400 Subject: [PATCH 3/4] Add missing idle time adjustment while executing read-only trxs and correct a format error --- plugins/producer_plugin/producer_plugin.cpp | 15 +++++++++++++-- 1 file changed, 13 insertions(+), 2 deletions(-) diff --git a/plugins/producer_plugin/producer_plugin.cpp b/plugins/producer_plugin/producer_plugin.cpp index a779856d78..c26bdb926d 100644 --- a/plugins/producer_plugin/producer_plugin.cpp +++ b/plugins/producer_plugin/producer_plugin.cpp @@ -281,11 +281,11 @@ struct block_time_tracker { if( _log.is_enabled( fc::log_level::debug ) ) { auto now = fc::time_point::now(); add_idle_time( now - idle_trx_time ); - fc_dlog( _log, "Block #${n} trx idle: ${i}us out of ${t}us, success: ${sn}, ${s}us, fail: ${fn}, ${f}us, transient: ${tn}, ${t}us, other: ${o}us", + fc_dlog( _log, "Block #${n} trx idle: ${i}us out of ${t}us, success: ${sn}, ${s}us, fail: ${fn}, ${f}us, transient: ${trn}, ${tr}us, other: ${o}us", ("n", block_num) ("i", block_idle_time)("t", now - clear_time)("sn", trx_success_num)("s", trx_success_time) ("fn", trx_fail_num)("f", trx_fail_time) - ("tn", transient_trx_num)("t", transient_trx_time) + ("trn", transient_trx_num)("tr", transient_trx_time) ("o", (now - clear_time) - block_idle_time - trx_success_time - trx_fail_time - transient_trx_time) ); } } @@ -2882,6 +2882,7 @@ void producer_plugin_impl::switch_to_read_window() { return; } + auto& chain = chain_plug->chain(); uint32_t pending_block_num = chain.head_block_num() + 1; _ro_read_window_start_time = fc::time_point::now(); @@ -2996,6 +2997,12 @@ bool producer_plugin_impl::push_read_only_transaction(transaction_metadata_ptr t if( !_ro_in_read_only_mode ) { chain.set_db_read_only_mode(); } + + if ( app().executor().is_write_window() ) { + auto idle_time = fc::time_point::now() - _idle_trx_time; + _time_tracker.add_idle_time( idle_time ); + } + // use read-window/write-window deadline if there are read/write windows, otherwise use block_deadline if only the app thead auto window_deadline = (_ro_thread_pool_size != 0) ? _ro_window_deadline : calculate_block_deadline( chain.pending_block_time() ); @@ -3009,6 +3016,10 @@ bool producer_plugin_impl::push_read_only_transaction(transaction_metadata_ptr t if( retry ) { _ro_exhausted_trx_queue.push_front( {std::move(trx), std::move(next)} ); } + + if ( app().executor().is_write_window() ) { + _idle_trx_time = fc::time_point::now(); + } } catch ( const guard_exception& e ) { chain_plugin::handle_guard_exception(e); } catch ( boost::interprocess::bad_alloc& ) { From e09d9570cb7abaf58581d2daab008bf529f703cd Mon Sep 17 00:00:00 2001 From: Lin Huang Date: Mon, 3 Apr 2023 11:03:38 -0400 Subject: [PATCH 4/4] remove duplicated _ro_in_read_only_mode --- plugins/producer_plugin/producer_plugin.cpp | 17 ++++++----------- 1 file changed, 6 insertions(+), 11 deletions(-) diff --git a/plugins/producer_plugin/producer_plugin.cpp b/plugins/producer_plugin/producer_plugin.cpp index c26bdb926d..b6f9c60a44 100644 --- a/plugins/producer_plugin/producer_plugin.cpp +++ b/plugins/producer_plugin/producer_plugin.cpp @@ -281,11 +281,11 @@ struct block_time_tracker { if( _log.is_enabled( fc::log_level::debug ) ) { auto now = fc::time_point::now(); add_idle_time( now - idle_trx_time ); - fc_dlog( _log, "Block #${n} trx idle: ${i}us out of ${t}us, success: ${sn}, ${s}us, fail: ${fn}, ${f}us, transient: ${trn}, ${tr}us, other: ${o}us", + fc_dlog( _log, "Block #${n} trx idle: ${i}us out of ${t}us, success: ${sn}, ${s}us, fail: ${fn}, ${f}us, transient: ${trans_trx_num}, ${trans_trx_time}us, other: ${o}us", ("n", block_num) ("i", block_idle_time)("t", now - clear_time)("sn", trx_success_num)("s", trx_success_time) ("fn", trx_fail_num)("f", trx_fail_time) - ("trn", transient_trx_num)("tr", transient_trx_time) + ("trans_trx_num", transient_trx_num)("trans_trx_time", transient_trx_time) ("o", (now - clear_time) - block_idle_time - trx_success_time - trx_fail_time - transient_trx_time) ); } } @@ -472,7 +472,6 @@ class producer_plugin_impl : public std::enable_shared_from_this _ro_num_active_exec_tasks{ 0 }; - bool _ro_in_read_only_mode{false}; // only modified on app thread std::vector> _ro_exec_tasks_fut; void start_write_window(); @@ -2852,7 +2851,6 @@ void producer_plugin_impl::start_write_window() { app().executor().set_to_write_window(); chain.unset_db_read_only_mode(); - _ro_in_read_only_mode = false; _idle_trx_time = _ro_window_deadline = fc::time_point::now(); _ro_window_deadline += _ro_write_window_time_us; // not allowed on block producers, so no need to limit to block deadline @@ -2892,7 +2890,6 @@ void producer_plugin_impl::switch_to_read_window() { return fc::time_point::now() >= ro_window_deadline || (received_block->load() >= pending_block_num); // should_exit() }); chain.set_db_read_only_mode(); - _ro_in_read_only_mode = true; _ro_all_threads_exec_time_us = 0; // start a read-only execution task in each thread in the thread pool @@ -2988,17 +2985,15 @@ bool producer_plugin_impl::push_read_only_transaction(transaction_metadata_ptr t return true; } - // when executing on the main thread while in the write window, need to switch db mode to read only - // _ro_in_read_only_mode can only be false if running on main thread as it is only modified from the main thread + // When executing a read-only trx on the main thread while in the write window, + // need to switch db mode to read only. auto db_read_only_mode_guard = fc::make_scoped_exit([&]{ - if( !_ro_in_read_only_mode ) + if( app().executor().is_write_window() ) chain.unset_db_read_only_mode(); }); - if( !_ro_in_read_only_mode ) { - chain.set_db_read_only_mode(); - } if ( app().executor().is_write_window() ) { + chain.set_db_read_only_mode(); auto idle_time = fc::time_point::now() - _idle_trx_time; _time_tracker.add_idle_time( idle_time ); }