assumevalid: log every script validation state change

l0rinc commented at 5:14 am on July 15, 2025: contributor

The -assumevalid option skips script verification for a specified block and all its ancestors during Initial Block Download. Many new users are surprised when this suddenly slows their node to a halt. This commit adds a log message to clearly indicate when this optimization ends and full validation begins (and vice versa).

The behavior can easily be tested by adding this before the new log:

0    // TODO hack to enable/disable script checks based on block height for testing purposes
1         if (pindex->nHeight < 100) fScriptChecks = false;
2    else if (pindex->nHeight < 200) fScriptChecks = true;
3    else if (pindex->nHeight < 300) fScriptChecks = false;
4    else if (pindex->nHeight < 400) fScriptChecks = true;

and exercise the new code with:

0cmake -B build && cmake --build build && mkdir -p demo && build/bin/bitcoind -datadir=demo -stopatheight=500 | grep 'signature validation'

showing something like:

Disabling signature validations at block #1 (00000000839a8e6886ab5951d76f411475428afc90947ee320161bbf18eb6048).
Enabling signature validations at block #100 (000000007bc154e0fa7ea32218a72fe2c1bb9f86cf8c9ebf9a715ed27fdb229a).
Disabling signature validations at block #200 (000000008f1a7008320c16b8402b7f11e82951f44ca2663caf6860ab2eeef320).
Enabling signature validations at block #300 (0000000062b69e4a2c3312a5782d7798b0711e9ebac065cd5d19f946439f8609).

DrahtBot commented at 5:14 am on July 15, 2025: contributor

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

Code Coverage & Benchmarks

For details see: https://corecheck.dev/bitcoin/bitcoin/pulls/32975.

Reviews

See the guideline for information on the review process.

Type	Reviewers
ACK	achow101, ajtowns, davidgumberg
Concept ACK	hodlinator

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

Conflicts

No conflicts as of last run.

in src/validation.cpp:2604 in a4c0e6c9e8 outdated

