From d3a185a33b7bc09e4ca998f42f1f9aea8177ef8a Mon Sep 17 00:00:00 2001 From: "Wladimir J. van der Laan" Date: Thu, 18 Jan 2018 17:21:08 +0100 Subject: net: Move misbehaving logging to net logging category This moves the error messages for misbehavior (when available) into the line that reports the misbehavior, as well as moves the logging to the `net` category. This is a continuation of #11583 and avoids serious-looking errors due to misbehaving peers. To do this, Misbehaving() gains an optional `message` argument. E.g. change: 2018-01-18 16:02:27 Misbehaving: x.x.x.x:62174 peer=164603 (80 -> 100) BAN THRESHOLD EXCEEDED 2018-01-18 16:02:27 ERROR: non-continuous headers sequence to 2018-01-18 16:02:27 Misbehaving: x.x.x.x:62174 peer=164603 (80 -> 100) BAN THRESHOLD EXCEEDED: non-continuous headers sequence --- src/net_processing.cpp | 45 ++++++++++++++++++++++----------------------- src/net_processing.h | 2 +- 2 files changed, 23 insertions(+), 24 deletions(-) (limited to 'src') diff --git a/src/net_processing.cpp b/src/net_processing.cpp index 3cf96be61a..edebccfb31 100644 --- a/src/net_processing.cpp +++ b/src/net_processing.cpp @@ -750,7 +750,7 @@ unsigned int LimitOrphanTxSize(unsigned int nMaxOrphans) } // Requires cs_main. -void Misbehaving(NodeId pnode, int howmuch) +void Misbehaving(NodeId pnode, int howmuch, const std::string& message) { if (howmuch == 0) return; @@ -761,12 +761,13 @@ void Misbehaving(NodeId pnode, int howmuch) state->nMisbehavior += howmuch; int banscore = gArgs.GetArg("-banscore", DEFAULT_BANSCORE_THRESHOLD); + std::string message_prefixed = message.empty() ? "" : (": " + message); if (state->nMisbehavior >= banscore && state->nMisbehavior - howmuch < banscore) { - LogPrintf("%s: %s peer=%d (%d -> %d) BAN THRESHOLD EXCEEDED\n", __func__, state->name, pnode, state->nMisbehavior-howmuch, state->nMisbehavior); + LogPrint(BCLog::NET, "%s: %s peer=%d (%d -> %d) BAN THRESHOLD EXCEEDED%s\n", __func__, state->name, pnode, state->nMisbehavior-howmuch, state->nMisbehavior, message_prefixed); state->fShouldBan = true; } else - LogPrintf("%s: %s peer=%d (%d -> %d)\n", __func__, state->name, pnode, state->nMisbehavior-howmuch, state->nMisbehavior); + LogPrint(BCLog::NET, "%s: %s peer=%d (%d -> %d)%s\n", __func__, state->name, pnode, state->nMisbehavior-howmuch, state->nMisbehavior, message_prefixed); } @@ -1260,8 +1261,7 @@ inline void static SendBlockTransactions(const CBlock& block, const BlockTransac for (size_t i = 0; i < req.indexes.size(); i++) { if (req.indexes[i] >= block.vtx.size()) { LOCK(cs_main); - Misbehaving(pfrom->GetId(), 100); - LogPrintf("Peer %d sent us a getblocktxn with out-of-bounds tx indices", pfrom->GetId()); + Misbehaving(pfrom->GetId(), 100, strprintf("Peer %d sent us a getblocktxn with out-of-bounds tx indices", pfrom->GetId())); return; } resp.txn[i] = block.vtx[req.indexes[i]]; @@ -1318,8 +1318,8 @@ bool static ProcessHeadersMessage(CNode *pfrom, CConnman *connman, const std::ve uint256 hashLastBlock; for (const CBlockHeader& header : headers) { if (!hashLastBlock.IsNull() && header.hashPrevBlock != hashLastBlock) { - Misbehaving(pfrom->GetId(), 20); - return error("non-continuous headers sequence"); + Misbehaving(pfrom->GetId(), 20, "non-continuous headers sequence"); + return false; } hashLastBlock = header.GetHash(); } @@ -1338,7 +1338,9 @@ bool static ProcessHeadersMessage(CNode *pfrom, CConnman *connman, const std::ve if (state.IsInvalid(nDoS)) { LOCK(cs_main); if (nDoS > 0) { - Misbehaving(pfrom->GetId(), nDoS); + Misbehaving(pfrom->GetId(), nDoS, "invalid header received"); + } else { + LogPrint(BCLog::NET, "peer=%d: invalid header received\n", pfrom->GetId()); } if (punish_duplicate_invalid && mapBlockIndex.find(first_invalid_header.GetHash()) != mapBlockIndex.end()) { // Goal: don't allow outbound peers to use up our outbound @@ -1374,7 +1376,7 @@ bool static ProcessHeadersMessage(CNode *pfrom, CConnman *connman, const std::ve // etc), and not just the duplicate-invalid case. pfrom->fDisconnect = true; } - return error("invalid header received"); + return false; } } @@ -1783,8 +1785,8 @@ bool static ProcessMessage(CNode* pfrom, const std::string& strCommand, CDataStr if (vAddr.size() > 1000) { LOCK(cs_main); - Misbehaving(pfrom->GetId(), 20); - return error("message addr size() = %u", vAddr.size()); + Misbehaving(pfrom->GetId(), 20, strprintf("message addr size() = %u", vAddr.size())); + return false; } // Store the new addresses @@ -1859,8 +1861,8 @@ bool static ProcessMessage(CNode* pfrom, const std::string& strCommand, CDataStr if (vInv.size() > MAX_INV_SZ) { LOCK(cs_main); - Misbehaving(pfrom->GetId(), 20); - return error("message inv size() = %u", vInv.size()); + Misbehaving(pfrom->GetId(), 20, strprintf("message inv size() = %u", vInv.size())); + return false; } bool fBlocksOnly = !fRelayTxes; @@ -1920,8 +1922,8 @@ bool static ProcessMessage(CNode* pfrom, const std::string& strCommand, CDataStr if (vInv.size() > MAX_INV_SZ) { LOCK(cs_main); - Misbehaving(pfrom->GetId(), 20); - return error("message getdata size() = %u", vInv.size()); + Misbehaving(pfrom->GetId(), 20, strprintf("message getdata size() = %u", vInv.size())); + return false; } LogPrint(BCLog::NET, "received getdata (%u invsz) peer=%d\n", vInv.size(), pfrom->GetId()); @@ -2323,9 +2325,8 @@ 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); + Misbehaving(pfrom->GetId(), nDoS, strprintf("Peer %d sent us invalid header via cmpctblock\n", pfrom->GetId())); } else { LogPrint(BCLog::NET, "Peer %d sent us invalid header via cmpctblock\n", pfrom->GetId()); } @@ -2411,8 +2412,7 @@ bool static ProcessMessage(CNode* pfrom, const std::string& strCommand, CDataStr ReadStatus status = partialBlock.InitData(cmpctblock, vExtraTxnForCompact); if (status == READ_STATUS_INVALID) { MarkBlockAsReceived(pindex->GetBlockHash()); // Reset in-flight state in case of whitelist - Misbehaving(pfrom->GetId(), 100); - LogPrintf("Peer %d sent us invalid compact block\n", pfrom->GetId()); + Misbehaving(pfrom->GetId(), 100, strprintf("Peer %d sent us invalid compact block\n", pfrom->GetId())); return true; } else if (status == READ_STATUS_FAILED) { // Duplicate txindexes, the block is now in-flight, so just request it @@ -2539,8 +2539,7 @@ bool static ProcessMessage(CNode* pfrom, const std::string& strCommand, CDataStr ReadStatus status = partialBlock.FillBlock(*pblock, resp.txn); if (status == READ_STATUS_INVALID) { MarkBlockAsReceived(resp.blockhash); // Reset in-flight state in case of whitelist - Misbehaving(pfrom->GetId(), 100); - LogPrintf("Peer %d sent us invalid compact block/non-matching block transactions\n", pfrom->GetId()); + Misbehaving(pfrom->GetId(), 100, strprintf("Peer %d sent us invalid compact block/non-matching block transactions\n", pfrom->GetId())); return true; } else if (status == READ_STATUS_FAILED) { // Might have collided, fall back to getdata now :( @@ -2602,8 +2601,8 @@ bool static ProcessMessage(CNode* pfrom, const std::string& strCommand, CDataStr unsigned int nCount = ReadCompactSize(vRecv); if (nCount > MAX_HEADERS_RESULTS) { LOCK(cs_main); - Misbehaving(pfrom->GetId(), 20); - return error("headers message size = %u", nCount); + Misbehaving(pfrom->GetId(), 20, strprintf("headers message size = %u", nCount)); + return false; } headers.resize(nCount); for (unsigned int n = 0; n < nCount; n++) { diff --git a/src/net_processing.h b/src/net_processing.h index 4f2b8935f4..b534ef01c3 100644 --- a/src/net_processing.h +++ b/src/net_processing.h @@ -79,6 +79,6 @@ struct CNodeStateStats { /** Get statistics from node state */ bool GetNodeStateStats(NodeId nodeid, CNodeStateStats &stats); /** Increase a node's misbehavior score. */ -void Misbehaving(NodeId nodeid, int howmuch); +void Misbehaving(NodeId nodeid, int howmuch, const std::string& message=""); #endif // BITCOIN_NET_PROCESSING_H -- cgit v1.2.3