validation: log CChainState::CheckBlockIndex() consistency checks #22956

jonatack · 2021-09-12T13:34:44Z

The -checkblockindex configuration option performs occasional consistency checks of the block tree, chainstate, and other validation data structures.

There is currently no logging of the checks to see when they happen and their duration.

This patch:

adds a BLOCK logging category, as the validation category is high-frequency
logs the CChainState::CheckBlockIndex() consistency checks and duration

Example (on signet, while catching up to chain tip):

$ ./src/bitcoind -signet -checkaddrman=10 -debug=lock -debug=block
...
2021-09-12T13:03:18Z [msghand] CheckBlockIndex: consistency checks started
2021-09-12T13:03:18Z [opencon] Enter: lock contention cs_main, net_processing.cpp:1152 started
2021-09-12T13:03:18Z [msghand] CheckBlockIndex: consistency checks completed (433.58ms)
2021-09-12T13:03:18Z [msghand] CheckBlockIndex: consistency checks started
2021-09-12T13:03:19Z [msghand] CheckBlockIndex: consistency checks completed (411.67ms)
2021-09-12T13:03:19Z [opencon] Enter: lock contention cs_main, net_processing.cpp:1152 completed (811929μs)

To test:

$ ./src/bitcoind -debug=block

DrahtBot · 2021-09-12T15:23:36Z

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

Conflicts

Reviewers, this pull request conflicts with the following ones:

#23235 (Reduce unnecessary default logging by ajtowns)

If you consider this pull request important, please also help to review the conflicting pull requests. Ideally, start with the one that should be merged first.

klementtan

Code review and tested ACK 572cf0dd547b69580b7796d2192617ab4a318a5f

2021-09-13T07:01:58Z CheckBlockIndex: consistency checks started
2021-09-13T07:01:58Z CheckBlockIndex: consistency checks completed (63.12ms)
2021-09-13T07:01:58Z CheckBlockIndex: consistency checks started
2021-09-13T07:01:58Z Enter: lock contention ::cs_main, validation.cpp:4876 started
2021-09-13T07:01:58Z CheckBlockIndex: consistency checks completed (57.97ms)

maflcko · 2021-09-13T07:27:50Z

src/logging.cpp

Is there a guideline on which log category to use within validation? There is BENCH used for benchmarking validation. There is VALIDATION used for storage and validation. Now there is BLOCK used for CheckBlockIndex.

Not that I know of. I published a doc at https://github.com/jonatack/bitcoin-development/blob/master/logging.md#log-categories that is an updated version of this Bitcoin Stack Exchange answer in 2017 by @achow101 and am considering adding it to the RPC logging help.

Is there a reason to not re-use the BENCH or VALIDATION category? Seems overkill to introduce a new category for a single log line that is mostly only enabled for devs/debugging.

We did that for instance with MEMPOOLREJ (1 line), QT (1 line), LOCK (1 line), PROXY (1 line), RAND (2 lines), COINDB (3 lines) and CMPCTBLOCK (3 lines), among others.

My thought was that VALIDATION is too busy and BENCH would be ok but seems not directly related to consistency checks (rename it?) We could also rename CMPCTBLOCK to BLOCK and add it to that group.

I think a BLOCK category makes sense in the sense that "block storage" is separate from "validation". We have a separate label for it too. If it is planned to be used for other messages too.

On the other hand this particular functionality is already enabled with a special option (-checkblockindex), so for this specifically I'm not sure also adding a separate category makes sense.

RAND (2 lines)

I think this one should go into a more general UTIL category at some point.

QT (1 line)

One line that captures everything from Qt's internal logging system 😄

I think a BLOCK category makes sense in the sense that "block storage" is separate from "validation". We have a separate label for it too. If it is planned to be used for other messages too.

On the other hand this particular functionality is already enabled with a special option (-checkblockindex), so for this specifically I'm not sure also adding a separate category makes sense.

Right. It doesn't seem ideal to use BCLog::VALIDATION or BCLog::BENCH, and LogPrintf would require bitcoind to be restarted to turn off the -checkblockindex config option. Maybe rename the low-frequency BCLog::CMPCTBLOCK category to BCLog::BLOCK and use that, but it would be a bit more disruptive than the current proposal.

