validation: Improve error handling when VerifyDB dosn't finish successfully

mzumsande commented at 8:24 pm on July 8, 2022: contributor

VerifyDB() can fail to complete due to insufficient dbcache at the level 3 checks. This PR improves the error handling in this case in the following ways:

The rpc -verifychain now returns false if the check can’t be completed due to insufficient cache
During init, we only log a warning if the default values for -checkblocks and -checklevel are taken and the check doesn’t complete. However, if the user actively specifies one of these args, we return with an InitError if we can’t complete the check.

This PR also changes -verifychain RPC to return false if the verification didn’t finish due to missing block data (pruning) or due to being interrupted by the node being shutdown.

Previously, this PR also included a fix for a possible assert during verification - this was done in #27009 (now merged).

fanquake added the label Validation on Jul 8, 2022

saranshisatgit commented at 3:31 am on July 9, 2022: none

I have tested the PR the command ./bitcoin-cli -signet verifychain 4 1000 returns true , does it requires tests to be written ?

maflcko commented at 8:29 am on July 11, 2022: member

In the future the RPC can probably be extended with a “warnings” and “error” field, but this patch lgtm.

saranshisatgit commented at 8:55 am on July 11, 2022: none

You mean changing the RPC return response prior adding objects for warning and error,

0static RPCHelpMan verifychain()
1if warning then (display Warning)
2if error then  (display Error)
3or else return response

It might require to or add new fields in the RPC?

This might mean that changing the way return is responding in RPC?

mzumsande commented at 2:50 pm on July 11, 2022: contributor

Note that this doesn’t only affect the verifychain RPC, but is also called as part of the startup (with the default level 3), which prevent the node from starting if validation fails. I think because of that, the current strategy is to only return an error if we are sure something is invalid, but permit the application to start with just a warning in the debug log if we couldn’t complete all checks. If only the RPC was affected, it would be ok to just return an error if we weren’t able to do all the checks we asked for.

saranshisatgit commented at 1:18 pm on July 12, 2022: none

verifychain

The above methods aborts, the code does produce assertion and thus abort, are you suggesting that it should rather identify for the user to simply ignore or warn the user that there is an issue with the verification of the chain, since we are starting up?

I was thinking to simply ignore the assertion or probably by pass the assertion by catching it some way rather abort() and probably it will help for the better and cleaner user inspection.

mzumsande commented at 1:38 pm on July 12, 2022: contributor

are you suggesting that it should rather identify for the user to simply ignore or warn the user that there is an issue with the verification of the chain, since we are starting up?

This PR reduces the number of checks that are being made when there is not sufficient ccache memory, so that the assertion can’t hit anymore (assertions can’t be ignored in general). What I was talking about is what VerifyDB() should do if it didn’t completely verify the blocks at the levels required (but also didn’t encounter an actual error), and I explained why I think it is ok to give a warning in the debug log.

saranshisatgit commented at 9:35 am on July 14, 2022: none

Right, so it should be taken care by default or by input, as in this there is an input , so that means a user is always triggering the output.

Now, this is my suggestion, that we should perhaps make this part of the default startup and should throw some debut output and continue with the startup process.?

What do you think? @mzumsande

mzumsande commented at 6:14 pm on July 14, 2022: contributor

Now, this is my suggestion, that we should perhaps make this part of the default startup and should throw some debut output and continue with the startup process.?

Not sure I understand. VerifyDB() is already part of the default startup, and this PR adds a debug log entry if we skip some L3 checks because if our ccache is insufficient.

saranshisatgit commented at 10:57 am on July 15, 2022: none

I was under the assumption that you are talking about VerifyDB() handling the checks like the above on its own on the startup, rather the rpc doing the check !

DrahtBot commented at 10:59 am on September 23, 2022: 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	ryanofsky, john-moffett, MarcoFalke, achow101
Concept ACK	pablomartin4btc, hernanmarino
Stale ACK	fanquake

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

Conflicts

Reviewers, this pull request conflicts with the following ones:

#27125 (refactor, kernel: Decouple ArgsManager from blockstorage by TheCharlatan)
#25977 (refactor: Replace std::optional<bilingual_str> with util::Result by ryanofsky)
#25665 (refactor: Add util::Result failure values, multiple error and warning messages by ryanofsky)

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.

in src/validation.cpp:4060 in b7adbca206 outdated

4008     if (pindexFailure) {
4009         return error("VerifyDB(): *** coin database inconsistencies found (last %i blocks, %i good transactions before that)\n", chainstate.m_chain.Height() - pindexFailure->nHeight + 1, nGoodTransactions);
4010     }
4011-
4012+    if (skipped_l3_checks) {
4013+        LogPrintf("VerifyDB(): Skipped verification of level >=3 (insufficient database cache size). Consider increasing -dbcache.\n");

fanquake commented at 2:26 pm on October 3, 2022:

Maybe put Skipped verification of... on it’s own line:

02022-10-03T14:00:20Z Verifying last 6 blocks at level 4
12022-10-03T14:00:20Z [0%]...[16%]...[25%]...[33%]...[41%]...[50%]...VerifyDB(): Skipped verification of level >=3 (insufficient database cache size). Consider increasing -dbcache.
22022-10-03T14:00:20Z [DONE].

maflcko commented at 3:22 pm on October 3, 2022:

I think we can just put each of [x%] on it’s own line. This would avoid breaking logging of other threads running at the same time, simplify the code, and also allow to see the timestamps over time.

mzumsande commented at 6:54 pm on October 3, 2022:

Will add a commit to do that - the downside is obviously is that it makes the progress logging more verbose (up to 10 lines instead of one).

mzumsande commented at 5:08 pm on October 7, 2022:

done

fanquake approved

fanquake commented at 2:34 pm on October 3, 2022: member

ACK b7adbca2061e5a88130f61e2744885ab97340d5c - Could be improved in follow ups. i.e if a user has explictly set -checklevel=3||4, it’s probably better to abort on too-small dbcache/where we can’t actually perform the checks, rather than log a warning.

I also agree that changing verifychain to return warnings/errors is also a better behaviour than returning true (and just logging) when you’ve actually skipped level 3 & 4 checks.

mzumsande commented at 5:48 pm on October 3, 2022: contributor

Happy to incorporate the suggestions from above here (no need for a follow-up).

mzumsande force-pushed on Oct 7, 2022

mzumsande commented at 5:07 pm on October 7, 2022: contributor

I expanded this PR to incorporate the feedback (and rebased): Additionally changed behavior:

The rpc -verifychain now returns false if the check can’t be completed due to insufficient cache.
During init, we only log a warning if the default values for -checkblocks and -checklevel are taken and the check doesn’t complete. However, if the user actively specifies one of these args, we return with an InitError.
Logging of verification progress is split over multiple lines. This is more verbose, but now each update has its own timestamp, and other threads logging concurrently will no longer lead to mangled output.

Will adjust OP and title.

mzumsande force-pushed on Oct 7, 2022

mzumsande renamed this:
~~validation: Skip VerifyDB checks of level >=3 if dbcache is too small~~
validation: Improve error handling when VerifyDB fails due to insufficient dbcache
on Oct 7, 2022

in src/rpc/blockchain.cpp:1128 in a1c83166f3 outdated

1106@@ -1107,7 +1107,7 @@ static RPCHelpMan verifychain()
1107 
1108     Chainstate& active_chainstate = chainman.ActiveChainstate();
1109     return CVerifyDB().VerifyDB(
1110-        active_chainstate, chainman.GetParams().GetConsensus(), active_chainstate.CoinsTip(), check_level, check_depth);
1111+               active_chainstate, chainman.GetParams().GetConsensus(), active_chainstate.CoinsTip(), check_level, check_depth) == VerifyDBResult::SUCCESS;

