p2p: log mutated blocks when unknown & valid PoW

0xB10C commented at 12:12 pm on March 4, 2024: contributor

Follow-up to #29412. Before 29412, we were logging an error when receiving an unknown mutated block with a valid PoW. With 29412, we only log about mutated blocks to the net debug logging category. As the mutated block logging is and has been useful for detecting and debugging problem of some mining pools, it’s re-added here. See the conversation starting here: #29412 (comment).

Old blocks can cheaply be mutated and send to us. We don’t log when receiving these. However, blocks with a valid PoW (above our DoS threshold) that we didn’t know about could indicate a problem, for example, on the miner side. By logging about these mutated blocks, we make it easier to notice and debug these cases.

DrahtBot commented at 12:12 pm on March 4, 2024: contributor

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. A summary of reviews will appear here.

Conflicts

Reviewers, this pull request conflicts with the following ones:

#29538 (refactor: Improve naming of CBlock::GetHash() -> GetHeaderHash() by fjahr)

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.

0xB10C commented at 12:12 pm on March 4, 2024: contributor

I’m interested in conceptual review on:

An attacker could try to fill our disk by sending us the same mutated block that we then log. As they get disconnected after sending a mutated block, the attack frequency is limited. Accepting the header of the mutated block would avoid this, but would partly revert #29412, as we would do some processing (accepting the header) on mutated blocks. See also #29412 (comment) and following comment.
This adds another log-assertion in the functional tests. We might want to avoid these: #29524 (review)

DrahtBot added the label P2P on Mar 4, 2024

0xB10C force-pushed on Mar 4, 2024

DrahtBot commented at 12:23 pm on March 4, 2024: 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/22244171302

DrahtBot added the label CI failed on Mar 4, 2024

fanquake commented at 12:35 pm on March 4, 2024: member

0net_processing.cpp:4733:53: error: cannot call function 'MaybeCheckNotHeld' while mutex 'cs_main' is held [-Werror,-Wthread-safety-analysis]
1                   const CBlockIndex* mutated_block{WITH_LOCK(m_chainman.GetMutex(), return m_chainman.m_blockman.LookupBlockIndex(pblock->GetHash()))};
2                                                    ^
3./sync.h:301:30: note: expanded from macro 'WITH_LOCK'
4#define WITH_LOCK(cs, code) (MaybeCheckNotHeld(cs), [&]() -> decltype(auto) { LOCK(cs); code; }())
5                             ^
61 error generated.

p2p: log mutated blocks when unknown & valid PoW

Old blocks can cheaply be mutated and send to us. We don't log
when receiving these. However, blocks with a valid PoW (above
our DoS threshold) that we didn't know about could indicate a
problem, for example, on the miner side. By logging about these
mutated blocks, we make it easier to notice and debug these cases.

ffd22c8e5a

in src/net_processing.cpp:4732 in 5fce7ef36b outdated

