Do not make it trivial for inbound peers to generate log entries #11583

pull TheBlueMatt wants to merge 1 commits into bitcoin:master from TheBlueMatt:2017-10-no-net-log changing 3 files +23 −14
  1. TheBlueMatt commented at 11:01 PM on October 30, 2017: member

    Based on #11580 because I'm lazy.

    We should generally avoid writing to debug.log unconditionally for inbound peers which misbehave (the peer being about to be banned being an exception, since they cannot do this twice).

  2. fanquake added the label P2P on Oct 30, 2017
  3. practicalswift commented at 6:03 AM on October 31, 2017: contributor

    Concept ACK

  4. in src/net_processing.cpp:1515 in 7344795aa6 outdated 
    1510 | @@ -1514,7 +1511,9 @@ bool static ProcessMessage(CNode* pfrom, const std::string& strCommand, CDataStr
1511 |          if (nVersion < MIN_PEER_PROTO_VERSION)
1512 |          {
1513 |              // disconnect from peers older than this proto version
1514 | -            LogPrintf("peer=%d using obsolete version %i; disconnecting\n", pfrom->GetId(), nVersion);
1515 | +            std::string obsolete_msg(strprintf("peer=%d using obsolete version %i; disconnecting\n", pfrom->GetId(), nVersion));
1516 | +            if (pfrom->fInbound) LogPrint(BCLog::NET, "%s", obsolete_log);
    promag commented at 2:29 PM on October 31, 2017:

    obsolete_msg or above obsolete_log?

  5. in src/net_processing.cpp:1516 in 7344795aa6 outdated 
    1510 | @@ -1511,7 +1511,9 @@ bool static ProcessMessage(CNode* pfrom, const std::string& strCommand, CDataStr
1511 |          if (nVersion < MIN_PEER_PROTO_VERSION)
1512 |          {
1513 |              // disconnect from peers older than this proto version
1514 | -            LogPrintf("peer=%d using obsolete version %i; disconnecting\n", pfrom->GetId(), nVersion);
1515 | +            std::string obsolete_msg(strprintf("peer=%d using obsolete version %i; disconnecting\n", pfrom->GetId(), nVersion));
1516 | +            if (pfrom->fInbound) LogPrint(BCLog::NET, "%s", obsolete_log);
1517 | +            else                 LogPrintf(           "%s", obsolete_log);
    promag commented at 2:32 PM on October 31, 2017:

    Same as above.

  6. promag commented at 2:32 PM on October 31, 2017: member

    Concept ACK.

  7. TheBlueMatt force-pushed on Oct 31, 2017
  8. ryanofsky commented at 3:57 PM on November 2, 2017: member

    utACK dba516034898cd390a07edf86af3e9ff9f52c911. I didn't try to verify there were no missing logprints, but these changes seem reasonable.

    I think it would be good to add your "We should generally avoid writing to debug.log unconditionally..." comment from the commit message to the LogFlags enum, so there is a little information about good logging practices and how the enum values are supposed to be used.

  9. meshcollider commented at 4:53 AM on November 5, 2017: contributor

    Concept ACK

  10. laanwj commented at 1:38 PM on November 9, 2017: member

    "We should generally avoid writing to debug.log unconditionally"

    Yes please. Loose logging practices just cause scared users.

    Concept ACK.

  11. in src/net_processing.cpp:1516 in dba5160348 outdated 
    1510 | @@ -1514,7 +1511,9 @@ bool static ProcessMessage(CNode* pfrom, const std::string& strCommand, CDataStr
1511 |          if (nVersion < MIN_PEER_PROTO_VERSION)
1512 |          {
1513 |              // disconnect from peers older than this proto version
1514 | -            LogPrintf("peer=%d using obsolete version %i; disconnecting\n", pfrom->GetId(), nVersion);
1515 | +            std::string obsolete_log(strprintf("peer=%d using obsolete version %i; disconnecting\n", pfrom->GetId(), nVersion));
1516 | +            if (pfrom->fInbound) LogPrint(BCLog::NET, "%s", obsolete_log);
1517 | +            else                 LogPrintf(           "%s", obsolete_log);
    laanwj commented at 2:14 PM on November 9, 2017:

    Would prefer to create a BCLog::ALWAYS category and use something like pfrom->fInbound ? BCLog::NET: BCLog::ALWAYS instead of repeating the log statements in this way. (after that you could even factor it to a uint32_t log_category = ...` at the beginning of the function ProcessMessage)

  12. TheBlueMatt force-pushed on Nov 9, 2017
  13. TheBlueMatt commented at 5:41 PM on November 9, 2017: member

    After discussion on IRC I removed the weird branching on fInbound to decide between LogPrint and LogPrintf...added a new "New outbound peer connected" log to ::VERACK handling to replace it. Also added a general comment in util.h about LogPrint/LogPrintf usage.

  14. ghost commented at 11:27 PM on November 9, 2017: none

    What about the debug.log message "connection from <Peer> dropped (banned)"? I banned the nodes in gmaxwells banlist.cli.txt, and some of them aggressively try to connect permanently every few seconds after being banned, e.g. this one (this is a original cutout of the debug.log, the messages are exactly like this (except the x-anonymization), I did not remove other log entries in between)

    2017-11-x 15:55:34 connection from 129.13.252.x:36133 dropped (banned)
2017-11-x 15:55:39 connection from 129.13.252.x:36225 dropped (banned)
2017-11-x 15:55:43 connection from 129.13.252.x:36363 dropped (banned)
2017-11-x 15:55:47 connection from 129.13.252.x:36474 dropped (banned)
2017-11-x 15:55:50 connection from 129.13.252.x:36579 dropped (banned)
2017-11-x 15:55:53 connection from 129.13.252.x:36673 dropped (banned)
2017-11-x 15:55:56 connection from 129.13.252.x:36780 dropped (banned)
2017-11-x 15:56:00 connection from 129.13.252.x:36888 dropped (banned)
2017-11-x 15:56:03 connection from 129.13.252.x:36989 dropped (banned)
2017-11-x 15:56:07 connection from 129.13.252.x:37108 dropped (banned)
2017-11-x 15:56:10 connection from 129.13.252.x:37210 dropped (banned)
2017-11-x 15:56:13 connection from 129.13.252.x:37307 dropped (banned)
2017-11-x 15:56:17 connection from 129.13.252.x:37409 dropped (banned)
2017-11-x 15:56:20 connection from 129.13.252.x:37516 dropped (banned)
2017-11-x 15:56:23 connection from 129.13.252.x:37612 dropped (banned)
2017-11-x 15:56:27 connection from 129.13.252.x:37712 dropped (banned)
2017-11-x 15:56:30 connection from 129.13.252.x:37814 dropped (banned)

    Because this permanently spammed the debug.log, I added iptables rules to drop these silently on OS layer :-/

    Edit: running 0.15.1rc1

  15. Do not make it trivial for inbound peers to generate log entries
    We should generally avoid writing to debug.log unconditionally for
inbound peers which misbehave (the peer being about to be banned
being an exception, since they cannot do this twice).

To avoid removing logs for outbound peers, a new log is added to
notify users when a new outbound peer is connected which mimics
the version print.
    be9f38c613
  16. TheBlueMatt force-pushed on Nov 9, 2017
  17. TheBlueMatt commented at 11:41 PM on November 9, 2017: member

    Added the banned listing to the list as well (thanks!)...I'm sure there's others that are missed that can be triggered in validation logic, but I'll leave those for a future PR.

  18. greenaddress commented at 3:24 PM on December 9, 2017: contributor

    Concept ACK.

  19. laanwj commented at 3:51 PM on December 11, 2017: member

    utACK be9f38c6131ab0c7ad96e4f6f3d8b5ae6f870ea9

  20. laanwj merged this on Dec 11, 2017
  21. laanwj closed this on Dec 11, 2017
  22. laanwj referenced this in commit 37ffa16933 on Dec 11, 2017
  23. laanwj referenced this in commit 27803ab153 on Jan 18, 2018
  24. laanwj referenced this in commit d3a185a33b on Jan 24, 2018
  25. clemtaylor referenced this in commit c887f87d59 on Feb 3, 2018
  26. laanwj referenced this in commit eaeaa2d0b4 on Feb 6, 2018
  27. laanwj referenced this in commit 9a32114626 on Feb 6, 2018
  28. hkjn referenced this in commit c2c29b9b5e on Feb 12, 2018
  29. hkjn referenced this in commit 9818539bb8 on Feb 12, 2018
  30. HashUnlimited referenced this in commit 099e8ad6fa on Jul 31, 2018
  31. HashUnlimited referenced this in commit 9cf1961192 on Jul 31, 2018
  32. lionello referenced this in commit f740082471 on Nov 7, 2018
  33. lionello referenced this in commit 415ccf6df5 on Nov 7, 2018
  34. deadalnix referenced this in commit f6c8a4ef79 on Jan 20, 2019
  35. PastaPastaPasta referenced this in commit f4fb2c1906 on Jan 26, 2020
  36. PastaPastaPasta referenced this in commit 3564993bcb on Jan 26, 2020
  37. PastaPastaPasta referenced this in commit 7510859633 on Jan 26, 2020
  38. PastaPastaPasta referenced this in commit f7fc238d2a on Jan 26, 2020
  39. PastaPastaPasta referenced this in commit f920fa0c4f on Jan 26, 2020
  40. PastaPastaPasta referenced this in commit 887e3aa582 on Jan 27, 2020
  41. PastaPastaPasta referenced this in commit 49549390af on Jan 27, 2020
  42. PastaPastaPasta referenced this in commit 12a9809824 on Jan 27, 2020
  43. random-zebra referenced this in commit faa5290bf9 on Jan 13, 2021
  44. ckti referenced this in commit 9b18bc0bc0 on Mar 28, 2021
  45. ckti referenced this in commit 06219ebcd0 on Mar 28, 2021
  46. ckti referenced this in commit 165859c9e3 on Mar 28, 2021
  47. gades referenced this in commit 7c35c8d250 on Jun 30, 2021
  48. DrahtBot locked this on Sep 8, 2021
Contributors
TheBlueMattpracticalswiftpromagryanofskymeshcolliderlaanwjghostgreenaddress
Labels
P2P
Linked (view graph)
#11580 Do not send (potentially) invalid headers in response to getheaders#12218 net: Move misbehaving logging to net logging category#12219 More granular net logging
github-metadata-mirror

This is a metadata mirror of the GitHub repository bitcoin/bitcoin. This site is not affiliated with GitHub. Content is generated from a GitHub metadata backup.
generated: 2026-04-13 18:15 UTC
This site is hosted by @0xB10C
More mirrored repositories can be found on mirror.b10c.me