log: don’t log total disk read time in ConnectTip bench #27673

pull Sjors wants to merge 1 commits into bitcoin:master from Sjors:2023/05/div-zero changing 1 files +4 −6
  1. Sjors commented at 11:17 am on May 16, 2023: member

    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

  2. ConnectTip: don't log total disk read time in bench
    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.
    bc862fad29
  3. DrahtBot commented at 11:17 am on May 16, 2023: contributor

    The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.

    Reviews

    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.

  4. in src/validation.cpp:2838 in bc862fad29
    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.
    


    Sjors commented at 11:30 am on May 16, 2023:
    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.

    maflcko commented at 12:24 pm on May 16, 2023:
    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.

    Sjors commented at 12:41 pm on May 16, 2023:
    We also call ConnectTip() from TestBlockValidity() and VerifyDB(). Do you know how the counter is supposed to behave in those cases?

    maflcko commented at 1:30 pm on May 16, 2023:

    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.


    Sjors commented at 2:55 pm on May 16, 2023:
    Happy to review such a change, but I barely remember making the original PR and am not very familiar with the bench logging.
  5. arnonrdp approved
  6. DrahtBot renamed this:
    ConnectTip: don't log total disk read time in bench
    log: don't log total disk read time in ConnectTip bench
    on May 25, 2023
  7. DrahtBot added the label Utils/log/libs on May 25, 2023
  8. maflcko commented at 4:15 pm on May 25, 2023: member

    lgtm ACK bc862fad294fdb3e4232734497d0693a0da4d63a 🐓

    Signature:

    0untrusted 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}"
    1RUTRmVTMeKV5npGrKx1nqXCw5zeVHdtdYURB/KlyA/LMFgpNCs+SkW9a8N95d+U4AP1RJMi+krxU1A3Yux4bpwZNLvVBKy0wLgM=
    2trusted comment: lgtm ACK bc862fad294fdb3e4232734497d0693a0da4d63a 🐓
    3k9lCbJsD8cZpwqsabLNVoj3esgmXdB1XCA5byJMD9p5Ie1n1ex3DRDaQp156zNHgtwFOJUQbLKkQABcjFYpABA==
    
  9. fanquake requested review from willcl-ark on May 26, 2023
  10. willcl-ark commented at 9:31 am on May 30, 2023: member

    tACK bc862fad29

    I was able to reproduce dropping the commit from this pull (and on master):

    02023-05-30T09:27:25Z loadblk thread start
    1validation.cpp:2839:5: runtime error: division by zero
    22023-05-30T09:27:25Z [bench]   - Load block from disk: 0.06ms [0.00s (infms/blk)]
    32023-05-30T09:27:25Z [bench]   - Connect total: 0.36ms [0.00s (0.36ms/blk)]
    42023-05-30T09:27:25Z [bench]   - Flush: 0.03ms [0.00s (0.03ms/blk)]
    52023-05-30T09:27:25Z [bench]   - Writing chainstate: 0.02ms [0.00s (0.02ms/blk)]
    

    and after this pull:

    02023-05-30T09:30:30Z loadblk thread start
    12023-05-30T09:30:30Z [bench]   - Load block from disk: 0.06ms
    22023-05-30T09:30:30Z [bench]   - Connect total: 0.09ms [0.00s (0.09ms/blk)]
    32023-05-30T09:30:30Z [bench]   - Flush: 0.03ms [0.00s (0.03ms/blk)]
    42023-05-30T09:30:30Z [bench]   - Writing chainstate: 0.02ms [0.00s (0.02ms/blk)]
    
  11. DrahtBot removed review request from willcl-ark on May 30, 2023
  12. willcl-ark approved
  13. fanquake merged this on May 30, 2023
  14. fanquake closed this on May 30, 2023

  15. Sjors deleted the branch on May 30, 2023
  16. sidhujag referenced this in commit eb5e892747 on May 30, 2023
  17. bitcoin locked this on May 29, 2024

github-metadata-mirror

This is a metadata mirror of the GitHub repository bitcoin/bitcoin. This site is not affiliated with GitHub. Content is generated from a GitHub metadata backup.
generated: 2024-12-22 00:12 UTC

This site is hosted by @0xB10C
More mirrored repositories can be found on mirror.b10c.me