Do not log p2p bip61 reject messages, improve log, add tests
...per the IRC discussion around https://www.erisian.com.au/bitcoin-core-dev/log-2023-09-03.html#l-345.
Rationale for not logging the bip61 reject messages (as unknown commands):
-
they are not unknown and were valid before v20; see ##15437
-
peers have been observed that send a high number of these messages (I've seen 10k-20k messages per day from a single peer), thereby flooding the log when
-debug=net -
another option would be to continue logging bip61 reject messages, but with the
tracelog level instead
Rationale for improving the log output when receiving unknown commands:
- logging only a peer id isn't of much help after the fact in understanding the source of the message and debugging what/why
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 |
|---|---|
| Concept NACK | luke-jr |
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:
- #29641 (scripted-diff: Use LogInfo/LogDebug over LogPrintf/LogPrint by maflcko)
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.
logging only a peer id isn't of much help after the fact in understanding the source of the message and debugging what/why
Not sure. The details are already logged at the beginning of the connection, after the verack. So this seems odd to duplicate here. In any case, it seems like something that would need to be done for the whole codebase and not just here.
Not sure. Seems better to be consistent.
These aren't "unknown messages", though, so it could be reasonable to treat them differently.
These aren't "unknown messages", though, so it could be reasonable to treat them differently.
Yeah, but then you'll need to include a list of all known message types, because other unhandled message types can also be frequent for someone. Not sure if this is something we want to maintain.
Seems easier to adjust the log to say "unhandled" instead of "unknown"?
It doesn't seem inconsistent to me to ignore them. They are messages with a well-known meaning, and we can choose to handle them just as well as every other known message - it just so happens that in this case (a) the action to take when receiving such a message is "do nothing" and (b) we choose to not send such messages ourselves.
I mean consistency with other message types that are known but unhandled, like the getutxo message type, or the reqrecon message type, etc. (Both are "known", but they are logged as "unknown").
No objection, if other reviewers are fine with this.
The details are already logged at the beginning of the connection
Can drop the log improvement if people prefer, but it provides info not in the connection log. In my development environment I have similar peer details for all of the higher-level peer events to better observe and understand them. These allowed uncovering the issues in #28248. (If you are referring to the New outbound peer connected logging, I propose to improve it along with others in that pull.)
Can drop the log improvement if people prefer, but it provides info not in the connection log. In my development environment I have similar peer details for all of the higher-level peer events to better observe and understand them.
If there is something missing from the connection log, it should be added there, not here, no?
Locally I have a function ToString on a peer connection, which I add to log lines I am interested in, to make parsing easier. It would certainly be easier for me if existing log lines had a call to such a function, which would just print the peer id right now. It could then be modified, with config options, or in the source code to print something else, or hook into tracing, etc. Not sure if it would be useful for others as well, so I haven't made a pull request for this. Also, such a pull would require touching almost all net processing log lines.