Skip to content

Commit

Permalink
Do not make it trivial for inbound peers to generate log entries
Browse files Browse the repository at this point in the history 
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.
  • Loading branch information
@TheBlueMatt
TheBlueMatt committed Nov 9, 2017
1 parent 3788a84 commit be9f38c
Show file tree
Hide file tree
Showing 3 changed files with 23 additions and 14 deletions.
2 changes: 1 addition & 1 deletion src/net.cpp
View file
Expand Up @@ -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;
}
Expand Down
31 changes: 18 additions & 13 deletions src/net_processing.cpp
View file
Expand Up @@ -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
Expand Down Expand Up @@ -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;
Expand Down Expand Up @@ -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);
Expand Down Expand Up @@ -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) {
Expand Down Expand Up @@ -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;
}

Expand Down Expand Up @@ -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;
}
}
Expand Down Expand Up @@ -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;
}
}
Expand Down Expand Up @@ -2837,7 +2842,7 @@ bool PeerLogicValidation::ProcessMessages(CNode* pfrom, std::atomic<bool>& 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;
}
Expand All @@ -2846,7 +2851,7 @@ bool PeerLogicValidation::ProcessMessages(CNode* pfrom, std::atomic<bool>& 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();
Expand All @@ -2859,7 +2864,7 @@ bool PeerLogicValidation::ProcessMessages(CNode* pfrom, std::atomic<bool>& 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));
Expand All @@ -2882,17 +2887,17 @@ bool PeerLogicValidation::ProcessMessages(CNode* pfrom, std::atomic<bool>& 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
{
Expand All @@ -2906,7 +2911,7 @@ bool PeerLogicValidation::ProcessMessages(CNode* pfrom, std::atomic<bool>& 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);
Expand Down
4 changes: 4 additions & 0 deletions src/util.h
View file
Expand Up @@ -132,6 +132,10 @@ template<typename T, typename... Args> 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)
Expand Down

0 comments on commit be9f38c

Please sign in to comment.