From cc3d97500e2082f4911b2ee4d05624d60f05d323 Mon Sep 17 00:00:00 2001 From: woodser Date: Sat, 14 Dec 2024 09:10:01 -0500 Subject: [PATCH] throttle warnings in KeepAlive and PeerExchange handlers #1468 --- .../network/p2p/network/Connection.java | 16 +++++++------- .../p2p/peers/keepalive/KeepAliveHandler.java | 21 +++++++++++++++---- .../peerexchange/PeerExchangeHandler.java | 19 ++++++++++++++--- 3 files changed, 41 insertions(+), 15 deletions(-) diff --git a/p2p/src/main/java/haveno/network/p2p/network/Connection.java b/p2p/src/main/java/haveno/network/p2p/network/Connection.java index 1a7f1b84dfd..8165ecd0b3a 100644 --- a/p2p/src/main/java/haveno/network/p2p/network/Connection.java +++ b/p2p/src/main/java/haveno/network/p2p/network/Connection.java @@ -175,9 +175,9 @@ public static int getShutdownTimeout() { // throttle logs of reported invalid requests private static final long LOG_THROTTLE_INTERVAL_MS = 30000; // throttle logging rule violations and warnings to once every 30 seconds private static long lastLoggedInvalidRequestReportTs = 0; - private static int numUnloggedInvalidRequestReports = 0; + private static int numThrottledInvalidRequestReports = 0; private static long lastLoggedWarningTs = 0; - private static int numUnloggedWarnings = 0; + private static int numThrottledWarnings = 0; /////////////////////////////////////////////////////////////////////////////////////////// // Constructor @@ -620,7 +620,7 @@ private static synchronized boolean reportInvalidRequest(Connection connection, boolean logReport = System.currentTimeMillis() - lastLoggedInvalidRequestReportTs > LOG_THROTTLE_INTERVAL_MS; // count the number of unlogged reports since last log entry - if (!logReport) numUnloggedInvalidRequestReports++; + if (!logReport) numThrottledInvalidRequestReports++; // handle report if (logReport) log.warn("We got reported the ruleViolation {} at connection with address={}, uid={}, errorMessage={}", ruleViolation, connection.getPeersNodeAddressProperty(), connection.getUid(), errorMessage); @@ -654,8 +654,8 @@ private static synchronized boolean reportInvalidRequest(Connection connection, private static synchronized void resetReportedInvalidRequestsThrottle(boolean logReport) { if (logReport) { - if (numUnloggedInvalidRequestReports > 0) log.warn("We received {} other reports of invalid requests since the last log entry", numUnloggedInvalidRequestReports); - numUnloggedInvalidRequestReports = 0; + if (numThrottledInvalidRequestReports > 0) log.warn("We received {} other reports of invalid requests since the last log entry", numThrottledInvalidRequestReports); + numThrottledInvalidRequestReports = 0; lastLoggedInvalidRequestReportTs = System.currentTimeMillis(); } } @@ -940,11 +940,11 @@ private synchronized void throttleWarn(String msg) { boolean logWarning = System.currentTimeMillis() - lastLoggedWarningTs > LOG_THROTTLE_INTERVAL_MS; if (logWarning) { log.warn(msg); - if (numUnloggedWarnings > 0) log.warn("We received {} other log warnings since the last log entry", numUnloggedWarnings); - numUnloggedWarnings = 0; + if (numThrottledWarnings > 0) log.warn("{} warnings were throttled since the last log entry", numThrottledWarnings); + numThrottledWarnings = 0; lastLoggedWarningTs = System.currentTimeMillis(); } else { - numUnloggedWarnings++; + numThrottledWarnings++; } } } diff --git a/p2p/src/main/java/haveno/network/p2p/peers/keepalive/KeepAliveHandler.java b/p2p/src/main/java/haveno/network/p2p/peers/keepalive/KeepAliveHandler.java index 91ba2278c0b..7d2243aa1b8 100644 --- a/p2p/src/main/java/haveno/network/p2p/peers/keepalive/KeepAliveHandler.java +++ b/p2p/src/main/java/haveno/network/p2p/peers/keepalive/KeepAliveHandler.java @@ -40,8 +40,10 @@ class KeepAliveHandler implements MessageListener { private static final Logger log = LoggerFactory.getLogger(KeepAliveHandler.class); - private static final int DELAY_MS = 10_000; + private static final long LOG_THROTTLE_INTERVAL_MS = 60000; // throttle logging warnings to once every 60 seconds + private static long lastLoggedWarningTs = 0; + private static int numThrottledWarnings = 0; /////////////////////////////////////////////////////////////////////////////////////////// @@ -147,9 +149,8 @@ public void onMessage(NetworkEnvelope networkEnvelope, Connection connection) { cleanup(); listener.onComplete(); } else { - log.warn("Nonce not matching. That should never happen.\n\t" + - "We drop that message. nonce={} / requestNonce={}", - nonce, pong.getRequestNonce()); + throttleWarn("Nonce not matching. That should never happen.\n" + + "\tWe drop that message. nonce=" + nonce + " / requestNonce=" + pong.getRequestNonce()); } } else { log.trace("We have stopped already. We ignore that onMessage call."); @@ -167,4 +168,16 @@ private void cleanup() { delayTimer = null; } } + + private synchronized void throttleWarn(String msg) { + boolean logWarning = System.currentTimeMillis() - lastLoggedWarningTs > LOG_THROTTLE_INTERVAL_MS; + if (logWarning) { + log.warn(msg); + if (numThrottledWarnings > 0) log.warn("{} warnings were throttled since the last log entry", numThrottledWarnings); + numThrottledWarnings = 0; + lastLoggedWarningTs = System.currentTimeMillis(); + } else { + numThrottledWarnings++; + } + } } diff --git a/p2p/src/main/java/haveno/network/p2p/peers/peerexchange/PeerExchangeHandler.java b/p2p/src/main/java/haveno/network/p2p/peers/peerexchange/PeerExchangeHandler.java index 1a929289a0a..da4e749965e 100644 --- a/p2p/src/main/java/haveno/network/p2p/peers/peerexchange/PeerExchangeHandler.java +++ b/p2p/src/main/java/haveno/network/p2p/peers/peerexchange/PeerExchangeHandler.java @@ -45,6 +45,9 @@ class PeerExchangeHandler implements MessageListener { // We want to keep timeout short here private static final long TIMEOUT = 90; private static final int DELAY_MS = 500; + private static final long LOG_THROTTLE_INTERVAL_MS = 60000; // throttle logging warnings to once every 60 seconds + private static long lastLoggedWarningTs = 0; + private static int numThrottledWarnings = 0; /////////////////////////////////////////////////////////////////////////////////////////// @@ -173,9 +176,8 @@ public void onMessage(NetworkEnvelope networkEnvelope, Connection connection) { cleanup(); listener.onComplete(); } else { - log.warn("Nonce not matching. That should never happen.\n\t" + - "We drop that message. nonce={} / requestNonce={}", - nonce, getPeersResponse.getRequestNonce()); + throttleWarn("Nonce not matching. That should never happen.\n" + + "\tWe drop that message. nonce=" + nonce + " / requestNonce=" + getPeersResponse.getRequestNonce()); } } else { log.trace("We have stopped that handler already. We ignore that onMessage call."); @@ -216,4 +218,15 @@ private void cleanup() { } } + private synchronized void throttleWarn(String msg) { + boolean logWarning = System.currentTimeMillis() - lastLoggedWarningTs > LOG_THROTTLE_INTERVAL_MS; + if (logWarning) { + log.warn(msg); + if (numThrottledWarnings > 0) log.warn("{} warnings were throttled since the last log entry", numThrottledWarnings); + numThrottledWarnings = 0; + lastLoggedWarningTs = System.currentTimeMillis(); + } else { + numThrottledWarnings++; + } + } }