From b7b0635fdd1824c2f53d5e34a1a1f718e7f6af3a Mon Sep 17 00:00:00 2001 From: Armin Date: Thu, 5 Jul 2018 17:54:59 +0200 Subject: [PATCH 1/2] TESTS: Check for Netty resource leaks * Enabled advanced leak detection when loading `EsTestCase` * Added custom `Appender` to collect leak logs and check for logged errors in a way similar to what is done for the `StatusLogger` * Fixes #20398 --- .../org/elasticsearch/test/ESTestCase.java | 32 +++++++++++++++++++ 1 file changed, 32 insertions(+) diff --git a/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java b/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java index 7d44b3230a15f..e47b51736cfcc 100644 --- a/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java +++ b/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java @@ -32,8 +32,12 @@ import org.apache.logging.log4j.Level; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.core.Appender; +import org.apache.logging.log4j.core.LogEvent; import org.apache.logging.log4j.core.LoggerContext; +import org.apache.logging.log4j.core.appender.AbstractAppender; import org.apache.logging.log4j.core.config.Configurator; +import org.apache.logging.log4j.core.layout.PatternLayout; import org.apache.logging.log4j.status.StatusConsoleListener; import org.apache.logging.log4j.status.StatusData; import org.apache.logging.log4j.status.StatusLogger; @@ -179,6 +183,8 @@ public abstract class ESTestCase extends LuceneTestCase { private static final AtomicInteger portGenerator = new AtomicInteger(); + private static final Collection nettyLoggedLeaks = new ArrayList<>(); + @AfterClass public static void resetPortCounter() { portGenerator.set(0); @@ -188,6 +194,25 @@ public static void resetPortCounter() { System.setProperty("log4j.shutdownHookEnabled", "false"); System.setProperty("log4j2.disable.jmx", "true"); + // Enable Netty leak detection and monitor logger for logged leak errors + System.setProperty("io.netty.leakDetection.level", "advanced"); + String leakLoggerName = "io.netty.util.ResourceLeakDetector"; + Logger leakLogger = LogManager.getLogger(leakLoggerName); + Appender leakAppender = new AbstractAppender(leakLoggerName, null, + PatternLayout.newBuilder().withPattern("%m").build()) { + @Override + public void append(LogEvent event) { + String message = event.getMessage().getFormattedMessage(); + if (Level.ERROR.equals(event.getLevel()) && message.contains("LEAK:")) { + synchronized (nettyLoggedLeaks) { + nettyLoggedLeaks.add(message); + } + } + } + }; + leakAppender.start(); + Loggers.addAppender(leakLogger, leakAppender); + // shutdown hook so that when the test JVM exits, logging is shutdown too Runtime.getRuntime().addShutdownHook(new Thread(() -> { LoggerContext context = (LoggerContext) LogManager.getContext(false); @@ -432,6 +457,13 @@ protected static void checkStaticState(boolean afterClass) throws Exception { statusData.clear(); } } + synchronized (nettyLoggedLeaks) { + try { + assertThat(nettyLoggedLeaks, empty()); + } finally { + nettyLoggedLeaks.clear(); + } + } } // this must be a separate method from other ensure checks above so suite scoped integ tests can call...TODO: fix that From 43ed1d8426c8d19b2ec292eca2feaf40d1f680f6 Mon Sep 17 00:00:00 2001 From: Armin Date: Fri, 20 Jul 2018 06:08:00 +0200 Subject: [PATCH 2/2] CR: Stop netty leak logger on shutdown --- .../src/main/java/org/elasticsearch/test/ESTestCase.java | 1 + 1 file changed, 1 insertion(+) diff --git a/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java b/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java index f7937231868c4..5d555ece438fa 100644 --- a/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java +++ b/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java @@ -219,6 +219,7 @@ public void append(LogEvent event) { // shutdown hook so that when the test JVM exits, logging is shutdown too Runtime.getRuntime().addShutdownHook(new Thread(() -> { + leakAppender.stop(); LoggerContext context = (LoggerContext) LogManager.getContext(false); Configurator.shutdown(context); }));