Skip to content

Commit 0667560

Browse files
committed
Debug logs for applying blocks
1 parent 34823b1 commit 0667560

File tree

7 files changed

+70
-25
lines changed

7 files changed

+70
-25
lines changed

validator/apply-block.cpp

Lines changed: 21 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -29,7 +29,7 @@ namespace validator {
2929

3030
void ApplyBlock::abort_query(td::Status reason) {
3131
if (promise_) {
32-
VLOG(VALIDATOR_WARNING) << "aborting apply block query for " << id_ << ": " << reason;
32+
VLOG(VALIDATOR_WARNING) << "aborting apply block query for " << id_.to_str() << ": " << reason;
3333
promise_.set_error(std::move(reason));
3434
}
3535
stop();
@@ -51,7 +51,7 @@ void ApplyBlock::alarm() {
5151
}
5252

5353
void ApplyBlock::start_up() {
54-
VLOG(VALIDATOR_DEBUG) << "running apply_block for " << id_;
54+
VLOG(VALIDATOR_DEBUG) << "running apply_block for " << id_.to_str() << ", mc_seqno=" << masterchain_block_id_.seqno();
5555

5656
if (id_.is_masterchain()) {
5757
masterchain_block_id_ = id_;
@@ -71,6 +71,7 @@ void ApplyBlock::start_up() {
7171
}
7272

7373
void ApplyBlock::got_block_handle(BlockHandle handle) {
74+
VLOG(VALIDATOR_DEBUG) << "got_block_handle";
7475
handle_ = std::move(handle);
7576

7677
if (handle_->is_applied() && (!handle_->id().is_masterchain() || handle_->processed())) {
@@ -79,6 +80,7 @@ void ApplyBlock::got_block_handle(BlockHandle handle) {
7980
}
8081

8182
if (handle_->is_applied()) {
83+
VLOG(VALIDATOR_DEBUG) << "already applied";
8284
auto P =
8385
td::PromiseCreator::lambda([SelfId = actor_id(this), seqno = handle_->id().id.seqno](td::Result<BlockIdExt> R) {
8486
R.ensure();
@@ -94,16 +96,19 @@ void ApplyBlock::got_block_handle(BlockHandle handle) {
9496
}
9597

9698
if (handle_->id().id.seqno == 0) {
99+
VLOG(VALIDATOR_DEBUG) << "seqno == 0";
97100
written_block_data();
98101
return;
99102
}
100103

101104
if (handle_->is_archived()) {
105+
VLOG(VALIDATOR_DEBUG) << "already archived";
102106
finish_query();
103107
return;
104108
}
105109

106110
if (handle_->received()) {
111+
VLOG(VALIDATOR_DEBUG) << "already received";
107112
written_block_data();
108113
return;
109114
}
@@ -117,6 +122,7 @@ void ApplyBlock::got_block_handle(BlockHandle handle) {
117122
}
118123
});
119124

125+
VLOG(VALIDATOR_DEBUG) << "storing block data";
120126
td::actor::send_closure(manager_, &ValidatorManager::set_block_data, handle_, block_, std::move(P));
121127
} else {
122128
auto P = td::PromiseCreator::lambda([SelfId = actor_id(this), handle = handle_](td::Result<td::Ref<BlockData>> R) {
@@ -128,13 +134,14 @@ void ApplyBlock::got_block_handle(BlockHandle handle) {
128134
}
129135
});
130136

137+
VLOG(VALIDATOR_DEBUG) << "wait for block data";
131138
td::actor::send_closure(manager_, &ValidatorManager::wait_block_data, handle_, apply_block_priority(), timeout_,
132139
std::move(P));
133140
}
134141
}
135142

136143
void ApplyBlock::written_block_data() {
137-
VLOG(VALIDATOR_DEBUG) << "apply block: written block data for " << id_;
144+
VLOG(VALIDATOR_DEBUG) << "written_block_data";
138145
if (!handle_->id().seqno()) {
139146
CHECK(handle_->inited_split_after());
140147
CHECK(handle_->inited_state_root_hash());
@@ -165,24 +172,26 @@ void ApplyBlock::written_block_data() {
165172
}
166173
});
167174

175+
VLOG(VALIDATOR_DEBUG) << "wait_block_state";
168176
td::actor::send_closure(manager_, &ValidatorManager::wait_block_state, handle_, apply_block_priority(), timeout_,
169177
true, std::move(P));
170178
}
171179
}
172180

173181
void ApplyBlock::got_cur_state(td::Ref<ShardState> state) {
174-
VLOG(VALIDATOR_DEBUG) << "apply block: received state for " << id_;
182+
VLOG(VALIDATOR_DEBUG) << "got_cur_state";
175183
state_ = std::move(state);
176184
CHECK(handle_->received_state());
177185
written_state();
178186
}
179187

180188
void ApplyBlock::written_state() {
189+
VLOG(VALIDATOR_DEBUG) << "written_state";
181190
if (handle_->is_applied() && handle_->processed()) {
182191
finish_query();
183192
return;
184193
}
185-
VLOG(VALIDATOR_DEBUG) << "apply block: setting next for parents of " << id_;
194+
VLOG(VALIDATOR_DEBUG) << "setting next for parents";
186195

187196
if (handle_->id().id.seqno != 0 && !handle_->is_applied()) {
188197
auto P = td::PromiseCreator::lambda([SelfId = actor_id(this)](td::Result<td::Unit> R) {
@@ -208,12 +217,13 @@ void ApplyBlock::written_state() {
208217
}
209218

210219
void ApplyBlock::written_next() {
220+
VLOG(VALIDATOR_DEBUG) << "written_next";
211221
if (handle_->is_applied() && handle_->processed()) {
212222
finish_query();
213223
return;
214224
}
215225

216-
VLOG(VALIDATOR_DEBUG) << "apply block: applying parents of " << id_;
226+
VLOG(VALIDATOR_DEBUG) << "applying parents";
217227

218228
if (handle_->id().id.seqno != 0 && !handle_->is_applied()) {
219229
auto P = td::PromiseCreator::lambda([SelfId = actor_id(this)](td::Result<td::Unit> R) {
@@ -241,7 +251,8 @@ void ApplyBlock::written_next() {
241251
}
242252

243253
void ApplyBlock::applied_prev() {
244-
VLOG(VALIDATOR_DEBUG) << "apply block: waiting manager's confirm for " << id_;
254+
VLOG(VALIDATOR_DEBUG) << "applying parents";
255+
VLOG(VALIDATOR_DEBUG) << "applied_prev, waiting manager's confirm";
245256
if (!id_.is_masterchain()) {
246257
handle_->set_masterchain_ref_block(masterchain_block_id_.seqno());
247258
}
@@ -253,10 +264,11 @@ void ApplyBlock::applied_prev() {
253264
}
254265
});
255266
td::actor::send_closure(manager_, &ValidatorManager::new_block, handle_, state_, std::move(P));
267+
256268
}
257269

258270
void ApplyBlock::applied_set() {
259-
VLOG(VALIDATOR_DEBUG) << "apply block: setting apply bit for " << id_;
271+
VLOG(VALIDATOR_DEBUG) << "applied_set";
260272
handle_->set_applied();
261273
if (handle_->id().seqno() > 0) {
262274
CHECK(handle_->handle_moved_to_archive());
@@ -270,6 +282,7 @@ void ApplyBlock::applied_set() {
270282
td::actor::send_closure(SelfId, &ApplyBlock::finish_query);
271283
}
272284
});
285+
VLOG(VALIDATOR_DEBUG) << "flush handle";
273286
handle_->flush(manager_, handle_, std::move(P));
274287
} else {
275288
finish_query();

validator/impl/accept-block.cpp

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -350,6 +350,7 @@ bool AcceptBlockQuery::check_send_error(td::actor::ActorId<AcceptBlockQuery> Sel
350350
}
351351

352352
void AcceptBlockQuery::finish_query() {
353+
VLOG(VALIDATOR_DEBUG) << "finish_query()";
353354
if (apply_) {
354355
ValidatorInvariants::check_post_accept(handle_);
355356
}
@@ -448,6 +449,7 @@ void AcceptBlockQuery::got_block_candidate_data(td::BufferSlice data) {
448449
}
449450

450451
void AcceptBlockQuery::got_block_handle_cont() {
452+
VLOG(VALIDATOR_DEBUG) << "got_block_handle_cont()";
451453
if (data_.not_null() && !handle_->received()) {
452454
td::actor::send_closure(
453455
manager_, &ValidatorManager::set_block_data, handle_, data_, [SelfId = actor_id(this)](td::Result<td::Unit> R) {
@@ -514,9 +516,11 @@ void AcceptBlockQuery::written_block_info() {
514516
td::actor::send_closure_bool(SelfId, &AcceptBlockQuery::got_prev_state, R.move_as_ok());
515517
});
516518

519+
VLOG(VALIDATOR_DEBUG) << "wait_prev_block_state";
517520
td::actor::send_closure(manager_, &ValidatorManager::wait_prev_block_state, handle_, priority(), timeout_,
518521
std::move(P));
519522
} else {
523+
VLOG(VALIDATOR_DEBUG) << "wait_block_data";
520524
td::actor::send_closure(manager_, &ValidatorManager::wait_block_data, handle_, priority(), timeout_,
521525
[SelfId = actor_id(this)](td::Result<td::Ref<BlockData>> R) {
522526
check_send_error(SelfId, R) ||

validator/impl/check-proof.cpp

Lines changed: 10 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -43,7 +43,7 @@ void CheckProof::alarm() {
4343

4444
void CheckProof::abort_query(td::Status reason) {
4545
if (promise_) {
46-
VLOG(VALIDATOR_WARNING) << "aborting check proof for " << id_ << " query: " << reason;
46+
VLOG(VALIDATOR_WARNING) << "aborting check proof for " << id_.to_str() << " query: " << reason;
4747
promise_.set_error(std::move(reason));
4848
}
4949
stop();
@@ -271,6 +271,7 @@ bool CheckProof::init_parse(bool is_aux) {
271271
}
272272

273273
void CheckProof::start_up() {
274+
VLOG(VALIDATOR_DEBUG) << "started check proof for " << id_.to_str() << ", mode=" << mode_;
274275
alarm_timestamp() = timeout_;
275276

276277
auto res = vm::std_boc_deserialize(proof_->data());
@@ -324,6 +325,7 @@ void CheckProof::start_up() {
324325
}
325326

326327
void CheckProof::got_block_handle(BlockHandle handle) {
328+
VLOG(VALIDATOR_DEBUG) << "got_block_handle";
327329
handle_ = std::move(handle);
328330
CHECK(handle_);
329331
if (!is_proof() || skip_check_signatures_) {
@@ -353,6 +355,7 @@ void CheckProof::got_block_handle(BlockHandle handle) {
353355
}
354356

355357
void CheckProof::got_masterchain_state(td::Ref<MasterchainState> state) {
358+
VLOG(VALIDATOR_DEBUG) << "got_masterchain_state #" << state->get_seqno();
356359
CHECK(is_proof());
357360
state_ = std::move(state);
358361

@@ -366,6 +369,7 @@ void CheckProof::got_masterchain_state(td::Ref<MasterchainState> state) {
366369
}
367370

368371
void CheckProof::process_masterchain_state() {
372+
VLOG(VALIDATOR_DEBUG) << "process_masterchain_state";
369373
CHECK(is_proof());
370374
CHECK(state_.not_null());
371375

@@ -396,6 +400,7 @@ void CheckProof::process_masterchain_state() {
396400
}
397401

398402
void CheckProof::check_signatures(Ref<ValidatorSet> s) {
403+
VLOG(VALIDATOR_DEBUG) << "check_signatures";
399404
if (s->get_catchain_seqno() != catchain_seqno_) {
400405
abort_query(td::Status::Error(ErrorCode::protoviolation, PSTRING() << "bad validator catchain seqno: expected "
401406
<< s->get_catchain_seqno() << ", found "
@@ -449,6 +454,7 @@ void CheckProof::check_signatures(Ref<ValidatorSet> s) {
449454
}
450455

451456
void CheckProof::got_block_handle_2(BlockHandle handle) {
457+
VLOG(VALIDATOR_DEBUG) << "got_block_handle_2 " << handle->id().id.to_str();
452458
handle_ = std::move(handle);
453459

454460
handle_->set_split(before_split_);
@@ -468,16 +474,19 @@ void CheckProof::got_block_handle_2(BlockHandle handle) {
468474
// do not save proof if we skipped signatures
469475
auto proof = Ref<Proof>(proof_);
470476
CHECK(proof.not_null());
477+
VLOG(VALIDATOR_DEBUG) << "set_block_proof";
471478
td::actor::send_closure_later(manager_, &ValidatorManager::set_block_proof, handle_, std::move(proof),
472479
std::move(P));
473480
} else if (is_proof()) {
474481
auto proof = Ref<Proof>(proof_);
475482
CHECK(proof.not_null());
476483
CHECK(sig_ok_);
484+
VLOG(VALIDATOR_DEBUG) << "set_block_proof";
477485
td::actor::send_closure_later(manager_, &ValidatorManager::set_block_proof, handle_, std::move(proof),
478486
std::move(P));
479487
} else {
480488
CHECK(proof_.not_null());
489+
VLOG(VALIDATOR_DEBUG) << "set_block_proof_link";
481490
td::actor::send_closure_later(manager_, &ValidatorManager::set_block_proof_link, handle_, proof_, std::move(P));
482491
}
483492
}

validator/impl/fabric.cpp

Lines changed: 11 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -158,37 +158,39 @@ void run_hardfork_accept_block_query(BlockIdExt id, td::Ref<BlockData> data,
158158
void run_apply_block_query(BlockIdExt id, td::Ref<BlockData> block, BlockIdExt masterchain_block_id,
159159
td::actor::ActorId<ValidatorManager> manager, td::Timestamp timeout,
160160
td::Promise<td::Unit> promise) {
161-
td::actor::create_actor<ApplyBlock>(PSTRING() << "apply " << id, id, std::move(block), masterchain_block_id, manager,
162-
timeout, std::move(promise))
161+
td::actor::create_actor<ApplyBlock>(PSTRING() << "apply" << id.id.to_str(), id, std::move(block),
162+
masterchain_block_id, manager, timeout, std::move(promise))
163163
.release();
164164
}
165165

166166
void run_check_proof_query(BlockIdExt id, td::Ref<Proof> proof, td::actor::ActorId<ValidatorManager> manager,
167167
td::Timestamp timeout, td::Promise<BlockHandle> promise, bool skip_check_signatures) {
168-
td::actor::create_actor<CheckProof>("checkproof", id, std::move(proof), manager, timeout, std::move(promise),
169-
skip_check_signatures)
168+
td::actor::create_actor<CheckProof>(PSTRING() << "checkproof" << id.id.to_str(), id, std::move(proof), manager,
169+
timeout, std::move(promise), skip_check_signatures)
170170
.release();
171171
}
172172

173173
void run_check_proof_query(BlockIdExt id, td::Ref<Proof> proof, td::actor::ActorId<ValidatorManager> manager,
174174
td::Timestamp timeout, td::Promise<BlockHandle> promise,
175175
td::Ref<ProofLink> rel_key_block_proof, bool skip_check_signatures) {
176-
td::actor::create_actor<CheckProof>("checkproof/key", id, std::move(proof), manager, timeout, std::move(promise),
177-
skip_check_signatures, std::move(rel_key_block_proof))
176+
td::actor::create_actor<CheckProof>(PSTRING() << "checkproof/key" << id.id.to_str(), id, std::move(proof), manager,
177+
timeout, std::move(promise), skip_check_signatures,
178+
std::move(rel_key_block_proof))
178179
.release();
179180
}
180181

181182
void run_check_proof_query(BlockIdExt id, td::Ref<Proof> proof, td::actor::ActorId<ValidatorManager> manager,
182183
td::Timestamp timeout, td::Promise<BlockHandle> promise,
183184
td::Ref<MasterchainState> rel_mc_state, bool skip_check_signatures) {
184-
td::actor::create_actor<CheckProof>("checkproof/st", id, std::move(proof), manager, timeout, std::move(promise),
185-
skip_check_signatures, std::move(rel_mc_state))
185+
td::actor::create_actor<CheckProof>(PSTRING() << "checkproof/st" << id.id.to_str(), id, std::move(proof), manager,
186+
timeout, std::move(promise), skip_check_signatures, std::move(rel_mc_state))
186187
.release();
187188
}
188189

189190
void run_check_proof_link_query(BlockIdExt id, td::Ref<ProofLink> proof, td::actor::ActorId<ValidatorManager> manager,
190191
td::Timestamp timeout, td::Promise<BlockHandle> promise) {
191-
td::actor::create_actor<CheckProof>("checkprooflink", id, std::move(proof), manager, timeout, std::move(promise))
192+
td::actor::create_actor<CheckProof>(PSTRING() << "checkprooflink" << id.id.to_str(), id, std::move(proof), manager,
193+
timeout, std::move(promise))
192194
.release();
193195
}
194196

validator/manager.cpp

Lines changed: 4 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -229,9 +229,10 @@ void ValidatorManagerImpl::new_block_broadcast(BlockBroadcast broadcast, td::Pro
229229
}
230230
promise.set_result(std::move(R));
231231
};
232-
td::actor::create_actor<ValidateBroadcast>("broadcast", std::move(broadcast), last_masterchain_block_handle_,
233-
last_masterchain_state_, last_known_key_block_handle_, actor_id(this),
234-
td::Timestamp::in(2.0), std::move(promise))
232+
BlockIdExt block_id = broadcast.block_id;
233+
td::actor::create_actor<ValidateBroadcast>(
234+
PSTRING() << "broadcast" << block_id.id.to_str(), std::move(broadcast), last_masterchain_block_handle_,
235+
last_masterchain_state_, last_known_key_block_handle_, actor_id(this), td::Timestamp::in(2.0), std::move(promise))
235236
.release();
236237
}
237238

validator/net/download-block.cpp

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -294,7 +294,7 @@ void DownloadBlock::got_block_partial_proof(td::BufferSlice proof) {
294294
}
295295

296296
void DownloadBlock::checked_block_proof() {
297-
VLOG(FULL_NODE_DEBUG) << "checked proof for " << block_id_;
297+
VLOG(FULL_NODE_DEBUG) << "checked proof for " << block_id_.to_str();
298298

299299
if (!handle_) {
300300
CHECK(!short_);

0 commit comments

Comments
 (0)