Add more logs for BlockArchiver and similar things

SpyCheese · SpyCheese · commit 66ddb328f38f · 2025-10-27T15:22:50.000+03:00
diff --git a/validator/apply-block.cpp b/validator/apply-block.cpp
@@ -36,7 +36,7 @@ void ApplyBlock::abort_query(td::Status reason) {
 }
 
 void ApplyBlock::finish_query() {
-  VLOG(VALIDATOR_DEBUG) << "successfully finishing apply block query";
+  VLOG(VALIDATOR_DEBUG) << "successfully finishing apply block query in " << perf_timer_.elapsed() << " s";
   handle_->set_processed();
   ValidatorInvariants::check_post_apply(handle_);
 
diff --git a/validator/db/archiver.cpp b/validator/db/archiver.cpp
@@ -30,6 +30,7 @@ BlockArchiver::BlockArchiver(BlockHandle handle, td::actor::ActorId<ArchiveManag
 }
 
 void BlockArchiver::start_up() {
+  VLOG(VALIDATOR_DEBUG) << "started block archiver for " << handle_->id().to_str();
   if (handle_->id().is_masterchain()) {
     td::actor::send_closure(db_, &Db::get_block_state, handle_,
                             [SelfId = actor_id(this), archive = archive_](td::Result<td::Ref<ShardState>> R) {
@@ -46,6 +47,7 @@ void BlockArchiver::start_up() {
 }
 
 void BlockArchiver::move_handle() {
+  VLOG(VALIDATOR_DEBUG) << "move_handle";
   if (handle_->handle_moved_to_archive()) {
     moved_handle();
   } else {
@@ -58,6 +60,7 @@ void BlockArchiver::move_handle() {
 }
 
 void BlockArchiver::moved_handle() {
+  VLOG(VALIDATOR_DEBUG) << "moved_handle";
   CHECK(handle_->handle_moved_to_archive());
   if (handle_->moved_to_archive()) {
     finish_query();
@@ -78,6 +81,7 @@ void BlockArchiver::moved_handle() {
 }
 
 void BlockArchiver::got_proof(td::BufferSlice data) {
+  VLOG(VALIDATOR_DEBUG) << "got_proof";
   auto P = td::PromiseCreator::lambda([SelfId = actor_id(this)](td::Result<td::Unit> R) {
     R.ensure();
     td::actor::send_closure(SelfId, &BlockArchiver::written_proof);
@@ -87,6 +91,7 @@ void BlockArchiver::got_proof(td::BufferSlice data) {
 }
 
 void BlockArchiver::written_proof() {
+  VLOG(VALIDATOR_DEBUG) << "written_proof";
   if (!handle_->inited_proof_link()) {
     written_proof_link();
     return;
@@ -102,6 +107,7 @@ void BlockArchiver::written_proof() {
 }
 
 void BlockArchiver::got_proof_link(td::BufferSlice data) {
+  VLOG(VALIDATOR_DEBUG) << "got_proof_link";
   auto P = td::PromiseCreator::lambda([SelfId = actor_id(this)](td::Result<td::Unit> R) {
     R.ensure();
     td::actor::send_closure(SelfId, &BlockArchiver::written_proof_link);
@@ -111,6 +117,7 @@ void BlockArchiver::got_proof_link(td::BufferSlice data) {
 }
 
 void BlockArchiver::written_proof_link() {
+  VLOG(VALIDATOR_DEBUG) << "written_proof_link";
   if (!handle_->received()) {
     written_block_data();
     return;
@@ -124,6 +131,7 @@ void BlockArchiver::written_proof_link() {
 }
 
 void BlockArchiver::got_block_data(td::BufferSlice data) {
+  VLOG(VALIDATOR_DEBUG) << "got_block_data";
   auto P = td::PromiseCreator::lambda([SelfId = actor_id(this)](td::Result<td::Unit> R) {
     R.ensure();
     td::actor::send_closure(SelfId, &BlockArchiver::written_block_data);
@@ -133,6 +141,7 @@ void BlockArchiver::got_block_data(td::BufferSlice data) {
 }
 
 void BlockArchiver::written_block_data() {
+  VLOG(VALIDATOR_DEBUG) << "written_block_data";
   handle_->set_moved_to_archive();
 
   auto P = td::PromiseCreator::lambda([SelfId = actor_id(this)](td::Result<td::Unit> R) {
@@ -143,15 +152,16 @@ void BlockArchiver::written_block_data() {
 }
 
 void BlockArchiver::finish_query() {
+  VLOG(VALIDATOR_DEBUG) << "finished archiving block in " << timer_.elapsed() << " s";
   if (promise_) {
     promise_.set_value(td::Unit());
   }
   stop();
 }
 
 void BlockArchiver::abort_query(td::Status reason) {
+  VLOG(VALIDATOR_WARNING) << "failed to archive block " << handle_->id() << ": " << reason;
   if (promise_) {
-    VLOG(VALIDATOR_WARNING) << "failed to archive block " << handle_->id() << ": " << reason;
     promise_.set_error(std::move(reason));
   }
   stop();
diff --git a/validator/db/archiver.hpp b/validator/db/archiver.hpp
@@ -54,6 +54,7 @@ class BlockArchiver : public td::actor::Actor {
   td::actor::ActorId<ArchiveManager> archive_;
   td::actor::ActorId<Db> db_;
   td::Promise<td::Unit> promise_;
+  td::Timer timer_;
 };
 
 }  // namespace validator
diff --git a/validator/db/rootdb.cpp b/validator/db/rootdb.cpp
@@ -389,8 +389,8 @@ void RootDb::try_get_static_file(FileHash file_hash, td::Promise<td::BufferSlice
 }
 
 void RootDb::apply_block(BlockHandle handle, td::Promise<td::Unit> promise) {
-  td::actor::create_actor<BlockArchiver>("archiver", std::move(handle), archive_db_.get(), actor_id(this),
-                                         std::move(promise))
+  td::actor::create_actor<BlockArchiver>(PSTRING() << "archiver" << handle->id().id.to_str(), std::move(handle),
+                                         archive_db_.get(), actor_id(this), std::move(promise))
       .release();
 }
 
@@ -464,8 +464,8 @@ void RootDb::start_up() {
 }
 
 void RootDb::archive(BlockHandle handle, td::Promise<td::Unit> promise) {
-  td::actor::create_actor<BlockArchiver>("archiveblock", std::move(handle), archive_db_.get(), actor_id(this),
-                                         std::move(promise))
+  td::actor::create_actor<BlockArchiver>(PSTRING() << "archiver" << handle->id().id.to_str(), std::move(handle),
+                                         archive_db_.get(), actor_id(this), std::move(promise))
       .release();
 }
 
diff --git a/validator/manager.cpp b/validator/manager.cpp
@@ -1595,6 +1595,7 @@ void ValidatorManagerImpl::new_block_cont(BlockHandle handle, td::Ref<ShardState
                                           td::Promise<td::Unit> promise) {
   if (state->get_shard().is_masterchain() && handle->id().id.seqno > last_masterchain_seqno_) {
     if (handle->id().id.seqno == last_masterchain_seqno_ + 1) {
+      VLOG(VALIDATOR_DEBUG) << "new block " << handle->id().id.to_str() << " is the next masterchain block";
       last_masterchain_seqno_ = handle->id().id.seqno;
       last_masterchain_state_ = td::Ref<MasterchainState>{state};
       last_masterchain_block_id_ = handle->id();
@@ -1614,6 +1615,7 @@ void ValidatorManagerImpl::new_block_cont(BlockHandle handle, td::Ref<ShardState
           last_masterchain_block_id_ = last_masterchain_block_handle_->id();
           last_masterchain_seqno_ = last_masterchain_block_id_.id.seqno;
           CHECK(it->first == last_masterchain_seqno_);
+          VLOG(VALIDATOR_DEBUG) << "processing pending masterchain block " << last_masterchain_block_id_.id.to_str();
 
           auto l_promise = std::move(std::get<2>(it->second));
           last_masterchain_block_handle_->set_processed();
@@ -1630,6 +1632,7 @@ void ValidatorManagerImpl::new_block_cont(BlockHandle handle, td::Ref<ShardState
         }
       }
     } else {
+      VLOG(VALIDATOR_DEBUG) << "new block " << handle->id().id.to_str() << " is too new masterchain block";
       auto it = pending_masterchain_states_.find(handle->id().id.seqno);
       if (it != pending_masterchain_states_.end()) {
         std::get<2>(it->second).emplace_back(std::move(promise));
@@ -1642,12 +1645,14 @@ void ValidatorManagerImpl::new_block_cont(BlockHandle handle, td::Ref<ShardState
       }
     }
   } else {
+    VLOG(VALIDATOR_DEBUG) << "new block " << handle->id().id.to_str() << " is already processed";
     handle->set_processed();
     promise.set_value(td::Unit());
   }
 }
 
 void ValidatorManagerImpl::new_block(BlockHandle handle, td::Ref<ShardState> state, td::Promise<td::Unit> promise) {
+  VLOG(VALIDATOR_DEBUG) << "new block " << handle->id().id.to_str();
   if (handle->is_applied()) {
     return new_block_cont(std::move(handle), std::move(state), std::move(promise));
   } else {
@@ -2296,7 +2301,9 @@ void ValidatorManagerImpl::new_masterchain_block() {
     td::actor::send_closure(actor, &ShardBlockRetainer::update_masterchain_state, last_masterchain_state_);
   }
   if (last_masterchain_seqno_ % 1024 == 0) {
-    LOG(WARNING) << "applied masterchain block " << last_masterchain_block_id_;
+    LOG(WARNING) << "applied masterchain block " << last_masterchain_block_id_.to_str();
+  } else {
+    LOG(DEBUG) << "applied masterchain block " << last_masterchain_block_id_.to_str();
   }
 }
 
diff --git a/validator/validate-broadcast.cpp b/validator/validate-broadcast.cpp
@@ -37,7 +37,8 @@ void ValidateBroadcast::abort_query(td::Status reason) {
 
 void ValidateBroadcast::finish_query() {
   if (promise_) {
-    VLOG(VALIDATOR_DEBUG) << "validated broadcast for " << broadcast_.block_id.to_str();
+    VLOG(VALIDATOR_DEBUG) << "validated broadcast for " << broadcast_.block_id.to_str() << " in "
+                          << perf_timer_.elapsed() << " s";
     promise_.set_result(td::Unit());
   }
   stop();
@@ -321,8 +322,8 @@ void ValidateBroadcast::checked_proof() {
     });
 
     VLOG(VALIDATOR_DEBUG) << "apply block";
-    td::actor::create_actor<ApplyBlock>("applyblock", handle_->id(), data_, handle_->id(), manager_, timeout_,
-                                        std::move(P))
+    td::actor::create_actor<ApplyBlock>(PSTRING() << "apply" << handle_->id().id.to_str(), handle_->id(), data_,
+                                        handle_->id(), manager_, timeout_, std::move(P))
         .release();
   } else {
     finish_query();

Original file line number	Diff line number	Diff line change
`@@ -36,7 +36,7 @@ void ApplyBlock::abort_query(td::Status reason) {`
`36`	`36`	`}`
`37`	`37`
`38`	`38`	`void ApplyBlock::finish_query() {`
`39`		`- VLOG(VALIDATOR_DEBUG) << "successfully finishing apply block query";`
	`39`	`+ VLOG(VALIDATOR_DEBUG) << "successfully finishing apply block query in " << perf_timer_.elapsed() << " s";`
`40`	`40`	`handle_->set_processed();`
`41`	`41`	`ValidatorInvariants::check_post_apply(handle_);`
`42`	`42`
Original file line number	Diff line number	Diff line change
`@@ -30,6 +30,7 @@ BlockArchiver::BlockArchiver(BlockHandle handle, td::actor::ActorId<ArchiveManag`
`30`	`30`	`}`
`31`	`31`
`32`	`32`	`void BlockArchiver::start_up() {`
	`33`	`+ VLOG(VALIDATOR_DEBUG) << "started block archiver for " << handle_->id().to_str();`
`33`	`34`	`if (handle_->id().is_masterchain()) {`
`34`	`35`	`td::actor::send_closure(db_, &Db::get_block_state, handle_,`
`35`	`36`	`[SelfId = actor_id(this), archive = archive_](td::Result<td::Ref<ShardState>> R) {`
`@@ -46,6 +47,7 @@ void BlockArchiver::start_up() {`
`46`	`47`	`}`
`47`	`48`
`48`	`49`	`void BlockArchiver::move_handle() {`
	`50`	`+ VLOG(VALIDATOR_DEBUG) << "move_handle";`
`49`	`51`	`if (handle_->handle_moved_to_archive()) {`
`50`	`52`	`moved_handle();`
`51`	`53`	`} else {`
`@@ -58,6 +60,7 @@ void BlockArchiver::move_handle() {`
`58`	`60`	`}`
`59`	`61`
`60`	`62`	`void BlockArchiver::moved_handle() {`
	`63`	`+ VLOG(VALIDATOR_DEBUG) << "moved_handle";`
`61`	`64`	`CHECK(handle_->handle_moved_to_archive());`
`62`	`65`	`if (handle_->moved_to_archive()) {`
`63`	`66`	`finish_query();`
`@@ -78,6 +81,7 @@ void BlockArchiver::moved_handle() {`
`78`	`81`	`}`
`79`	`82`
`80`	`83`	`void BlockArchiver::got_proof(td::BufferSlice data) {`
	`84`	`+ VLOG(VALIDATOR_DEBUG) << "got_proof";`
`81`	`85`	`auto P = td::PromiseCreator::lambda([SelfId = actor_id(this)](td::Result<td::Unit> R) {`
`82`	`86`	`R.ensure();`
`83`	`87`	`td::actor::send_closure(SelfId, &BlockArchiver::written_proof);`
`@@ -87,6 +91,7 @@ void BlockArchiver::got_proof(td::BufferSlice data) {`
`87`	`91`	`}`
`88`	`92`
`89`	`93`	`void BlockArchiver::written_proof() {`
	`94`	`+ VLOG(VALIDATOR_DEBUG) << "written_proof";`
`90`	`95`	`if (!handle_->inited_proof_link()) {`
`91`	`96`	`written_proof_link();`
`92`	`97`	`return;`
`@@ -102,6 +107,7 @@ void BlockArchiver::written_proof() {`
`102`	`107`	`}`
`103`	`108`
`104`	`109`	`void BlockArchiver::got_proof_link(td::BufferSlice data) {`
	`110`	`+ VLOG(VALIDATOR_DEBUG) << "got_proof_link";`
`105`	`111`	`auto P = td::PromiseCreator::lambda([SelfId = actor_id(this)](td::Result<td::Unit> R) {`
`106`	`112`	`R.ensure();`
`107`	`113`	`td::actor::send_closure(SelfId, &BlockArchiver::written_proof_link);`
`@@ -111,6 +117,7 @@ void BlockArchiver::got_proof_link(td::BufferSlice data) {`
`111`	`117`	`}`
`112`	`118`
`113`	`119`	`void BlockArchiver::written_proof_link() {`
	`120`	`+ VLOG(VALIDATOR_DEBUG) << "written_proof_link";`
`114`	`121`	`if (!handle_->received()) {`
`115`	`122`	`written_block_data();`
`116`	`123`	`return;`
`@@ -124,6 +131,7 @@ void BlockArchiver::written_proof_link() {`
`124`	`131`	`}`
`125`	`132`
`126`	`133`	`void BlockArchiver::got_block_data(td::BufferSlice data) {`
	`134`	`+ VLOG(VALIDATOR_DEBUG) << "got_block_data";`
`127`	`135`	`auto P = td::PromiseCreator::lambda([SelfId = actor_id(this)](td::Result<td::Unit> R) {`
`128`	`136`	`R.ensure();`
`129`	`137`	`td::actor::send_closure(SelfId, &BlockArchiver::written_block_data);`
`@@ -133,6 +141,7 @@ void BlockArchiver::got_block_data(td::BufferSlice data) {`
`133`	`141`	`}`
`134`	`142`
`135`	`143`	`void BlockArchiver::written_block_data() {`
	`144`	`+ VLOG(VALIDATOR_DEBUG) << "written_block_data";`
`136`	`145`	`handle_->set_moved_to_archive();`
`137`	`146`
`138`	`147`	`auto P = td::PromiseCreator::lambda([SelfId = actor_id(this)](td::Result<td::Unit> R) {`
`@@ -143,15 +152,16 @@ void BlockArchiver::written_block_data() {`
`143`	`152`	`}`
`144`	`153`
`145`	`154`	`void BlockArchiver::finish_query() {`
	`155`	`+ VLOG(VALIDATOR_DEBUG) << "finished archiving block in " << timer_.elapsed() << " s";`
`146`	`156`	`if (promise_) {`
`147`	`157`	`promise_.set_value(td::Unit());`
`148`	`158`	`}`
`149`	`159`	`stop();`
`150`	`160`	`}`
`151`	`161`
`152`	`162`	`void BlockArchiver::abort_query(td::Status reason) {`
	`163`	`+ VLOG(VALIDATOR_WARNING) << "failed to archive block " << handle_->id() << ": " << reason;`
`153`	`164`	`if (promise_) {`
`154`		`- VLOG(VALIDATOR_WARNING) << "failed to archive block " << handle_->id() << ": " << reason;`
`155`	`165`	`promise_.set_error(std::move(reason));`
`156`	`166`	`}`
`157`	`167`	`stop();`
Original file line number	Diff line number	Diff line change
`@@ -389,8 +389,8 @@ void RootDb::try_get_static_file(FileHash file_hash, td::Promise<td::BufferSlice`
`389`	`389`	`}`
`390`	`390`
`391`	`391`	`void RootDb::apply_block(BlockHandle handle, td::Promise<td::Unit> promise) {`
`392`		`- td::actor::create_actor<BlockArchiver>("archiver", std::move(handle), archive_db_.get(), actor_id(this),`
`393`		`- std::move(promise))`
	`392`	`+ td::actor::create_actor<BlockArchiver>(PSTRING() << "archiver" << handle->id().id.to_str(), std::move(handle),`
	`393`	`+ archive_db_.get(), actor_id(this), std::move(promise))`
`394`	`394`	`.release();`
`395`	`395`	`}`
`396`	`396`
`@@ -464,8 +464,8 @@ void RootDb::start_up() {`
`464`	`464`	`}`
`465`	`465`
`466`	`466`	`void RootDb::archive(BlockHandle handle, td::Promise<td::Unit> promise) {`
`467`		`- td::actor::create_actor<BlockArchiver>("archiveblock", std::move(handle), archive_db_.get(), actor_id(this),`
`468`		`- std::move(promise))`
	`467`	`+ td::actor::create_actor<BlockArchiver>(PSTRING() << "archiver" << handle->id().id.to_str(), std::move(handle),`
	`468`	`+ archive_db_.get(), actor_id(this), std::move(promise))`
`469`	`469`	`.release();`
`470`	`470`	`}`
`471`	`471`
Original file line number	Diff line number	Diff line change
`@@ -1595,6 +1595,7 @@ void ValidatorManagerImpl::new_block_cont(BlockHandle handle, td::Ref<ShardState`
`1595`	`1595`	`td::Promise<td::Unit> promise) {`
`1596`	`1596`	`if (state->get_shard().is_masterchain() && handle->id().id.seqno > last_masterchain_seqno_) {`
`1597`	`1597`	`if (handle->id().id.seqno == last_masterchain_seqno_ + 1) {`
	`1598`	`+ VLOG(VALIDATOR_DEBUG) << "new block " << handle->id().id.to_str() << " is the next masterchain block";`
`1598`	`1599`	`last_masterchain_seqno_ = handle->id().id.seqno;`
`1599`	`1600`	`last_masterchain_state_ = td::Ref<MasterchainState>{state};`
`1600`	`1601`	`last_masterchain_block_id_ = handle->id();`
`@@ -1614,6 +1615,7 @@ void ValidatorManagerImpl::new_block_cont(BlockHandle handle, td::Ref<ShardState`
`1614`	`1615`	`last_masterchain_block_id_ = last_masterchain_block_handle_->id();`
`1615`	`1616`	`last_masterchain_seqno_ = last_masterchain_block_id_.id.seqno;`
`1616`	`1617`	`CHECK(it->first == last_masterchain_seqno_);`
	`1618`	`+ VLOG(VALIDATOR_DEBUG) << "processing pending masterchain block " << last_masterchain_block_id_.id.to_str();`
`1617`	`1619`
`1618`	`1620`	`auto l_promise = std::move(std::get<2>(it->second));`
`1619`	`1621`	`last_masterchain_block_handle_->set_processed();`
`@@ -1630,6 +1632,7 @@ void ValidatorManagerImpl::new_block_cont(BlockHandle handle, td::Ref<ShardState`
`1630`	`1632`	`}`
`1631`	`1633`	`}`
`1632`	`1634`	`} else {`
	`1635`	`+ VLOG(VALIDATOR_DEBUG) << "new block " << handle->id().id.to_str() << " is too new masterchain block";`
`1633`	`1636`	`auto it = pending_masterchain_states_.find(handle->id().id.seqno);`
`1634`	`1637`	`if (it != pending_masterchain_states_.end()) {`
`1635`	`1638`	`std::get<2>(it->second).emplace_back(std::move(promise));`
`@@ -1642,12 +1645,14 @@ void ValidatorManagerImpl::new_block_cont(BlockHandle handle, td::Ref<ShardState`
`1642`	`1645`	`}`
`1643`	`1646`	`}`
`1644`	`1647`	`} else {`
	`1648`	`+ VLOG(VALIDATOR_DEBUG) << "new block " << handle->id().id.to_str() << " is already processed";`
`1645`	`1649`	`handle->set_processed();`
`1646`	`1650`	`promise.set_value(td::Unit());`
`1647`	`1651`	`}`
`1648`	`1652`	`}`
`1649`	`1653`
`1650`	`1654`	`void ValidatorManagerImpl::new_block(BlockHandle handle, td::Ref<ShardState> state, td::Promise<td::Unit> promise) {`
	`1655`	`+ VLOG(VALIDATOR_DEBUG) << "new block " << handle->id().id.to_str();`
`1651`	`1656`	`if (handle->is_applied()) {`
`1652`	`1657`	`return new_block_cont(std::move(handle), std::move(state), std::move(promise));`
`1653`	`1658`	`} else {`
`@@ -2296,7 +2301,9 @@ void ValidatorManagerImpl::new_masterchain_block() {`
`2296`	`2301`	`td::actor::send_closure(actor, &ShardBlockRetainer::update_masterchain_state, last_masterchain_state_);`
`2297`	`2302`	`}`
`2298`	`2303`	`if (last_masterchain_seqno_ % 1024 == 0) {`
`2299`		`- LOG(WARNING) << "applied masterchain block " << last_masterchain_block_id_;`
	`2304`	`+ LOG(WARNING) << "applied masterchain block " << last_masterchain_block_id_.to_str();`
	`2305`	`+ } else {`
	`2306`	`+ LOG(DEBUG) << "applied masterchain block " << last_masterchain_block_id_.to_str();`
`2300`	`2307`	`}`
`2301`	`2308`	`}`
`2302`	`2309`