The " Load block from disk" log introduced in #24216 incorrectly assumed num_blocks_total would be greater than 0. This is not guaranteed until the ConnectBlock call right below it.
The total and average metric is not very useful because it does not distinguish between blocks read from disk and those loaded from memory. So rather than fixing the divide by zero issue, we just drop the metric.
Fixes #27635
This incorrectly assumed num_blocks_total would be greater than 0. This is not guaranteed until the ConnectBlock call right below it.
The total and average metric is not very useful because it does not distinguish between blocks read from disk and those loaded from memory. So rather than fixing the divide by zero issue, we just drop the metric.
<!--e57a25ab6845829454e8d69fc972939a-->
The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.
<!--021abf342d371248e50ceaed478a90ca-->
See the guideline for information on the review process.
| Type | Reviewers |
|---|---|
| ACK | MarcoFalke, willcl-ark |
If your review is incorrectly listed, please react with 👎 to this comment and the bot will ignore it on the next update.
2838 | - LogPrint(BCLog::BENCH, " - Load block from disk: %.2fms [%.2fs (%.2fms/blk)]\n", 2839 | - Ticks<MillisecondsDouble>(time_2 - time_1), 2840 | - Ticks<SecondsDouble>(time_read_from_disk_total), 2841 | - Ticks<MillisecondsDouble>(time_read_from_disk_total) / num_blocks_total); 2842 | + // When adding aggregate statistics in the future, keep in mind that 2843 | + // num_blocks_total may be zero until the ConnectBlock() call below.
Fwiw I think this warning is useful because many of the bench logs use / num_blocks_total and there's a assert(num_blocks_total > 0) just a few lines down.
I'd say it would be fine to move the ++num_blocks_total; to this line instead, and the assert as well. Self-documenting code is better than potentially outdated docs.
We also call ConnectTip() from TestBlockValidity() and VerifyDB(). Do you know how the counter is supposed to behave in those cases?
Maybe all globals can be moved to function scope and the num_blocks_total can be duplicated to both functions where it is used?
This would ensure that the counts in one function do not affect the counts in another, given that they are not guaranteed to be equal.
Happy to review such a change, but I barely remember making the original PR and am not very familiar with the bench logging.
lgtm ACK bc862fad294fdb3e4232734497d0693a0da4d63a 🐓
<details><summary>Show signature</summary>
Signature:
untrusted comment: signature from minisign secret key on empty file; verify via: minisign -Vm "${path_to_any_empty_file}" -P RWTRmVTMeKV5noAMqVlsMugDDCyyTSbA3Re5AkUrhvLVln0tSaFWglOw -x "${path_to_this_whole_four_line_signature_blob}"
RUTRmVTMeKV5npGrKx1nqXCw5zeVHdtdYURB/KlyA/LMFgpNCs+SkW9a8N95d+U4AP1RJMi+krxU1A3Yux4bpwZNLvVBKy0wLgM=
trusted comment: lgtm ACK bc862fad294fdb3e4232734497d0693a0da4d63a 🐓
k9lCbJsD8cZpwqsabLNVoj3esgmXdB1XCA5byJMD9p5Ie1n1ex3DRDaQp156zNHgtwFOJUQbLKkQABcjFYpABA==
</details>
tACK bc862fad29
I was able to reproduce dropping the commit from this pull (and on master):
2023-05-30T09:27:25Z loadblk thread start
validation.cpp:2839:5: runtime error: division by zero
2023-05-30T09:27:25Z [bench] - Load block from disk: 0.06ms [0.00s (infms/blk)]
2023-05-30T09:27:25Z [bench] - Connect total: 0.36ms [0.00s (0.36ms/blk)]
2023-05-30T09:27:25Z [bench] - Flush: 0.03ms [0.00s (0.03ms/blk)]
2023-05-30T09:27:25Z [bench] - Writing chainstate: 0.02ms [0.00s (0.02ms/blk)]
and after this pull:
2023-05-30T09:30:30Z loadblk thread start
2023-05-30T09:30:30Z [bench] - Load block from disk: 0.06ms
2023-05-30T09:30:30Z [bench] - Connect total: 0.09ms [0.00s (0.09ms/blk)]
2023-05-30T09:30:30Z [bench] - Flush: 0.03ms [0.00s (0.03ms/blk)]
2023-05-30T09:30:30Z [bench] - Writing chainstate: 0.02ms [0.00s (0.02ms/blk)]
