mirror of
https://github.com/ton-blockchain/ton
synced 2025-03-09 15:40:10 +00:00
Adjust allowed time lag for last_liteserver_state + more verbose logs (#836)
* Add logs to collator and validator * More logs to get_ext_messages, decrease verbosity level * Adjust allowed time lag for last_liteserver_state * Change verbosity of STATUS message --------- Co-authored-by: SpyCheese <mikle98@yandex.ru>
This commit is contained in:
EmelyanenkoK
GitHub
parent
1fc4a0faed
commit
ace934ff35
5 changed files with 58 additions and 32 deletions
|
|
@ -106,7 +106,7 @@ Collator::Collator(ShardIdFull shard, bool is_hardfork, UnixTime min_ts, BlockId
|
|||
* The results of these queries are handled by corresponding callback functions.
|
||||
*/
|
||||
void Collator::start_up() {
|
||||
LOG(DEBUG) << "Collator for shard " << shard_.to_str() << " started";
|
||||
LOG(WARNING) << "Collator for shard " << shard_.to_str() << " started";
|
||||
LOG(DEBUG) << "Previous block #1 is " << prev_blocks.at(0).to_str();
|
||||
if (prev_blocks.size() > 1) {
|
||||
LOG(DEBUG) << "Previous block #2 is " << prev_blocks.at(1).to_str();
|
||||
|
|
@ -554,7 +554,7 @@ bool Collator::preprocess_prev_mc_state() {
|
|||
* @param res The retreived masterchain state.
|
||||
*/
|
||||
void Collator::after_get_mc_state(td::Result<std::pair<Ref<MasterchainState>, BlockIdExt>> res) {
|
||||
LOG(DEBUG) << "in Collator::after_get_mc_state()";
|
||||
LOG(WARNING) << "in Collator::after_get_mc_state()";
|
||||
--pending;
|
||||
if (res.is_error()) {
|
||||
fatal_error(res.move_as_error());
|
||||
|
|
@ -589,7 +589,7 @@ void Collator::after_get_mc_state(td::Result<std::pair<Ref<MasterchainState>, Bl
|
|||
* @param res The retrieved shard state.
|
||||
*/
|
||||
void Collator::after_get_shard_state(int idx, td::Result<Ref<ShardState>> res) {
|
||||
LOG(DEBUG) << "in Collator::after_get_shard_state(" << idx << ")";
|
||||
LOG(WARNING) << "in Collator::after_get_shard_state(" << idx << ")";
|
||||
--pending;
|
||||
if (res.is_error()) {
|
||||
fatal_error(res.move_as_error());
|
||||
|
|
@ -820,7 +820,6 @@ bool Collator::request_out_msg_queue_size() {
|
|||
* @param res The obtained outbound queue.
|
||||
*/
|
||||
void Collator::got_neighbor_out_queue(int i, td::Result<Ref<MessageQueue>> res) {
|
||||
LOG(DEBUG) << "obtained outbound queue for neighbor #" << i;
|
||||
--pending;
|
||||
if (res.is_error()) {
|
||||
fatal_error(res.move_as_error());
|
||||
|
|
@ -828,6 +827,7 @@ void Collator::got_neighbor_out_queue(int i, td::Result<Ref<MessageQueue>> res)
|
|||
}
|
||||
Ref<MessageQueue> outq_descr = res.move_as_ok();
|
||||
block::McShardDescr& descr = neighbors_.at(i);
|
||||
LOG(WARNING) << "obtained outbound queue for neighbor #" << i << " : " << descr.shard().to_str();
|
||||
if (outq_descr->get_block_id() != descr.blk_) {
|
||||
LOG(DEBUG) << "outq_descr->id = " << outq_descr->get_block_id().to_str() << " ; descr.id = " << descr.blk_.to_str();
|
||||
fatal_error(
|
||||
|
|
@ -893,7 +893,7 @@ void Collator::got_out_queue_size(size_t i, td::Result<td::uint32> res) {
|
|||
return;
|
||||
}
|
||||
td::uint32 size = res.move_as_ok();
|
||||
LOG(DEBUG) << "got outbound queue size from prev block #" << i << ": " << size;
|
||||
LOG(WARNING) << "got outbound queue size from prev block #" << i << ": " << size;
|
||||
out_msg_queue_size_ += size;
|
||||
check_pending();
|
||||
}
|
||||
|
|
@ -1762,7 +1762,7 @@ bool Collator::register_shard_block_creators(std::vector<td::Bits256> creator_li
|
|||
*/
|
||||
bool Collator::try_collate() {
|
||||
if (!preinit_complete) {
|
||||
LOG(DEBUG) << "running do_preinit()";
|
||||
LOG(WARNING) << "running do_preinit()";
|
||||
if (!do_preinit()) {
|
||||
return fatal_error(-667, "error preinitializing data required by collator");
|
||||
}
|
||||
|
|
@ -2062,7 +2062,7 @@ bool Collator::do_collate() {
|
|||
// After do_collate started it will not be interrupted by timeout
|
||||
alarm_timestamp() = td::Timestamp::never();
|
||||
|
||||
LOG(DEBUG) << "do_collate() : start";
|
||||
LOG(WARNING) << "do_collate() : start";
|
||||
if (!fetch_config_params()) {
|
||||
return fatal_error("cannot fetch required configuration parameters from masterchain state");
|
||||
}
|
||||
|
|
@ -2276,8 +2276,8 @@ bool Collator::out_msg_queue_cleanup() {
|
|||
}
|
||||
return !delivered;
|
||||
});
|
||||
LOG(INFO) << "deleted " << deleted << " messages from out_msg_queue after merge, remaining queue size is "
|
||||
<< out_msg_queue_size_;
|
||||
LOG(WARNING) << "deleted " << deleted << " messages from out_msg_queue after merge, remaining queue size is "
|
||||
<< out_msg_queue_size_;
|
||||
if (res < 0) {
|
||||
return fatal_error("error scanning/updating OutMsgQueue");
|
||||
}
|
||||
|
|
@ -2352,8 +2352,8 @@ bool Collator::out_msg_queue_cleanup() {
|
|||
std::swap(queue_parts[i], queue_parts.back());
|
||||
queue_parts.pop_back();
|
||||
}
|
||||
LOG(INFO) << "deleted " << deleted << " messages from out_msg_queue, remaining queue size is "
|
||||
<< out_msg_queue_size_;
|
||||
LOG(WARNING) << "deleted " << deleted << " messages from out_msg_queue, remaining queue size is "
|
||||
<< out_msg_queue_size_;
|
||||
}
|
||||
if (verbosity >= 2) {
|
||||
auto rt = out_msg_queue_->get_root();
|
||||
|
|
@ -5035,7 +5035,7 @@ void Collator::return_block_candidate(td::Result<td::Unit> saved) {
|
|||
fatal_error(std::move(err));
|
||||
} else {
|
||||
CHECK(block_candidate);
|
||||
LOG(INFO) << "sending new BlockCandidate to Promise";
|
||||
LOG(WARNING) << "sending new BlockCandidate to Promise";
|
||||
main_promise(block_candidate->clone());
|
||||
busy_ = false;
|
||||
stop();
|
||||
|
|
@ -5133,6 +5133,8 @@ void Collator::after_get_external_messages(td::Result<std::vector<Ref<ExtMessage
|
|||
bad_ext_msgs_.emplace_back(ext_msg->hash());
|
||||
}
|
||||
}
|
||||
LOG(WARNING) << "got " << vect.size() << " external messages from mempool, " << bad_ext_msgs_.size()
|
||||
<< " bad messages";
|
||||
check_pending();
|
||||
}
|
||||
|
||||
|
|
|
|||
|
|
@ -202,10 +202,12 @@ void run_validate_query(ShardIdFull shard, UnixTime min_ts, BlockIdExt min_maste
|
|||
seqno = p.seqno();
|
||||
}
|
||||
}
|
||||
td::actor::create_actor<ValidateQuery>(
|
||||
PSTRING() << (is_fake ? "fakevalidate" : "validateblock") << shard.to_str() << ":" << (seqno + 1), shard, min_ts,
|
||||
min_masterchain_block_id, std::move(prev), std::move(candidate), std::move(validator_set), std::move(manager),
|
||||
timeout, std::move(promise), is_fake)
|
||||
static std::atomic<size_t> idx;
|
||||
td::actor::create_actor<ValidateQuery>(PSTRING() << (is_fake ? "fakevalidate" : "validateblock") << shard.to_str()
|
||||
<< ":" << (seqno + 1) << "#" << idx.fetch_add(1),
|
||||
shard, min_ts, min_masterchain_block_id, std::move(prev), std::move(candidate),
|
||||
std::move(validator_set), std::move(manager), timeout, std::move(promise),
|
||||
is_fake)
|
||||
.release();
|
||||
}
|
||||
|
||||
|
|
|
|||
|
|
@ -234,6 +234,7 @@ bool ValidateQuery::fatal_error(std::string err_msg, int err_code) {
|
|||
*/
|
||||
void ValidateQuery::finish_query() {
|
||||
if (main_promise) {
|
||||
LOG(WARNING) << "validate query done";
|
||||
main_promise.set_result(now_);
|
||||
}
|
||||
stop();
|
||||
|
|
@ -252,7 +253,7 @@ void ValidateQuery::finish_query() {
|
|||
* Then the function also sends requests to the ValidatorManager to fetch blocks and shard stated.
|
||||
*/
|
||||
void ValidateQuery::start_up() {
|
||||
LOG(INFO) << "validate query for " << block_candidate.id.to_str() << " started";
|
||||
LOG(WARNING) << "validate query for " << block_candidate.id.to_str() << " started";
|
||||
alarm_timestamp() = timeout;
|
||||
rand_seed_.set_zero();
|
||||
created_by_ = block_candidate.pubkey;
|
||||
|
|
@ -667,7 +668,7 @@ bool ValidateQuery::extract_collated_data() {
|
|||
* @param res The result of the retrieval of the latest masterchain state.
|
||||
*/
|
||||
void ValidateQuery::after_get_latest_mc_state(td::Result<std::pair<Ref<MasterchainState>, BlockIdExt>> res) {
|
||||
LOG(DEBUG) << "in ValidateQuery::after_get_latest_mc_state()";
|
||||
LOG(WARNING) << "in ValidateQuery::after_get_latest_mc_state()";
|
||||
--pending;
|
||||
if (res.is_error()) {
|
||||
fatal_error(res.move_as_error());
|
||||
|
|
@ -708,7 +709,7 @@ void ValidateQuery::after_get_latest_mc_state(td::Result<std::pair<Ref<Mastercha
|
|||
* @param res The result of the masterchain state retrieval.
|
||||
*/
|
||||
void ValidateQuery::after_get_mc_state(td::Result<Ref<ShardState>> res) {
|
||||
LOG(DEBUG) << "in ValidateQuery::after_get_mc_state() for " << mc_blkid_.to_str();
|
||||
LOG(WARNING) << "in ValidateQuery::after_get_mc_state() for " << mc_blkid_.to_str();
|
||||
--pending;
|
||||
if (res.is_error()) {
|
||||
fatal_error(res.move_as_error());
|
||||
|
|
@ -752,7 +753,7 @@ void ValidateQuery::got_mc_handle(td::Result<BlockHandle> res) {
|
|||
* @param res The result of the shard state retrieval.
|
||||
*/
|
||||
void ValidateQuery::after_get_shard_state(int idx, td::Result<Ref<ShardState>> res) {
|
||||
LOG(DEBUG) << "in ValidateQuery::after_get_shard_state(" << idx << ")";
|
||||
LOG(WARNING) << "in ValidateQuery::after_get_shard_state(" << idx << ")";
|
||||
--pending;
|
||||
if (res.is_error()) {
|
||||
fatal_error(res.move_as_error());
|
||||
|
|
@ -1495,7 +1496,6 @@ bool ValidateQuery::request_neighbor_queues() {
|
|||
* @param res The obtained outbound queue.
|
||||
*/
|
||||
void ValidateQuery::got_neighbor_out_queue(int i, td::Result<Ref<MessageQueue>> res) {
|
||||
LOG(DEBUG) << "obtained outbound queue for neighbor #" << i;
|
||||
--pending;
|
||||
if (res.is_error()) {
|
||||
fatal_error(res.move_as_error());
|
||||
|
|
@ -1503,6 +1503,7 @@ void ValidateQuery::got_neighbor_out_queue(int i, td::Result<Ref<MessageQueue>>
|
|||
}
|
||||
Ref<MessageQueue> outq_descr = res.move_as_ok();
|
||||
block::McShardDescr& descr = neighbors_.at(i);
|
||||
LOG(WARNING) << "obtained outbound queue for neighbor #" << i << " : " << descr.shard().to_str();
|
||||
if (outq_descr->get_block_id() != descr.blk_) {
|
||||
LOG(DEBUG) << "outq_descr->id = " << outq_descr->get_block_id().to_str() << " ; descr.id = " << descr.blk_.to_str();
|
||||
fatal_error(
|
||||
|
|
@ -6187,6 +6188,7 @@ bool ValidateQuery::try_validate() {
|
|||
}
|
||||
try {
|
||||
if (!stage_) {
|
||||
LOG(WARNING) << "try_validate stage 0";
|
||||
if (!compute_prev_state()) {
|
||||
return fatal_error(-666, "cannot compute previous state");
|
||||
}
|
||||
|
|
@ -6216,6 +6218,7 @@ bool ValidateQuery::try_validate() {
|
|||
return true;
|
||||
}
|
||||
}
|
||||
LOG(WARNING) << "try_validate stage 1";
|
||||
LOG(INFO) << "running automated validity checks for block candidate " << id_.to_str();
|
||||
if (!block::gen::t_Block.validate_ref(10000000, block_root_)) {
|
||||
return reject_query("block "s + id_.to_str() + " failed to pass automated validity checks");
|
||||
|
|
|
|||
|
|
@ -784,6 +784,8 @@ void ValidatorManagerImpl::wait_block_message_queue_short(BlockIdExt block_id, t
|
|||
|
||||
void ValidatorManagerImpl::get_external_messages(ShardIdFull shard,
|
||||
td::Promise<std::vector<td::Ref<ExtMessage>>> promise) {
|
||||
td::Timer t;
|
||||
size_t processed = 0, deleted = 0;
|
||||
std::vector<td::Ref<ExtMessage>> res;
|
||||
MessageId<ExtMessage> left{AccountIdPrefixFull{shard.workchain, shard.shard & (shard.shard - 1)}, Bits256::zero()};
|
||||
auto it = ext_messages_.lower_bound(left);
|
||||
|
|
@ -792,10 +794,12 @@ void ValidatorManagerImpl::get_external_messages(ShardIdFull shard,
|
|||
if (!shard_contains(shard, s.dst)) {
|
||||
break;
|
||||
}
|
||||
++processed;
|
||||
if (it->second->expired()) {
|
||||
ext_addr_messages_[it->second->address()].erase(it->first.hash);
|
||||
ext_messages_hashes_.erase(it->first.hash);
|
||||
it = ext_messages_.erase(it);
|
||||
++deleted;
|
||||
continue;
|
||||
}
|
||||
if (it->second->is_active()) {
|
||||
|
|
@ -803,6 +807,9 @@ void ValidatorManagerImpl::get_external_messages(ShardIdFull shard,
|
|||
}
|
||||
it++;
|
||||
}
|
||||
LOG(WARNING) << "get_external_messages to shard " << shard.to_str() << " : time=" << t.elapsed()
|
||||
<< " result_size=" << res.size() << " processed=" << processed << " expired=" << deleted
|
||||
<< " total_size=" << ext_messages_.size();
|
||||
promise.set_value(std::move(res));
|
||||
}
|
||||
|
||||
|
|
@ -1356,7 +1363,18 @@ td::Ref<MasterchainState> ValidatorManagerImpl::do_get_last_liteserver_state() {
|
|||
if (last_masterchain_state_.is_null()) {
|
||||
return {};
|
||||
}
|
||||
if (last_liteserver_state_.is_null() || last_liteserver_state_->get_unix_time() < td::Clocks::system() - 30) {
|
||||
if (last_liteserver_state_.is_null()) {
|
||||
last_liteserver_state_ = last_masterchain_state_;
|
||||
return last_liteserver_state_;
|
||||
}
|
||||
if (last_liteserver_state_->get_seqno() == last_masterchain_state_->get_seqno()) {
|
||||
return last_liteserver_state_;
|
||||
}
|
||||
// If liteserver seqno (i.e. shard client) lags then use last masterchain state for liteserver
|
||||
// Allowed lag depends on the block rate
|
||||
double time_per_block = double(last_masterchain_state_->get_unix_time() - last_liteserver_state_->get_unix_time()) /
|
||||
double(last_masterchain_state_->get_seqno() - last_liteserver_state_->get_seqno());
|
||||
if (td::Clocks::system() - double(last_liteserver_state_->get_unix_time()) > std::min(time_per_block * 8, 180.0)) {
|
||||
last_liteserver_state_ = last_masterchain_state_;
|
||||
}
|
||||
return last_liteserver_state_;
|
||||
|
|
@ -2356,15 +2374,15 @@ void ValidatorManagerImpl::alarm() {
|
|||
}
|
||||
if (log_status_at_.is_in_past()) {
|
||||
if (last_masterchain_block_handle_) {
|
||||
LOG(INFO) << "STATUS: last_masterchain_block_ago="
|
||||
<< td::format::as_time(td::Clocks::system() - last_masterchain_block_handle_->unix_time())
|
||||
<< " last_known_key_block_ago="
|
||||
<< td::format::as_time(td::Clocks::system() - (last_known_key_block_handle_->inited_unix_time()
|
||||
? last_known_key_block_handle_->unix_time()
|
||||
: 0))
|
||||
<< " shard_client_ago="
|
||||
<< td::format::as_time(td::Clocks::system() -
|
||||
(shard_client_handle_ ? shard_client_handle_->unix_time() : 0));
|
||||
LOG(ERROR) << "STATUS: last_masterchain_block_ago="
|
||||
<< td::format::as_time(td::Clocks::system() - last_masterchain_block_handle_->unix_time())
|
||||
<< " last_known_key_block_ago="
|
||||
<< td::format::as_time(td::Clocks::system() - (last_known_key_block_handle_->inited_unix_time()
|
||||
? last_known_key_block_handle_->unix_time()
|
||||
: 0))
|
||||
<< " shard_client_ago="
|
||||
<< td::format::as_time(td::Clocks::system() -
|
||||
(shard_client_handle_ ? shard_client_handle_->unix_time() : 0));
|
||||
}
|
||||
log_status_at_ = td::Timestamp::in(60.0);
|
||||
}
|
||||
|
|
|
|||
|
|
@ -136,7 +136,7 @@ void ValidatorGroup::accept_block_candidate(td::uint32 round_id, PublicKeyHash s
|
|||
std::vector<BlockSignature> approve_signatures,
|
||||
validatorsession::ValidatorSessionStats stats,
|
||||
td::Promise<td::Unit> promise) {
|
||||
if (round_id >= last_known_round_id_) {
|
||||
if (round_id >= last_known_round_id_) {
|
||||
last_known_round_id_ = round_id + 1;
|
||||
}
|
||||
auto sig_set = create_signature_set(std::move(signatures));
|
||||
|
|
@ -150,6 +150,7 @@ void ValidatorGroup::accept_block_candidate(td::uint32 round_id, PublicKeyHash s
|
|||
return;
|
||||
}
|
||||
auto next_block_id = create_next_block_id(root_hash, file_hash);
|
||||
LOG(WARNING) << "Accepted block " << next_block_id;
|
||||
td::actor::send_closure(manager_, &ValidatorManager::log_validator_session_stats, next_block_id, std::move(stats));
|
||||
auto block =
|
||||
block_data.size() > 0 ? create_block(next_block_id, std::move(block_data)).move_as_ok() : td::Ref<BlockData>{};
|
||||
|
|
|
|||
Loading…
Add table
Add a link
Reference in a new issue