From b8111d8b5b65efbe0434e286778af09ba3bb8242 Mon Sep 17 00:00:00 2001 From: EmelyanenkoK Date: Mon, 8 Apr 2024 11:15:52 +0300 Subject: [PATCH 01/10] Fix setting due_payment in storage phase (#957) Co-authored-by: SpyCheese --- common/global-version.h | 2 +- crypto/block/transaction.cpp | 4 ++++ crypto/block/transaction.h | 1 + validator/impl/validate-query.cpp | 1 + 4 files changed, 7 insertions(+), 1 deletion(-) diff --git a/common/global-version.h b/common/global-version.h index 0a90ab85e..a6775ffa4 100644 --- a/common/global-version.h +++ b/common/global-version.h @@ -19,6 +19,6 @@ namespace ton { // See doc/GlobalVersions.md -const int SUPPORTED_VERSION = 6; +const int SUPPORTED_VERSION = 7; } diff --git a/crypto/block/transaction.cpp b/crypto/block/transaction.cpp index 88966179d..0fb3a45e2 100644 --- a/crypto/block/transaction.cpp +++ b/crypto/block/transaction.cpp @@ -898,6 +898,9 @@ bool Transaction::prepare_storage_phase(const StoragePhaseConfig& cfg, bool forc res->fees_collected = to_pay; res->fees_due = td::zero_refint(); balance -= std::move(to_pay); + if (cfg.global_version >= 7) { + due_payment = td::zero_refint(); + } } else if (acc_status == Account::acc_frozen && !force_collect && to_pay < cfg.delete_due_limit) { // do not collect fee res->last_paid_updated = (res->is_special ? 0 : account.last_paid); @@ -3668,6 +3671,7 @@ td::Status FetchConfigParams::fetch_config_params( compute_phase_cfg->mc_gas_prices = std::move(mc_gas_prices); compute_phase_cfg->special_gas_full = config.get_global_version() >= 5; storage_phase_cfg->enable_due_payment = config.get_global_version() >= 4; + storage_phase_cfg->global_version = config.get_global_version(); compute_phase_cfg->block_rand_seed = *rand_seed; compute_phase_cfg->max_vm_data_depth = size_limits.max_vm_data_depth; compute_phase_cfg->global_config = config.get_root_cell(); diff --git a/crypto/block/transaction.h b/crypto/block/transaction.h index 42cd84a83..6d8e8a29f 100644 --- a/crypto/block/transaction.h +++ b/crypto/block/transaction.h @@ -82,6 +82,7 @@ struct StoragePhaseConfig { td::RefInt256 freeze_due_limit; td::RefInt256 delete_due_limit; bool enable_due_payment{false}; + int global_version = 0; StoragePhaseConfig() = default; StoragePhaseConfig(const std::vector* _pricing, td::RefInt256 freeze_limit = {}, td::RefInt256 delete_limit = {}) diff --git a/validator/impl/validate-query.cpp b/validator/impl/validate-query.cpp index d925fce63..8b2723c33 100644 --- a/validator/impl/validate-query.cpp +++ b/validator/impl/validate-query.cpp @@ -947,6 +947,7 @@ bool ValidateQuery::fetch_config_params() { compute_phase_cfg_.mc_gas_prices = mc_gas_prices.move_as_ok(); compute_phase_cfg_.special_gas_full = config_->get_global_version() >= 5; storage_phase_cfg_.enable_due_payment = config_->get_global_version() >= 4; + storage_phase_cfg_.global_version = config_->get_global_version(); compute_phase_cfg_.block_rand_seed = rand_seed_; compute_phase_cfg_.libraries = std::make_unique(config_->get_libraries_root(), 256); compute_phase_cfg_.max_vm_data_depth = size_limits.max_vm_data_depth; From a2bd695b89ff98aca877a545ae639f5ace2e0d8b Mon Sep 17 00:00:00 2001 From: EmelyanenkoK Date: Mon, 8 Apr 2024 14:29:54 +0300 Subject: [PATCH 02/10] Fix prepare_vm_c7 (#958) Co-authored-by: SpyCheese --- crypto/block/transaction.cpp | 7 +++---- crypto/smc-envelope/SmartContract.cpp | 11 +++++++---- validator/impl/liteserver.cpp | 11 +++++++---- 3 files changed, 17 insertions(+), 12 deletions(-) diff --git a/crypto/block/transaction.cpp b/crypto/block/transaction.cpp index 0fb3a45e2..24013a40f 100644 --- a/crypto/block/transaction.cpp +++ b/crypto/block/transaction.cpp @@ -1321,7 +1321,7 @@ Ref Transaction::prepare_vm_c7(const ComputePhaseConfig& cfg) const { vm::StackEntry::maybe(cfg.global_config) // global_config:(Maybe Cell) ] = SmartContractInfo; }; if (cfg.global_version >= 4) { - tuple.push_back(new_code); // code:Cell + tuple.push_back(vm::StackEntry::maybe(new_code)); // code:Cell if (msg_balance_remaining.is_valid()) { tuple.push_back(msg_balance_remaining.as_vm_tuple()); // in_msg_value:[Integer (Maybe Cell)] } else { @@ -1338,11 +1338,10 @@ Ref Transaction::prepare_vm_c7(const ComputePhaseConfig& cfg) const { // Inside validator, collator and liteserver checking external message contexts // prev_blocks_info is always not null, since get_prev_blocks_info() // may only return tuple or raise Error (See crypto/block/mc-config.cpp#2223) - tuple.push_back(cfg.prev_blocks_info.not_null() ? vm::StackEntry(cfg.prev_blocks_info) : vm::StackEntry()); + tuple.push_back(vm::StackEntry::maybe(cfg.prev_blocks_info)); } if (cfg.global_version >= 6) { - tuple.push_back(cfg.unpacked_config_tuple.not_null() ? vm::StackEntry(cfg.unpacked_config_tuple) - : vm::StackEntry()); // unpacked_config_tuple:[...] + tuple.push_back(vm::StackEntry::maybe(cfg.unpacked_config_tuple)); // unpacked_config_tuple:[...] tuple.push_back(due_payment.not_null() ? due_payment : td::zero_refint()); // due_payment:Integer tuple.push_back(compute_phase->precompiled_gas_usage ? vm::StackEntry(td::make_refint(compute_phase->precompiled_gas_usage.value())) diff --git a/crypto/smc-envelope/SmartContract.cpp b/crypto/smc-envelope/SmartContract.cpp index ce3beba9c..2578a9514 100644 --- a/crypto/smc-envelope/SmartContract.cpp +++ b/crypto/smc-envelope/SmartContract.cpp @@ -157,11 +157,11 @@ td::Ref prepare_vm_c7(SmartContract::Args args, td::Ref cod td::make_refint(0), //TODO: // trans_lt:Integer std::move(rand_seed_int), // rand_seed:Integer block::CurrencyCollection(args.balance).as_vm_tuple(), // balance_remaining:[Integer (Maybe Cell)] - vm::load_cell_slice_ref(address), // myself:MsgAddressInt - vm::StackEntry::maybe(config) //vm::StackEntry::maybe(td::Ref()) + vm::load_cell_slice_ref(address), // myself:MsgAddressInt + vm::StackEntry::maybe(config) // vm::StackEntry::maybe(td::Ref()) }; if (args.config && args.config.value()->get_global_version() >= 4) { - tuple.push_back(code.not_null() ? code : vm::StackEntry{}); // code:Cell + tuple.push_back(vm::StackEntry::maybe(code)); // code:Cell tuple.push_back(block::CurrencyCollection::zero().as_vm_tuple()); // in_msg_value:[Integer (Maybe Cell)] tuple.push_back(td::zero_refint()); // storage_fees:Integer @@ -175,7 +175,10 @@ td::Ref prepare_vm_c7(SmartContract::Args args, td::Ref cod tuple.push_back(args.config.value()->get_unpacked_config_tuple(now)); // unpacked_config_tuple tuple.push_back(td::zero_refint()); // due_payment // precomiled_gas_usage:(Maybe Integer) - auto precompiled = args.config.value()->get_precompiled_contracts_config().get_contract(code->get_hash().bits()); + td::optional precompiled; + if (code.not_null()) { + precompiled = args.config.value()->get_precompiled_contracts_config().get_contract(code->get_hash().bits()); + } tuple.push_back(precompiled ? td::make_refint(precompiled.value().gas_usage) : vm::StackEntry()); } auto tuple_ref = td::make_cnt_ref>(std::move(tuple)); diff --git a/validator/impl/liteserver.cpp b/validator/impl/liteserver.cpp index 42cb0560e..7fa6e59e5 100644 --- a/validator/impl/liteserver.cpp +++ b/validator/impl/liteserver.cpp @@ -1419,7 +1419,7 @@ static td::Ref prepare_vm_c7(ton::UnixTime now, ton::LogicalTime lt, config ? config->get_root_cell() : vm::StackEntry() // global_config:(Maybe Cell) ] = SmartContractInfo; }; if (config && config->get_global_version() >= 4) { - tuple.push_back(my_code); // code:Cell + tuple.push_back(vm::StackEntry::maybe(my_code)); // code:Cell tuple.push_back(block::CurrencyCollection::zero().as_vm_tuple()); // in_msg_value:[Integer (Maybe Cell)] tuple.push_back(td::zero_refint()); // storage_fees:Integer @@ -1430,10 +1430,13 @@ static td::Ref prepare_vm_c7(ton::UnixTime now, ton::LogicalTime lt, tuple.push_back(info.is_ok() ? info.move_as_ok() : vm::StackEntry()); } if (config && config->get_global_version() >= 6) { - tuple.push_back(config->get_unpacked_config_tuple(now)); // unpacked_config_tuple:[...] - tuple.push_back(due_payment); // due_payment:Integer + tuple.push_back(vm::StackEntry::maybe(config->get_unpacked_config_tuple(now))); // unpacked_config_tuple:[...] + tuple.push_back(due_payment); // due_payment:Integer // precomiled_gas_usage:(Maybe Integer) - auto precompiled = config->get_precompiled_contracts_config().get_contract(my_code->get_hash().bits()); + td::optional precompiled; + if (my_code.not_null()) { + precompiled = config->get_precompiled_contracts_config().get_contract(my_code->get_hash().bits()); + } tuple.push_back(precompiled ? td::make_refint(precompiled.value().gas_usage) : vm::StackEntry()); } auto tuple_ref = td::make_cnt_ref>(std::move(tuple)); From 2b45b09211d8df491d5f31e04d58fc0bd6bf4d67 Mon Sep 17 00:00:00 2001 From: EmelyanenkoK Date: Wed, 10 Apr 2024 12:36:46 +0300 Subject: [PATCH 03/10] Add changelog for April update --- Changelog.md | 14 ++++++++++++++ recent_changelog.md | 8 +++----- 2 files changed, 17 insertions(+), 5 deletions(-) diff --git a/Changelog.md b/Changelog.md index 318128c2b..a02410557 100644 --- a/Changelog.md +++ b/Changelog.md @@ -1,3 +1,17 @@ +## 2024.04 Update + +1. Emulator: Single call optimized runGetMethod added +2. Tonlib: a series of proof improvements, also breaking Change in `liteServer.getAllShardsInfo` method (see below) +3. DB: usage statistics now collected, outdated persistent states are not serialized +4. LS: fast `getOutMsgQueueSizes` added, preliminary support of non-final block requests +5. Network: lz4 compression of block candidates (disabled by default). +6. Overlays: add custom overlays +7. Transaction Executor: fixed issue with due_payment collection + +* `liteServer.getAllShardsInfo` method was updated for better efficiency. Previously, field proof contained BoC with two roots: one for BlockState from block's root and another for ShardHashes from BlockState. Now, it returns a single-root proof BoC, specifically the merkle proof of ShardHashes directly from the block's root, streamlining data access and integrity. Checking of the proof requires to check that ShardHashes in the `data` correspond to ShardHashes from the block. + +Besides the work of the core team, this update is based on the efforts of @akifoq (due_payment issue). + ## 2024.03 Update 1. Preparatory (not enabled yet) code for pre-compiled smart-contract. diff --git a/recent_changelog.md b/recent_changelog.md index dac0c651e..f0b029eea 100644 --- a/recent_changelog.md +++ b/recent_changelog.md @@ -5,11 +5,9 @@ 3. DB: usage statistics now collected, outdated persistent states are not serialized 4. LS: fast `getOutMsgQueueSizes` added, preliminary support of non-final block requests 5. Network: lz4 compression of block candidates (disabled by default). - - - ---- +6. Overlays: add custom overlays +7. Transaction Executor: fixed issue with due_payment collection * `liteServer.getAllShardsInfo` method was updated for better efficiency. Previously, field proof contained BoC with two roots: one for BlockState from block's root and another for ShardHashes from BlockState. Now, it returns a single-root proof BoC, specifically the merkle proof of ShardHashes directly from the block's root, streamlining data access and integrity. Checking of the proof requires to check that ShardHashes in the `data` correspond to ShardHashes from the block. - +Besides the work of the core team, this update is based on the efforts of @akifoq (due_payment issue). From c07356062aaa56bd34d354ca86ecbf8c50727a74 Mon Sep 17 00:00:00 2001 From: neodix42 Date: Wed, 10 Apr 2024 13:04:56 +0300 Subject: [PATCH 04/10] add usage of liblz4-dev to Dockerfile (#960) --- Dockerfile | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/Dockerfile b/Dockerfile index e3cd7b26e..76c06b350 100644 --- a/Dockerfile +++ b/Dockerfile @@ -1,6 +1,6 @@ FROM ubuntu:22.04 as builder RUN apt-get update && \ - DEBIAN_FRONTEND=noninteractive apt-get install -y build-essential cmake clang openssl libssl-dev zlib1g-dev gperf wget git ninja-build libsecp256k1-dev libsodium-dev libmicrohttpd-dev pkg-config autoconf automake libtool && \ + DEBIAN_FRONTEND=noninteractive apt-get install -y build-essential cmake clang openssl libssl-dev zlib1g-dev gperf wget git ninja-build libsecp256k1-dev libsodium-dev libmicrohttpd-dev liblz4-dev pkg-config autoconf automake libtool && \ rm -rf /var/lib/apt/lists/* ENV CC clang ENV CXX clang++ @@ -19,7 +19,7 @@ RUN mkdir build && \ FROM ubuntu:22.04 RUN apt-get update && \ - apt-get install -y wget libatomic1 openssl libsecp256k1-dev libsodium-dev libmicrohttpd-dev && \ + apt-get install -y wget libatomic1 openssl libsecp256k1-dev libsodium-dev libmicrohttpd-dev liblz4-dev && \ rm -rf /var/lib/apt/lists/* RUN mkdir -p /var/ton-work/db && \ @@ -36,4 +36,4 @@ WORKDIR /var/ton-work/db COPY ./docker/init.sh ./docker/control.template ./ RUN chmod +x init.sh -ENTRYPOINT ["/var/ton-work/db/init.sh"] \ No newline at end of file +ENTRYPOINT ["/var/ton-work/db/init.sh"] From 190aa6bd4af9bd53f95474be2cde78df121788fc Mon Sep 17 00:00:00 2001 From: EmelyanenkoK Date: Mon, 15 Apr 2024 13:44:12 +0300 Subject: [PATCH 05/10] Use shard client timestamp to determine expiration of temp archives (#965) Co-authored-by: SpyCheese --- validator/manager.cpp | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/validator/manager.cpp b/validator/manager.cpp index e186902ad..d88a50154 100644 --- a/validator/manager.cpp +++ b/validator/manager.cpp @@ -2418,9 +2418,9 @@ void ValidatorManagerImpl::state_serializer_update(BlockSeqno seqno) { void ValidatorManagerImpl::alarm() { try_advance_gc_masterchain_block(); alarm_timestamp() = td::Timestamp::in(1.0); - if (last_masterchain_block_handle_ && gc_masterchain_handle_) { - td::actor::send_closure(db_, &Db::run_gc, last_masterchain_block_handle_->unix_time(), - gc_masterchain_handle_->unix_time(), static_cast(opts_->archive_ttl())); + if (shard_client_handle_ && gc_masterchain_handle_) { + td::actor::send_closure(db_, &Db::run_gc, shard_client_handle_->unix_time(), gc_masterchain_handle_->unix_time(), + static_cast(opts_->archive_ttl())); } if (log_status_at_.is_in_past()) { if (last_masterchain_block_handle_) { From 25f61dff161b9c76dce0fc62dc51da911a208b68 Mon Sep 17 00:00:00 2001 From: EmelyanenkoK Date: Mon, 15 Apr 2024 13:44:30 +0300 Subject: [PATCH 06/10] Tonlib patch (#966) * Bugfix in tonlib * Fix calling actors in RunEmulator * Fix checking proofs in blocks.getTransactions and blocks.getShards * tonlib-cli: Fix printing special cells --------- Co-authored-by: SpyCheese --- tonlib/tonlib/TonlibClient.cpp | 24 +++++++++++++++++------- tonlib/tonlib/tonlib-cli.cpp | 3 ++- 2 files changed, 19 insertions(+), 8 deletions(-) diff --git a/tonlib/tonlib/TonlibClient.cpp b/tonlib/tonlib/TonlibClient.cpp index 86acbcc37..39029ca4e 100644 --- a/tonlib/tonlib/TonlibClient.cpp +++ b/tonlib/tonlib/TonlibClient.cpp @@ -1891,7 +1891,9 @@ class RunEmulator : public TonlibQueryActor { if (stopped_) { return; } - get_block_id([self = this](td::Result&& block_id) { self->set_block_id(std::move(block_id)); }); + get_block_id([SelfId = actor_id(this)](td::Result&& block_id) { + td::actor::send_closure(SelfId, &RunEmulator::set_block_id, std::move(block_id)); + }); } void set_block_id(td::Result&& block_id) { @@ -1900,8 +1902,12 @@ class RunEmulator : public TonlibQueryActor { } else { block_id_ = block_id.move_as_ok(); - get_mc_state_root([self = this](td::Result>&& mc_state_root) { self->set_mc_state_root(std::move(mc_state_root)); }); - get_account_state([self = this](td::Result>&& state) { self->set_account_state(std::move(state)); }); + get_mc_state_root([SelfId = actor_id(this)](td::Result>&& mc_state_root) { + td::actor::send_closure(SelfId, &RunEmulator::set_mc_state_root, std::move(mc_state_root)); + }); + get_account_state([SelfId = actor_id(this)](td::Result>&& state) { + td::actor::send_closure(SelfId, &RunEmulator::set_account_state, std::move(state)); + }); check(get_transactions(0)); inc(); @@ -1923,7 +1929,9 @@ class RunEmulator : public TonlibQueryActor { } else { account_state_ = account_state.move_as_ok(); send_query(int_api::ScanAndLoadGlobalLibs{account_state_->get_raw_state()}, - [self = this](td::Result R) { self->set_global_libraries(std::move(R)); }); + [SelfId = actor_id(this)](td::Result R) { + td::actor::send_closure(SelfId, &RunEmulator::set_global_libraries, std::move(R)); + }); } } @@ -5521,7 +5529,7 @@ td::Status TonlibClient::do_request(const tonlib_api::blocks_getShards& request, } block::ShardConfig sh_conf; - if (!sh_conf.unpack(mc_extra.shard_hashes)) { + if (!sh_conf.unpack(data_csr)) { return td::Status::Error("cannot extract shard block list from shard configuration"); } auto ids = sh_conf.get_shard_hash_ids(true); @@ -5544,7 +5552,9 @@ td::Status TonlibClient::do_request(const tonlib_api::blocks_getShards& request, return td::Status::OK(); } -td::Status check_lookup_block_proof(lite_api_ptr& result, int mode, ton::BlockId blkid, ton::BlockIdExt client_mc_blkid, td::uint64 lt, td::uint32 utime); +td::Status check_lookup_block_proof(lite_api_ptr& result, int mode, + ton::BlockId blkid, ton::BlockIdExt client_mc_blkid, td::uint64 lt, + td::uint32 utime); td::Status TonlibClient::do_request(const tonlib_api::blocks_lookupBlock& request, td::Promise>&& promise) { @@ -5730,7 +5740,7 @@ auto to_tonlib_api(const ton::lite_api::liteServer_transactionId& txid) td::Status check_block_transactions_proof(lite_api_ptr& bTxes, int32_t mode, ton::LogicalTime start_lt, td::Bits256 start_addr, td::Bits256 root_hash, int req_count) { - if (mode & ton::lite_api::liteServer_listBlockTransactions::WANT_PROOF_MASK == 0) { + if ((mode & ton::lite_api::liteServer_listBlockTransactions::WANT_PROOF_MASK) == 0) { return td::Status::OK(); } constexpr int max_answer_transactions = 256; diff --git a/tonlib/tonlib/tonlib-cli.cpp b/tonlib/tonlib/tonlib-cli.cpp index 1107a5d04..5a32b50f3 100644 --- a/tonlib/tonlib/tonlib-cli.cpp +++ b/tonlib/tonlib/tonlib-cli.cpp @@ -1423,7 +1423,8 @@ class TonlibCli : public td::actor::Actor { if (r_cell.is_error()) { sb << ""; } - auto cs = vm::load_cell_slice(r_cell.move_as_ok()); + bool spec = true; + auto cs = vm::load_cell_slice_special(r_cell.move_as_ok(), spec); std::stringstream ss; cs.print_rec(ss); sb << ss.str(); From d2b012c883f0406e8d031b202d7c9b53e2de1236 Mon Sep 17 00:00:00 2001 From: EmelyanenkoK Date: Thu, 25 Apr 2024 18:45:39 +0300 Subject: [PATCH 07/10] Add write time stats to celldb/db_stats.txt (#972) Co-authored-by: SpyCheese --- tdutils/td/utils/Timer.cpp | 4 +++ tdutils/td/utils/Timer.h | 1 + validator/CMakeLists.txt | 2 ++ validator/db/archive-slice.cpp | 66 +++++++++------------------------- validator/db/celldb.cpp | 22 ++++++++++-- validator/db/celldb.hpp | 25 ++++++++++--- validator/db/db-utils.cpp | 54 ++++++++++++++++++++++++++++ validator/db/db-utils.h | 33 +++++++++++++++++ 8 files changed, 149 insertions(+), 58 deletions(-) create mode 100644 validator/db/db-utils.cpp create mode 100644 validator/db/db-utils.h diff --git a/tdutils/td/utils/Timer.cpp b/tdutils/td/utils/Timer.cpp index 0f6a7d6ed..1f72fba96 100644 --- a/tdutils/td/utils/Timer.cpp +++ b/tdutils/td/utils/Timer.cpp @@ -87,4 +87,8 @@ void PerfWarningTimer::reset() { start_at_ = 0; } +double PerfWarningTimer::elapsed() const { + return Time::now() - start_at_; +} + } // namespace td diff --git a/tdutils/td/utils/Timer.h b/tdutils/td/utils/Timer.h index 18ea35d7c..3e0cafbf5 100644 --- a/tdutils/td/utils/Timer.h +++ b/tdutils/td/utils/Timer.h @@ -53,6 +53,7 @@ class PerfWarningTimer { PerfWarningTimer &operator=(PerfWarningTimer &&) = delete; ~PerfWarningTimer(); void reset(); + double elapsed() const; private: string name_; diff --git a/validator/CMakeLists.txt b/validator/CMakeLists.txt index a25ac7e1f..20462caeb 100644 --- a/validator/CMakeLists.txt +++ b/validator/CMakeLists.txt @@ -25,6 +25,8 @@ set(VALIDATOR_DB_SOURCE db/statedb.cpp db/staticfilesdb.cpp db/staticfilesdb.hpp + db/db-utils.cpp + db/db-utils.h db/package.hpp db/package.cpp diff --git a/validator/db/archive-slice.cpp b/validator/db/archive-slice.cpp index 86c2ee932..daee546b0 100644 --- a/validator/db/archive-slice.cpp +++ b/validator/db/archive-slice.cpp @@ -24,6 +24,7 @@ #include "td/utils/port/path.h" #include "common/delay.h" #include "files-async.hpp" +#include "db-utils.h" namespace ton { @@ -41,16 +42,14 @@ class PackageStatistics { void record_read(double time, uint64_t bytes) { read_bytes.fetch_add(bytes, std::memory_order_relaxed); - std::lock_guard guard(read_mutex); + std::lock_guard guard(read_mutex); read_time.insert(time); - read_time_sum += time; } void record_write(double time, uint64_t bytes) { write_bytes.fetch_add(bytes, std::memory_order_relaxed); - std::lock_guard guard(write_mutex); + std::lock_guard guard(write_mutex); write_time.insert(time); - write_time_sum += time; } std::string to_string_and_reset() { @@ -64,68 +63,35 @@ class PackageStatistics { ss << "ton.pack.read.bytes COUNT : " << read_bytes.exchange(0, std::memory_order_relaxed) << "\n"; ss << "ton.pack.write.bytes COUNT : " << write_bytes.exchange(0, std::memory_order_relaxed) << "\n"; - std::multiset temp_read_time; - double temp_read_time_sum; + PercentileStats temp_read_time; { - std::lock_guard guard(read_mutex); + std::lock_guard guard(read_mutex); temp_read_time = std::move(read_time); read_time.clear(); - temp_read_time_sum = read_time_sum; - read_time_sum = 0; } - auto read_stats = calculate_statistics(temp_read_time); - ss << "ton.pack.read.micros P50 : " << read_stats[0] << - " P95 : " << read_stats[1] << - " P99 : " << read_stats[2] << - " P100 : " << read_stats[3] << - " COUNT : " << temp_read_time.size() << - " SUM : " << temp_read_time_sum << "\n"; - - std::multiset temp_write_time; - double temp_write_time_sum; + ss << "ton.pack.read.micros " << temp_read_time.to_string() << "\n"; + + PercentileStats temp_write_time; { - std::lock_guard guard(write_mutex); + std::lock_guard guard(write_mutex); temp_write_time = std::move(write_time); write_time.clear(); - temp_write_time_sum = write_time_sum; - write_time_sum = 0; } - auto write_stats = calculate_statistics(temp_write_time); - ss << "ton.pack.write.micros P50 : " << write_stats[0] << - " P95 : " << write_stats[1] << - " P99 : " << write_stats[2] << - " P100 : " << write_stats[3] << - " COUNT : " << temp_write_time.size() << - " SUM : " << temp_write_time_sum << "\n"; + ss << "ton.pack.write.micros " << temp_write_time.to_string() << "\n"; return ss.str(); } private: - std::atomic_uint64_t open_count; - std::atomic_uint64_t close_count; - std::multiset read_time; - std::atomic_uint64_t read_bytes; - std::multiset write_time; - std::atomic_uint64_t write_bytes; - double read_time_sum; - double write_time_sum; + std::atomic_uint64_t open_count{0}; + std::atomic_uint64_t close_count{0}; + PercentileStats read_time; + std::atomic_uint64_t read_bytes{0}; + PercentileStats write_time; + std::atomic_uint64_t write_bytes{0}; mutable std::mutex read_mutex; mutable std::mutex write_mutex; - - std::vector calculate_statistics(const std::multiset& data) const { - if (data.empty()) return {0, 0, 0, 0}; - - auto size = data.size(); - auto calc_percentile = [&](double p) -> double { - auto it = data.begin(); - std::advance(it, static_cast(std::ceil(p * double(size)) - 1)); - return *it; - }; - - return {calc_percentile(0.5), calc_percentile(0.95), calc_percentile(0.99), *data.rbegin()}; - } }; void DbStatistics::init() { diff --git a/validator/db/celldb.cpp b/validator/db/celldb.cpp index d9803cbe2..294515a31 100644 --- a/validator/db/celldb.cpp +++ b/validator/db/celldb.cpp @@ -89,7 +89,7 @@ void CellDbIn::start_up() { statistics_flush_at_ = td::Timestamp::in(60.0); } cell_db_ = std::make_shared(td::RocksDb::open(path_, statistics_).move_as_ok()); - + boc_ = vm::DynamicBagOfCellsDb::create(); boc_->set_celldb_compress_depth(opts_->get_celldb_compress_depth()); @@ -155,6 +155,9 @@ void CellDbIn::store_cell(BlockIdExt block_id, td::Ref cell, td::Promi td::actor::send_closure(parent_, &CellDb::update_snapshot, cell_db_->snapshot()); promise.set_result(boc_->load_cell(cell->get_hash().as_slice())); + if (!opts_->get_disable_rocksdb_stats()) { + cell_db_statistics_.store_cell_time_.insert(timer.elapsed() * 1e6); + } } void CellDbIn::get_cell_db_reader(td::Promise> promise) { @@ -162,8 +165,9 @@ void CellDbIn::get_cell_db_reader(td::Promise> } void CellDbIn::flush_db_stats() { - auto stats = td::RocksDb::statistics_to_string(statistics_); - auto to_file_r = td::FileFd::open(path_ + "/db_stats.txt", td::FileFd::Truncate | td::FileFd::Create | td::FileFd::Write, 0644); + auto stats = td::RocksDb::statistics_to_string(statistics_) + cell_db_statistics_.to_string(); + auto to_file_r = + td::FileFd::open(path_ + "/db_stats.txt", td::FileFd::Truncate | td::FileFd::Create | td::FileFd::Write, 0644); if (to_file_r.is_error()) { LOG(ERROR) << "Failed to open db_stats.txt: " << to_file_r.move_as_error(); return; @@ -176,6 +180,7 @@ void CellDbIn::flush_db_stats() { return; } td::RocksDb::reset_statistics(statistics_); + cell_db_statistics_.clear(); } void CellDbIn::alarm() { @@ -278,6 +283,9 @@ void CellDbIn::gc_cont2(BlockHandle handle) { td::actor::send_closure(parent_, &CellDb::update_snapshot, cell_db_->snapshot()); DCHECK(get_block(key_hash).is_error()); + if (!opts_->get_disable_rocksdb_stats()) { + cell_db_statistics_.gc_cell_time_.insert(timer.elapsed() * 1e6); + } } void CellDbIn::skip_gc() { @@ -441,6 +449,14 @@ td::BufferSlice CellDbIn::DbEntry::release() { return create_serialize_tl_object(create_tl_block_id(block_id), prev, next, root_hash); } +std::string CellDbIn::CellDbStatistics::to_string() { + td::StringBuilder ss; + ss << "ton.celldb.store_cell.micros " << store_cell_time_.to_string() << "\n"; + ss << "ton.celldb.gc_cell.micros " << gc_cell_time_.to_string() << "\n"; + ss << "ton.celldb.total_time.micros : " << (td::Timestamp::now().at() - stats_start_time_.at()) * 1e6 << "\n"; + return ss.as_cslice().str(); +} + } // namespace validator } // namespace ton diff --git a/validator/db/celldb.hpp b/validator/db/celldb.hpp index 573d4b995..7dc1fa781 100644 --- a/validator/db/celldb.hpp +++ b/validator/db/celldb.hpp @@ -26,6 +26,7 @@ #include "interfaces/block-handle.h" #include "auto/tl/ton_api.h" #include "validator.h" +#include "db-utils.h" namespace rocksdb { class Statistics; @@ -42,9 +43,11 @@ class CellDbAsyncExecutor; class CellDbBase : public td::actor::Actor { public: - virtual void start_up(); + void start_up() override; + protected: std::shared_ptr async_executor; + private: void execute_sync(std::function f); friend CellDbAsyncExecutor; @@ -76,8 +79,7 @@ class CellDbIn : public CellDbBase { RootHash root_hash; DbEntry(tl_object_ptr entry); - DbEntry() { - } + DbEntry() = default; DbEntry(BlockIdExt block_id, KeyHash prev, KeyHash next, RootHash root_hash) : block_id(block_id), prev(prev), next(next), root_hash(root_hash) { } @@ -109,8 +111,6 @@ class CellDbIn : public CellDbBase { std::unique_ptr boc_; std::shared_ptr cell_db_; - std::shared_ptr statistics_; - td::Timestamp statistics_flush_at_ = td::Timestamp::never(); std::function on_load_callback_; std::set cells_to_migrate_; @@ -127,6 +127,21 @@ class CellDbIn : public CellDbBase { }; std::unique_ptr migration_stats_; + struct CellDbStatistics { + PercentileStats store_cell_time_; + PercentileStats gc_cell_time_; + td::Timestamp stats_start_time_ = td::Timestamp::now(); + + std::string to_string(); + void clear() { + *this = CellDbStatistics{}; + } + }; + + std::shared_ptr statistics_; + CellDbStatistics cell_db_statistics_; + td::Timestamp statistics_flush_at_ = td::Timestamp::never(); + public: class MigrationProxy : public td::actor::Actor { public: diff --git a/validator/db/db-utils.cpp b/validator/db/db-utils.cpp new file mode 100644 index 000000000..9375f97e6 --- /dev/null +++ b/validator/db/db-utils.cpp @@ -0,0 +1,54 @@ +/* + This file is part of TON Blockchain Library. + + TON Blockchain Library is free software: you can redistribute it and/or modify + it under the terms of the GNU Lesser General Public License as published by + the Free Software Foundation, either version 2 of the License, or + (at your option) any later version. + + TON Blockchain Library is distributed in the hope that it will be useful, + but WITHOUT ANY WARRANTY; without even the implied warranty of + MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + GNU Lesser General Public License for more details. + + You should have received a copy of the GNU Lesser General Public License + along with TON Blockchain Library. If not, see . +*/ +#include "db-utils.h" + +#include "td/utils/logging.h" + +#include + +namespace ton::validator { + +void PercentileStats::insert(double value) { + values_.insert(value); +} + +std::string PercentileStats::to_string() const { + double percentiles[4] = {0.0, 0.0, 0.0, 0.0}; + double sum = 0.0; + size_t size = values_.size(); + if (!values_.empty()) { + size_t indices[4] = {(size_t)std::ceil(0.5 * (double)size) - 1, (size_t)std::ceil(0.95 * (double)size) - 1, + (size_t)std::ceil(0.99 * (double)size) - 1, size - 1}; + size_t i = 0; + for (auto it = values_.begin(); it != values_.end(); ++it, ++i) { + for (size_t j = 0; j < 4; ++j) { + if (indices[j] == i) { + percentiles[j] = *it; + } + } + sum += *it; + } + } + return PSTRING() << "P50 : " << percentiles[0] << " P95 : " << percentiles[1] << " P99 : " << percentiles[2] + << " P100 : " << percentiles[3] << " COUNT : " << size << " SUM : " << sum; +} + +void PercentileStats::clear() { + values_.clear(); +} + +} // namespace ton::validator \ No newline at end of file diff --git a/validator/db/db-utils.h b/validator/db/db-utils.h new file mode 100644 index 000000000..8ffbf5c97 --- /dev/null +++ b/validator/db/db-utils.h @@ -0,0 +1,33 @@ +/* + This file is part of TON Blockchain Library. + + TON Blockchain Library is free software: you can redistribute it and/or modify + it under the terms of the GNU Lesser General Public License as published by + the Free Software Foundation, either version 2 of the License, or + (at your option) any later version. + + TON Blockchain Library is distributed in the hope that it will be useful, + but WITHOUT ANY WARRANTY; without even the implied warranty of + MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + GNU Lesser General Public License for more details. + + You should have received a copy of the GNU Lesser General Public License + along with TON Blockchain Library. If not, see . +*/ +#pragma once +#include +#include + +namespace ton::validator { + +class PercentileStats { + public: + void insert(double value); + std::string to_string() const; + void clear(); + + private: + std::multiset values_; +}; + +} // namespace ton::validator \ No newline at end of file From 9a543c6b28b4f7d952f4b0225b5f8ee433a3f392 Mon Sep 17 00:00:00 2001 From: EmelyanenkoK Date: Thu, 25 Apr 2024 18:47:15 +0300 Subject: [PATCH 08/10] Add more info to session stats (#973) * Improve validator session stats * Improve validator session stats Add got_submit_at, collation_cached, validation_cached. Fix stats cleanup. * Fix setting timestamp for cached blocks * Add serialize/deserialize time, serialized size to validator session stats, fix setting is_accepted --------- Co-authored-by: SpyCheese --- tl/generate/scheme/ton_api.tl | 9 +- tl/generate/scheme/ton_api.tlo | Bin 87952 -> 88712 bytes validator-session/candidate-serializer.cpp | 1 - validator-session/validator-session-types.h | 51 ++++- validator-session/validator-session.cpp | 223 ++++++++++++++++---- validator-session/validator-session.h | 14 +- validator-session/validator-session.hpp | 22 +- validator/manager.cpp | 8 +- validator/validator-group.cpp | 43 ++-- validator/validator-group.hpp | 6 +- 10 files changed, 309 insertions(+), 68 deletions(-) diff --git a/tl/generate/scheme/ton_api.tl b/tl/generate/scheme/ton_api.tl index c61bad858..af9df3fd0 100644 --- a/tl/generate/scheme/ton_api.tl +++ b/tl/generate/scheme/ton_api.tl @@ -752,7 +752,14 @@ http.server.config dhs:(vector http.server.dnsEntry) local_hosts:(vector http.se ---types--- -validatorSession.statsProducer id:int256 candidate_id:int256 block_status:int block_timestamp:long comment:string = validatorSession.StatsProducer; +validatorSession.statsProducer id:int256 candidate_id:int256 block_status:int comment:string + block_timestamp:double is_accepted:Bool is_ours:Bool got_submit_at:double + collation_time:double collated_at:double collation_cached:Bool + validation_time:double validated_at:double validation_cached:Bool + gen_utime:double + approved_weight:long approved_33pct_at:double approved_66pct_at:double + signed_weight:long signed_33pct_at:double signed_66pct_at:double + serialize_time:double deserialize_time:double serialized_size:int = validatorSession.StatsProducer; validatorSession.statsRound timestamp:long producers:(vector validatorSession.statsProducer) = validatorSession.StatsRound; diff --git a/tl/generate/scheme/ton_api.tlo b/tl/generate/scheme/ton_api.tlo index b8f5d5a4936db19e0d67c2f4bf647954b93cccf4..c97fa2feefc0767775d31b5c072aaf671c979e35 100644 GIT binary patch delta 460 zcmbQRp0#5u>xLbMES~D@>YMi%^4tcqrk~+qRNw@O-8?4bBQd$KR(ZMvFJr*;3A~Il zlQ&FenV!MRC^7lOECEjL%;NaO Mn6=%7kI}~y0408<1poj5 delta 92 zcmeC!$~s{^>xLbMEGHyC=x*L)$a9+&#FCqSP=Ha4H=rm#r8GIUhyf%vxu8d5x&$v{ n!1NAYMv2KYN(858@-j+KZZPHm>z=+rfUyJ2+HNDr=;H|hYdj%F diff --git a/validator-session/candidate-serializer.cpp b/validator-session/candidate-serializer.cpp index c220b4a95..a85c4b72e 100644 --- a/validator-session/candidate-serializer.cpp +++ b/validator-session/candidate-serializer.cpp @@ -14,7 +14,6 @@ You should have received a copy of the GNU Lesser General Public License along with TON Blockchain Library. If not, see . */ -#pragma once #include "candidate-serializer.h" #include "tl-utils/tl-utils.hpp" #include "vm/boc.h" diff --git a/validator-session/validator-session-types.h b/validator-session/validator-session-types.h index bcbaa8f71..db06bbd9c 100644 --- a/validator-session/validator-session-types.h +++ b/validator-session/validator-session-types.h @@ -76,8 +76,57 @@ struct ValidatorSessionStats { PublicKeyHash id = PublicKeyHash::zero(); ValidatorSessionCandidateId candidate_id = ValidatorSessionCandidateId::zero(); int block_status = status_none; - td::uint64 block_timestamp = 0; + double block_timestamp = -1.0; std::string comment; + + bool is_accepted = false; + bool is_ours = false; + double got_submit_at = -1.0; + double collation_time = -1.0; + double validation_time = -1.0; + double collated_at = -1.0; + double validated_at = -1.0; + bool collation_cached = false; + bool validation_cached = false; + double gen_utime = -1.0; + + std::vector approvers, signers; + ValidatorWeight approved_weight = 0; + ValidatorWeight signed_weight = 0; + double approved_33pct_at = -1.0; + double approved_66pct_at = -1.0; + double signed_33pct_at = -1.0; + double signed_66pct_at = -1.0; + + double serialize_time = -1.0; + double deserialize_time = -1.0; + td::int32 serialized_size = -1; + + void set_approved_by(td::uint32 id, ValidatorWeight weight, ValidatorWeight total_weight) { + if (!approvers.at(id)) { + approvers.at(id) = true; + approved_weight += weight; + if (approved_33pct_at <= 0.0 && approved_weight >= total_weight / 3 + 1) { + approved_33pct_at = td::Clocks::system(); + } + if (approved_66pct_at <= 0.0 && approved_weight >= (total_weight * 2) / 3 + 1) { + approved_66pct_at = td::Clocks::system(); + } + } + } + + void set_signed_by(td::uint32 id, ValidatorWeight weight, ValidatorWeight total_weight) { + if (!signers.at(id)) { + signers.at(id) = true; + signed_weight += weight; + if (signed_33pct_at <= 0.0 && signed_weight >= total_weight / 3 + 1) { + signed_33pct_at = td::Clocks::system(); + } + if (signed_66pct_at <= 0.0 && signed_weight >= (total_weight * 2) / 3 + 1) { + signed_66pct_at = td::Clocks::system(); + } + } + } }; struct Round { td::uint64 timestamp = 0; diff --git a/validator-session/validator-session.cpp b/validator-session/validator-session.cpp index 6b328b2bd..215b6b12d 100644 --- a/validator-session/validator-session.cpp +++ b/validator-session/validator-session.cpp @@ -20,6 +20,7 @@ #include "td/utils/Random.h" #include "td/utils/crypto.h" #include "candidate-serializer.h" +#include "td/utils/overloaded.h" namespace ton { @@ -86,6 +87,7 @@ void ValidatorSessionImpl::process_blocks(std::vector for (auto &msg : msgs) { VLOG(VALIDATOR_SESSION_INFO) << this << ": applying action: " << msg.get(); + stats_process_action(local_idx(), *msg); real_state_ = ValidatorSessionState::action(description(), real_state_, local_idx(), att, msg.get()); } @@ -167,6 +169,7 @@ void ValidatorSessionImpl::preprocess_block(catchain::CatChainBlock *block) { for (auto &msg : B->actions_) { VLOG(VALIDATOR_SESSION_INFO) << this << "[node " << description().get_source_id(block->source()) << "][block " << block->hash() << "]: applying action " << msg.get(); + stats_process_action(block->source(), *msg); state = ValidatorSessionState::action(description(), state, block->source(), att, msg.get()); } state = ValidatorSessionState::make_all(description(), state, block->source(), att); @@ -222,9 +225,11 @@ void ValidatorSessionImpl::process_broadcast(PublicKeyHash src, td::BufferSlice // Note: src is not necessarily equal to the sender of this message: // If requested using get_broadcast_p2p, src is the creator of the block, sender possibly is some other node. auto src_idx = description().get_source_idx(src); + td::Timer deserialize_timer; auto R = deserialize_candidate(data, compress_block_candidates_, description().opts().max_block_size + description().opts().max_collated_data_size + 1024); + double deserialize_time = deserialize_timer.elapsed(); if (R.is_error()) { VLOG(VALIDATOR_SESSION_WARNING) << this << "[node " << src << "][broadcast " << sha256_bits256(data.as_slice()) << "]: failed to parse: " << R.move_as_error(); @@ -255,6 +260,18 @@ void ValidatorSessionImpl::process_broadcast(PublicKeyHash src, td::BufferSlice return; } + auto stat = stats_get_candidate_stat(block_round, src, block_id); + if (stat) { + if (stat->block_status == ValidatorSessionStats::status_none) { + stat->block_status = ValidatorSessionStats::status_received; + } + if (stat->block_timestamp <= 0.0) { + stat->block_timestamp = td::Clocks::system(); + } + stat->deserialize_time = deserialize_time; + stat->serialized_size = data.size(); + } + if ((td::int32)block_round < (td::int32)cur_round_ - MAX_PAST_ROUND_BLOCK || block_round >= cur_round_ + MAX_FUTURE_ROUND_BLOCK) { VLOG(VALIDATOR_SESSION_NOTICE) << this << "[node " << src << "][broadcast " << block_id @@ -291,7 +308,6 @@ void ValidatorSessionImpl::process_broadcast(PublicKeyHash src, td::BufferSlice CHECK(!pending_reject_.count(block_id)); CHECK(!rejected_.count(block_id)); - stats_set_candidate_status(cur_round_, src, block_id, ValidatorSessionStats::status_received); auto v = virtual_state_->choose_blocks_to_approve(description(), local_idx()); for (auto &b : v) { if (b && SentBlock::get_block_id(b) == block_id) { @@ -363,9 +379,16 @@ void ValidatorSessionImpl::process_query(PublicKeyHash src, td::BufferSlice data } void ValidatorSessionImpl::candidate_decision_fail(td::uint32 round, ValidatorSessionCandidateId hash, - std::string result, td::uint32 src, td::BufferSlice proof) { - stats_set_candidate_status(round, description().get_source_id(src), hash, ValidatorSessionStats::status_rejected, - result); + std::string result, td::uint32 src, td::BufferSlice proof, + double validation_time, bool validation_cached) { + auto stat = stats_get_candidate_stat(round, description().get_source_id(src), hash); + if (stat) { + stat->block_status = ValidatorSessionStats::status_rejected; + stat->comment = result; + stat->validation_time = validation_time; + stat->validated_at = td::Clocks::system(); + stat->validation_cached = validation_cached; + } if (round != cur_round_) { return; } @@ -379,9 +402,17 @@ void ValidatorSessionImpl::candidate_decision_fail(td::uint32 round, ValidatorSe } void ValidatorSessionImpl::candidate_decision_ok(td::uint32 round, ValidatorSessionCandidateId hash, RootHash root_hash, - FileHash file_hash, td::uint32 src, td::uint32 ok_from) { - stats_set_candidate_status(round, description().get_source_id(src), hash, ValidatorSessionStats::status_approved, - PSTRING() << "ts=" << ok_from); + FileHash file_hash, td::uint32 src, td::uint32 ok_from, + double validation_time, bool validation_cached) { + auto stat = stats_get_candidate_stat(round, description().get_source_id(src), hash); + if (stat) { + stat->block_status = ValidatorSessionStats::status_approved; + stat->comment = PSTRING() << "ts=" << ok_from; + stat->validation_time = validation_time; + stat->gen_utime = (double)ok_from; + stat->validated_at = td::Clocks::system(); + stat->validation_cached = validation_cached; + } if (round != cur_round_) { return; } @@ -418,10 +449,8 @@ void ValidatorSessionImpl::candidate_approved_signed(td::uint32 round, Validator } void ValidatorSessionImpl::generated_block(td::uint32 round, ValidatorSessionCandidateId root_hash, - td::BufferSlice data, td::BufferSlice collated_data) { - if (round != cur_round_) { - return; - } + td::BufferSlice data, td::BufferSlice collated_data, double collation_time, + bool collation_cached) { if (data.size() > description().opts().max_block_size || collated_data.size() > description().opts().max_collated_data_size) { LOG(ERROR) << this << ": generated candidate is too big. Dropping. size=" << data.size() << " " @@ -430,13 +459,27 @@ void ValidatorSessionImpl::generated_block(td::uint32 round, ValidatorSessionCan } auto file_hash = sha256_bits256(data.as_slice()); auto collated_data_file_hash = sha256_bits256(collated_data.as_slice()); + auto block_id = description().candidate_id(local_idx(), root_hash, file_hash, collated_data_file_hash); + auto stat = stats_get_candidate_stat(round, local_id(), block_id); + if (stat) { + stat->block_status = ValidatorSessionStats::status_received; + stat->collation_time = collation_time; + stat->collated_at = td::Clocks::system(); + stat->block_timestamp = td::Clocks::system(); + stat->collation_cached = collation_cached; + } + if (round != cur_round_) { + return; + } + td::Timer serialize_timer; auto b = create_tl_object(local_id().tl(), round, root_hash, std::move(data), std::move(collated_data)); - auto B = serialize_candidate(b, compress_block_candidates_).move_as_ok(); - - auto block_id = description().candidate_id(local_idx(), root_hash, file_hash, collated_data_file_hash); + if (stat) { + stat->serialize_time = serialize_timer.elapsed(); + stat->serialized_size = B.size(); + } td::actor::send_closure(catchain_, &catchain::CatChain::send_broadcast, std::move(B)); @@ -496,11 +539,11 @@ void ValidatorSessionImpl::check_generate_slot() { td::PerfWarningTimer timer{"too long block generation", 1.0}; auto P = td::PromiseCreator::lambda([SelfId = actor_id(this), print_id = print_id(), timer = std::move(timer), - round = cur_round_](td::Result R) { + round = cur_round_](td::Result R) { if (R.is_ok()) { - auto c = R.move_as_ok(); + auto c = std::move(R.ok_ref().candidate); td::actor::send_closure(SelfId, &ValidatorSessionImpl::generated_block, round, c.id.root_hash, - c.data.clone(), c.collated_data.clone()); + c.data.clone(), c.collated_data.clone(), timer.elapsed(), R.ok().is_cached); } else { LOG(WARNING) << print_id << ": failed to generate block candidate: " << R.move_as_error(); } @@ -550,6 +593,16 @@ void ValidatorSessionImpl::try_approve_block(const SentBlock *block) { it->second->round_ = std::max(it->second->round_, cur_round_); td::PerfWarningTimer timer{"too long block validation", 1.0}; auto &B = it->second; + auto stat = stats_get_candidate_stat(B->round_, PublicKeyHash{B->src_}); + if (stat) { + // Can happen if block is cached from previous round + if (stat->block_status == ValidatorSessionStats::status_none) { + stat->block_status = ValidatorSessionStats::status_received; + } + if (stat->block_timestamp <= 0.0) { + stat->block_timestamp = td::Clocks::system(); + } + } auto P = td::PromiseCreator::lambda([round = cur_round_, hash = block_id, root_hash = block->get_root_hash(), file_hash = block->get_file_hash(), timer = std::move(timer), @@ -563,10 +616,10 @@ void ValidatorSessionImpl::try_approve_block(const SentBlock *block) { auto R = res.move_as_ok(); if (R.is_ok()) { td::actor::send_closure(SelfId, &ValidatorSessionImpl::candidate_decision_ok, round, hash, root_hash, - file_hash, src, R.ok_from()); + file_hash, src, R.ok_from(), timer.elapsed(), R.is_cached()); } else { td::actor::send_closure(SelfId, &ValidatorSessionImpl::candidate_decision_fail, round, hash, R.reason(), - src, R.proof()); + src, R.proof(), timer.elapsed(), R.is_cached()); } }); pending_approve_.insert(block_id); @@ -824,22 +877,28 @@ void ValidatorSessionImpl::on_new_round(td::uint32 round) { cur_stats_.approve_signatures = (td::uint32)export_approve_sigs.size(); cur_stats_.approve_signatures_weight = approve_signatures_weight; cur_stats_.creator = description().get_source_id(block->get_src_idx()); + auto stat = stats_get_candidate_stat(cur_round_, cur_stats_.creator); + if (stat) { + stat->is_accepted = true; + } + auto stats = cur_stats_; + while (!stats.rounds.empty() && stats.rounds.size() + stats.first_round - 1 > cur_round_) { + stats.rounds.pop_back(); + } if (it == blocks_.end()) { callback_->on_block_committed(cur_round_, description().get_source_public_key(block->get_src_idx()), block->get_root_hash(), block->get_file_hash(), td::BufferSlice(), - std::move(export_sigs), std::move(export_approve_sigs), std::move(cur_stats_)); + std::move(export_sigs), std::move(export_approve_sigs), std::move(stats)); } else { callback_->on_block_committed(cur_round_, description().get_source_public_key(block->get_src_idx()), block->get_root_hash(), block->get_file_hash(), it->second->data_.clone(), - std::move(export_sigs), std::move(export_approve_sigs), std::move(cur_stats_)); + std::move(export_sigs), std::move(export_approve_sigs), std::move(stats)); } } cur_round_++; if (have_block) { stats_init(); - } else { - stats_add_round(); } auto it2 = blocks_.begin(); while (it2 != blocks_.end()) { @@ -997,13 +1056,35 @@ void ValidatorSessionImpl::start_up() { } void ValidatorSessionImpl::stats_init() { + auto old_rounds = std::move(cur_stats_.rounds); + if (stats_inited_ && cur_stats_.first_round + old_rounds.size() > cur_round_) { + old_rounds.erase(old_rounds.begin(), old_rounds.end() - (cur_stats_.first_round + old_rounds.size() - cur_round_)); + } else { + old_rounds.clear(); + } cur_stats_ = ValidatorSessionStats(); + cur_stats_.rounds = std::move(old_rounds); cur_stats_.first_round = cur_round_; cur_stats_.session_id = unique_hash_; cur_stats_.total_validators = description().get_total_nodes(); cur_stats_.total_weight = description().get_total_weight(); cur_stats_.self = description().get_source_id(local_idx()); - stats_add_round(); + + for (auto it = stats_pending_approve_.begin(); it != stats_pending_approve_.end(); ) { + if (it->first.first < cur_round_) { + it = stats_pending_approve_.erase(it); + } else { + ++it; + } + } + for (auto it = stats_pending_sign_.begin(); it != stats_pending_sign_.end(); ) { + if (it->first.first < cur_round_) { + it = stats_pending_sign_.erase(it); + } else { + ++it; + } + } + stats_inited_ = true; } void ValidatorSessionImpl::stats_add_round() { @@ -1016,6 +1097,9 @@ void ValidatorSessionImpl::stats_add_round() { if (priority >= 0) { CHECK((size_t)priority < round.producers.size()); round.producers[priority].id = description().get_source_id(i); + round.producers[priority].is_ours = (local_idx() == i); + round.producers[priority].approvers.resize(description().get_total_nodes(), false); + round.producers[priority].signers.resize(description().get_total_nodes(), false); } } while (!round.producers.empty() && round.producers.back().id.is_zero()) { @@ -1023,26 +1107,93 @@ void ValidatorSessionImpl::stats_add_round() { } } -void ValidatorSessionImpl::stats_set_candidate_status(td::uint32 round, PublicKeyHash src, - ValidatorSessionCandidateId candidate_id, int status, - std::string comment) { - if (round < cur_stats_.first_round || round - cur_stats_.first_round >= cur_stats_.rounds.size()) { - return; +ValidatorSessionStats::Producer *ValidatorSessionImpl::stats_get_candidate_stat( + td::uint32 round, PublicKeyHash src, ValidatorSessionCandidateId candidate_id) { + if (round < cur_stats_.first_round || round > cur_round_ + 5) { + return nullptr; + } + while (round - cur_stats_.first_round >= cur_stats_.rounds.size()) { + stats_add_round(); } auto &stats_round = cur_stats_.rounds[round - cur_stats_.first_round]; auto it = std::find_if(stats_round.producers.begin(), stats_round.producers.end(), [&](const ValidatorSessionStats::Producer &p) { return p.id == src; }); if (it == stats_round.producers.end()) { - return; + return nullptr; + } + if (!candidate_id.is_zero()) { + it->candidate_id = candidate_id; } - it->candidate_id = candidate_id; - if (it->block_status == ValidatorSessionStats::status_none) { - it->block_timestamp = (td::uint64)td::Clocks::system(); + auto it2 = stats_pending_approve_.find({round, it->candidate_id}); + if (it2 != stats_pending_approve_.end()) { + for (td::uint32 node_id : it2->second) { + it->set_approved_by(node_id, description().get_node_weight(node_id), description().get_total_weight()); + } + stats_pending_approve_.erase(it2); + } + it2 = stats_pending_sign_.find({round, it->candidate_id}); + if (it2 != stats_pending_sign_.end()) { + for (td::uint32 node_id : it2->second) { + it->set_signed_by(node_id, description().get_node_weight(node_id), description().get_total_weight()); + } + stats_pending_sign_.erase(it2); + } + return &*it; +} + +ValidatorSessionStats::Producer *ValidatorSessionImpl::stats_get_candidate_stat_by_id( + td::uint32 round, ValidatorSessionCandidateId candidate_id) { + if (round < cur_stats_.first_round || round > cur_round_ + 5) { + return nullptr; } - it->block_status = status; - if (!comment.empty()) { - it->comment = std::move(comment); + while (round - cur_stats_.first_round >= cur_stats_.rounds.size()) { + stats_add_round(); } + auto &stats_round = cur_stats_.rounds[round - cur_stats_.first_round]; + auto it = std::find_if(stats_round.producers.begin(), stats_round.producers.end(), + [&](const ValidatorSessionStats::Producer &p) { return p.candidate_id == candidate_id; }); + if (it == stats_round.producers.end()) { + return nullptr; + } + return &*it; +} + +void ValidatorSessionImpl::stats_process_action(td::uint32 node_id, ton_api::validatorSession_round_Message &action) { + ton_api::downcast_call(action, td::overloaded( + [&](const ton_api::validatorSession_message_submittedBlock &obj) { + auto candidate_id = description().candidate_id( + node_id, obj.root_hash_, obj.file_hash_, obj.collated_data_file_hash_); + auto stat = stats_get_candidate_stat( + obj.round_, description().get_source_id(node_id), candidate_id); + if (stat && stat->got_submit_at <= 0.0) { + stat->got_submit_at = td::Clocks::system(); + } + }, + [&](const ton_api::validatorSession_message_approvedBlock &obj) { + if (obj.candidate_ == skip_round_candidate_id()) { + return; + } + auto stat = stats_get_candidate_stat_by_id(obj.round_, obj.candidate_); + if (stat) { + stat->set_approved_by(node_id, description().get_node_weight(node_id), + description().get_total_weight()); + } else { + stats_pending_approve_[{obj.round_, obj.candidate_}].push_back(node_id); + } + }, + [&](const ton_api::validatorSession_message_commit &obj) { + if (obj.candidate_ == skip_round_candidate_id()) { + return; + } + auto stat = stats_get_candidate_stat_by_id(obj.round_, obj.candidate_); + if (stat) { + stat->set_signed_by(node_id, description().get_node_weight(node_id), + description().get_total_weight()); + } else { + stats_pending_sign_[{obj.round_, obj.candidate_}].push_back(node_id); + } + }, + [](const auto &) {})); } td::actor::ActorOwn ValidatorSession::create( diff --git a/validator-session/validator-session.h b/validator-session/validator-session.h index 6300eaa49..2dd6625c1 100644 --- a/validator-session/validator-session.h +++ b/validator-session/validator-session.h @@ -56,6 +56,12 @@ class ValidatorSession : public td::actor::Actor { td::BufferSlice proof() const { return proof_.clone(); } + bool is_cached() const { + return is_cached_; + } + void set_is_cached(bool value = true) { + is_cached_ = value; + } CandidateDecision(td::uint32 ok_from) { ok_ = true; ok_from_ = ok_from; @@ -69,6 +75,12 @@ class ValidatorSession : public td::actor::Actor { td::uint32 ok_from_ = 0; std::string reason_; td::BufferSlice proof_; + bool is_cached_ = false; + }; + + struct GeneratedCandidate { + BlockCandidate candidate; + bool is_cached = false; }; class Callback { @@ -76,7 +88,7 @@ class ValidatorSession : public td::actor::Actor { virtual void on_candidate(td::uint32 round, PublicKey source, ValidatorSessionRootHash root_hash, td::BufferSlice data, td::BufferSlice collated_data, td::Promise promise) = 0; - virtual void on_generate_slot(td::uint32 round, td::Promise promise) = 0; + virtual void on_generate_slot(td::uint32 round, td::Promise promise) = 0; virtual void on_block_committed(td::uint32 round, PublicKey source, ValidatorSessionRootHash root_hash, ValidatorSessionFileHash file_hash, td::BufferSlice data, std::vector> signatures, diff --git a/validator-session/validator-session.hpp b/validator-session/validator-session.hpp index 619f7178a..005292c03 100644 --- a/validator-session/validator-session.hpp +++ b/validator-session/validator-session.hpp @@ -159,10 +159,19 @@ class ValidatorSessionImpl : public ValidatorSession { bool compress_block_candidates_ = false; ValidatorSessionStats cur_stats_; + bool stats_inited_ = false; + std::map, std::vector> + stats_pending_approve_; // round, candidate_id -> approvers + std::map, std::vector> + stats_pending_sign_; // round, candidate_id -> signers void stats_init(); void stats_add_round(); - void stats_set_candidate_status(td::uint32 round, PublicKeyHash src, ValidatorSessionCandidateId candidate_id, - int status, std::string comment = ""); + ValidatorSessionStats::Producer *stats_get_candidate_stat( + td::uint32 round, PublicKeyHash src, + ValidatorSessionCandidateId candidate_id = ValidatorSessionCandidateId::zero()); + ValidatorSessionStats::Producer *stats_get_candidate_stat_by_id(td::uint32 round, + ValidatorSessionCandidateId candidate_id); + void stats_process_action(td::uint32 node_id, ton_api::validatorSession_round_Message &action); public: ValidatorSessionImpl(catchain::CatChainSessionId session_id, ValidatorSessionOptions opts, PublicKeyHash local_id, @@ -190,17 +199,16 @@ class ValidatorSessionImpl : public ValidatorSession { void process_query(PublicKeyHash src, td::BufferSlice data, td::Promise promise); void try_approve_block(const SentBlock *block); - void try_sign(); - void candidate_decision_fail(td::uint32 round, ValidatorSessionCandidateId hash, std::string result, - td::uint32 src, td::BufferSlice proof); + void candidate_decision_fail(td::uint32 round, ValidatorSessionCandidateId hash, std::string result, td::uint32 src, + td::BufferSlice proof, double validation_time, bool validation_cached); void candidate_decision_ok(td::uint32 round, ValidatorSessionCandidateId hash, RootHash root_hash, FileHash file_hash, - td::uint32 src, td::uint32 ok_from); + td::uint32 src, td::uint32 ok_from, double validation_time, bool validation_cached); void candidate_approved_signed(td::uint32 round, ValidatorSessionCandidateId hash, td::uint32 ok_from, td::BufferSlice signature); void generated_block(td::uint32 round, ValidatorSessionRootHash root_hash, td::BufferSlice data, - td::BufferSlice collated); + td::BufferSlice collated, double collation_time, bool collation_cached); void signed_block(td::uint32 round, ValidatorSessionCandidateId hash, td::BufferSlice signature); void end_request(td::uint32 round, ValidatorSessionCandidateId block_id) { diff --git a/validator/manager.cpp b/validator/manager.cpp index d88a50154..37281cc9a 100644 --- a/validator/manager.cpp +++ b/validator/manager.cpp @@ -2714,8 +2714,12 @@ void ValidatorManagerImpl::log_validator_session_stats(BlockIdExt block_id, std::vector> producers; for (const auto &producer : round.producers) { producers.push_back(create_tl_object( - producer.id.bits256_value(), producer.candidate_id, producer.block_status, producer.block_timestamp, - producer.comment)); + producer.id.bits256_value(), producer.candidate_id, producer.block_status, producer.comment, + producer.block_timestamp, producer.is_accepted, producer.is_ours, producer.got_submit_at, + producer.collation_time, producer.collated_at, producer.collation_cached, producer.validation_time, + producer.validated_at, producer.validation_cached, producer.gen_utime, producer.approved_weight, + producer.approved_33pct_at, producer.approved_66pct_at, producer.signed_weight, producer.signed_33pct_at, + producer.signed_66pct_at, producer.serialize_time, producer.deserialize_time, producer.serialized_size)); } rounds.push_back(create_tl_object(round.timestamp, std::move(producers))); } diff --git a/validator/validator-group.cpp b/validator/validator-group.cpp index 05628ef5d..5193e5233 100644 --- a/validator/validator-group.cpp +++ b/validator/validator-group.cpp @@ -27,7 +27,8 @@ namespace ton { namespace validator { -void ValidatorGroup::generate_block_candidate(td::uint32 round_id, td::Promise promise) { +void ValidatorGroup::generate_block_candidate( + td::uint32 round_id, td::Promise promise) { if (round_id > last_known_round_id_) { last_known_round_id_ = round_id; } @@ -37,14 +38,18 @@ void ValidatorGroup::generate_block_candidate(td::uint32 round_id, td::Promiseresult) { - promise.set_result(cached_collated_block_->result.value().clone()); + promise.set_value({cached_collated_block_->result.value().clone(), true}); } else { - cached_collated_block_->promises.push_back(std::move(promise)); + cached_collated_block_->promises.push_back(promise.wrap([](BlockCandidate &&res) { + return validatorsession::ValidatorSession::GeneratedCandidate{std::move(res), true}; + })); } return; } cached_collated_block_ = std::make_shared(); - cached_collated_block_->promises.push_back(std::move(promise)); + cached_collated_block_->promises.push_back(promise.wrap([](BlockCandidate &&res) { + return validatorsession::ValidatorSession::GeneratedCandidate{std::move(res), false}; + })); run_collate_query( shard_, min_ts_, min_masterchain_block_id_, prev_block_ids_, Ed25519_PublicKey{local_id_full_.ed25519_value().raw()}, validator_set_, manager_, td::Timestamp::in(10.0), @@ -73,7 +78,7 @@ void ValidatorGroup::generated_block_candidate(std::shared_ptr promise) { + td::Promise> promise) { if (round_id > last_known_round_id_) { last_known_round_id_ = round_id; } @@ -88,7 +93,7 @@ void ValidatorGroup::validate_block_candidate(td::uint32 round_id, BlockCandidat CacheKey cache_key = block_to_cache_key(block); auto it = approved_candidates_cache_.find(cache_key); if (it != approved_candidates_cache_.end()) { - promise.set_result(it->second); + promise.set_value({it->second, true}); return; } @@ -113,7 +118,7 @@ void ValidatorGroup::validate_block_candidate(td::uint32 round_id, BlockCandidat ts); td::actor::send_closure(SelfId, &ValidatorGroup::add_available_block_candidate, block.pubkey.as_bits256(), block.id, block.collated_file_hash); - promise.set_result(ts); + promise.set_value({ts, false}); }, [&](CandidateReject reject) { promise.set_error( @@ -247,15 +252,18 @@ std::unique_ptr ValidatorGroup::ma void on_candidate(td::uint32 round, PublicKey source, validatorsession::ValidatorSessionRootHash root_hash, td::BufferSlice data, td::BufferSlice collated_data, td::Promise promise) override { - auto P = td::PromiseCreator::lambda([id = id_, promise = std::move(promise)](td::Result R) mutable { - if (R.is_ok()) { - promise.set_value(validatorsession::ValidatorSession::CandidateDecision{R.move_as_ok()}); - } else { - auto S = R.move_as_error(); - promise.set_value( - validatorsession::ValidatorSession::CandidateDecision{S.message().c_str(), td::BufferSlice()}); - } - }); + auto P = + td::PromiseCreator::lambda([promise = std::move(promise)](td::Result> R) mutable { + if (R.is_ok()) { + validatorsession::ValidatorSession::CandidateDecision decision(R.ok().first); + decision.set_is_cached(R.ok().second); + promise.set_value(std::move(decision)); + } else { + auto S = R.move_as_error(); + promise.set_value( + validatorsession::ValidatorSession::CandidateDecision{S.message().c_str(), td::BufferSlice()}); + } + }); BlockCandidate candidate{Ed25519_PublicKey{source.ed25519_value().raw()}, BlockIdExt{0, 0, 0, root_hash, sha256_bits256(data.as_slice())}, @@ -264,7 +272,8 @@ std::unique_ptr ValidatorGroup::ma td::actor::send_closure(id_, &ValidatorGroup::validate_block_candidate, round, std::move(candidate), std::move(P)); } - void on_generate_slot(td::uint32 round, td::Promise promise) override { + void on_generate_slot(td::uint32 round, + td::Promise promise) override { td::actor::send_closure(id_, &ValidatorGroup::generate_block_candidate, round, std::move(promise)); } void on_block_committed(td::uint32 round, PublicKey source, validatorsession::ValidatorSessionRootHash root_hash, diff --git a/validator/validator-group.hpp b/validator/validator-group.hpp index 2dbff8de2..cb3f7a630 100644 --- a/validator/validator-group.hpp +++ b/validator/validator-group.hpp @@ -34,8 +34,10 @@ class ValidatorManager; class ValidatorGroup : public td::actor::Actor { public: - void generate_block_candidate(td::uint32 round_id, td::Promise promise); - void validate_block_candidate(td::uint32 round_id, BlockCandidate block, td::Promise promise); + void generate_block_candidate(td::uint32 round_id, + td::Promise promise); + void validate_block_candidate(td::uint32 round_id, BlockCandidate block, + td::Promise> promise); void accept_block_candidate(td::uint32 round_id, PublicKeyHash src, td::BufferSlice block, RootHash root_hash, FileHash file_hash, std::vector signatures, std::vector approve_signatures, From 037053fffec58dedf8e72051fb695a4a42d3d9f3 Mon Sep 17 00:00:00 2001 From: EmelyanenkoK Date: Mon, 29 Apr 2024 16:33:10 +0300 Subject: [PATCH 09/10] More verbose state serializer logs (#976) Co-authored-by: SpyCheese --- crypto/vm/large-boc-serializer.cpp | 60 ++++++++++++++++++++++-------- validator/state-serializer.cpp | 30 +++++++++------ 2 files changed, 63 insertions(+), 27 deletions(-) diff --git a/crypto/vm/large-boc-serializer.cpp b/crypto/vm/large-boc-serializer.cpp index fe16b7678..fbd065dc9 100644 --- a/crypto/vm/large-boc-serializer.cpp +++ b/crypto/vm/large-boc-serializer.cpp @@ -14,6 +14,9 @@ You should have received a copy of the GNU Lesser General Public License along with TON Blockchain Library. If not, see . */ +#include "td/utils/Time.h" +#include "td/utils/Timer.h" + #include #include "vm/boc.h" #include "vm/boc-writers.h" @@ -30,7 +33,8 @@ class LargeBocSerializer { public: using Hash = Cell::Hash; - explicit LargeBocSerializer(std::shared_ptr reader) : reader(std::move(reader)) {} + explicit LargeBocSerializer(std::shared_ptr reader) : reader(std::move(reader)) { + } void add_root(Hash root); td::Status import_cells(); @@ -65,7 +69,8 @@ class LargeBocSerializer { std::map cells; std::vector*> cell_list; struct RootInfo { - RootInfo(Hash hash, int idx) : hash(hash), idx(idx) {} + RootInfo(Hash hash, int idx) : hash(hash), idx(idx) { + } Hash hash; int idx; }; @@ -78,6 +83,10 @@ class LargeBocSerializer { void reorder_cells(); int revisit(int cell_idx, int force = 0); td::uint64 compute_sizes(int mode, int& r_size, int& o_size); + + td::Timestamp log_speed_at_; + size_t processed_cells_ = 0; + static constexpr double LOG_SPEED_PERIOD = 120.0; }; void LargeBocSerializer::add_root(Hash root) { @@ -85,12 +94,16 @@ void LargeBocSerializer::add_root(Hash root) { } td::Status LargeBocSerializer::import_cells() { + td::Timer timer; + log_speed_at_ = td::Timestamp::in(LOG_SPEED_PERIOD); + processed_cells_ = 0; for (auto& root : roots) { TRY_RESULT(idx, import_cell(root.hash)); root.idx = idx; } reorder_cells(); CHECK(!cell_list.empty()); + LOG(ERROR) << "serializer: import_cells took " << timer.elapsed() << "s, " << cell_count << " cells"; return td::Status::OK(); } @@ -98,6 +111,12 @@ td::Result LargeBocSerializer::import_cell(Hash hash, int depth) { if (depth > Cell::max_depth) { return td::Status::Error("error while importing a cell into a bag of cells: cell depth too large"); } + ++processed_cells_; + if (log_speed_at_.is_in_past()) { + log_speed_at_ += LOG_SPEED_PERIOD; + LOG(WARNING) << "serializer: import_cells " << (double)processed_cells_ / LOG_SPEED_PERIOD << " cells/s"; + processed_cells_ = 0; + } auto it = cells.find(hash); if (it != cells.end()) { it->second.should_cache = true; @@ -282,6 +301,7 @@ td::uint64 LargeBocSerializer::compute_sizes(int mode, int& r_size, int& o_size) } td::Status LargeBocSerializer::serialize(td::FileFd& fd, int mode) { + td::Timer timer; using Mode = BagOfCells::Mode; BagOfCells::Info info; if ((mode & Mode::WithCacheBits) && !(mode & Mode::WithIndex)) { @@ -313,13 +333,9 @@ td::Status LargeBocSerializer::serialize(td::FileFd& fd, int mode) { return td::Status::Error("bag of cells is too large"); } - boc_writers::FileWriter writer{fd, (size_t) info.total_size}; - auto store_ref = [&](unsigned long long value) { - writer.store_uint(value, info.ref_byte_size); - }; - auto store_offset = [&](unsigned long long value) { - writer.store_uint(value, info.offset_byte_size); - }; + boc_writers::FileWriter writer{fd, (size_t)info.total_size}; + auto store_ref = [&](unsigned long long value) { writer.store_uint(value, info.ref_byte_size); }; + auto store_offset = [&](unsigned long long value) { writer.store_uint(value, info.offset_byte_size); }; writer.store_uint(info.magic, 4); @@ -371,6 +387,8 @@ td::Status LargeBocSerializer::serialize(td::FileFd& fd, int mode) { } DCHECK(writer.position() == info.data_offset); size_t keep_position = writer.position(); + log_speed_at_ = td::Timestamp::in(LOG_SPEED_PERIOD); + processed_cells_ = 0; for (int i = 0; i < cell_count; ++i) { auto hash = cell_list[cell_count - 1 - i]->first; const auto& dc_info = cell_list[cell_count - 1 - i]->second; @@ -389,6 +407,12 @@ td::Status LargeBocSerializer::serialize(td::FileFd& fd, int mode) { DCHECK(k > i && k < cell_count); store_ref(k); } + ++processed_cells_; + if (log_speed_at_.is_in_past()) { + log_speed_at_ += LOG_SPEED_PERIOD; + LOG(WARNING) << "serializer: serialize " << (double)processed_cells_ / LOG_SPEED_PERIOD << " cells/s"; + processed_cells_ = 0; + } } DCHECK(writer.position() - keep_position == info.data_size); if (info.has_crc32c) { @@ -396,17 +420,23 @@ td::Status LargeBocSerializer::serialize(td::FileFd& fd, int mode) { writer.store_uint(td::bswap32(crc), 4); } DCHECK(writer.empty()); - return writer.finalize(); -} + TRY_STATUS(writer.finalize()); + LOG(ERROR) << "serializer: serialize took " << timer.elapsed() << "s, " << cell_count << " cells, " + << writer.position() << " bytes"; + return td::Status::OK(); } +} // namespace -td::Status std_boc_serialize_to_file_large(std::shared_ptr reader, Cell::Hash root_hash, - td::FileFd& fd, int mode) { +td::Status std_boc_serialize_to_file_large(std::shared_ptr reader, Cell::Hash root_hash, td::FileFd& fd, + int mode) { + td::Timer timer; CHECK(reader != nullptr) LargeBocSerializer serializer(reader); serializer.add_root(root_hash); TRY_STATUS(serializer.import_cells()); - return serializer.serialize(fd, mode); + TRY_STATUS(serializer.serialize(fd, mode)); + LOG(ERROR) << "serialization took " << timer.elapsed() << "s"; + return td::Status::OK(); } -} +} // namespace vm diff --git a/validator/state-serializer.cpp b/validator/state-serializer.cpp index 8e1b1b575..93363d3b2 100644 --- a/validator/state-serializer.cpp +++ b/validator/state-serializer.cpp @@ -132,27 +132,33 @@ void AsyncStateSerializer::next_iteration() { if (attempt_ < max_attempt() && last_key_block_id_.id.seqno < last_block_id_.id.seqno && need_serialize(masterchain_handle_)) { if (!have_masterchain_state_) { - LOG(INFO) << "started serializing persistent state for " << masterchain_handle_->id().id; + LOG(ERROR) << "started serializing persistent state for " << masterchain_handle_->id().id.to_str(); // block next attempts immediately, but send actual request later running_ = true; + double delay = td::Random::fast(0, 3600); + LOG(WARNING) << "serializer delay = " << delay << "s"; delay_action([SelfId = actor_id( this)]() { td::actor::send_closure(SelfId, &AsyncStateSerializer::request_masterchain_state); }, - td::Timestamp::in(td::Random::fast(0, 3600))); + td::Timestamp::in(delay)); return; } while (next_idx_ < shards_.size()) { if (!need_monitor(shards_[next_idx_].shard_full())) { next_idx_++; } else { - // block next attempts immediately, but send actual request later - running_ = true; - delay_action( - [SelfId = actor_id(this), shard = shards_[next_idx_]]() { td::actor::send_closure(SelfId, &AsyncStateSerializer::request_shard_state, shard); }, - td::Timestamp::in(td::Random::fast(0, 1800))); + // block next attempts immediately, but send actual request later + running_ = true; + double delay = td::Random::fast(0, 1800); + LOG(WARNING) << "serializer delay = " << delay << "s"; + delay_action( + [SelfId = actor_id(this), shard = shards_[next_idx_]]() { + td::actor::send_closure(SelfId, &AsyncStateSerializer::request_shard_state, shard); + }, + td::Timestamp::in(delay)); return; } } - LOG(INFO) << "finished serializing persistent state for " << masterchain_handle_->id().id; + LOG(ERROR) << "finished serializing persistent state for " << masterchain_handle_->id().id.to_str(); last_key_block_ts_ = masterchain_handle_->unix_time(); last_key_block_id_ = masterchain_handle_->id(); } @@ -194,7 +200,7 @@ void AsyncStateSerializer::got_masterchain_handle(BlockHandle handle) { void AsyncStateSerializer::got_masterchain_state(td::Ref state, std::shared_ptr cell_db_reader) { - LOG(INFO) << "serializing masterchain state " << masterchain_handle_->id().id; + LOG(ERROR) << "serializing masterchain state " << masterchain_handle_->id().id.to_str(); have_masterchain_state_ = true; CHECK(next_idx_ == 0); CHECK(shards_.size() == 0); @@ -217,7 +223,7 @@ void AsyncStateSerializer::got_masterchain_state(td::Ref state } void AsyncStateSerializer::stored_masterchain_state() { - LOG(INFO) << "finished serializing masterchain state " << masterchain_handle_->id().id; + LOG(ERROR) << "finished serializing masterchain state " << masterchain_handle_->id().id.to_str(); running_ = false; next_iteration(); } @@ -247,13 +253,13 @@ void AsyncStateSerializer::got_shard_handle(BlockHandle handle) { void AsyncStateSerializer::got_shard_state(BlockHandle handle, td::Ref state, std::shared_ptr cell_db_reader) { - LOG(INFO) << "serializing shard state " << handle->id().id; + LOG(ERROR) << "serializing shard state " << handle->id().id.to_str(); auto write_data = [hash = state->root_cell()->get_hash(), cell_db_reader](td::FileFd& fd) { return vm::std_boc_serialize_to_file_large(cell_db_reader, hash, fd, 31); }; auto P = td::PromiseCreator::lambda([SelfId = actor_id(this), handle](td::Result R) { R.ensure(); - LOG(INFO) << "finished serializing shard state " << handle->id().id; + LOG(ERROR) << "finished serializing shard state " << handle->id().id.to_str(); td::actor::send_closure(SelfId, &AsyncStateSerializer::success_handler); }); td::actor::send_closure(manager_, &ValidatorManager::store_persistent_state_file_gen, handle->id(), From 6fb2019a4fe16dcf298a46c9c719987b18411320 Mon Sep 17 00:00:00 2001 From: EmelyanenkoK Date: Wed, 8 May 2024 17:41:15 +0300 Subject: [PATCH 10/10] Improve validator session stats (#982) * Add list of validators * Fix producer stats * Make round and stats timestamps more meaningful Co-authored-by: SpyCheese --- tl/generate/scheme/ton_api.tl | 8 +++- tl/generate/scheme/ton_api.tlo | Bin 88712 -> 89348 bytes validator-session/validator-session-types.h | 18 ++++++++- validator-session/validator-session.cpp | 39 ++++++++++++-------- validator/interfaces/validator-manager.h | 1 + validator/manager-disk.hpp | 3 ++ validator/manager-hardfork.hpp | 3 ++ validator/manager.cpp | 28 +++++++++++++- validator/manager.hpp | 1 + validator/validator-group.cpp | 19 ++++++++++ 10 files changed, 99 insertions(+), 21 deletions(-) diff --git a/tl/generate/scheme/ton_api.tl b/tl/generate/scheme/ton_api.tl index af9df3fd0..3db2ace98 100644 --- a/tl/generate/scheme/ton_api.tl +++ b/tl/generate/scheme/ton_api.tl @@ -761,13 +761,17 @@ validatorSession.statsProducer id:int256 candidate_id:int256 block_status:int co signed_weight:long signed_33pct_at:double signed_66pct_at:double serialize_time:double deserialize_time:double serialized_size:int = validatorSession.StatsProducer; -validatorSession.statsRound timestamp:long producers:(vector validatorSession.statsProducer) = validatorSession.StatsRound; +validatorSession.statsRound timestamp:double producers:(vector validatorSession.statsProducer) = validatorSession.StatsRound; -validatorSession.stats success:Bool id:tonNode.blockIdExt timestamp:long self:int256 session_id:int256 cc_seqno:int +validatorSession.stats success:Bool id:tonNode.blockIdExt timestamp:double self:int256 session_id:int256 cc_seqno:int creator:int256 total_validators:int total_weight:long signatures:int signatures_weight:long approve_signatures:int approve_signatures_weight:long first_round:int rounds:(vector validatorSession.statsRound) = validatorSession.Stats; +validatorSession.newValidatorGroupStats.node id:int256 weight:long = validatorSession.newValidatorGroupStats.Node; +validatorSession.newValidatorGroupStats session_id:int256 workchain:int shard:long cc_seqno:int timestamp:double + self_idx:int nodes:(vector validatorSession.newValidatorGroupStats.node) = validatorSession.NewValidatorGroupStats; + ---functions--- ---types--- diff --git a/tl/generate/scheme/ton_api.tlo b/tl/generate/scheme/ton_api.tlo index c97fa2feefc0767775d31b5c072aaf671c979e35..b0d5f315b0603c43be7a61d0f9290c55a69a744a 100644 GIT binary patch delta 461 zcmeC!%G$DvmG{wXeJchiVBN^;Y^c8fyu=yxvc#Osl*E$!qTtlx;>`R!J-^iQFqoKo zQGRK`VABHA6KaB6_>R_0Vhi*b}Nn%OyP$9ux9mpKfT$C_VX1fWTynZ!VKpd{v#kmWxq%@`+gj zoE*ieIcf2kDHW49T1Zchd8Z-)avdYo$3@O;Ivlob2SFxHzro3v!wT|^*z|(}jAE<| zAolbWF2)#;N!u@QF<{9 delta 183 zcmZqK#oDozmG{wXeJchiVBW~sNXEq%U z+qQ!s9m|*SF|t5Ro^Hs)C^mh+5F;xmNcGKQLOx8>dwCe8Cs(8jO#dOoXu|>$-+o4z H(ZUk|G!Q%& diff --git a/validator-session/validator-session-types.h b/validator-session/validator-session-types.h index db06bbd9c..e13c36d24 100644 --- a/validator-session/validator-session-types.h +++ b/validator-session/validator-session-types.h @@ -129,7 +129,7 @@ struct ValidatorSessionStats { } }; struct Round { - td::uint64 timestamp = 0; + double timestamp = -1.0; std::vector producers; }; @@ -139,7 +139,7 @@ struct ValidatorSessionStats { bool success = false; ValidatorSessionId session_id = ValidatorSessionId::zero(); CatchainSeqno cc_seqno = 0; - td::uint64 timestamp = 0; + double timestamp = -1.0; PublicKeyHash self = PublicKeyHash::zero(); PublicKeyHash creator = PublicKeyHash::zero(); td::uint32 total_validators = 0; @@ -150,6 +150,20 @@ struct ValidatorSessionStats { ValidatorWeight approve_signatures_weight = 0; }; +struct NewValidatorGroupStats { + struct Node { + PublicKeyHash id = PublicKeyHash::zero(); + ValidatorWeight weight = 0; + }; + + ValidatorSessionId session_id = ValidatorSessionId::zero(); + ShardIdFull shard{masterchainId}; + CatchainSeqno cc_seqno = 0; + double timestamp = -1.0; + td::uint32 self_idx = 0; + std::vector nodes; +}; + } // namespace validatorsession } // namespace ton diff --git a/validator-session/validator-session.cpp b/validator-session/validator-session.cpp index 215b6b12d..d2fe64589 100644 --- a/validator-session/validator-session.cpp +++ b/validator-session/validator-session.cpp @@ -871,7 +871,7 @@ void ValidatorSessionImpl::on_new_round(td::uint32 round) { callback_->on_block_skipped(cur_round_); } else { cur_stats_.success = true; - cur_stats_.timestamp = (td::uint64)td::Clocks::system(); + cur_stats_.timestamp = td::Clocks::system(); cur_stats_.signatures = (td::uint32)export_sigs.size(); cur_stats_.signatures_weight = signatures_weight; cur_stats_.approve_signatures = (td::uint32)export_approve_sigs.size(); @@ -899,6 +899,12 @@ void ValidatorSessionImpl::on_new_round(td::uint32 round) { cur_round_++; if (have_block) { stats_init(); + } else { + size_t round_idx = cur_round_ - cur_stats_.first_round; + while (round_idx >= cur_stats_.rounds.size()) { + stats_add_round(); + } + cur_stats_.rounds[round_idx].timestamp = td::Clocks::system(); } auto it2 = blocks_.begin(); while (it2 != blocks_.end()) { @@ -988,9 +994,7 @@ void ValidatorSessionImpl::destroy() { } void ValidatorSessionImpl::get_current_stats(td::Promise promise) { - ValidatorSessionStats stats = cur_stats_; - stats.timestamp = (td::uint64)td::Clocks::system(); - promise.set_result(std::move(stats)); + promise.set_result(cur_stats_); } void ValidatorSessionImpl::get_validator_group_info_for_litequery( @@ -1084,26 +1088,31 @@ void ValidatorSessionImpl::stats_init() { ++it; } } + + if (cur_stats_.rounds.empty()) { + stats_add_round(); + } + cur_stats_.rounds[0].timestamp = td::Clocks::system(); stats_inited_ = true; } void ValidatorSessionImpl::stats_add_round() { + td::uint32 round = cur_stats_.first_round + cur_stats_.rounds.size(); cur_stats_.rounds.emplace_back(); - auto& round = cur_stats_.rounds.back(); - round.timestamp = (td::uint64)td::Clocks::system(); - round.producers.resize(description().get_max_priority() + 1); + auto& stat = cur_stats_.rounds.back(); + stat.producers.resize(description().get_max_priority() + 1); for (td::uint32 i = 0; i < description().get_total_nodes(); i++) { - td::int32 priority = description().get_node_priority(i, cur_round_); + td::int32 priority = description().get_node_priority(i, round); if (priority >= 0) { - CHECK((size_t)priority < round.producers.size()); - round.producers[priority].id = description().get_source_id(i); - round.producers[priority].is_ours = (local_idx() == i); - round.producers[priority].approvers.resize(description().get_total_nodes(), false); - round.producers[priority].signers.resize(description().get_total_nodes(), false); + CHECK((size_t)priority < stat.producers.size()); + stat.producers[priority].id = description().get_source_id(i); + stat.producers[priority].is_ours = (local_idx() == i); + stat.producers[priority].approvers.resize(description().get_total_nodes(), false); + stat.producers[priority].signers.resize(description().get_total_nodes(), false); } } - while (!round.producers.empty() && round.producers.back().id.is_zero()) { - round.producers.pop_back(); + while (!stat.producers.empty() && stat.producers.back().id.is_zero()) { + stat.producers.pop_back(); } } diff --git a/validator/interfaces/validator-manager.h b/validator/interfaces/validator-manager.h index 41412fb17..278915f16 100644 --- a/validator/interfaces/validator-manager.h +++ b/validator/interfaces/validator-manager.h @@ -171,6 +171,7 @@ class ValidatorManager : public ValidatorManagerInterface { virtual void wait_shard_client_state(BlockSeqno seqno, td::Timestamp timeout, td::Promise promise) = 0; virtual void log_validator_session_stats(BlockIdExt block_id, validatorsession::ValidatorSessionStats stats) = 0; + virtual void log_new_validator_group_stats(validatorsession::NewValidatorGroupStats stats) = 0; virtual void get_block_handle_for_litequery(BlockIdExt block_id, td::Promise promise) = 0; virtual void get_block_data_for_litequery(BlockIdExt block_id, td::Promise> promise) = 0; diff --git a/validator/manager-disk.hpp b/validator/manager-disk.hpp index d5a6e909f..eca6a7418 100644 --- a/validator/manager-disk.hpp +++ b/validator/manager-disk.hpp @@ -378,6 +378,9 @@ class ValidatorManagerImpl : public ValidatorManager { void log_validator_session_stats(BlockIdExt block_id, validatorsession::ValidatorSessionStats stats) override { UNREACHABLE(); } + void log_new_validator_group_stats(validatorsession::NewValidatorGroupStats stats) override { + UNREACHABLE(); + } void get_out_msg_queue_size(BlockIdExt block_id, td::Promise promise) override { if (queue_size_counter_.empty()) { queue_size_counter_ = diff --git a/validator/manager-hardfork.hpp b/validator/manager-hardfork.hpp index 7937729ce..f0cf83de5 100644 --- a/validator/manager-hardfork.hpp +++ b/validator/manager-hardfork.hpp @@ -439,6 +439,9 @@ class ValidatorManagerImpl : public ValidatorManager { void log_validator_session_stats(BlockIdExt block_id, validatorsession::ValidatorSessionStats stats) override { UNREACHABLE(); } + void log_new_validator_group_stats(validatorsession::NewValidatorGroupStats stats) override { + UNREACHABLE(); + } void get_out_msg_queue_size(BlockIdExt block_id, td::Promise promise) override { if (queue_size_counter_.empty()) { queue_size_counter_ = diff --git a/validator/manager.cpp b/validator/manager.cpp index 37281cc9a..ddc582251 100644 --- a/validator/manager.cpp +++ b/validator/manager.cpp @@ -2729,7 +2729,7 @@ void ValidatorManagerImpl::log_validator_session_stats(BlockIdExt block_id, stats.cc_seqno, stats.creator.bits256_value(), stats.total_validators, stats.total_weight, stats.signatures, stats.signatures_weight, stats.approve_signatures, stats.approve_signatures_weight, stats.first_round, std::move(rounds)); - std::string s = td::json_encode(td::ToJson(*obj.get()), false); + auto s = td::json_encode(td::ToJson(*obj.get()), false); s.erase(std::remove_if(s.begin(), s.end(), [](char c) { return c == '\n' || c == '\r'; }), s.end()); std::ofstream file; @@ -2737,7 +2737,31 @@ void ValidatorManagerImpl::log_validator_session_stats(BlockIdExt block_id, file << s << "\n"; file.close(); - LOG(INFO) << "Writing validator session stats for " << block_id.id; + LOG(INFO) << "Writing validator session stats for " << block_id.id.to_str(); +} + +void ValidatorManagerImpl::log_new_validator_group_stats(validatorsession::NewValidatorGroupStats stats) { + std::string fname = opts_->get_session_logs_file(); + if (fname.empty()) { + return; + } + std::vector> nodes; + for (const auto &node : stats.nodes) { + nodes.push_back( + create_tl_object(node.id.bits256_value(), node.weight)); + } + auto obj = create_tl_object( + stats.session_id, stats.shard.workchain, stats.shard.shard, stats.cc_seqno, stats.timestamp, stats.self_idx, + std::move(nodes)); + auto s = td::json_encode(td::ToJson(*obj.get()), false); + s.erase(std::remove_if(s.begin(), s.end(), [](char c) { return c == '\n' || c == '\r'; }), s.end()); + + std::ofstream file; + file.open(fname, std::ios_base::app); + file << s << "\n"; + file.close(); + + LOG(INFO) << "Writing new validator group stats for " << stats.shard.to_str(); } void ValidatorManagerImpl::get_block_handle_for_litequery(BlockIdExt block_id, td::Promise promise) { diff --git a/validator/manager.hpp b/validator/manager.hpp index 7e5930d37..d6d0307b3 100644 --- a/validator/manager.hpp +++ b/validator/manager.hpp @@ -565,6 +565,7 @@ class ValidatorManagerImpl : public ValidatorManager { void wait_shard_client_state(BlockSeqno seqno, td::Timestamp timeout, td::Promise promise) override; void log_validator_session_stats(BlockIdExt block_id, validatorsession::ValidatorSessionStats stats) override; + void log_new_validator_group_stats(validatorsession::NewValidatorGroupStats stats) override; void get_out_msg_queue_size(BlockIdExt block_id, td::Promise promise) override { if (queue_size_counter_.empty()) { diff --git a/validator/validator-group.cpp b/validator/validator-group.cpp index 5193e5233..6a71d306a 100644 --- a/validator/validator-group.cpp +++ b/validator/validator-group.cpp @@ -377,6 +377,22 @@ void ValidatorGroup::start(std::vector prev, BlockIdExt min_masterch prev_block_ids_ = std::vector{next_block_id}; } postponed_accept_.clear(); + + validatorsession::NewValidatorGroupStats stats; + stats.session_id = session_id_; + stats.shard = shard_; + stats.cc_seqno = validator_set_->get_catchain_seqno(); + stats.timestamp = td::Clocks::system(); + td::uint32 idx = 0; + for (const auto& node : validator_set_->export_vector()) { + PublicKeyHash id = ValidatorFullId{node.key}.compute_short_id(); + if (id == local_id_) { + stats.self_idx = idx; + } + stats.nodes.push_back(validatorsession::NewValidatorGroupStats::Node{id, node.weight}); + ++idx; + } + td::actor::send_closure(manager_, &ValidatorManager::log_new_validator_group_stats, std::move(stats)); } void ValidatorGroup::destroy() { @@ -390,6 +406,9 @@ void ValidatorGroup::destroy() { return; } auto stats = R.move_as_ok(); + if (stats.rounds.empty()) { + return; + } stats.cc_seqno = cc_seqno; td::actor::send_closure(manager, &ValidatorManager::log_validator_session_stats, block_id, std::move(stats));