ERROR AcceptBlockHeader log messages are kind of noisy

laanwj commented at 6:14 pm on November 8, 2019: member

This is the “harvest” of one day on one normal-running node (31 messages):

 02019-11-07T00:32:02Z ERROR: AcceptBlockHeader: prev block not found
 12019-11-07T01:02:36Z ERROR: AcceptBlockHeader: Consensus::ContextualCheckBlockHeader: 000000000000014219120d5167a4281437fc379129d4ba6f6e956ca1db77f5fa, bad-diffbits, incorrect proof of work
 22019-11-07T01:08:55Z ERROR: AcceptBlockHeader: Consensus::ContextualCheckBlockHeader: 000000004bfb561102f5f04d4bab0cc70a403da70b82ce33657e10ed46b9000f, bad-diffbits, incorrect proof of work
 32019-11-07T01:56:13Z ERROR: AcceptBlockHeader: Consensus::ContextualCheckBlockHeader: 000000000000001daed8bac77bdf571441649e51732e91bec984cf97a39005a1, bad-diffbits, incorrect proof of work
 42019-11-07T03:11:12Z ERROR: AcceptBlockHeader: Consensus::ContextualCheckBlockHeader: 00000000bdcf539dc39dce363d791103e80c8a7180dff3c9c8a4f25f3500b8c9, bad-diffbits, incorrect proof of work
 52019-11-07T04:04:51Z ERROR: AcceptBlockHeader: Consensus::ContextualCheckBlockHeader: 000000004bfb561102f5f04d4bab0cc70a403da70b82ce33657e10ed46b9000f, bad-diffbits, incorrect proof of work
 62019-11-07T04:05:45Z ERROR: AcceptBlockHeader: Consensus::CheckBlockHeader: 2d94a35159bf59897eb709534f707ac587112ef8e2db52a7c7153099e77cecf3, high-hash, proof of work failed
 72019-11-07T04:16:24Z ERROR: AcceptBlockHeader: Consensus::ContextualCheckBlockHeader: 000000000000001daed8bac77bdf571441649e51732e91bec984cf97a39005a1, bad-diffbits, incorrect proof of work
 82019-11-07T04:22:01Z ERROR: AcceptBlockHeader: Consensus::CheckBlockHeader: 0fd7ab36246daf61802e10a0316cc2b0f17a1d6404bfdd53878ba34e158b4680, high-hash, proof of work failed
 92019-11-07T04:28:31Z ERROR: AcceptBlockHeader: Consensus::CheckBlockHeader: 0fd7ab36246daf61802e10a0316cc2b0f17a1d6404bfdd53878ba34e158b4680, high-hash, proof of work failed
