Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

test: Added test to ensure log and failure happen when work is less than active chainstate #30105

Conversation

kevkevinpal
Copy link
Contributor

@kevkevinpal kevkevinpal commented May 15, 2024

This adds coverage to the ActivateSnapshot function asserting that when we try to use a snapshot with too little work done on it, using loadtxoutset. That this log and rpc error are thrown

log
[snapshot] activation failed - work does not exceed active chainstate
[snapshot] activation failed - population failed
rpc error
Unable to load UTXO snapshot

Adds coverage to this code https://github.com/bitcoin/bitcoin/blob/master/src/validation.cpp#L5659

@DrahtBot
Copy link
Contributor

DrahtBot commented May 15, 2024

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

Code Coverage

For detailed information about the code coverage, see the test coverage report.

Reviews

See the guideline for information on the review process.

Type Reviewers
ACK rkrux
Concept ACK tdb3

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:

  • #29996 (test: Assumeutxo: import snapshot in a node with a divergent chain by alfonsoromanz)
  • #29681 (test: loading assumeutxo snapshot start states by BrandonOdiwuor)

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.

@DrahtBot DrahtBot added the Tests label May 15, 2024
@kevkevinpal kevkevinpal force-pushed the assumeutxoExceedActiveChainstatelog branch 4 times, most recently from 641c0fa to de7ac86 Compare May 15, 2024 00:59
@DrahtBot
Copy link
Contributor

🚧 At least one of the CI tasks failed. Make sure to run all tests locally, according to the
documentation.

Possibly this is due to a silent merge conflict (the changes in this pull request being
incompatible with the current code in the target branch). If so, make sure to rebase on the latest
commit of the target branch.

Leave a comment here, if you need help tracking down a confusing failure.

Debug: https://github.com/bitcoin/bitcoin/runs/24977593545

Copy link
Contributor

@tdb3 tdb3 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

Thanks. It's great to add test coverage. Left a question.

@@ -237,6 +237,9 @@ def run_test(self):
# will allow us to test n1's sync-to-tip on top of a snapshot.
self.generate(n0, nblocks=100, sync_fun=self.no_op)

with n0.assert_debug_log(expected_msgs=["[snapshot] activation failed - work does not exceed active chainstate","[snapshot] activation failed - population failed"]):
Copy link
Contributor

@tdb3 tdb3 May 15, 2024

Choose a reason for hiding this comment

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

Made a temporary modification of a word in the expected message (of feature_assumeutxo.py to test that a mismatch would be caught (it was, as expected). Restored to original expected message then modified the message in validation.cpp. This mismatch was also detected (as expected)l.

LogPrintf("[snapshot] activation failed - work does not exceed active chainstate\n");

The default timeout for assert_debug_log() is 2 seconds. I haven't had a chance to dig deeper yet, but are we confident there isn't a potential timing issue with the message arriving into the debug log later than 2 seconds? (e.g. a late arrival potentially causing an intermittent test failure). I haven't encountered this, but only ran the tests a few times.

def assert_debug_log(self, expected_msgs, unexpected_msgs=None, timeout=2):

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Thanks for the review!

I think the timeout should be fine there is even a comment pointing out that we check the work twice because we want to fail fast
https://github.com/bitcoin/bitcoin/blob/master/src/validation.cpp#L5655-L5657

test/functional/feature_assumeutxo.py Show resolved Hide resolved
Copy link

@rkrux rkrux left a comment

Choose a reason for hiding this comment

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

Make successful, all functional tests also. Asked a question and provided a suggestion.

@kevkevinpal Should we get rid of this TODO on line 26 now?
https://github.com/bitcoin/bitcoin/blob/master/test/functional/feature_assumeutxo.py#L26

@@ -237,6 +237,9 @@ def run_test(self):
# will allow us to test n1's sync-to-tip on top of a snapshot.
self.generate(n0, nblocks=100, sync_fun=self.no_op)

with n0.assert_debug_log(expected_msgs=["[snapshot] activation failed - work does not exceed active chainstate","[snapshot] activation failed - population failed"]):
assert_raises_rpc_error(-32603, "Unable to load UTXO snapshot", n0.loadtxoutset, dump_output['path'])
Copy link

Choose a reason for hiding this comment

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

@kevkevinpal We are loading the snapshot of n0 in n0 itslelf? Should it not be loaded into n1?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Thank you for the review!

yes, we should be able to remove that TODO: (removed in ac1b0e3)

I used n0 instead of n1 because if we use n1 it will properly work because n1 is not synced up yet. So I used n0 to loadtxoutset of a chainstate which is certain to be older than its current chainstate

Copy link

Choose a reason for hiding this comment

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

I see, though it seemed unusual initially that we are loading a snapshot in the same node. But now that I think more about it - this can happen in a real world scenario as well, right? Eg: When the node is re-started after a long time and needs to catch up to the latest blocks.

…han active chainstate

Signed-off-by: kevkevinpal <oapallikunnel@gmail.com>
@kevkevinpal kevkevinpal force-pushed the assumeutxoExceedActiveChainstatelog branch from de7ac86 to ac1b0e3 Compare May 16, 2024 12:16
Copy link

@rkrux rkrux left a comment

Choose a reason for hiding this comment

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

tACK ac1b0e3

There's a lint error though here, but otherwise LGTM.

@DrahtBot DrahtBot requested a review from tdb3 May 16, 2024 12:29
@rkrux
Copy link

rkrux commented May 16, 2024

Just realised this is similar to this PR: #29428

@DrahtBot
Copy link
Contributor

🚧 At least one of the CI tasks failed. Make sure to run all tests locally, according to the
documentation.

Possibly this is due to a silent merge conflict (the changes in this pull request being
incompatible with the current code in the target branch). If so, make sure to rebase on the latest
commit of the target branch.

Leave a comment here, if you need help tracking down a confusing failure.

Debug: https://github.com/bitcoin/bitcoin/runs/25050589884

@kevkevinpal
Copy link
Contributor Author

Just realised this is similar to this PR: #29428

Oh nice I didnt see this, closing this now

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

4 participants