From d6f6310745e4049284b69129ec80cf4e5f312736 Mon Sep 17 00:00:00 2001 From: Ryan Ernst Date: Mon, 6 Oct 2025 15:48:41 -0700 Subject: [PATCH 1/2] Add prefix to java util logging logger names The bridge between Java util logging and Log4j works by mapping each log message received in JUL to a log event in log4j. The JUL bridge tests check that messages of varying log levels are emitted. Unfortunately this has a bad interaction with entitlements and tests. When a class (eg Regex, used by the test mock logger) is loaded, entitlements looks at that class to see if it should transform it. It then logs a trace message to say it will not be transformed. Yet if a class is loaded late, like Regex is, entitlements will emit this trace log message while log4j is already appending the original test log message. That in turn causes a status log message indicating a recursive call to the mock appender, which tests do not expect, and the test fails. This commit sidesteps the issue by adding a special prefix, `jul`, to the mapping between logger names in JUL and log4j. By not setting the log level of the root log4j logger, the entitlements trace message is never emitted. --- muted-tests.yml | 3 --- .../common/logging/JULBridge.java | 11 +++++++++- .../common/logging/JULBridgeTests.java | 22 ++++++++++--------- 3 files changed, 22 insertions(+), 14 deletions(-) diff --git a/muted-tests.yml b/muted-tests.yml index 6e7df82f43b16..ffbe46f9c9e86 100644 --- a/muted-tests.yml +++ b/muted-tests.yml @@ -369,9 +369,6 @@ tests: - class: org.elasticsearch.xpack.sql.qa.mixed_node.SqlCompatIT method: testNullsOrderWithMissingOrderSupportQueryingNewNode issue: https://github.com/elastic/elasticsearch/issues/132249 -- class: org.elasticsearch.common.logging.JULBridgeTests - method: testThrowable - issue: https://github.com/elastic/elasticsearch/issues/132280 - class: org.elasticsearch.xpack.ml.integration.AutodetectMemoryLimitIT method: testManyDistinctOverFields issue: https://github.com/elastic/elasticsearch/issues/132308 diff --git a/server/src/main/java/org/elasticsearch/common/logging/JULBridge.java b/server/src/main/java/org/elasticsearch/common/logging/JULBridge.java index f16fa15394084..14708a75e5086 100644 --- a/server/src/main/java/org/elasticsearch/common/logging/JULBridge.java +++ b/server/src/main/java/org/elasticsearch/common/logging/JULBridge.java @@ -58,9 +58,18 @@ public static void install() { private JULBridge() {} + // package private for tests. Prefix log4j logger names with "jul" to distinguish from other loggers + static String loggerName(String julLoggerName) { + String loggerName = "jul"; + if (julLoggerName.isEmpty() == false) { + loggerName += "." + julLoggerName; + } + return loggerName; + } + @Override public void publish(LogRecord record) { - Logger logger = LogManager.getLogger(record.getLoggerName()); + Logger logger = LogManager.getLogger(loggerName(record.getLoggerName())); Level level = translateJulLevel(record.getLevel()); Throwable thrown = record.getThrown(); diff --git a/server/src/test/java/org/elasticsearch/common/logging/JULBridgeTests.java b/server/src/test/java/org/elasticsearch/common/logging/JULBridgeTests.java index 1d45a056ce232..d5070c78f4981 100644 --- a/server/src/test/java/org/elasticsearch/common/logging/JULBridgeTests.java +++ b/server/src/test/java/org/elasticsearch/common/logging/JULBridgeTests.java @@ -21,6 +21,7 @@ import org.junit.Before; import org.junit.BeforeClass; +import java.lang.invoke.MethodHandles; import java.util.logging.ConsoleHandler; import java.util.logging.Handler; @@ -59,11 +60,12 @@ public static void restoreLoggerState() { } } - private void assertLogged(Runnable loggingCode, LoggingExpectation... expectations) { - Logger testLogger = LogManager.getLogger(""); + private void assertLogged(String julLoggerName, Runnable loggingCode, LoggingExpectation... expectations) { + String loggerName = JULBridge.loggerName(julLoggerName); + Logger testLogger = LogManager.getLogger(loggerName); Level savedLevel = testLogger.getLevel(); - try (var mockLog = MockLog.capture("")) { + try (var mockLog = MockLog.capture(loggerName)) { Loggers.setLevel(testLogger, Level.ALL); for (var expectation : expectations) { mockLog.addExpectation(expectation); @@ -76,7 +78,7 @@ private void assertLogged(Runnable loggingCode, LoggingExpectation... expectatio } private void assertMessage(String msg, java.util.logging.Level julLevel, Level expectedLevel) { - assertLogged(() -> logger.log(julLevel, msg), new SeenEventExpectation(msg, "", expectedLevel, msg)); + assertLogged("", () -> logger.log(julLevel, msg), new SeenEventExpectation(msg, "jul", expectedLevel, msg)); } private static java.util.logging.Level julLevel(int value) { @@ -113,13 +115,13 @@ public void testCustomLevels() { public void testThrowable() { JULBridge.install(); java.util.logging.Logger logger = java.util.logging.Logger.getLogger(""); - assertLogged(() -> logger.log(java.util.logging.Level.SEVERE, "error msg", new Exception("some error")), new LoggingExpectation() { + assertLogged("", () -> logger.log(java.util.logging.Level.SEVERE, "error msg", new Exception("some error")), new LoggingExpectation() { boolean matched = false; @Override public void match(LogEvent event) { Throwable thrown = event.getThrown(); - matched = event.getLoggerName().equals("") + matched = event.getLoggerName().equals("jul") && event.getMessage().getFormattedMessage().equals("error msg") && thrown != null && thrown.getMessage().equals("some error"); @@ -135,19 +137,19 @@ public void assertMatched() { public void testChildLogger() { JULBridge.install(); java.util.logging.Logger childLogger = java.util.logging.Logger.getLogger("foo"); - assertLogged(() -> childLogger.info("child msg"), new SeenEventExpectation("child msg", "foo", Level.INFO, "child msg")); + assertLogged("foo", () -> childLogger.info("child msg"), new SeenEventExpectation("child msg", "jul.foo", Level.INFO, "child msg")); } public void testNullMessage() { JULBridge.install(); - assertLogged(() -> logger.info((String) null), new SeenEventExpectation("null msg", "", Level.INFO, "")); + assertLogged("", () -> logger.info((String) null), new SeenEventExpectation("null msg", "jul", Level.INFO, "")); } public void testFormattedMessage() { JULBridge.install(); - assertLogged( + assertLogged("", () -> logger.log(java.util.logging.Level.INFO, "{0}", "a var"), - new SeenEventExpectation("formatted msg", "", Level.INFO, "a var") + new SeenEventExpectation("formatted msg", "jul", Level.INFO, "a var") ); } } From 4db6145e72ec7e3525a4e359113e9e59f60928f4 Mon Sep 17 00:00:00 2001 From: elasticsearchmachine Date: Mon, 6 Oct 2025 23:06:41 +0000 Subject: [PATCH 2/2] [CI] Auto commit changes from spotless --- .../common/logging/JULBridgeTests.java | 40 ++++++++++--------- 1 file changed, 22 insertions(+), 18 deletions(-) diff --git a/server/src/test/java/org/elasticsearch/common/logging/JULBridgeTests.java b/server/src/test/java/org/elasticsearch/common/logging/JULBridgeTests.java index d5070c78f4981..00c3baf93a9f0 100644 --- a/server/src/test/java/org/elasticsearch/common/logging/JULBridgeTests.java +++ b/server/src/test/java/org/elasticsearch/common/logging/JULBridgeTests.java @@ -21,7 +21,6 @@ import org.junit.Before; import org.junit.BeforeClass; -import java.lang.invoke.MethodHandles; import java.util.logging.ConsoleHandler; import java.util.logging.Handler; @@ -115,23 +114,27 @@ public void testCustomLevels() { public void testThrowable() { JULBridge.install(); java.util.logging.Logger logger = java.util.logging.Logger.getLogger(""); - assertLogged("", () -> logger.log(java.util.logging.Level.SEVERE, "error msg", new Exception("some error")), new LoggingExpectation() { - boolean matched = false; - - @Override - public void match(LogEvent event) { - Throwable thrown = event.getThrown(); - matched = event.getLoggerName().equals("jul") - && event.getMessage().getFormattedMessage().equals("error msg") - && thrown != null - && thrown.getMessage().equals("some error"); + assertLogged( + "", + () -> logger.log(java.util.logging.Level.SEVERE, "error msg", new Exception("some error")), + new LoggingExpectation() { + boolean matched = false; + + @Override + public void match(LogEvent event) { + Throwable thrown = event.getThrown(); + matched = event.getLoggerName().equals("jul") + && event.getMessage().getFormattedMessage().equals("error msg") + && thrown != null + && thrown.getMessage().equals("some error"); + } + + @Override + public void assertMatched() { + assertThat("expected to see error message but did not", matched, equalTo(true)); + } } - - @Override - public void assertMatched() { - assertThat("expected to see error message but did not", matched, equalTo(true)); - } - }); + ); } public void testChildLogger() { @@ -147,7 +150,8 @@ public void testNullMessage() { public void testFormattedMessage() { JULBridge.install(); - assertLogged("", + assertLogged( + "", () -> logger.log(java.util.logging.Level.INFO, "{0}", "a var"), new SeenEventExpectation("formatted msg", "jul", Level.INFO, "a var") );