Looks like #23235 did some of the clean-ups here?

Looks like #23235 did some of the clean-ups here?

Looked at it, but that change looks like it needs cleaning up and given how this simple change couldn't go through, I didn't attempt it.

jonatack · 2021-10-05T10:05:34Z

Rebased following the merge of #20487, which added the UTIL logging category.

DrahtBot · 2021-10-14T06:19:42Z

🐙 This pull request conflicts with the target branch and needs rebase.

_{Want to unsubscribe from rebase notifications on this pull request? Just convert this pull request to a "draft".}

laanwj · 2021-11-12T19:23:31Z

Code review ACK (but unfortunately needs rebase again)

DrahtBot · 2022-02-22T12:17:20Z

There hasn't been much activity lately and the patch still needs rebase. What is the status here?

Is it still relevant? ➡️ Please solve the conflicts to make it ready for review and to ensure the CI passes.
Is it no longer relevant? ➡️ Please close.
Did the author lose interest or time to work on this? ➡️ Please close it and mark it 'Up for grabs' with the label, so that it can be picked up in the future.

fanquake · 2022-05-25T08:29:48Z

What is the status of this?

maflcko · 2022-05-25T08:36:27Z

Closing due to several months of inactivity for a "simple" logging change. Feel free to reopen this or open a new pull request.

jonatack · 2022-05-25T08:40:00Z

Indeed, I thought it would be simple but no agreement on which logging category to use.

DrahtBot added the Validation label Sep 12, 2021

DrahtBot mentioned this pull request Sep 12, 2021

Add syscall sandboxing using seccomp-bpf (Linux secure computing mode) #20487

Merged

klementtan approved these changes Sep 13, 2021

View reviewed changes

maflcko reviewed Sep 13, 2021

View reviewed changes

DrahtBot added the Needs rebase label Oct 4, 2021

jonatack added 2 commits October 5, 2021 11:57

log: add BLOCK logging category

fbd0951

validation: log CChainState::CheckBlockIndex() consistency checks

dfca02e

jonatack force-pushed the CheckBlockIndex-logging branch from 572cf0d to dfca02e Compare October 5, 2021 10:01

DrahtBot removed the Needs rebase label Oct 5, 2021

DrahtBot mentioned this pull request Oct 9, 2021

Reduce unnecessary default logging #23235

Merged

DrahtBot added the Needs rebase label Oct 14, 2021

maflcko closed this May 25, 2022

bitcoin locked and limited conversation to collaborators May 25, 2023

validation: log CChainState::CheckBlockIndex() consistency checks #22956

validation: log CChainState::CheckBlockIndex() consistency checks #22956

Uh oh!

Conversation

jonatack commented Sep 12, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

DrahtBot commented Sep 12, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Conflicts

Uh oh!

klementtan left a comment • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

maflcko Sep 13, 2021

Choose a reason for hiding this comment

Uh oh!

jonatack Sep 13, 2021

Choose a reason for hiding this comment

Uh oh!

maflcko Sep 22, 2021

Choose a reason for hiding this comment

Uh oh!

jonatack Sep 22, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

laanwj Sep 23, 2021

Choose a reason for hiding this comment

Uh oh!

jonatack Sep 29, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

maflcko Oct 26, 2021

Choose a reason for hiding this comment

Uh oh!

jonatack May 25, 2022

Choose a reason for hiding this comment

Uh oh!

jonatack commented Oct 5, 2021

Uh oh!

DrahtBot commented Oct 14, 2021

Uh oh!

laanwj commented Nov 12, 2021

Uh oh!

DrahtBot commented Feb 22, 2022

Uh oh!

fanquake commented May 25, 2022

Uh oh!

maflcko commented May 25, 2022

Uh oh!

jonatack commented May 25, 2022

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

6 participants

jonatack commented Sep 12, 2021 •

edited

Loading

DrahtBot commented Sep 12, 2021 •

edited

Loading

klementtan left a comment •

edited

Loading

jonatack Sep 22, 2021 •

edited

Loading

jonatack Sep 29, 2021 •

edited

Loading