From be9f38c6131ab0c7ad96e4f6f3d8b5ae6f870ea9 Mon Sep 17 00:00:00 2001 From: Matt Corallo Date: Mon, 30 Oct 2017 18:56:37 -0400 Subject: [PATCH] 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. --- src/net.cpp | 2 +- src/net_processing.cpp | 31 ++++++++++++++++++------------- src/util.h | 4 ++++ 3 files changed, 23 insertions(+), 14 deletions(-) diff --git a/src/net.cpp b/src/net.cpp index 258599747..4453f409a 100644 --- a/src/net.cpp +++ b/src/net.cpp @@ -1111,7 +1111,7 @@ void CConnman::AcceptConnection(const ListenSocket& hListenSocket) { if (IsBanned(addr) && !whitelisted) { - LogPrintf("connection from %s dropped (banned)\n", addr.ToString()); + LogPrint(BCLog::NET, "connection from %s dropped (banned)\n", addr.ToString()); CloseSocket(hSocket); return; } diff --git a/src/net_processing.cpp b/src/net_processing.cpp index b26caf377..8e76dabc8 100644 --- a/src/net_processing.cpp +++ b/src/net_processing.cpp @@ -1042,7 +1042,7 @@ void static ProcessGetData(CNode* pfrom, const Consensus::Params& consensusParam } send = BlockRequestAllowed(mi->second, consensusParams); if (!send) { - LogPrintf("%s: ignoring request from peer=%i for old block that isn't in the main chain\n", __func__, pfrom->GetId()); + LogPrint(BCLog::NET, "%s: ignoring request from peer=%i for old block that isn't in the main chain\n", __func__, pfrom->GetId()); } } // disconnect node in case we have reached the outbound limit for serving historical blocks @@ -1511,7 +1511,7 @@ bool static ProcessMessage(CNode* pfrom, const std::string& strCommand, CDataStr if (nVersion < MIN_PEER_PROTO_VERSION) { // disconnect from peers older than this proto version - LogPrintf("peer=%d using obsolete version %i; disconnecting\n", pfrom->GetId(), nVersion); + LogPrint(BCLog::NET, "peer=%d using obsolete version %i; disconnecting\n", pfrom->GetId(), nVersion); connman->PushMessage(pfrom, CNetMsgMaker(INIT_PROTO_VERSION).Make(NetMsgType::REJECT, strCommand, REJECT_OBSOLETE, strprintf("Version must be %d or greater", MIN_PEER_PROTO_VERSION))); pfrom->fDisconnect = true; @@ -1611,7 +1611,7 @@ bool static ProcessMessage(CNode* pfrom, const std::string& strCommand, CDataStr if (fLogIPs) remoteAddr = ", peeraddr=" + pfrom->addr.ToString(); - LogPrintf("receive version message: %s: version %d, blocks=%d, us=%s, peer=%d%s\n", + LogPrint(BCLog::NET, "receive version message: %s: version %d, blocks=%d, us=%s, peer=%d%s\n", cleanSubVer, pfrom->nVersion, pfrom->nStartingHeight, addrMe.ToString(), pfrom->GetId(), remoteAddr); @@ -1654,6 +1654,9 @@ bool static ProcessMessage(CNode* pfrom, const std::string& strCommand, CDataStr // Mark this node as currently connected, so we update its timestamp later. LOCK(cs_main); State(pfrom->GetId())->fCurrentlyConnected = true; + LogPrintf("New outbound peer connected: version: %d, blocks=%d, peer=%d%s\n", + pfrom->nVersion.load(), pfrom->nStartingHeight, pfrom->GetId(), + (fLogIPs ? strprintf(", peeraddr=%s", pfrom->addr.ToString()) : "")); } if (pfrom->nVersion >= SENDHEADERS_VERSION) { @@ -1932,7 +1935,7 @@ bool static ProcessMessage(CNode* pfrom, const std::string& strCommand, CDataStr BlockMap::iterator it = mapBlockIndex.find(req.blockhash); if (it == mapBlockIndex.end() || !(it->second->nStatus & BLOCK_HAVE_DATA)) { - LogPrintf("Peer %d sent us a getblocktxn for a block we don't have", pfrom->GetId()); + LogPrint(BCLog::NET, "Peer %d sent us a getblocktxn for a block we don't have", pfrom->GetId()); return true; } @@ -1984,7 +1987,7 @@ bool static ProcessMessage(CNode* pfrom, const std::string& strCommand, CDataStr pindex = (*mi).second; if (!BlockRequestAllowed(pindex, chainparams.GetConsensus())) { - LogPrintf("%s: ignoring request from peer=%i for old block header that isn't in the main chain\n", __func__, pfrom->GetId()); + LogPrint(BCLog::NET, "%s: ignoring request from peer=%i for old block header that isn't in the main chain\n", __func__, pfrom->GetId()); return true; } } @@ -2232,10 +2235,12 @@ bool static ProcessMessage(CNode* pfrom, const std::string& strCommand, CDataStr int nDoS; if (state.IsInvalid(nDoS)) { if (nDoS > 0) { + LogPrintf("Peer %d sent us invalid header via cmpctblock\n", pfrom->GetId()); LOCK(cs_main); Misbehaving(pfrom->GetId(), nDoS); + } else { + LogPrint(BCLog::NET, "Peer %d sent us invalid header via cmpctblock\n", pfrom->GetId()); } - LogPrintf("Peer %d sent us invalid header via cmpctblock\n", pfrom->GetId()); return true; } } @@ -2837,7 +2842,7 @@ bool PeerLogicValidation::ProcessMessages(CNode* pfrom, std::atomic& inter msg.SetVersion(pfrom->GetRecvVersion()); // Scan for message start if (memcmp(msg.hdr.pchMessageStart, chainparams.MessageStart(), CMessageHeader::MESSAGE_START_SIZE) != 0) { - LogPrintf("PROCESSMESSAGE: INVALID MESSAGESTART %s peer=%d\n", SanitizeString(msg.hdr.GetCommand()), pfrom->GetId()); + LogPrint(BCLog::NET, "PROCESSMESSAGE: INVALID MESSAGESTART %s peer=%d\n", SanitizeString(msg.hdr.GetCommand()), pfrom->GetId()); pfrom->fDisconnect = true; return false; } @@ -2846,7 +2851,7 @@ bool PeerLogicValidation::ProcessMessages(CNode* pfrom, std::atomic& inter CMessageHeader& hdr = msg.hdr; if (!hdr.IsValid(chainparams.MessageStart())) { - LogPrintf("PROCESSMESSAGE: ERRORS IN HEADER %s peer=%d\n", SanitizeString(hdr.GetCommand()), pfrom->GetId()); + LogPrint(BCLog::NET, "PROCESSMESSAGE: ERRORS IN HEADER %s peer=%d\n", SanitizeString(hdr.GetCommand()), pfrom->GetId()); return fMoreWork; } std::string strCommand = hdr.GetCommand(); @@ -2859,7 +2864,7 @@ bool PeerLogicValidation::ProcessMessages(CNode* pfrom, std::atomic& inter const uint256& hash = msg.GetMessageHash(); if (memcmp(hash.begin(), hdr.pchChecksum, CMessageHeader::CHECKSUM_SIZE) != 0) { - LogPrintf("%s(%s, %u bytes): CHECKSUM ERROR expected %s was %s\n", __func__, + LogPrint(BCLog::NET, "%s(%s, %u bytes): CHECKSUM ERROR expected %s was %s\n", __func__, SanitizeString(strCommand), nMessageSize, HexStr(hash.begin(), hash.begin()+CMessageHeader::CHECKSUM_SIZE), HexStr(hdr.pchChecksum, hdr.pchChecksum+CMessageHeader::CHECKSUM_SIZE)); @@ -2882,17 +2887,17 @@ bool PeerLogicValidation::ProcessMessages(CNode* pfrom, std::atomic& inter if (strstr(e.what(), "end of data")) { // Allow exceptions from under-length message on vRecv - LogPrintf("%s(%s, %u bytes): Exception '%s' caught, normally caused by a message being shorter than its stated length\n", __func__, SanitizeString(strCommand), nMessageSize, e.what()); + LogPrint(BCLog::NET, "%s(%s, %u bytes): Exception '%s' caught, normally caused by a message being shorter than its stated length\n", __func__, SanitizeString(strCommand), nMessageSize, e.what()); } else if (strstr(e.what(), "size too large")) { // Allow exceptions from over-long size - LogPrintf("%s(%s, %u bytes): Exception '%s' caught\n", __func__, SanitizeString(strCommand), nMessageSize, e.what()); + LogPrint(BCLog::NET, "%s(%s, %u bytes): Exception '%s' caught\n", __func__, SanitizeString(strCommand), nMessageSize, e.what()); } else if (strstr(e.what(), "non-canonical ReadCompactSize()")) { // Allow exceptions from non-canonical encoding - LogPrintf("%s(%s, %u bytes): Exception '%s' caught\n", __func__, SanitizeString(strCommand), nMessageSize, e.what()); + LogPrint(BCLog::NET, "%s(%s, %u bytes): Exception '%s' caught\n", __func__, SanitizeString(strCommand), nMessageSize, e.what()); } else { @@ -2906,7 +2911,7 @@ bool PeerLogicValidation::ProcessMessages(CNode* pfrom, std::atomic& inter } if (!fRet) { - LogPrintf("%s(%s, %u bytes) FAILED peer=%d\n", __func__, SanitizeString(strCommand), nMessageSize, pfrom->GetId()); + LogPrint(BCLog::NET, "%s(%s, %u bytes) FAILED peer=%d\n", __func__, SanitizeString(strCommand), nMessageSize, pfrom->GetId()); } LOCK(cs_main); diff --git a/src/util.h b/src/util.h index 480a80c0a..a0c4b33ad 100644 --- a/src/util.h +++ b/src/util.h @@ -132,6 +132,10 @@ template static inline void MarkUsed(const T& t, c MarkUsed(args...); } +// Be conservative when using LogPrintf/error or other things which +// unconditionally log to debug.log! It should not be the case that an inbound +// peer can fill up a users disk with debug.log entries. + #ifdef USE_COVERAGE #define LogPrintf(...) do { MarkUsed(__VA_ARGS__); } while(0) #define LogPrint(category, ...) do { MarkUsed(__VA_ARGS__); } while(0)