102019-11-07T04:40:18Z ERROR: AcceptBlockHeader: Consensus::ContextualCheckBlockHeader: 000000004bfb561102f5f04d4bab0cc70a403da70b82ce33657e10ed46b9000f, bad-diffbits, incorrect proof of work
112019-11-07T04:54:09Z ERROR: AcceptBlockHeader: Consensus::ContextualCheckBlockHeader: 000000000000001daed8bac77bdf571441649e51732e91bec984cf97a39005a1, bad-diffbits, incorrect proof of work
122019-11-07T06:36:36Z ERROR: AcceptBlockHeader: Consensus::ContextualCheckBlockHeader: 000000004bfb561102f5f04d4bab0cc70a403da70b82ce33657e10ed46b9000f, bad-diffbits, incorrect proof of work
132019-11-07T08:06:25Z ERROR: AcceptBlockHeader: prev block not found
142019-11-07T08:35:49Z ERROR: AcceptBlockHeader: Consensus::ContextualCheckBlockHeader: 000000000000001daed8bac77bdf571441649e51732e91bec984cf97a39005a1, bad-diffbits, incorrect proof of work
152019-11-07T08:36:30Z ERROR: AcceptBlockHeader: Consensus::ContextualCheckBlockHeader: 00000000bdcf539dc39dce363d791103e80c8a7180dff3c9c8a4f25f3500b8c9, bad-diffbits, incorrect proof of work
162019-11-07T08:56:15Z ERROR: AcceptBlockHeader: Consensus::ContextualCheckBlockHeader: 000000000000001daed8bac77bdf571441649e51732e91bec984cf97a39005a1, bad-diffbits, incorrect proof of work
172019-11-07T09:39:10Z ERROR: AcceptBlockHeader: Consensus::CheckBlockHeader: 2d94a35159bf59897eb709534f707ac587112ef8e2db52a7c7153099e77cecf3, high-hash, proof of work failed
182019-11-07T10:12:22Z ERROR: AcceptBlockHeader: Consensus::CheckBlockHeader: 0fd7ab36246daf61802e10a0316cc2b0f17a1d6404bfdd53878ba34e158b4680, high-hash, proof of work failed
192019-11-07T10:25:25Z ERROR: AcceptBlockHeader: Consensus::ContextualCheckBlockHeader: 00000000bdcf539dc39dce363d791103e80c8a7180dff3c9c8a4f25f3500b8c9, bad-diffbits, incorrect proof of work
202019-11-07T11:56:59Z ERROR: AcceptBlockHeader: Consensus::ContextualCheckBlockHeader: 000000000000014219120d5167a4281437fc379129d4ba6f6e956ca1db77f5fa, bad-diffbits, incorrect proof of work
212019-11-07T13:59:09Z ERROR: AcceptBlockHeader: Consensus::ContextualCheckBlockHeader: 000000000000000000639be19a0123a1c99d9fef89f0b8ac055a77f4ef86ae3b, bad-diffbits, incorrect proof of work
222019-11-07T14:54:46Z ERROR: AcceptBlockHeader: Consensus::CheckBlockHeader: 0fd7ab36246daf61802e10a0316cc2b0f17a1d6404bfdd53878ba34e158b4680, high-hash, proof of work failed
232019-11-07T15:57:01Z ERROR: AcceptBlockHeader: Consensus::ContextualCheckBlockHeader: 000000000000014219120d5167a4281437fc379129d4ba6f6e956ca1db77f5fa, bad-diffbits, incorrect proof of work
242019-11-07T18:27:44Z ERROR: AcceptBlockHeader: Consensus::ContextualCheckBlockHeader: 000000000000000000639be19a0123a1c99d9fef89f0b8ac055a77f4ef86ae3b, bad-diffbits, incorrect proof of work
252019-11-07T18:50:31Z ERROR: AcceptBlockHeader: Consensus::CheckBlockHeader: 0fd7ab36246daf61802e10a0316cc2b0f17a1d6404bfdd53878ba34e158b4680, high-hash, proof of work failed
262019-11-07T19:58:57Z ERROR: AcceptBlockHeader: Consensus::ContextualCheckBlockHeader: 000000000000014219120d5167a4281437fc379129d4ba6f6e956ca1db77f5fa, bad-diffbits, incorrect proof of work
272019-11-07T20:29:11Z ERROR: AcceptBlockHeader: Consensus::ContextualCheckBlockHeader: 000000000000000000639be19a0123a1c99d9fef89f0b8ac055a77f4ef86ae3b, bad-diffbits, incorrect proof of work
282019-11-07T21:07:06Z ERROR: AcceptBlockHeader: prev block not found
292019-11-07T22:30:22Z ERROR: AcceptBlockHeader: prev block not found
302019-11-07T23:10:53Z ERROR: AcceptBlockHeader: prev block not found

That’s a lot of ERROR.

Usually we follow the principle that we don’t want to have any things in the log by default that might worry users unnecessarily. I think these are ERRORs which are easily to trigger on the P2P network by feeding invalid headers, we might want to tone them down to normal log messages or even hide them in a debug category.

laanwj added the label Validation on Nov 8, 2019

laanwj renamed this:
~~ERROR AceptBlockHeader log messages are kind of noisy~~
ERROR AcceptBlockHeader log messages are kind of noisy
on Nov 8, 2019

