Merge bitcoin/bitcoin#22904: sync, log: inline lock contention logging macro to fix duration, improve BCLog::LogMsg()

f530202353 Make unexpected time type in BCLog::LogMsg() a compile-time error (Martin Ankerl)
bddae7e7ff Add util/types.h with ALWAYS_FALSE template (MarcoFalke)
498b323425 log, timer: improve BCLog::LogMsg() (Jon Atack)
8d2f847ed9 sync: inline lock contention logging macro to fix time duration (Jon Atack)

Pull request description:

  Follow-up to #22736.

  The first commit addresses the issue identified and reported by Martin Ankerl in https://github.com/bitcoin/bitcoin/pull/22736#discussion_r703019629 to fix the lock contention duration reporting.

  The next three commits make improvements to the timer code in `BCLog::LogMsg()` and add `util/types.h` with an `ALWAYS_FALSE` template, that springboard from https://github.com/bitcoin/bitcoin/pull/22736#discussion_r702747920 by Marco Falke.

ACKs for top commit:
  martinus:
    re-ACK f530202353. I ran a fully synced node for about a day. My node was mostly idle though so not much was going on. I [wrote a little script](https://github.com/martinus/bitcoin-stuff/blob/main/scripts/parse-debuglog-contention-single.rb) to parse the `debug.log` and summarize the output to see if anything interesting was going on, here is the result:
  theStack:
    ACK f530202353

Tree-SHA512: 37d093eac5590e1b5846ab5994d0950d71e131177d1afe4a5f7fcd614270f977e0ea117e7af788e9a74ddcccab35b42ec8fa4db3a3378940d4988df7d21cdaaa
This commit is contained in:
merge-script
2021-09-09 15:55:03 +02:00
6 changed files with 27 additions and 30 deletions

View File

@@ -15,9 +15,9 @@ BOOST_FIXTURE_TEST_SUITE(logging_tests, BasicTestingSetup)
BOOST_AUTO_TEST_CASE(logging_timer)
{
SetMockTime(1);
auto sec_timer = BCLog::Timer<std::chrono::seconds>("tests", "end_msg");
auto micro_timer = BCLog::Timer<std::chrono::microseconds>("tests", "end_msg");
SetMockTime(2);
BOOST_CHECK_EQUAL(sec_timer.LogMsg("test secs"), "tests: test secs (1.00s)");
BOOST_CHECK_EQUAL(micro_timer.LogMsg("test micros"), "tests: test micros (1000000μs)");
SetMockTime(1);
auto ms_timer = BCLog::Timer<std::chrono::milliseconds>("tests", "end_msg");
@@ -25,9 +25,9 @@ BOOST_AUTO_TEST_CASE(logging_timer)
BOOST_CHECK_EQUAL(ms_timer.LogMsg("test ms"), "tests: test ms (1000.00ms)");
SetMockTime(1);
auto micro_timer = BCLog::Timer<std::chrono::microseconds>("tests", "end_msg");
auto sec_timer = BCLog::Timer<std::chrono::seconds>("tests", "end_msg");
SetMockTime(2);
BOOST_CHECK_EQUAL(micro_timer.LogMsg("test micros"), "tests: test micros (1000000μs)");
BOOST_CHECK_EQUAL(sec_timer.LogMsg("test secs"), "tests: test secs (1.00s)");
}
BOOST_AUTO_TEST_SUITE_END()