pablomartin4btc commented at 6:53 pm on December 6, 2022:

nit: not sure about those extra spaces there; could you please double check what’s mentioned in the developer notes about AlignAfterOpenBracket style option?

mzumsande commented at 8:57 pm on December 7, 2022:

I ran the Clang formatter script over the commits (as described in /contrib/devtools/README.txt) and I’m pretty sure it added the space for me.

pablomartin4btc commented at 7:10 pm on December 6, 2022: member

Tested ACK, I’ve managed to reproduce the issue before the fix as follows in the screenshots:

From the bitcoind execution, level 3 & 4 from cli (which crashes it) pr 25574 - bitcoind - before fix

From the client terminal, level 3 or 4 both return true (this one before it crashes)

pr 25574 - cli - before fix

After applying the fix, both levels return false:

And bitcoind doesn’t crash anymore (capturing both levels):

fanquake added this to the milestone 25.0 on Dec 7, 2022

LarryRuane commented at 4:36 pm on December 7, 2022: contributor

Just FYI, I was unable to reproduce the problem with bitcoin-cli -signet verifychain 4 1000. However, it did reproduce when I increased the number of blocks to 5000. I’ll review this PR soon.

hernanmarino commented at 1:43 am on December 8, 2022: contributor

tested ACK , everything running as expected.

achow101 commented at 8:03 pm on January 5, 2023: member

ACK a1c83166f33d44a0909d8789d3a4bc8b2539842e

in src/node/chainstate.cpp:173 in e7dfc74340 outdated