emilengler commented at 11:49 am on November 9, 2019: contributor

Maybe it is now a good idea to add a --verbose option to bitcoind, which does show such kinds of messages but without it won’t

MarcoFalke commented at 1:45 pm on November 9, 2019: member

@emilengler That option is called -debug

practicalswift commented at 1:54 pm on November 9, 2019: contributor

Concept ACK on moving this to debug: improved signal-to-noise is good

emilengler commented at 11:00 pm on November 9, 2019: contributor

@MarcoFalke Didn’t knew it existed but then I agree with @practicalswift

laanwj commented at 11:23 am on November 10, 2019: member

The reason I’m creating a discussion topic here is not because I’m confused how to implement this (:smile:), but because it’s slightly controversial and I might be confused about the ’easy to generate’ part.

I think we do want ERROR for validation errors on blocks unconditionally, after checking proof-of-work, because significant computation time went into generating them, and miners sending them might be indication of a deeper problem with the network.

I think this is not the case for block headers, definitely not “bad-diffbits” or “proof of work failed”. We made a similar decision about transactions. They’re easy to send so they should not clutter the log by default.

jnewbery commented at 7:40 pm on November 15, 2019: member

Concept ACK removing the worrying ERROR text from these logs.

I think we do want ERROR for validation errors on blocks unconditionally

I don’t think I agree. I’d usually associate ERROR in the debug logs as a software error rather than a peer feeding us bad data. Perhaps change all validation logs to print something like validation error rather than ERROR?

laanwj commented at 4:18 pm on November 18, 2019: member

I don’t think I agree. I’d usually associate ERROR in the debug logs as a software error rather than a peer feeding us bad data. Perhaps change all validation logs to print something like validation error rather than ERROR?

OK, maybe. My point here is that headers are categorically different from blocks in this regard.

Also in many cases, block validation errors do mean there’s database corruption. You can’t really distinguish all your peers feeding you bad blocks with valid PoW from local corruption.

jnewbery commented at 4:24 pm on November 18, 2019: member

Also in many cases, block validation errors do mean there’s database corruption. You can’t really distinguish all your peers feeding you bad blocks with valid PoW from local corruption.

We absolutely do want to distinguish these cases. That’s why we have BlockValidationState.IsValid() and BlockValidationState.IsError(). The second is used in cases where there is local corruption.

sipa commented at 4:31 pm on November 18, 2019: member

@jnewbery I think @laanwj is referring to failed block validation that are due to local corruption, but aren’t detected as corruption.

laanwj commented at 4:35 pm on November 18, 2019: member

Maybe it’s possible to distinguish some cases, but definitely not in general. Let’s say, I’ve had cases of UTXO database corruption due to failing hardware that weren’t detected by that. The only thing that was revealing it was that it was rejecting every single block on the network.

I mean, how can you even know if your local UTXO database is missing entries (or has additional ones that shouldn’t be there)? In a decentralized network, your own database is the only reference.

ghost commented at 7:03 am on September 2, 2020: none

According to my understanding, ERROR: AcceptBlockHeader: Consensus::CheckBlockHeader: can be excluded from log file using -debug or -debugexclude mentioned in https://github.com/bitcoin/bitcoin/pull/10123/ because it is assigned a category ‘VALIDATION’ in: https://github.com/bitcoin/bitcoin/blob/48c1083632687a42ac603d4f241e70616a1d3815/src/validation.cpp#L3643

Other error messages saved in logs are not assigned any category and LogPrintf is used instead of LogPrint in https://github.com/bitcoin/bitcoin/blob/48c1083632687a42ac603d4f241e70616a1d3815/src/validation.cpp#L3622

MarcoFalke added the label Block storage on Oct 11, 2021

MarcoFalke added the label Utils/log/libs on Oct 11, 2021

MarcoFalke removed the label Block storage on Oct 11, 2021

laanwj closed this on Apr 14, 2022

DrahtBot locked this on Apr 14, 2023

ERROR AcceptBlockHeader log messages are kind of noisy #17421