4725@@ -4726,7 +4726,19 @@ void PeerManagerImpl::ProcessMessage(CNode& pfrom, const std::string& msg_type,
4726                            /*check_witness_root=*/DeploymentActiveAfter(prev_block, m_chainman, Consensus::DEPLOYMENT_SEGWIT))) {
4727             LogDebug(BCLog::NET, "Received mutated block from peer=%d\n", peer->m_id);
4728             Misbehaving(*peer, 100, "mutated block");
4729-            WITH_LOCK(cs_main, RemoveBlockRequest(pblock->GetHash(), peer->m_id));
4730+            {
4731+                LOCK(cs_main);
4732+                RemoveBlockRequest(pblock->GetHash(), peer->m_id);
4733+                if (prev_block && prev_block->nChainWork + CalculateHeadersWork({pblock->GetBlockHeader()}) >= GetAntiDoSWorkThreshold()) {

dergoegge commented at 12:48 pm on March 4, 2024:

This is not an actual proof-of-work check. CalculateHeadersWork only returns the work claimed by the header but doesn’t check whether the header actually has valid work. So the log is trivial to trigger by anyone.

instagibbs commented at 2:04 pm on March 5, 2024:

0                if (prev_block->nChainWork + CalculateHeadersWork({pblock->GetBlockHeader()}) >= GetAntiDoSWorkThreshold()) {

instagibbs commented at 2:46 pm on March 5, 2024:

that’s a very unfortunate name for the function

Sjors commented at 2:49 pm on March 5, 2024:

And it’s bitten people before, see e.g. #27278 (review)

0xB10C commented at 8:18 am on March 6, 2024:

ugh, good catch.

0xB10C force-pushed on Mar 4, 2024

0xB10C commented at 1:54 pm on March 4, 2024: contributor

Dropped the chainman lock. We are already locking cs_main, which should be enough (although I’m not 100% certain I fully understand our locking internals here).

DrahtBot removed the label CI failed on Mar 4, 2024

in test/functional/p2p_mutated_blocks.py:89 in ffd22c8e5a

82@@ -79,7 +83,10 @@ def self_transfer_requested():
83 
84         # Attempt to clear the honest relayer's download request by sending the
85         # mutated block (as the attacker).
86-        with self.nodes[0].assert_debug_log(expected_msgs=["Block mutated: bad-txnmrklroot, hashMerkleRoot mismatch"]):
87+        with self.nodes[0].assert_debug_log(
88+          expected_msgs=["Block mutated: bad-txnmrklroot, hashMerkleRoot mismatch"],
89+          # header is known - mutated block isn't logged
90+          unexpected_msgs=[LOGMESSAGE_REJECTED_MUTATED_BLOCK]):

Sjors commented at 10:22 am on March 5, 2024:

unexpected_msgs is unused

instagibbs commented at 1:59 pm on March 5, 2024:

hm? it’s an arg for assert_debug_log

Sjors commented at 2:19 pm on March 5, 2024:

Oh oops, nvm

Sjors commented at 2:22 pm on March 5, 2024:

In that case, it’s good that you’re also testing below that LOGMESSAGE_REJECTED_MUTATED_BLOCK is logged. Otherwise if the string is changed in the code, we would not catch later regressions (where it shows up in the log).

Sjors commented at 10:31 am on March 5, 2024: member

Somewhat related: #27277

There I’m trying to declutter -debug=validation. That could also be a useful target for the log messages here. It’s not on by default - so there’s need to worry about disk filling. It’s also not a noisy as -debug=net. I marked it as draft though, because over the last few rebases things got a bit confusing.

fanquake requested review from instagibbs on Mar 5, 2024

fanquake requested review from dergoegge on Mar 5, 2024

in test/functional/p2p_mutated_blocks.py:137 in ffd22c8e5a

132+        attacker = self.nodes[0].add_p2p_connection(P2PInterface())
133+        with self.nodes[0].assert_debug_log(
134+          expected_msgs=["bad-witness-nonce-size, CheckWitnessMalleation", LOGMESSAGE_REJECTED_MUTATED_BLOCK]):
135+            attacker.send_message(msg_block(mutated_block))
136+        attacker.wait_for_disconnect(timeout=5)
137+

instagibbs commented at 2:20 pm on March 5, 2024:

Logic seems wrong, and here’s a test which catches it. We’ll make an unconditional log for every mutated block, over and over. To mitigate this we would need to accept the header of the mutated block and use that to rate-limit the log.

0
1        # But won't log a second time
2        attacker = self.nodes[0].add_p2p_connection(P2PInterface())
3        with self.nodes[0].assert_debug_log(
4          expected_msgs=["Received mutated block from peer"], # have it wait for this to make sure unexpected has time
5          unexpected_msgs=["bad-witness-nonce-size, CheckWitnessMalleation", LOGMESSAGE_REJECTED_MUTATED_BLOCK]):
6            attacker.send_message(msg_block(mutated_block))
7        attacker.wait_for_disconnect(timeout=5)

0xB10C commented at 8:18 am on March 6, 2024:

This was mentioned in #29412 (comment) too. The current implementation in this PR is the same behavior as before #29412. The logging is somewhat rate-limited by needing to open a new connection each time.

I agree that re-introducing this isn’t ideal. As this would partially revert #29412 again, I don’t think it’s worth having this on-by-default logging: #29549 (comment)

instagibbs changes_requested

0xB10C commented at 8:18 am on March 6, 2024: contributor

I came to the conclusion that checking for mutations early (before we even look at the header), isn’t trivially compatible with doing anything that’s potentially DoSable (e.g. logging), even if we disconnect after each mutated block. As mentioned in #29412 (comment) and #29549 (review), we would want to check (and accept) the header before logging, which would partially revert #29412. I don’t think logging mutated blocks is worth doing this.

Additionally, this is only a problem if the mutated block is submitted over a custom/broken P2P client that doesn’t itself check the block. Any miner using submitblock on their node will notice that their block is mutated.

If still wanted, it’s probably better to log mutated blocks in debug=validation (with e.g. #27277). I don’t plan to work on this at the moment.

0xB10C closed this on Mar 6, 2024

p2p: log mutated blocks when unknown & valid PoW #29549

Code Coverage

Reviews

Conflicts