From 19398bb73e3a24ac2ddab0515bc34e23cbf57731 Mon Sep 17 00:00:00 2001 From: woodser Date: Sat, 14 Dec 2024 18:15:26 -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 1a7f1b84..8165ecd0 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 class Connection implements HasCapabilities, Runnable, MessageListener { // 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 @@ public class Connection implements HasCapabilities, Runnable, MessageListener { 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 @@ public class Connection implements HasCapabilities, Runnable, MessageListener { 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 @@ public class Connection implements HasCapabilities, Runnable, MessageListener { 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 91ba2278..07ea9397 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 @@ import java.util.concurrent.TimeUnit; 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 @@ class KeepAliveHandler implements MessageListener { 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() + ", peerNodeAddress=" + connection.getPeersNodeAddressOptional().orElseGet(null)); } } else { log.trace("We have stopped already. We ignore that onMessage call."); @@ -167,4 +168,16 @@ class KeepAliveHandler implements MessageListener { 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 1a929289..0b10307c 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 @@ class PeerExchangeHandler implements MessageListener { 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() + ", peerNodeAddress=" + connection.getPeersNodeAddressOptional().orElseGet(null)); } } else { log.trace("We have stopped that handler already. We ignore that onMessage call."); @@ -216,4 +218,15 @@ class PeerExchangeHandler implements MessageListener { } } + 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++; + } + } }