Add GetPerfTimerStats (#451)

* Add getperfwarningtimeraverage query for validator-engine-console

* Fix for getperfwarningtimeraverage query

* getperftimerstats

* Add history max size: 1 hour

* PerfWarningTimer: move callback instead of copy

* PerfWarningTimer: fix move constructor bug

* PerfWarningTimer: fix bug: lifetime of the callback was greater than lifetime of the local variable 'manager' captured by reference

* Fix validate-query.cpp: 'manager' used after it was moved

* PerfWarningTimer: remove logs

* getperftimerstats: write to json file

* getperftimerstatsjson

Co-authored-by: legaii <jgates.ardux@gmail.com>
Co-authored-by: Ivan Siomash <106972486+legaii@users.noreply.github.com>

validator/apply-block.hpp

@@ -46,7 +46,10 @@ class ApplyBlock : public td::actor::Actor {
       , masterchain_block_id_(masterchain_block_id)
       , manager_(manager)
       , timeout_(timeout)
-      , promise_(std::move(promise)) {
+      , promise_(std::move(promise))
+      , perf_timer_("applyblock", 0.1, [manager](double duration) {
+          send_closure(manager, &ValidatorManager::add_perf_timer_stat, "applyblock", duration);
+        }) {
   }
 
   static constexpr td::uint32 apply_block_priority() {
@@ -78,7 +81,7 @@ class ApplyBlock : public td::actor::Actor {
   BlockHandle handle_;
   td::Ref<ShardState> state_;
 
-  td::PerfWarningTimer perf_timer_{"applyblock", 0.1};
+  td::PerfWarningTimer perf_timer_;
 };
 
 }  // namespace validator

validator/downloaders/wait-block-data.hpp

@@ -35,7 +35,10 @@ class WaitBlockData : public td::actor::Actor {
       , priority_(priority)
       , manager_(manager)
       , timeout_(timeout)
-      , promise_(std::move(promise)) {
+      , promise_(std::move(promise))
+      , perf_timer_("waitdata", 1.0, [manager](double duration) {
+          send_closure(manager, &ValidatorManager::add_perf_timer_stat, "waitdata", duration);
+        }) {
   }
 
   void update_timeout(td::Timestamp timeout, td::uint32 priority) {
@@ -74,7 +77,7 @@ class WaitBlockData : public td::actor::Actor {
   bool is_hardfork_ = false;
   td::Timestamp try_read_static_file_ = td::Timestamp::now();
 
-  //td::PerfWarningTimer perf_timer_{"waitdata", 1.0};
+  td::PerfWarningTimer perf_timer_;
 };
 
 }  // namespace validator

validator/downloaders/wait-block-state.hpp

@@ -32,7 +32,10 @@ class WaitBlockState : public td::actor::Actor {
       , priority_(priority)
       , manager_(manager)
       , timeout_(timeout)
-      , promise_(std::move(promise)) {
+      , promise_(std::move(promise))
+      , perf_timer_("waitstate", 1.0, [manager](double duration) {
+          send_closure(manager, &ValidatorManager::add_perf_timer_stat, "waitstate", duration);
+        }) {
   }
 
   void abort_query(td::Status reason);
@@ -80,7 +83,7 @@ class WaitBlockState : public td::actor::Actor {
   bool reading_from_db_ = false;
   td::Timestamp next_static_file_attempt_;
 
-  //td::PerfWarningTimer perf_timer_{"waitstate", 1.0};
+  td::PerfWarningTimer perf_timer_;
 };
 
 }  // namespace validator

validator/impl/accept-block.cpp

@@ -53,7 +53,10 @@ AcceptBlockQuery::AcceptBlockQuery(BlockIdExt id, td::Ref<BlockData> data, std::
     , is_fork_(false)
     , send_broadcast_(send_broadcast)
     , manager_(manager)
-    , promise_(std::move(promise)) {
+    , promise_(std::move(promise))
+    , perf_timer_("acceptblock", 0.1, [manager](double duration) {
+        send_closure(manager, &ValidatorManager::add_perf_timer_stat, "acceptblock", duration);
+      }) {
   state_keep_old_hash_.clear();
   state_old_hash_.clear();
   state_hash_.clear();
@@ -71,7 +74,10 @@ AcceptBlockQuery::AcceptBlockQuery(AcceptBlockQuery::IsFake fake, BlockIdExt id,
     , is_fork_(false)
     , send_broadcast_(false)
     , manager_(manager)
-    , promise_(std::move(promise)) {
+    , promise_(std::move(promise))
+    , perf_timer_("acceptblock", 0.1, [manager](double duration) {
+        send_closure(manager, &ValidatorManager::add_perf_timer_stat, "acceptblock", duration);
+      }) {
   state_keep_old_hash_.clear();
   state_old_hash_.clear();
   state_hash_.clear();
@@ -86,7 +92,10 @@ AcceptBlockQuery::AcceptBlockQuery(ForceFork ffork, BlockIdExt id, td::Ref<Block
     , is_fork_(true)
     , send_broadcast_(false)
     , manager_(manager)
-    , promise_(std::move(promise)) {
+    , promise_(std::move(promise))
+    , perf_timer_("acceptblock", 0.1, [manager](double duration) {
+        send_closure(manager, &ValidatorManager::add_perf_timer_stat, "acceptblock", duration);
+      }) {
   state_keep_old_hash_.clear();
   state_old_hash_.clear();
   state_hash_.clear();

validator/impl/accept-block.hpp

@@ -126,7 +126,7 @@ class AcceptBlockQuery : public td::actor::Actor {
   td::BufferSlice top_block_descr_data_;
   Ref<ShardTopBlockDescription> top_block_descr_;
 
-  td::PerfWarningTimer perf_timer_{"acceptblock", 0.1};
+  td::PerfWarningTimer perf_timer_;
 
   bool fatal_error(std::string msg, int code = -666);
   static bool check_send_error(td::actor::ActorId<AcceptBlockQuery> SelfId, td::Status error);

validator/impl/check-proof.hpp

@@ -47,7 +47,10 @@ class CheckProof : public td::actor::Actor {
       , manager_(manager)
       , timeout_(timeout)
       , promise_(std::move(promise))
-      , skip_check_signatures_(skip_check_signatures) {
+      , skip_check_signatures_(skip_check_signatures)
+      , perf_timer_("checkproof", 0.1, [manager](double duration) {
+          send_closure(manager, &ValidatorManager::add_perf_timer_stat, "checkproof", duration);
+        }) {
   }
   CheckProof(BlockIdExt id, td::Ref<Proof> proof, td::actor::ActorId<ValidatorManager> manager, td::Timestamp timeout,
              td::Promise<BlockHandle> promise, bool skip_check_signatures, td::Ref<MasterchainState> known_state)
@@ -58,7 +61,10 @@ class CheckProof : public td::actor::Actor {
       , timeout_(timeout)
       , promise_(std::move(promise))
       , state_(std::move(known_state))
-      , skip_check_signatures_(skip_check_signatures) {
+      , skip_check_signatures_(skip_check_signatures)
+      , perf_timer_("checkproof", 0.1, [manager](double duration) {
+          send_closure(manager, &ValidatorManager::add_perf_timer_stat, "checkproof", duration);
+        }) {
   }
   CheckProof(BlockIdExt id, td::Ref<ProofLink> proof_link, td::actor::ActorId<ValidatorManager> manager,
              td::Timestamp timeout, td::Promise<BlockHandle> promise)
@@ -67,7 +73,10 @@ class CheckProof : public td::actor::Actor {
       , proof_(std::move(proof_link))
       , manager_(manager)
       , timeout_(timeout)
-      , promise_(std::move(promise)) {
+      , promise_(std::move(promise))
+      , perf_timer_("checkproof", 0.1, [manager](double duration) {
+          send_closure(manager, &ValidatorManager::add_perf_timer_stat, "checkproof", duration);
+        }) {
   }
 
  private:
@@ -114,7 +123,7 @@ class CheckProof : public td::actor::Actor {
   bool skip_check_signatures_{false};
   bool sig_ok_{false};
 
-  td::PerfWarningTimer perf_timer_{"checkproof", 0.1};
+  td::PerfWarningTimer perf_timer_;
 
   static bool check_send_error(td::actor::ActorId<CheckProof> SelfId, td::Status error);
   template <typename T>

validator/impl/collator-impl.h

@@ -208,7 +208,7 @@ class Collator final : public td::actor::Actor {
   std::vector<Ref<vm::Cell>> collated_roots_;
   std::unique_ptr<ton::BlockCandidate> block_candidate;
 
-  td::PerfWarningTimer perf_timer_{"collate", 0.1};
+  td::PerfWarningTimer perf_timer_;
   //
   block::Account* lookup_account(td::ConstBitPtr addr) const;
   std::unique_ptr<block::Account> make_account_from(td::ConstBitPtr addr, Ref<vm::CellSlice> account,

validator/impl/collator.cpp

@@ -67,7 +67,10 @@ Collator::Collator(ShardIdFull shard, bool is_hardfork, UnixTime min_ts, BlockId
     , validator_set_(std::move(validator_set))
     , manager(manager)
     , timeout(timeout)
-    , main_promise(std::move(promise)) {
+    , main_promise(std::move(promise))
+    , perf_timer_("collate", 0.1, [manager](double duration) {
+        send_closure(manager, &ValidatorManager::add_perf_timer_stat, "collate", duration);
+      }) {
 }
 
 void Collator::start_up() {

validator/impl/validate-query.cpp

@@ -59,12 +59,15 @@ ValidateQuery::ValidateQuery(ShardIdFull shard, UnixTime min_ts, BlockIdExt min_
     , prev_blocks(std::move(prev))
     , block_candidate(std::move(candidate))
     , validator_set_(std::move(validator_set))
-    , manager(std::move(manager))
+    , manager(manager)
     , timeout(timeout)
     , main_promise(std::move(promise))
     , is_fake_(is_fake)
     , shard_pfx_(shard_.shard)
-    , shard_pfx_len_(ton::shard_prefix_length(shard_)) {
+    , shard_pfx_len_(ton::shard_prefix_length(shard_))
+    , perf_timer_("validateblock", 0.1, [manager](double duration) {
+        send_closure(manager, &ValidatorManager::add_perf_timer_stat, "validateblock", duration);
+      }) {
   proc_hash_.zero();
 }
 

validator/impl/validate-query.hpp

@@ -228,7 +228,7 @@ class ValidateQuery : public td::actor::Actor {
 
   std::vector<std::tuple<Bits256, Bits256, bool>> lib_publishers_, lib_publishers2_;
 
-  td::PerfWarningTimer perf_timer_{"validateblock", 0.1};
+  td::PerfWarningTimer perf_timer_;
 
   static constexpr td::uint32 priority() {
     return 2;

validator/manager-disk.hpp

@@ -358,6 +358,13 @@ class ValidatorManagerImpl : public ValidatorManager {
     UNREACHABLE();
   }
 
+  void prepare_perf_timer_stats(td::Promise<std::vector<PerfTimerStats>> promise) override {
+    UNREACHABLE();
+  }
+
+  void add_perf_timer_stat(std::string name, double duration) override {
+  }
+
   void truncate(BlockSeqno seqno, ConstBlockHandle handle, td::Promise<td::Unit> promise) override {
     UNREACHABLE();
   }

validator/manager-hardfork.hpp

@@ -417,6 +417,13 @@ class ValidatorManagerImpl : public ValidatorManager {
     UNREACHABLE();
   }
 
+  void prepare_perf_timer_stats(td::Promise<std::vector<PerfTimerStats>> promise) override {
+    UNREACHABLE();
+  }
+
+  void add_perf_timer_stat(std::string name, double duration) override {
+  }
+
   void truncate(BlockSeqno seqno, ConstBlockHandle handle, td::Promise<td::Unit> promise) override {
     UNREACHABLE();
   }

validator/manager.cpp

@@ -2495,6 +2495,24 @@ void ValidatorManagerImpl::prepare_stats(td::Promise<std::vector<std::pair<std::
   td::actor::send_closure(db_, &Db::prepare_stats, merger.make_promise("db."));
 }
 
+void ValidatorManagerImpl::prepare_perf_timer_stats(td::Promise<std::vector<PerfTimerStats>> promise) {
+  promise.set_value(std::vector<PerfTimerStats>(perf_timer_stats));
+}
+
+void ValidatorManagerImpl::add_perf_timer_stat(std::string name, double duration) {
+  for (auto &s : perf_timer_stats) {
+    if (s.name == name) {
+      double now = td::Time::now();
+      while (!s.stats.empty() && s.stats.front().first < now - 3600.0) {
+        s.stats.pop_front();
+      }
+      s.stats.push_back({td::Time::now(), duration});
+      return;
+    }
+  }
+  perf_timer_stats.push_back({name, {{td::Time::now(), duration}}});
+}
+
 void ValidatorManagerImpl::truncate(BlockSeqno seqno, ConstBlockHandle handle, td::Promise<td::Unit> promise) {
   td::actor::send_closure(db_, &Db::truncate, seqno, std::move(handle), std::move(promise));
 }

validator/manager.hpp

@@ -255,6 +255,8 @@ class ValidatorManagerImpl : public ValidatorManager {
   std::map<BlockSeqno, std::tuple<BlockHandle, td::Ref<MasterchainState>, std::vector<td::Promise<td::Unit>>>>
       pending_masterchain_states_;
 
+  std::vector<PerfTimerStats> perf_timer_stats;
+
   void new_masterchain_block();
   void update_shards();
   void update_shard_blocks();
@@ -526,6 +528,9 @@ class ValidatorManagerImpl : public ValidatorManager {
 
   void prepare_stats(td::Promise<std::vector<std::pair<std::string, std::string>>> promise) override;
 
+  void prepare_perf_timer_stats(td::Promise<std::vector<PerfTimerStats>> promise) override;
+  void add_perf_timer_stat(std::string name, double duration) override;
+
   void truncate(BlockSeqno seqno, ConstBlockHandle handle, td::Promise<td::Unit> promise) override;
 
   void wait_shard_client_state(BlockSeqno seqno, td::Timestamp timeout, td::Promise<td::Unit> promise) override;

validator/validate-broadcast.hpp

@@ -44,7 +44,7 @@ class ValidateBroadcast : public td::actor::Actor {
   td::Ref<ProofLink> proof_link_;
   BlockHandle handle_;
 
-  td::PerfWarningTimer perf_timer_{"validatebroadcast", 0.1};
+  td::PerfWarningTimer perf_timer_;
 
   bool exact_key_block_handle_;
   td::Ref<ProofLink> key_proof_link_;
@@ -60,7 +60,10 @@ class ValidateBroadcast : public td::actor::Actor {
       , last_known_masterchain_block_handle_(std::move(last_known_masterchain_block_handle))
       , manager_(manager)
       , timeout_(timeout)
-      , promise_(std::move(promise)) {
+      , promise_(std::move(promise))
+      , perf_timer_("validatebroadcast", 0.1, [manager](double duration) {
+          send_closure(manager, &ValidatorManager::add_perf_timer_stat, "validatebroadcast", duration);
+        }) {
   }
 
   void start_up() override;

validator/validator.h

@@ -19,6 +19,7 @@
 #pragma once
 
 #include <vector>
+#include <deque>
 
 #include "td/actor/actor.h"
 
@@ -44,6 +45,11 @@ class DownloadToken {
   virtual ~DownloadToken() = default;
 };
 
+struct PerfTimerStats {
+  std::string name;
+  std::deque<std::pair<double, double>> stats; // <Time::now(), duration>
+};
+
 struct ValidatorManagerOptions : public td::CntObject {
  public:
   enum class ShardCheckMode { m_monitor, m_validate };
@@ -214,6 +220,9 @@ class ValidatorManagerInterface : public td::actor::Actor {
 
   virtual void run_ext_query(td::BufferSlice data, td::Promise<td::BufferSlice> promise) = 0;
   virtual void prepare_stats(td::Promise<std::vector<std::pair<std::string, std::string>>> promise) = 0;
+
+  virtual void prepare_perf_timer_stats(td::Promise<std::vector<PerfTimerStats>> promise) = 0;
+  virtual void add_perf_timer_stat(std::string name, double duration) = 0;
 };
 
 }  // namespace validator