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
This commit is contained in:
Wladimir J. van der Laan 2018-01-18 17:21:08 +01:00
parent 898f560b55
commit d3a185a33b
2 changed files with 23 additions and 24 deletions

View file

@ -750,7 +750,7 @@ unsigned int LimitOrphanTxSize(unsigned int nMaxOrphans)
} }
// Requires cs_main. // Requires cs_main.
void Misbehaving(NodeId pnode, int howmuch) void Misbehaving(NodeId pnode, int howmuch, const std::string& message)
{ {
if (howmuch == 0) if (howmuch == 0)
return; return;
@ -761,12 +761,13 @@ void Misbehaving(NodeId pnode, int howmuch)
state->nMisbehavior += howmuch; state->nMisbehavior += howmuch;
int banscore = gArgs.GetArg("-banscore", DEFAULT_BANSCORE_THRESHOLD); int banscore = gArgs.GetArg("-banscore", DEFAULT_BANSCORE_THRESHOLD);
std::string message_prefixed = message.empty() ? "" : (": " + message);
if (state->nMisbehavior >= banscore && state->nMisbehavior - howmuch < banscore) 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; state->fShouldBan = true;
} else } 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++) { for (size_t i = 0; i < req.indexes.size(); i++) {
if (req.indexes[i] >= block.vtx.size()) { if (req.indexes[i] >= block.vtx.size()) {
LOCK(cs_main); LOCK(cs_main);
Misbehaving(pfrom->GetId(), 100); Misbehaving(pfrom->GetId(), 100, strprintf("Peer %d sent us a getblocktxn with out-of-bounds tx indices", pfrom->GetId()));
LogPrintf("Peer %d sent us a getblocktxn with out-of-bounds tx indices", pfrom->GetId());
return; return;
} }
resp.txn[i] = block.vtx[req.indexes[i]]; resp.txn[i] = block.vtx[req.indexes[i]];
@ -1318,8 +1318,8 @@ bool static ProcessHeadersMessage(CNode *pfrom, CConnman *connman, const std::ve
uint256 hashLastBlock; uint256 hashLastBlock;
for (const CBlockHeader& header : headers) { for (const CBlockHeader& header : headers) {
if (!hashLastBlock.IsNull() && header.hashPrevBlock != hashLastBlock) { if (!hashLastBlock.IsNull() && header.hashPrevBlock != hashLastBlock) {
Misbehaving(pfrom->GetId(), 20); Misbehaving(pfrom->GetId(), 20, "non-continuous headers sequence");
return error("non-continuous headers sequence"); return false;
} }
hashLastBlock = header.GetHash(); hashLastBlock = header.GetHash();
} }
@ -1338,7 +1338,9 @@ bool static ProcessHeadersMessage(CNode *pfrom, CConnman *connman, const std::ve
if (state.IsInvalid(nDoS)) { if (state.IsInvalid(nDoS)) {
LOCK(cs_main); LOCK(cs_main);
if (nDoS > 0) { 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()) { if (punish_duplicate_invalid && mapBlockIndex.find(first_invalid_header.GetHash()) != mapBlockIndex.end()) {
// Goal: don't allow outbound peers to use up our outbound // 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. // etc), and not just the duplicate-invalid case.
pfrom->fDisconnect = true; 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) if (vAddr.size() > 1000)
{ {
LOCK(cs_main); LOCK(cs_main);
Misbehaving(pfrom->GetId(), 20); Misbehaving(pfrom->GetId(), 20, strprintf("message addr size() = %u", vAddr.size()));
return error("message addr size() = %u", vAddr.size()); return false;
} }
// Store the new addresses // Store the new addresses
@ -1859,8 +1861,8 @@ bool static ProcessMessage(CNode* pfrom, const std::string& strCommand, CDataStr
if (vInv.size() > MAX_INV_SZ) if (vInv.size() > MAX_INV_SZ)
{ {
LOCK(cs_main); LOCK(cs_main);
Misbehaving(pfrom->GetId(), 20); Misbehaving(pfrom->GetId(), 20, strprintf("message inv size() = %u", vInv.size()));
return error("message inv size() = %u", vInv.size()); return false;
} }
bool fBlocksOnly = !fRelayTxes; bool fBlocksOnly = !fRelayTxes;
@ -1920,8 +1922,8 @@ bool static ProcessMessage(CNode* pfrom, const std::string& strCommand, CDataStr
if (vInv.size() > MAX_INV_SZ) if (vInv.size() > MAX_INV_SZ)
{ {
LOCK(cs_main); LOCK(cs_main);
Misbehaving(pfrom->GetId(), 20); Misbehaving(pfrom->GetId(), 20, strprintf("message getdata size() = %u", vInv.size()));
return error("message getdata size() = %u", vInv.size()); return false;
} }
LogPrint(BCLog::NET, "received getdata (%u invsz) peer=%d\n", vInv.size(), pfrom->GetId()); 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; int nDoS;
if (state.IsInvalid(nDoS)) { if (state.IsInvalid(nDoS)) {
if (nDoS > 0) { if (nDoS > 0) {
LogPrintf("Peer %d sent us invalid header via cmpctblock\n", pfrom->GetId());
LOCK(cs_main); LOCK(cs_main);
Misbehaving(pfrom->GetId(), nDoS); Misbehaving(pfrom->GetId(), nDoS, strprintf("Peer %d sent us invalid header via cmpctblock\n", pfrom->GetId()));
} else { } else {
LogPrint(BCLog::NET, "Peer %d sent us invalid header via cmpctblock\n", pfrom->GetId()); 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); ReadStatus status = partialBlock.InitData(cmpctblock, vExtraTxnForCompact);
if (status == READ_STATUS_INVALID) { if (status == READ_STATUS_INVALID) {
MarkBlockAsReceived(pindex->GetBlockHash()); // Reset in-flight state in case of whitelist MarkBlockAsReceived(pindex->GetBlockHash()); // Reset in-flight state in case of whitelist
Misbehaving(pfrom->GetId(), 100); Misbehaving(pfrom->GetId(), 100, strprintf("Peer %d sent us invalid compact block\n", pfrom->GetId()));
LogPrintf("Peer %d sent us invalid compact block\n", pfrom->GetId());
return true; return true;
} else if (status == READ_STATUS_FAILED) { } else if (status == READ_STATUS_FAILED) {
// Duplicate txindexes, the block is now in-flight, so just request it // 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); ReadStatus status = partialBlock.FillBlock(*pblock, resp.txn);
if (status == READ_STATUS_INVALID) { if (status == READ_STATUS_INVALID) {
MarkBlockAsReceived(resp.blockhash); // Reset in-flight state in case of whitelist MarkBlockAsReceived(resp.blockhash); // Reset in-flight state in case of whitelist
Misbehaving(pfrom->GetId(), 100); Misbehaving(pfrom->GetId(), 100, strprintf("Peer %d sent us invalid compact block/non-matching block transactions\n", pfrom->GetId()));
LogPrintf("Peer %d sent us invalid compact block/non-matching block transactions\n", pfrom->GetId());
return true; return true;
} else if (status == READ_STATUS_FAILED) { } else if (status == READ_STATUS_FAILED) {
// Might have collided, fall back to getdata now :( // 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); unsigned int nCount = ReadCompactSize(vRecv);
if (nCount > MAX_HEADERS_RESULTS) { if (nCount > MAX_HEADERS_RESULTS) {
LOCK(cs_main); LOCK(cs_main);
Misbehaving(pfrom->GetId(), 20); Misbehaving(pfrom->GetId(), 20, strprintf("headers message size = %u", nCount));
return error("headers message size = %u", nCount); return false;
} }
headers.resize(nCount); headers.resize(nCount);
for (unsigned int n = 0; n < nCount; n++) { for (unsigned int n = 0; n < nCount; n++) {

View file

@ -79,6 +79,6 @@ struct CNodeStateStats {
/** Get statistics from node state */ /** Get statistics from node state */
bool GetNodeStateStats(NodeId nodeid, CNodeStateStats &stats); bool GetNodeStateStats(NodeId nodeid, CNodeStateStats &stats);
/** Increase a node's misbehavior score. */ /** 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 #endif // BITCOIN_NET_PROCESSING_H