Merge #12218: net: Move misbehaving logging to net logging category

d3a185a net: Move misbehaving logging to net logging category (Wladimir J. van der Laan)

Pull request description:

  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. As it is impossible to correlate the `peer=X` numbers to specific incoming connections now without enabling the `net` category, it doesn't really help to see these messages by default.

  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

  When there is a category for "important" net messages (see #12219 ), we should move it there.

Tree-SHA512: 51c97e9a649bf5409f2fd4625fa1243a036e9c9de6037bb064244207408c2e0eb025e3af80866df673cdc006b8f35dc4078d074033f0d4c6a73bbb03949a269f
This commit is contained in:
Wladimir J. van der Laan 2018-02-06 12:34:17 +01:00
commit 9a32114626
No known key found for this signature in database
GPG Key ID: 1E4AED62986CD25D
2 changed files with 23 additions and 24 deletions

View File

@ -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++) {

View File

@ -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