Skip to content

Conversation

@maflcko
Copy link
Member

@maflcko maflcko commented Jan 31, 2023

The logging timer has many issues:

  • The underlying clock is mockable, meaning that benchmarks are useless when mocktime was set at the beginning or end of the benchmark.
  • The underlying clock is not monotonic, meaning that benchmarks are useless when the system time was changed during the benchmark.

Fix all issues in this patch.

@DrahtBot
Copy link
Contributor

DrahtBot commented Jan 31, 2023

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 john-moffett
Approach ACK stickies-v

If your review is incorrectly listed, please react with 👎 to this comment and the bot will ignore it on the next update.

Copy link
Contributor

@john-moffett john-moffett left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ACK fa3fc86

@fanquake fanquake requested a review from stickies-v January 31, 2023 14:36
Copy link
Contributor

@stickies-v stickies-v left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Concept ACK - using steady_clock seems strictly better.

@maflcko maflcko force-pushed the 2301-log-steady-clock- branch from fa3fc86 to fad7af7 Compare January 31, 2023 17:49
Copy link
Contributor

@stickies-v stickies-v left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Approach ACK fad7af7

New logic in timer.h LGTM, just not sure about the test coverage cuts - but I'm not overly concerned either.

Comment on lines +79 to +80
const std::string_view result_prefix{"tests: msg ("};
BOOST_CHECK_EQUAL(micro_timer.LogMsg("msg").substr(0, result_prefix.size()), result_prefix);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We don't need to cut all this test coverage, e.g. we can still cut the mocktime but:

  • capture auto test_start{std::chrono::steady_clock::now()} at the beginning and and ensure that LogMsg contains a duration that's longer than now() - test_start
  • ensure that the different timers accurately represent s/ms/μs

Do you think the current timer test coverage is unnecessary?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Not sure if the goal of a unit test is to re-implement the whole function on top of fuzzy parsing? Happy to push any patch if someone writes something, though.

@fanquake fanquake requested a review from john-moffett February 1, 2023 16:50
Copy link
Contributor

@john-moffett john-moffett left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ACK fad7af7

I'm fine with the unit test the way it is, but if you want to do a simple additional check to make sure there's a digit following the parenthesis, here's a diff:

diff --git a/src/test/logging_tests.cpp b/src/test/logging_tests.cpp
index beb9398c74d..64a9129aa16 100644
--- a/src/test/logging_tests.cpp
+++ b/src/test/logging_tests.cpp
@@ -8,0 +9 @@
+#include <util/strencodings.h>
@@ -80,0 +82,2 @@ BOOST_AUTO_TEST_CASE(logging_timer)
+    uint8_t digit;
+    BOOST_CHECK(ParseUInt8(micro_timer.LogMsg("msg").substr(result_prefix.size(), 1), &digit));

@fanquake fanquake merged commit 9dc50a5 into bitcoin:master Feb 2, 2023
@maflcko maflcko deleted the 2301-log-steady-clock-🔆 branch February 2, 2023 10:32
sidhujag pushed a commit to syscoin/syscoin that referenced this pull request Feb 3, 2023
fad7af7 Use steady clock for logging timer (MarcoFalke)

Pull request description:

  The logging timer has many issues:

  * The underlying clock is mockable, meaning that benchmarks are useless when mocktime was set at the beginning or end of the benchmark.
  * The underlying clock is not monotonic, meaning that benchmarks are useless when the system time was changed during the benchmark.

  Fix all issues in this patch.

ACKs for top commit:
  stickies-v:
    Approach ACK fad7af7
  john-moffett:
    ACK fad7af7

Tree-SHA512: bec8da0f338ed4611e1807937575e1b2afda25139d88015b1c29fa7d13946fbfbc4ee589b576c0508d505df5e5fafafcbc07d63ce4bab4b01475260d9d5d2107
@bitcoin bitcoin locked and limited conversation to collaborators Feb 2, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.

Projects

None yet

Development

Successfully merging this pull request may close these issues.

5 participants