172-                    options.check_blocks)) {
173+            VerifyDBResult result = CVerifyDB().VerifyDB(
174+                *chainstate, chainman.GetConsensus(), chainstate->CoinsDB(),
175+                options.check_level,
176+                options.check_blocks);
177+            if (result == VerifyDBResult::ERROR_CORRUPTED_BLOCK_DB) {

maflcko commented at 12:32 pm on January 6, 2023:

e7dfc743406bfa0cac94c640dd5eaeac4364c990: Should be switch-case to avoid missing an error value?

mzumsande commented at 8:54 pm on January 19, 2023:

changed to use switch.

in src/validation.h:356 in e7dfc74340 outdated

352 class CVerifyDB {
353 public:
354     CVerifyDB();
355     ~CVerifyDB();
356-    bool VerifyDB(
357+    VerifyDBResult VerifyDB(

maflcko commented at 12:33 pm on January 6, 2023:

e7dfc743406bfa0cac94c640dd5eaeac4364c990: should be nodiscard?

mzumsande commented at 8:54 pm on January 19, 2023:

done

in src/init.cpp:1505 in 42402bffda outdated

1437@@ -1438,6 +1438,7 @@ bool AppInitMain(NodeContext& node, interfaces::BlockAndHeaderTipInfo* tip_info)
1438         options.prune = node::fPruneMode;
1439         options.check_blocks = args.GetIntArg("-checkblocks", DEFAULT_CHECKBLOCKS);
1440         options.check_level = args.GetIntArg("-checklevel", DEFAULT_CHECKLEVEL);
1441+        options.fail_on_insufficient_dbcache = args.IsArgSet("-checkblocks") || args.IsArgSet("-checklevel");

maflcko commented at 12:39 pm on January 6, 2023:

42402bffda6643346cb2b51c9e85b389f3d19068: Any reason for this bool? The DEFAULT_CHECKLEVEL is 3, presumably because 4 would almost never work anyway. And with 3 the check can’t fail due to insufficient cache. Seems better to remove this bool and “replace” it with true?

maflcko commented at 1:05 pm on January 6, 2023:

Ah, I see previously insufficient cache on level 3 would silently pass, but in this pull you changed it to an error

maflcko commented at 1:33 pm on January 6, 2023:

I wonder if this requires a release note, or alternatively if the patch would be smaller and easier to review if it only fixed the level 4 issue and left level 3 as-is for now?

mzumsande commented at 9:04 pm on January 19, 2023:

I added a release note, for the rest see the top-level comment below.

in src/node/chainstate.h:43 in 42402bffda outdated

35@@ -35,7 +36,11 @@ struct ChainstateLoadOptions {
36 //! case, and treat other cases as errors. More complex applications may want to
37 //! try reindexing in the generic failure case, and pass an interrupt callback
38 //! and exit cleanly in the interrupted case.
39-enum class ChainstateLoadStatus { SUCCESS, FAILURE, FAILURE_INCOMPATIBLE_DB, INTERRUPTED };
40+enum class ChainstateLoadStatus { SUCCESS,
41+                                  FAILURE,
42+                                  FAILURE_INCOMPATIBLE_DB,
43+                                  INTERRUPTED,
44+                                  FAILURE_INSUFFICIENT_DBCACHE };

maflcko commented at 12:45 pm on January 6, 2023:

42402bffda6643346cb2b51c9e85b389f3d19068 nit: Maybe order this before/after FAILURE_INCOMPATIBLE_DB to group related things into one section?

mzumsande commented at 8:54 pm on January 19, 2023:

done

in src/validation.h:349 in 42402bffda outdated

345@@ -346,6 +346,7 @@ arith_uint256 CalculateHeadersWork(const std::vector<CBlockHeader>& headers);
346 enum class VerifyDBResult {
347     SUCCESS,
348     ERROR_CORRUPTED_BLOCK_DB,
349+    ERROR_INSUFFICIENT_CACHE

maflcko commented at 12:46 pm on January 6, 2023:

42402bffda6643346cb2b51c9e85b389f3d19068 nit : missing trailing ,?

in src/validation.cpp:4055 in 46ec70affa outdated

4061     if (pindexFailure) {
4062         return error("VerifyDB(): *** coin database inconsistencies found (last %i blocks, %i good transactions before that)\n", chainstate.m_chain.Height() - pindexFailure->nHeight + 1, nGoodTransactions);
4063     }
4064-
4065+    if (skipped_l3_checks) {
4066+        LogPrintf("VerifyDB(): Skipped verification of level >=3 (insufficient database cache size). Consider increasing -dbcache.\n");

maflcko commented at 12:51 pm on January 6, 2023:

nit 46ec70affaf6ea9d33a9c403b605c0fb5a0c1d6c: No need for the function name in newly added log message, since -logsourcelocations exists.

mzumsande commented at 8:55 pm on January 19, 2023:

removed the function name.

in src/validation.cpp:4018 in e7dfc74340 outdated

4016         }
4017         // check level 1: verify block validity
4018         if (nCheckLevel >= 1 && !CheckBlock(block, state, consensus_params)) {
4019-            return error("%s: *** found bad block at %d, hash=%s (%s)\n", __func__,
4020-                         pindex->nHeight, pindex->GetBlockHash().ToString(), state.ToString());
4021+            LogPrintf("%s: *** found bad block at %d, hash=%s (%s)\n", __func__,

maflcko commented at 12:54 pm on January 6, 2023:

nit in e7dfc743406bfa0cac94c640dd5eaeac4364c990: (here and elsewhere)

When changing this from error, which included ERROR: in the log message, it could make sense to keep some kind of mention of “error” and instead remove the function name, which the user can already inject via -logsourcelocations.

mzumsande commented at 8:57 pm on January 19, 2023:

Changed the logs to use “Verification error: (…)” everywhere.

maflcko approved

maflcko commented at 12:54 pm on January 6, 2023: member

review ACK a1c83166f33d44a0909d8789d3a4bc8b2539842e 💁

Signature:

 0-----BEGIN PGP SIGNED MESSAGE-----
 1Hash: SHA512
 2
 3review ACK a1c83166f33d44a0909d8789d3a4bc8b2539842e 💁
 4-----BEGIN PGP SIGNATURE-----
 5
 6iQGzBAEBCgAdFiEE+rVPoUahrI9sLGYTzit1aX5ppUgFAlwqrYAACgkQzit1aX5p
 7pUh5hgv9Eu0s1Ko/vpJoWfVuakYVEU7HmFMAqGM+iJtFO+eWSciUcfyMdMY+Pi7L
 8rS76o5lIRufk5x6CE7PaeOlxpfbMbKy7AEj13ps4cJiXEtFw/QPW4IhfGxgbxp8e
 9z7GBk7R9UzRhDYz3DF3MNp5M4m3xvQ/fQb2VlQKtjSgQ65vD4c1oLLhp48bMj/+B
10/QNVUOw0L6AsSI6EDjp3SWviDtfXyMxQiCpmkS1t+iM5rAuVXsJVfSUldTP5V6SP
11QFa5yNoomUIYXVwAOs1dHwj2G8r15r/wzZH8ucLz2JbGYiTsGgJszUhmrF1SLJlD
12cTGZnw4/CI9bbiRKQj+Cbp/bZiwwYqe972w7OBugWlqp8YM5xYAcrjVRFUHzn15B
13CvW6+LGE1QMQZSPRdjkea0F48CtxJ43WD8udtDNtor4Ehh7Lwx5BjQ3lhIsWa3Gp
14LejMpwMO2ceG8TQaibc80ARA/ahg2YQpqyoZW+KJDMzqgTvTKJaBn0fq07j1RzEu
15UodOx8e6
16=Jqoz
17-----END PGP SIGNATURE-----

in src/validation.cpp:4082 in a1c83166f3 outdated

3985@@ -3986,15 +3986,15 @@ VerifyDBResult CVerifyDB::VerifyDB(
3986     BlockValidationState state;

maflcko commented at 1:26 pm on January 6, 2023:

nit in a1c83166f33d44a0909d8789d3a4bc8b2539842e: Since this commit is a fixup (https://github.com/bitcoin/bitcoin/pull/25574#discussion_r985851229) to the first commit, it can be re-ordered right after the first commit, if you re-touch.

mzumsande commented at 8:57 pm on January 19, 2023:

done

maflcko commented at 1:33 pm on January 6, 2023: member

left more comments (feel free to ignore)

mzumsande referenced this in commit a96f7cb551 on Jan 19, 2023

mzumsande force-pushed on Jan 19, 2023

mzumsande commented at 9:03 pm on January 19, 2023: contributor

a1c8316 to a96f7cb: Addressed feedback by @MarcoFalke .

I wonder if this requires a release note, or alternatively if the patch would be smaller and easier to review if it only fixed the level 4 issue and left level 3 as-is for now?

I still think that both parts make sense - fixing the assert fail, and changing the error handling to inform the user that the desired checks were not executed in the case of an insufficient cache instead of continuing silently.

But if reviewers would prefer it, I could split this into two parts: Reduce this PR to the first two commits (or maybe just the first), and then have a follow-up PR for the rest? Opinions?

fanquake commented at 10:54 am on January 20, 2023: member

I’m in favor of this change as-is. I’d rather we start returning errors / fail to startup, and let the user know that they are requesting something impossible given their system, than continue to fail silently/not perform the requested checks.

I think highlighting this in a release note is ok, and if some users have to modify their .conf files/runtime options, because their previously set arguments weren’t actually acheiving anything (silent fail), that is also fine.

maflcko commented at 12:40 pm on January 20, 2023: member

because their previously set arguments weren’t actually acheiving anything (silent fail)

No, previously it was a silent pass on verifychain level 3. This pull changes it to the same type of fail (boolean value false) that would be occurring when the user ran into disk corruption. Not sure how user friendly that is. I am starting to think that if we want to return more error types from the rpc, it might be better to not cast every possible type into a boolean value.

fanquake commented at 1:16 pm on January 20, 2023: member

No, previously it was a silent pass on verifychain level 3.

Right, I misspoke, but I’d also consider it a “fail” for us to silently pass, but not actually do anything, if a user tries to perform a verification operation. I’m not sure why that’s something we should continue to support, as opposed to telling the user it’s not possible. In the worst case, at least it’d start exposing to users that calls they thought were previously doing something / meant something, actually don’t.

I am starting to think that if we want to return more error types from the rpc, it might be better to not cast every possible type into a boolean value.

Yea, a more explanatory error would be better as opposed to false.

maflcko commented at 1:24 pm on January 20, 2023: member

Yea, a more explanatory error would be better as opposed to false.

That’s a breaking RPC change, because a call that previously returned true now returns false (or an error message). If the RPC interface is broken, it appears more user-friendly to do only once. (Again, not asking the author to do here, but including the breaking commit here could cause breaking changes to be split over several releases.)

fanquake commented at 1:32 pm on January 20, 2023: member

That’s a breaking RPC change, because a call that previously returned true now returns false (or an error message).

I think breaking the RPC would be fine, given the currently returned result is potentially meaningless/unreliable. I’m wondering how much usage verifychain would actually get in the wild.

mzumsande commented at 4:17 pm on January 20, 2023: contributor

That’s a breaking RPC change, because a call that previously returned true now returns false (or an error message).

The RPC doc for verifychain says:

0Verifies blockchain database.
1(...)
2Result: 
3true|false    (boolean) Verified or not

If the check didn’t finish, the blockchain database was not verified, so the documentation is more in line with the behavior after this change than with the current behavior.

DrahtBot added the label Needs rebase on Jan 27, 2023

mzumsande force-pushed on Jan 31, 2023

mzumsande referenced this in commit 13c076652e on Jan 31, 2023

mzumsande commented at 3:59 pm on January 31, 2023: contributor

To make some progress, I decided to split this in two: I will soon open another PR just for the assertion error fix (would be nice to at least have this fix in 25.0 imo) and put this PR into draft / reopen it after that other PR gets merged.

[Edit]: See #27009

mzumsande marked this as a draft on Jan 31, 2023

DrahtBot removed the label Needs rebase on Jan 31, 2023

fanquake referenced this in commit 8f4ae65818 on Feb 5, 2023

maflcko removed this from the milestone 25.0 on Feb 6, 2023

mzumsande referenced this in commit f5724d1887 on Feb 6, 2023

mzumsande force-pushed on Feb 6, 2023

mzumsande commented at 9:17 pm on February 6, 2023: contributor

Rebased and put out of draft.

In the discussion of #27009, the issue of checks being left unfinished due to no more data being available in pruning mode came up:

How is logging a warning for the not-enough-memory case different from logging a warning for the not-enough-storage case (pruning)? I think the warning can be displayed more prominently in a follow-up, but I think doing the same for similar cases seems fine. (https://github.com/bitcoin/bitcoin/pull/27009#issuecomment-1418721284)

So the question is should the behavior be analogous in the case where the checks are left uncompleted due to pruning? That is, should we both abort init in this case (if -checkblocks and -checklevel were overwritten by the user) and also return false in the RPC? (@john-moffett @MarcoFalke ).

I kind of think that there is a small difference between the two cases: If it’s due to -dbcache, the query makes sense and the user can react by increasing their dbcache, with pruning it might make sense to handle this case gracefully, e.g. by not aborting init.

mzumsande marked this as ready for review on Feb 6, 2023

john-moffett commented at 9:38 pm on February 6, 2023: contributor

should we both abort init in this case (if -checkblocks and -checklevel were overwritten by the user)

It’s a close call for me. Given that the “prune failure” is unlikely to occur except on -checkblocks pretty substantially deep (at least 288, right?), I think it probably makes more sense to abort, since presumably they have a reason for it to be that deep. I suppose it also should be contingent on only having -checkblocks set.

Again, though, it’s a close call. I’d be okay with just a more detailed warning (eg - last n blocks requested to be checked, but only m are available due to pruning).

and also return false in the RPC?

I feel pretty strongly that we should, assuming we keep the boolean result, which I’m okay with. I’d also be okay if it were changed to a more expressive result, but maybe it doesn’t need the additional complexity.

mzumsande referenced this in commit 080f83e43d on Feb 13, 2023

mzumsande force-pushed on Feb 13, 2023

mzumsande commented at 9:07 pm on February 13, 2023: contributor

f5724d1 to 080f83e:

I added a commit to change the make the RPC return false in the case of unavailable data and improved the error messages. I left init behavior unchanged in this case (no aborts).

john-moffett commented at 2:23 pm on February 14, 2023: contributor

ACK https://github.com/bitcoin/bitcoin/commit/080f83e43ddc1fd2ddc57f6590b9166a373d38c2 apart from the incidental test failure, which you’ve probably already caught:

0diff --git a/test/functional/feature_pruning.py b/test/functional/feature_pruning.py
1index 664ed779db2..03f5f2c8037 100755
2--- a/test/functional/feature_pruning.py
3+++ b/test/functional/feature_pruning.py
4@@ -226 +226 @@ class PruneTest(BitcoinTestFramework):
5-        with self.nodes[2].assert_debug_log(expected_msgs=['block verification stopping at height', '(pruning, no data)']):
6+        with self.nodes[2].assert_debug_log(expected_msgs=['block verification stopping at height', '(no data)']):

DrahtBot requested review from achow101 on Feb 14, 2023

DrahtBot requested review from fanquake on Feb 14, 2023

DrahtBot requested review from maflcko on Feb 14, 2023

mzumsande referenced this in commit 42b192f0cb on Feb 14, 2023

mzumsande force-pushed on Feb 14, 2023

mzumsande commented at 3:50 pm on February 14, 2023: contributor

which you’ve probably already caught

I hadn’t, thanks for noticing! Fixed.

john-moffett approved

john-moffett commented at 5:05 pm on February 14, 2023: contributor

Re-ACK 42b192f0cbf9c04da111145c921344b0881b3ce3

in test/functional/feature_pruning.py:227 in 65067ee3d9 outdated

222@@ -223,7 +223,7 @@ def reorg_test(self):
223     def reorg_back(self):
224         # Verify that a block on the old main chain fork has been pruned away
225         assert_raises_rpc_error(-1, "Block not available (pruned data)", self.nodes[2].getblock, self.forkhash)
226-        with self.nodes[2].assert_debug_log(expected_msgs=['block verification stopping at height', '(pruning, no data)']):
227+        with self.nodes[2].assert_debug_log(expected_msgs=['block verification stopping at height', '(no data)']):
228             self.nodes[2].verifychain(checklevel=4, nblocks=0)

maflcko commented at 1:57 pm on February 15, 2023:

nit in 65067ee3d9730b9a121ed36d6a720cc7530a5d77: Could check that the return value is now false, instead of true?

mzumsande commented at 10:43 pm on February 16, 2023:

done

in src/rpc/blockchain.cpp:1113 in cf307244db outdated

1109@@ -1110,7 +1110,7 @@ static RPCHelpMan verifychain()
1110                     {"nblocks", RPCArg::Type::NUM, RPCArg::DefaultHint{strprintf("%d, 0=all", DEFAULT_CHECKBLOCKS)}, "The number of blocks to check."},
1111                 },
1112                 RPCResult{
1113-                    RPCResult::Type::BOOL, "", "Verified or not"},
1114+                    RPCResult::Type::BOOL, "", "Verification finished successfully. If false, check debug.log for reason."},

maflcko commented at 1:58 pm on February 15, 2023:

nit in cf307244db97e7b9e29a3d0ff948a6fa7877b548: In the future it could make sense to return the error right away for better UX? But would probably be too much for this pull here? :man_shrugging:

mzumsande commented at 10:45 pm on February 16, 2023:

That would break the existing API though - there might be users out there who’d need to adjust automated scripts if -verifychain returned a more complicated JSON object instead of a bool. I think I’d ACK a pull that does that, but would prefer not to include it here unless people really want it.

in src/node/chainstate.h:43 in cf307244db outdated

35@@ -35,7 +36,12 @@ struct ChainstateLoadOptions {
36 //! case, and treat other cases as errors. More complex applications may want to
37 //! try reindexing in the generic failure case, and pass an interrupt callback
38 //! and exit cleanly in the interrupted case.
39-enum class ChainstateLoadStatus { SUCCESS, FAILURE, FAILURE_INCOMPATIBLE_DB, INTERRUPTED };
40+enum class ChainstateLoadStatus { SUCCESS,
41+                                  FAILURE,
42+                                  FAILURE_INCOMPATIBLE_DB,
43+                                  FAILURE_INSUFFICIENT_DBCACHE,
44+                                  INTERRUPTED,

maflcko commented at 1:59 pm on February 15, 2023:

nit in cf307244db97e7b9e29a3d0ff948a6fa7877b548, if you retouch: clang-format?

 0diff --git a/src/node/chainstate.h b/src/node/chainstate.h
 1index db8b4f945e..1e885a22f1 100644
 2--- a/src/node/chainstate.h
 3+++ b/src/node/chainstate.h
 4@@ -36,11 +36,12 @@ struct ChainstateLoadOptions {
 5 //! case, and treat other cases as errors. More complex applications may want to
 6 //! try reindexing in the generic failure case, and pass an interrupt callback
 7 //! and exit cleanly in the interrupted case.
 8-enum class ChainstateLoadStatus { SUCCESS,
 9-                                  FAILURE,
10-                                  FAILURE_INCOMPATIBLE_DB,
11-                                  FAILURE_INSUFFICIENT_DBCACHE,
12-                                  INTERRUPTED,
13+enum class ChainstateLoadStatus {
14+    SUCCESS,
15+    FAILURE,
16+    FAILURE_INCOMPATIBLE_DB,
17+    FAILURE_INSUFFICIENT_DBCACHE,
18+    INTERRUPTED,
19 };
20 
21 //! Chainstate load status code and optional error string.

mzumsande commented at 10:46 pm on February 16, 2023:

fixed, though my local clang-format didn’t complain before.

in doc/release-notes-25574.md:6 in 42b192f0cb outdated

0@@ -0,0 +1,12 @@
1+Updated settings
2+----------------
3+
4+If the `-checkblocks` or `-checklevel` options are explicitly provided by the
5+user, but the verification checks cannot be completed due to an insufficient
6+dbcache, bitcoind will now return an error at startup. (#25574)

maflcko commented at 2:01 pm on February 15, 2023:

nit in 42b192f0cbf9c04da111145c921344b0881b3ce3:

0dbcache, Bitcoin Core will now return an error at startup. (#25574)

(holds for bitcoin-qt as well)

mzumsande commented at 10:46 pm on February 16, 2023:

done

maflcko approved

maflcko commented at 2:03 pm on February 15, 2023: member

Left some non-blocking nits. Please let us know if you want to get this merged or address them.

review ACK 42b192f0cbf9c04da111145c921344b0881b3ce3 🗽

Signature:

 0-----BEGIN PGP SIGNED MESSAGE-----
 1Hash: SHA512
 2
 3review ACK 42b192f0cbf9c04da111145c921344b0881b3ce3 🗽
 4-----BEGIN PGP SIGNATURE-----
 5
 6iQGzBAEBCgAdFiEE+rVPoUahrI9sLGYTzit1aX5ppUgFAlwqrYAACgkQzit1aX5p
 7pUifdwwAvc/JCJeayQbrEGp/U6K39POo5P/O9usm+J6g4ljlFy6hfoqnEjhvDbo6
 8rEfXUf9ZlxR466QmiI2/6+2g9IUmPlrNB3vwD8MM3XJulYtsSfFtFarUwf6Z4Qip
 9eQjVmaC69aJJ0/B+ZGMsj5fLF6+uA3DPQxlS5+ceGFn2Dgqttmas33hurQMQbNIu
100hUD0NwZSeHeCrdzlAyllIJDSouMvjHkwmifIeyt/St0z5F6wo4z6QqkGWQkPDGK
11Do+rUvDFSej2BeXW/LDKboHMBdph8YtPp4yvoDKnbthNfiRv+N2u4a7rQnbMtrLV
12oFsNSc4H74lYsE9lCLRzrK/qDIDrXXWL5/f1GRfMSVSNQphNOomM28V4yBiPeCR7
13T4v4G+WcsMI+lK9++dWk2J6J4d9eM5W09z/OJcGG271ARjdM38VppXxJzYQ9SPGw
143DqZfaGO8LEin5NOzT8i/NYOGdIyVCiu6WsD7PhFPa4PKimDXi5Ve+Ns1Hi1wYQ0
15rBqhvH0A
16=RQBu
17-----END PGP SIGNATURE-----

DrahtBot requested review from maflcko on Feb 15, 2023

mzumsande commented at 3:22 pm on February 15, 2023: contributor

Please let us know if you want to get this merged or address them.

I’ll address the comments later this week!

in src/validation.cpp:4157 in cf307244db outdated

4153@@ -4154,13 +4154,14 @@ VerifyDBResult CVerifyDB::VerifyDB(
4154     }
4155     if (skipped_l3_checks) {
4156         LogPrintf("Skipped verification of level >=3 (insufficient database cache size). Consider increasing -dbcache.\n");
4157+        return VerifyDBResult::ERROR_INSUFFICIENT_CACHE;

ryanofsky commented at 8:41 pm on February 15, 2023:

In commit “init, validation: Improve handling if VerifyDB() fails due to insufficient dbcache” (cf307244db97e7b9e29a3d0ff948a6fa7877b548)

This commit seems to change behavior by no longer logging No coin database inconsistencies in last %i blocks in the case where skipped_l3_checks is true. I think it would be still be good to log the number of blocks checked and that no inconsistencies were found. Perhaps the easiest way to do that would be to revert the other changes to this function in this commit and just return skipped_l3_checks ? INSUFFICIENT_CACHE : SUCCESS at the end.

mzumsande commented at 10:49 pm on February 16, 2023:

Done - decided to use if instead of ternary because skipped_no_block_data is treated similarly. I decided to give skipped_l3_checks precedence - so if in addition to this, skipped_no_block_data is also true, we’d report VerifyDBResult::SKIPPED_L3_CHECKS (which influences whether an InitError might be thrown).

ryanofsky commented at 3:46 pm on February 17, 2023:

re: #25574 (review)

Nice, it’s good that returning in one place makes it easier to see what the precedence is, or change what’s returned in the future.

in src/validation.h:356 in 42b192f0cb outdated

348@@ -349,12 +349,19 @@ bool HasValidProofOfWork(const std::vector<CBlockHeader>& headers, const Consens
349 /** Return the sum of the work on a given set of headers */
350 arith_uint256 CalculateHeadersWork(const std::vector<CBlockHeader>& headers);
351 
352+enum class VerifyDBResult {
353+    SUCCESS,
354+    ERROR_CORRUPTED_BLOCK_DB,
355+    ERROR_INSUFFICIENT_CACHE,
356+    INSUFFICIENT_BLOCK_DATA,

ryanofsky commented at 2:55 pm on February 16, 2023:

42b192f0cbf9c04da111145c921344b0881b3ce3

Would suggest dropping two ERROR_ prefixes here, because reason for inconsistent prefixes is not very clear, and the decision about whether to treat different conditions as errors should depend on the caller, not the implementation.

I think a simple { SUCCESS, CORRUPTED_BLOCK_DB, INSUFFICIENT_CACHE, INSUFFICIENT_BLOCK_DATA } result would suffice.

You could also go further and rename INSUFFICIENT_CACHE to SKIPPED_L3_CHECKS and rename INSUFFICIENT_BLOCK_DATA to SKIPPED_MISSING_BLOCKS so the check result plainly reflects the status of the check, not conditions leading to the status of the check. That would look like { SUCCESS, INTERRUPTED, SKIPPED_MISSING_BLOCKS, SKIPPED_L3_CHECKS, CORRUPTED_BLOCK_DB }

mzumsande commented at 10:50 pm on February 16, 2023:

done, using the second suggestion.

in src/test/util/setup_common.cpp:221 in cf307244db outdated

217@@ -218,6 +218,7 @@ void TestingSetup::LoadVerifyActivateChainstate()
218     options.prune = chainman.m_blockman.IsPruneMode();
219     options.check_blocks = m_args.GetIntArg("-checkblocks", DEFAULT_CHECKBLOCKS);
220     options.check_level = m_args.GetIntArg("-checklevel", DEFAULT_CHECKLEVEL);
221+    options.fail_on_insufficient_dbcache = false;

ryanofsky commented at 3:07 pm on February 16, 2023:

In commit “init, validation: Improve handling if VerifyDB() fails due to insufficient dbcache” (cf307244db97e7b9e29a3d0ff948a6fa7877b548)

This block of code seems to duplicate a block of code in AppInitMain, but in the AppInitMain block this PR is setting fail_on_insufficient_dbcache to args.IsArgSet("-checkblocks") || args.IsArgSet("-checklevel"), while here it is being set to false. Probably both blocks of code should be deduplicated and call a shared function later. But for now it would be better to avoid creating unnecessary differences in the two blocks of code. Or if there is a reason test code is doing something different, there should be a code comment explaining why.

maflcko commented at 3:56 pm on February 16, 2023:

Maybe just drop the hunk? Shouldn’t matter either way :man_shrugging:

mzumsande commented at 10:52 pm on February 16, 2023:

changed to use same setting as in AppInitMain.

in src/validation.cpp:4149 in 422127b696 outdated

4145@@ -4142,14 +4146,16 @@ bool CVerifyDB::VerifyDB(
4146                 skipped_l3_checks = true;
4147             }
4148         }
4149-        if (ShutdownRequested()) return true;
4150+        if (ShutdownRequested()) return VerifyDBResult::SUCCESS;

ryanofsky commented at 3:11 pm on February 16, 2023:

In commit “validation: Change return value of VerifyDB to enum type” (422127b696f390e7cd34e897e7d74f09e3dae2cb)

In the interest of preventing future bugs where shutdown could be interpreted as success, it seems like it would be less misleading (and easy) to return a VerifyDBResult::INTERRUPTED error code here, analogous to ChainstateLoadStatus::INTERRUPTED.

mzumsande commented at 10:53 pm on February 16, 2023:

Good point! I added a commit to do this and adjusted the release notes (since this also changes the behavior of the -verifydb RPC)

fanquake added this to the milestone 25.0 on Feb 16, 2023

ryanofsky approved

ryanofsky commented at 3:29 pm on February 16, 2023: contributor

Code review ACK 42b192f0cbf9c04da111145c921344b0881b3ce3 with some suggestions and bikeshedding (feel free to ignore)

in src/node/chainstate.h:28 in cf307244db outdated

24@@ -25,6 +25,7 @@ struct ChainstateLoadOptions {
25     bool reindex{false};
26     bool reindex_chainstate{false};
27     bool prune{false};
28+    bool fail_on_insufficient_dbcache{false};

ryanofsky commented at 3:36 pm on February 16, 2023:

In commit “init, validation: Improve handling if VerifyDB() fails due to insufficient dbcache” (cf307244db97e7b9e29a3d0ff948a6fa7877b548)

true might be a safer default for libbitcoinkernel. Also the name of this option ChainstateLoadOptions::fail_on_insufficient_dbcache seems a little misleading because it seems like it is referring to insuffcient dbcache for loading, not insufficient_dbcache for verification. Would maybe change it to ChainstateLoadOptions::require_full_verification with a comment that setting the option to false can allow using a smaller dbcache size.

mzumsande commented at 11:04 pm on February 16, 2023:

changed to ChainstateLoadOptions::fail_on_insufficient_dbcache also changed the default, although it’s never used because the bool is set during init.

I don’t understand the comment. require_full_verification is not an option the user can set, it’s value is determined by -checkblocks and -checklevel. So if a user wants to run with an extremely low dbcache, they should change those parameters (or just keep the default so that init will only warn).

ryanofsky commented at 4:03 pm on February 17, 2023:

re: #25574 (review)

Thanks for implementing the suggestion. This comment was not about bitcoind, but about code that uses libbitcoinkernel such as:

https://github.com/bitcoin/bitcoin/blob/fe1b3256888bd0e70d0c9655f565e139ec87b606/src/bitcoin-chainstate.cpp#L93-L96

Code like this has it’s own options and defaults, and is not aware of checkblocks or checklevel. It is just calling and using the LoadChainstate function directly. From the perspective of a LoadChainstate caller, I think fail_on_insufficient_dbcache could have been misleading because it sounds like it would allow loading with an insufficient dbcache, not just verifying with an insufficient dbcache. I do think in either case it wouldn’t be bad for the option to have a code comment, so I suggested one below.

validation: Change return value of VerifyDB to enum type

This does not change behavior. It is in preparation for
special handling of the case where VerifyDB doesn't finish
for various reasons, but doesn't fail.

6360b5302d

validation: return VerifyDBResult::INTERRUPTED if verification was interrupted

This means that the -verifydb RPC will now return false if it
cannot finish due to the node being shutdown.

d6f781f1cf

mzumsande referenced this in commit 8f4753a38f on Feb 16, 2023

mzumsande force-pushed on Feb 16, 2023

mzumsande renamed this:
~~validation: Improve error handling when VerifyDB fails due to insufficient dbcache~~
validation: Improve error handling when VerifyDB dosn't finish successfully
on Feb 16, 2023

init, validation: Improve handling if VerifyDB() fails due to insufficient dbcache

The rpc command verifychain now fails if the dbcache was not sufficient
to complete the verification at the specified level and depth.

In the same situation, the VerifyDB check during Init will now fail (and lead to
an early shutdown) if the user has explicitly specified -checkblocks or
-checklevel but the check couldn't be executed because of the limited
cache. If the user didn't change any of the two and is using the defaults, log a warning
but don't prevent the node from starting up.

0c7785bb25

validation: report if pruning prevents completion of verification

Now the verifychain RPC returns false if the checks didn't
finish because the blocks requested to be queried have been pruned.

57ef2a4812

doc: add release note for #25574 0af16e7134

mzumsande force-pushed on Feb 16, 2023

mzumsande commented at 11:17 pm on February 16, 2023: contributor

42b192f to 0af16e7:

Addressed comments by @MarcoFalke and @ryanofsky, thanks for the reviews! Also changed title and adjusted OP since this is no longer just about -dbcache-related error handling.

in src/node/chainstate.h:28 in 0c7785bb25 outdated

24@@ -25,6 +25,7 @@ struct ChainstateLoadOptions {
25     bool reindex{false};
26     bool reindex_chainstate{false};
27     bool prune{false};
28+    bool require_full_verification{true};

ryanofsky commented at 4:15 pm on February 17, 2023:

In commit “init, validation: Improve handling if VerifyDB() fails due to insufficient dbcache” (0c7785bb2540b69564104767d38342704230cbc2)

Might be worth adding a comment to explain why you would set the option. Maybe:

0//! Setting require_full_verification to true will require all checks at
1//! check_level (below) to succeed for loading to succeed. Setting it to
2//! false will skip checks if cache is not big enough to run them, so may be
3//! helpful for running with a small cache.

in src/validation.cpp:4109 in 6360b5302d outdated

4105@@ -4106,19 +4106,22 @@ bool CVerifyDB::VerifyDB(
4106         CBlock block;
4107         // check level 0: read from disk
4108         if (!ReadBlockFromDisk(block, pindex, consensus_params)) {
4109-            return error("VerifyDB(): *** ReadBlockFromDisk failed at %d, hash=%s", pindex->nHeight, pindex->GetBlockHash().ToString());
4110+            LogPrintf("Verification error: ReadBlockFromDisk failed at %d, hash=%s\n", pindex->nHeight, pindex->GetBlockHash().ToString());

ryanofsky commented at 4:21 pm on February 17, 2023:

In commit “validation: Change return value of VerifyDB to enum type” (6360b5302d2675788de5c4a28ea77d823f6d809e)

Commit message says this does not change behavior, but this is changing log prints slightly replacing VerifyDB(): prefix with Verification error:. This is probably a good change, but could be clarified in the commit message.

in src/node/chainstate.cpp:196 in d6f781f1cf outdated

192@@ -193,6 +193,7 @@ ChainstateLoadResult VerifyLoadedChainstate(ChainstateManager& chainman, const C
193                 options.check_blocks);
194             switch (result) {
195             case VerifyDBResult::SUCCESS:
196+            case VerifyDBResult::INTERRUPTED:

ryanofsky commented at 4:34 pm on February 17, 2023:

In commit “validation: return VerifyDBResult::INTERRUPTED if verification was interrupted” (d6f781f1cfcbc2c2ad5ee289a0642ed00386d013)

It would be less surprising to have VerifyDBResult::INTERRUPTED return ChainstateLoadStatus::INTERRUPTED than ChainstateLoadStatus::SUCCESS. Another potentially good side effect would be that it would avoid the caller printing a misleading load time if the load didn’t really succeed:

https://github.com/bitcoin/bitcoin/blob/fe1b3256888bd0e70d0c9655f565e139ec87b606/src/init.cpp#L1520-L1524

mzumsande commented at 10:35 pm on February 22, 2023:

Makes sense - I’ll open a small follow-up to address this in a few days.

ryanofsky approved

ryanofsky commented at 4:45 pm on February 17, 2023: contributor

Code review ACK 0af16e7134459e0820ab95d751093876c1ec4c6d. Only small suggested changes since the last review, like renaming some of the enum values. I did leave more suggestions, but they are not very important and could be followups

DrahtBot requested review from john-moffett on Feb 17, 2023

john-moffett approved

john-moffett commented at 9:52 pm on February 21, 2023: contributor

ACK 0af16e7134459e0820ab95d751093876c1ec4c6d

in src/validation.h:355 in d6f781f1cf outdated

351@@ -352,6 +352,7 @@ arith_uint256 CalculateHeadersWork(const std::vector<CBlockHeader>& headers);
352 enum class VerifyDBResult {
353     SUCCESS,
354     CORRUPTED_BLOCK_DB,
355+    INTERRUPTED,

maflcko commented at 11:44 am on February 22, 2023:

nit in d6f781f1cfcbc2c2ad5ee289a0642ed00386d013 (commit message), only if you retouch:

I think the rpc is called verifychain and not -verifydb?

maflcko approved

maflcko commented at 11:56 am on February 22, 2023: member

lgtm re-ACK 0af16e7134459e0820ab95d751093876c1ec4c6d 🎚

Signature:

 0-----BEGIN PGP SIGNED MESSAGE-----
 1Hash: SHA512
 2
 3lgtm re-ACK 0af16e7134459e0820ab95d751093876c1ec4c6d 🎚
 4-----BEGIN PGP SIGNATURE-----
 5
 6iQGzBAEBCgAdFiEE+rVPoUahrI9sLGYTzit1aX5ppUgFAlwqrYAACgkQzit1aX5p
 7pUgCEAwAl2HOYuqTfTHatbl1G6IC16Itmtb0chf3GhxESu4SIE7uNvMXIXVK2WG1
 8k5Sz9TeW2POSCwZnJtxdAzhNKwzN6Q79yJ0KL+6SOMxX7j4CaWun5b1kJf1xOlQx
 9gHBqBN1zLW65Wfh1L3qa4nzKiWwKdJJ2iUAUiatdJGLxElYIox98uTdq9Z3PuSSb
10Xu1ivXy/EdXu+nQMeogF5V+g/yZAdSKGYSgS2ldG8D7k8cvY5BxEM/0b1UAjYOrE
11gDKR7Ac7tG6sIzdfv+oY1vdjzRPbaATf2LoQiFgv0x0tPECKX+R19/g5UrU3DCZ0
121HSsj5rcuPJpy5YrL517v7K/XgUJlUhUsg6Xx7gn+jvu0qRrlhsFCSpv0XLzn+0J
13aIKCXWLTV+2bLcMcktl/0+c/iFpRiFHaO8q1E4ivBttoGf3cK8Jv1CFup/+yyPaK
14Ld8w3sZXEwuASxMEI03GbFKb1o4RMQojSkm9PaimfU3frbUFLTtUiHnw6X6SMjZ4
158KN4cKiS
16=q5XI
17-----END PGP SIGNATURE-----

achow101 commented at 7:10 pm on February 22, 2023: member

ACK 0af16e7134459e0820ab95d751093876c1ec4c6d

achow101 merged this on Feb 22, 2023

achow101 closed this on Feb 22, 2023

sidhujag referenced this in commit 51bb903325 on Feb 25, 2023

fanquake referenced this in commit 519ec2650e on Feb 28, 2023

sidhujag referenced this in commit b2ff0a045e on Feb 28, 2023

mzumsande deleted the branch on May 4, 2023

Fabcien referenced this in commit ed73e8a461 on Dec 7, 2023

Fabcien referenced this in commit 30388014c4 on Dec 7, 2023

Fabcien referenced this in commit e90d77d8a4 on Dec 7, 2023

Fabcien referenced this in commit f846659c07 on Dec 7, 2023

Fabcien referenced this in commit d6301c7a20 on Dec 8, 2023

bitcoin locked this on May 3, 2024

validation: Improve error handling when VerifyDB dosn’t finish successfully #25574

Reviews

Conflicts