2599@@ -2600,6 +2600,10 @@ bool Chainstate::ConnectBlock(const CBlock& block, BlockValidationState& state,
2600              Ticks<SecondsDouble>(m_chainman.time_forks),
2601              Ticks<MillisecondsDouble>(m_chainman.time_forks) / m_chainman.num_blocks_total);
2602 
2603+    if (fScriptChecks && pindex->pprev->GetBlockHash() == m_chainman.AssumedValidBlock()) {
2604+        LogInfo("Started signature validation at block %s.", block_hash.ToString());

maflcko commented at 6:33 am on July 15, 2025:

i don’t think this is correct. With -minimumchainwork=0 the two weeks worth of headers may be missing, and this log will never appear

l0rinc commented at 9:22 pm on July 15, 2025:

Thanks @maflcko - I couldn’t reproduce it with the previous version either (maybe I need more blocks or maybe doesn’t reproduce with -reindex reliably), but I have change the implementation to be closer to: “if script validation was turned off at the beginning and it just got enabled, log it once”. Let me know what you think.

l0rinc force-pushed on Jul 15, 2025

in src/validation.cpp:2607 in 9afcf118f0 outdated

2599@@ -2600,6 +2600,14 @@ bool Chainstate::ConnectBlock(const CBlock& block, BlockValidationState& state,
2600              Ticks<SecondsDouble>(m_chainman.time_forks),
2601              Ticks<MillisecondsDouble>(m_chainman.time_forks) / m_chainman.num_blocks_total);
2602 
2603+    {
2604+        static bool script_check_started{fScriptChecks}; // Only log if we start off with disabled script checks
2605+        if (fScriptChecks && !script_check_started) {
2606+            script_check_started = true;
2607+            LogInfo("Started signature validation at block %s.", block_hash.ToString());

maflcko commented at 7:47 am on July 16, 2025:

Not sure what the point is of logging this, when it doesn’t detect the case when the checks are enabled initially (due to the minchainwork being less than two weeks worth of headers on top of the av block) ? See also https://github.com/bitcoin/bitcoin/pull/31615

l0rinc commented at 2:45 pm on July 16, 2025:

Many users are surprised by the slowdowns that suddenly happen during IBD, this should clarify that. If this doesn’t work for some corner cases, I think that should be fine, it’s just meant to help explain the shift in IBD performance.

I can change it to include the case when script verification starts initially, but I explicitly meant this log to signal when the effect of assumevalid gets turned off, i.e. to explain “grinding to a halt” that many users were reporting.

See also #31615

yes, it’s the issue that I have reported almost a year ago. Can you explain why you think that’s related and how you’d like me to change this based on that?

l0rinc commented at 5:33 pm on July 16, 2025: contributor

Ran a reindex until 890k without -assumevalid to make sure it works for an actual IBD/reindex as well:

02025-07-16T04:43:03Z UpdateTip: new best=00000000000000000001b658dd1120e82e66d2790811f89ede9742ada3ed6d77 height=886157 version=0x22024000 log2_work=95.475345 tx=1161875261 date='2025-03-03T15:52:21Z' progress=0.955815 cache=4682.3MiB(34814627txo)
12025-07-16T04:43:03Z Started signature validation at block 000000000000000000022614dc170eadb7b544824cbcdb0732bdeca42839aa37.
22025-07-16T04:43:04Z UpdateTip: new best=000000000000000000022614dc170eadb7b544824cbcdb0732bdeca42839aa37 height=886158 version=0x24c3a000 log2_work=95.475357 tx=1161878233 date='2025-03-03T15:56:42Z' progress=0.955816 cache=4682.3MiB(34814461txo)

l0rinc renamed this:
~~[IBD] log start of script validation past `assumevalid` block~~
[IBD] log the start of script validation past `assumevalid` block
on Jul 21, 2025

in src/validation.cpp:2605 in 9afcf118f0 outdated

2599@@ -2600,6 +2600,14 @@ bool Chainstate::ConnectBlock(const CBlock& block, BlockValidationState& state,
2600              Ticks<SecondsDouble>(m_chainman.time_forks),
2601              Ticks<MillisecondsDouble>(m_chainman.time_forks) / m_chainman.num_blocks_total);
2602 
2603+    {
2604+        static bool script_check_started{fScriptChecks}; // Only log if we start off with disabled script checks
2605+        if (fScriptChecks && !script_check_started) {

luke-jr commented at 0:13 am on July 29, 2025:

fScriptChecks isn’t a one-way gate. It would be very confusing to see “Started validation” due to a block not an ancestor of the assumevalid block, and then have validation of the real chain continue without validation and no log informing the user it’s being skipped again.

l0rinc commented at 1:55 am on July 29, 2025:

Thanks, updated the code to log any such change, let me know what you think!

luke-jr changes_requested

l0rinc force-pushed on Jul 29, 2025

l0rinc requested review from luke-jr on Jul 29, 2025

l0rinc requested review from maflcko on Jul 29, 2025

l0rinc renamed this:
~~[IBD] log the start of script validation past `assumevalid` block~~
assumevalid: log every script validation state change
on Jul 29, 2025

in src/validation.cpp:2604 in bde37e49dd outdated

2599@@ -2600,6 +2600,13 @@ bool Chainstate::ConnectBlock(const CBlock& block, BlockValidationState& state,
2600              Ticks<SecondsDouble>(m_chainman.time_forks),
2601              Ticks<MillisecondsDouble>(m_chainman.time_forks) / m_chainman.num_blocks_total);
2602 
2603+    if (static std::optional<bool> prev{}; fScriptChecks != prev) {
2604+        if (prev.has_value()) {

luke-jr commented at 4:10 am on July 29, 2025:

Probably fine/better to log this the first time through for clarity.

l0rinc commented at 4:45 am on July 29, 2025:

I don’t mind doing that, but we’re already either logging:

Assuming ancestors of block 00000000000000000001b658dd1120e82e66d2790811f89ede9742ada3ed6d77 have valid signatures.

or

Validating signatures for all blocks.

Wouldn’t it be redundant to always state if we’re validating scripts not just when the state changes?

Edit: pushed, leaving https://github.com/bitcoin/bitcoin/blob/master/src/node/chainstate.cpp#L150 for now

l0rinc commented at 6:34 am on September 8, 2025:

After some usage I agree that we should always just log it, it’s not intuitive to see:

02025-09-08T05:58:02Z Assuming ancestors of block 00000000000000000000611fd22f2df7c8fbd0688745c3a6c3bb5109cc2a12cb have valid signatures.
1...
22025-09-08T05:58:39Z Enabling signature validations at block [#738580](/bitcoin-bitcoin/738580/) (00000000000000000003f5264e65db4f2db7ab624c19e8a27403df3ca069e8ab).

where 00000000000000000000611fd22f2df7c8fbd0688745c3a6c3bb5109cc2a12cb is 912683 and yet sigature verification was enabled for 738580 anyway for some reason (I will have to investigate why exactly).

Opened https://github.com/bitcoin/bitcoin/pull/33336

l0rinc force-pushed on Jul 29, 2025

l0rinc requested review from luke-jr on Jul 29, 2025

l0rinc force-pushed on Jul 29, 2025

DrahtBot added the label CI failed on Jul 29, 2025

l0rinc force-pushed on Jul 29, 2025

in test/functional/feature_assumevalid.py:161 in f008b50033 outdated

156@@ -157,8 +157,9 @@ def run_test(self):
157         # Send all blocks to node1. All blocks will be accepted.
158         for i in range(2202):
159             p2p1.send_without_ping(msg_block(self.blocks[i]))
160-        # Syncing 2200 blocks can take a while on slow systems. Give it plenty of time to sync.
161-        p2p1.sync_with_ping(timeout=960)
162+        with self.nodes[1].assert_debug_log(expected_msgs=['Disabling signature validations at block #1', 'Enabling signature validations at block #103']):
163+            # Syncing 2200 blocks can take a while on slow systems. Give it plenty of time to sync.
164+            p2p1.sync_with_ping(timeout=960)

maflcko commented at 6:58 am on July 29, 2025:

This is racy and will fail CI. You can reproduce this by adding a time.sleep(9) before the with?

l0rinc commented at 7:00 am on July 29, 2025:

Thanks, was wondering why it’s failing on some platforms. Do you have a better alternative?

maflcko commented at 7:03 am on July 29, 2025:

The with scope will have to be increased, if you want to keep it

l0rinc commented at 7:12 am on July 29, 2025:

Makes sense, thanks for the pointer!

l0rinc force-pushed on Jul 29, 2025

DrahtBot removed the label CI failed on Jul 29, 2025

in test/functional/feature_assumevalid.py:156 in 884a9114dc outdated

161-        p2p1.sync_with_ping(timeout=960)
162-        assert_equal(self.nodes[1].getblock(self.nodes[1].getbestblockhash())['height'], 2202)
163+        with self.nodes[1].assert_debug_log(expected_msgs=['Disabling signature validations at block #1', 'Enabling signature validations at block #103']):
164+            p2p1 = self.nodes[1].add_p2p_connection(BaseNode())
165+            p2p1.send_header_for_blocks(self.blocks[0:2000])
166+            p2p1.send_header_for_blocks(self.blocks[2000:])

maflcko commented at 2:33 pm on July 29, 2025:

you don’t need to include those. A header itself does not have any transactions to verify

l0rinc commented at 5:33 pm on July 29, 2025:

Yeah, I figured, but this way the scope of p2p1 is narrowed to a single block - seems more consistent than breaking it up

maflcko commented at 7:42 pm on July 29, 2025:

Python does not have lifetimes in block scopes and p2p1 will be visible outside of the block. Also, on a failure, the debug log snippet of this scope will be repeated, and will include irrelevant details twice.

l0rinc commented at 7:54 pm on July 29, 2025:

Ok, sure, thanks for the context, narrowed the scope to send and sync only

l0rinc force-pushed on Jul 29, 2025

hodlinator commented at 1:05 pm on August 2, 2025: contributor

Concept ACK

Good to communicate to users why their sync progress has slowed down.

Seems like it could be related to the reports in #32832, worth referencing in the PR description?

achow101 added this to the milestone 30.0 on Aug 7, 2025

in src/validation.cpp:2603 in 18a6cf6111 outdated

2599@@ -2600,6 +2600,11 @@ bool Chainstate::ConnectBlock(const CBlock& block, BlockValidationState& state,
2600              Ticks<SecondsDouble>(m_chainman.time_forks),
2601              Ticks<MillisecondsDouble>(m_chainman.time_forks) / m_chainman.num_blocks_total);
2602 
2603+    if (static bool prev{!fScriptChecks}; fScriptChecks != prev) {

ajtowns commented at 6:19 pm on August 8, 2025:

Seems dangerous to have an inline static variable, particularly with no lock annotations, and in kernel code.

Maybe better to do:

0static bool g_script_checks_enabled GUARDED_BY(::cs_main) {false};
1...
2    if (pindex == nullptr || pindex->nHeight == 0 || g_script_checks_enable != fScriptchecks) {
3        LogInfo("%s signature validations...", ...);
4        g_script_checks_enable = fScriptChecks;
5    }

I think this will give weird output with assumeutxo though – repeatedly reporting enabled for new blocks on the assumeutxo chain, and disabled for the IBD chain. Might be better to associate the bool with class Chainstate in that case?

l0rinc commented at 10:52 pm on August 8, 2025:

Thanks for the hint, I pushed the following changes:

moved the static state change to chainstate class - but instead of locking on it I made it an std::atomic<bool> (which likely isn’t necessary, since we’re already locking, but this seems safer and basically for free);
the script check was also changed to only trigger for IBD, not for assumeutxo or background validation.

Testing it with:

0// TODO hack to enable/disable script checks based on block height for testing purposes
1if (pindex->nHeight < 100) fScriptChecks = false;
2else if (pindex->nHeight < 200) fScriptChecks = true;
3else if (pindex->nHeight < 300) fScriptChecks = false;
4else if (pindex->nHeight < 400) fScriptChecks = true;
5
6if (fScriptChecks != m_prev_script_checks_logged && GetRole() == ChainstateRole::NORMAL) {
7    LogInfo("%s signature validations at block #%d (%s).", fScriptChecks ? "Enabling" : "Disabling", pindex->nHeight, block_hash.ToString());
8    m_prev_script_checks_logged = fScriptChecks;
9}

and running

0cmake -B build && cmake --build build && mkdir -p demo && build/bin/bitcoind -datadir=demo -stopatheight=500 | grep 'signature validation'

returns:

02025-08-08T22:46:47Z Disabling signature validations at block [#1](/bitcoin-bitcoin/1/) (00000000839a8e6886ab5951d76f411475428afc90947ee320161bbf18eb6048).
12025-08-08T22:46:47Z Enabling signature validations at block [#100](/bitcoin-bitcoin/100/) (000000007bc154e0fa7ea32218a72fe2c1bb9f86cf8c9ebf9a715ed27fdb229a).
22025-08-08T22:46:47Z Disabling signature validations at block [#200](/bitcoin-bitcoin/200/) (000000008f1a7008320c16b8402b7f11e82951f44ca2663caf6860ab2eeef320).
32025-08-08T22:46:47Z Enabling signature validations at block [#300](/bitcoin-bitcoin/300/) (0000000062b69e4a2c3312a5782d7798b0711e9ebac065cd5d19f946439f8609).

For simplicity, during AssumeUTXO no warnings are generated.

l0rinc commented at 7:50 pm on August 11, 2025:

I ran a full reindex as well:

0./build/bin/bitcoind -datadir=$DATA_DIR -stopatheight=$STOP -dbcache=$DBCACHE -reindex -blocksonly -connect=0 -printtoconsole=1

which shows the correct assumevalid behavior:

0cat ../BitcoinData/debug.log | grep 'signature validations'
12025-08-09T00:54:22Z Disabling signature validations at block [#1](/bitcoin-bitcoin/1/) (00000000839a8e6886ab5951d76f411475428afc90947ee320161bbf18eb6048).
22025-08-09T05:46:59Z Enabling signature validations at block [#886158](/bitcoin-bitcoin/886158/) (000000000000000000022614dc170eadb7b544824cbcdb0732bdeca42839aa37).

ajtowns commented at 3:22 am on August 12, 2025:

I think with the previous code, a fully synced node that was stopped and restarted would report “Enabling signature validation at block #909644 (…)” or similar on each restart, whereas I think the current code won’t do that. No particular opinion on which behaviour is better.

I wonder if it would be worth including the assume valid setting (and block height?) in the “Disabling signature validation message”, eg Assuming signatures are valid from block [#1](/bitcoin-bitcoin/1/) (...) until block [#886157](/bitcoin-bitcoin/886157/) (...).

l0rinc commented at 10:51 pm on August 12, 2025:

Assuming signatures are valid from block #1 (…) until block #886157 (…)

We are already displaying the target assumevalid block hash during init, e.g.:

2025-08-12T22:48:19Z Assuming ancestors of block 00000000000000000001b658dd1120e82e66d2790811f89ede9742ada3ed6d77 have valid signatures.

No particular opinion on which behaviour is better

I currently don’t think this is an important usecase after IBD. If any of the reviewers have a stronger preference, let me know, the change to always display the validation status would be trivial.

l0rinc force-pushed on Aug 8, 2025

assumevalid: log every script validation state change

The `-assumevalid` option skips script verification for a specified block and all its ancestors during Initial Block Download.
Many new users are surprised when this suddenly slows their node to a halt.
This commit adds a log message to clearly indicate when this optimization ends and full validation begins (and vice versa).

When using `-assumeutxo`, logging is suppressed for the active assumed-valid chainstate and for the background validation chainstate to avoid the confusing toggles.

-------

> cmake -B build && cmake --build build && mkdir -p demo && build/bin/bitcoind -datadir=demo -stopatheight=500 | grep 'signature validation'

```
2025-08-08T20:59:21Z Disabling signature validations at block #1 (00000000839a8e6886ab5951d76f411475428afc90947ee320161bbf18eb6048).
2025-08-08T20:59:21Z Enabling signature validations at block #100 (000000007bc154e0fa7ea32218a72fe2c1bb9f86cf8c9ebf9a715ed27fdb229a).
2025-08-08T20:59:21Z Disabling signature validations at block #200 (000000008f1a7008320c16b8402b7f11e82951f44ca2663caf6860ab2eeef320).
2025-08-08T20:59:21Z Enabling signature validations at block #300 (0000000062b69e4a2c3312a5782d7798b0711e9ebac065cd5d19f946439f8609).
```

fab2980bdc

l0rinc force-pushed on Aug 8, 2025

DrahtBot added the label CI failed on Aug 8, 2025

DrahtBot commented at 11:48 pm on August 8, 2025: contributor

🚧 At least one of the CI tasks failed. Task lint: https://github.com/bitcoin/bitcoin/runs/47715147143 LLM reason (✨ experimental): Lint errors due to duplicate include statements caused the CI failure.

Try to run the tests locally, according to the documentation. However, a CI failure may still happen due to a number of reasons, for example:

Possibly 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.
A sanitizer issue, which can only be found by compiling with the sanitizer and running the affected test.
An intermittent issue.

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

DrahtBot removed the label CI failed on Aug 9, 2025

achow101 commented at 9:55 pm on August 11, 2025: member

ACK fab2980bdc55b5c77f574f879a6ab62db5eda427

DrahtBot requested review from hodlinator on Aug 11, 2025

ajtowns commented at 3:17 am on August 14, 2025: contributor

crACK fab2980bdc55b5c77f574f879a6ab62db5eda427

code and tests look good; no opinion on how useful this will be at solving confusion over IBD speed

davidgumberg commented at 11:22 pm on August 14, 2025: contributor

untested crACK https://github.com/bitcoin/bitcoin/commit/fab2980bdc55b5c77f574f879a6ab62db5eda427

It seems useful to me to log when signature validations begin during an assumevalid IBD.

achow101 merged this on Aug 15, 2025

achow101 closed this on Aug 15, 2025

l0rinc deleted the branch on Aug 15, 2025

alexanderwiederin referenced this in commit 67b164b083 on Aug 21, 2025

yuvicc referenced this in commit 22f55cf11d on Aug 26, 2025

stringintech referenced this in commit ccb9779390 on Aug 27, 2025

l0rinc referenced this in commit 64ba2821b5 on Sep 8, 2025

assumevalid: log every script validation state change #32975

Code Coverage & Benchmarks

Reviews

Conflicts