From 2e4d0a81db7e5a44773842d910d13b7e6c97936d Mon Sep 17 00:00:00 2001 From: "Piotr P. Karwasz" Date: Tue, 10 Sep 2024 19:46:11 +0200 Subject: [PATCH] Fix reloading of the configuration from HTTP(S) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The `HttpWatcher` didn't propagate the observed last modification time back to the configuration. As a result, each new configuration was already deprecated when it started and the reconfiguration process looped. Closes #2937 Rewrite Jetty tests using WireMock Closes #2813 Co-authored-by: Volkan Yazıcı --- log4j-appserver/pom.xml | 10 + .../core/config/ConfigurationSourceTest.java | 62 +++-- .../HttpThreadContextMapFilterTest.java | 202 -------------- .../MutableThreadContextMapFilterTest.java | 250 ++++++++++++++---- .../core/net/UrlConnectionFactoryTest.java | 213 +++++++-------- .../logging/log4j/core/net/WireMockUtil.java | 84 ++++++ .../log4j/core/util/HttpWatcherTest.java | 160 +++++++++++ .../log4j/core/util/WatchHttpTest.java | 156 ----------- .../log4j/core/util/WatchManagerTest.java | 177 +++++++------ .../ConfigurationSourceTest.xml} | 19 +- .../src/test/resources/emptyConfig.json | 4 - .../MutableThreadContextMapFilterTest.xml | 35 +++ .../src/test/resources/filterConfig.json | 6 - .../logging/log4j/core/LoggerContext.java | 19 +- .../core/config/AbstractConfiguration.java | 30 ++- .../core/config/ConfigurationSource.java | 152 +++++------ .../log4j/core/config/HttpWatcher.java | 39 ++- .../log4j/core/config/package-info.java | 2 +- .../core/config/xml/XmlConfiguration.java | 12 +- .../filter/MutableThreadContextMapFilter.java | 57 ++-- .../logging/log4j/core/util/Loader.java | 5 +- .../logging/log4j/core/util/Source.java | 45 ++-- .../logging/log4j/core/util/WatchManager.java | 23 +- .../util/internal/HttpInputStreamUtil.java | 96 +++++-- .../logging/log4j/core/util/package-info.java | 2 +- log4j-parent/pom.xml | 16 -- pom.xml | 19 +- src/changelog/.2.x.x/2937-http-watcher.xml | 8 + 28 files changed, 1018 insertions(+), 885 deletions(-) delete mode 100644 log4j-core-test/src/test/java/org/apache/logging/log4j/core/filter/HttpThreadContextMapFilterTest.java create mode 100644 log4j-core-test/src/test/java/org/apache/logging/log4j/core/net/WireMockUtil.java create mode 100644 log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/HttpWatcherTest.java delete mode 100644 log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/WatchHttpTest.java rename log4j-core-test/src/test/resources/{log4j2-mutableFilter.xml => config/ConfigurationSourceTest.xml} (69%) delete mode 100644 log4j-core-test/src/test/resources/emptyConfig.json create mode 100644 log4j-core-test/src/test/resources/filter/MutableThreadContextMapFilterTest.xml delete mode 100644 log4j-core-test/src/test/resources/filterConfig.json create mode 100644 src/changelog/.2.x.x/2937-http-watcher.xml diff --git a/log4j-appserver/pom.xml b/log4j-appserver/pom.xml index df0ce0067df..0b9c10b0dd2 100644 --- a/log4j-appserver/pom.xml +++ b/log4j-appserver/pom.xml @@ -52,22 +52,32 @@ org.apache.tomcat.juli;transitive=false, org.eclipse.jetty.util;transitive=false + + + 9.4.56.v20240826 + 10.0.27 + org.eclipse.jetty jetty-util + ${jetty.version} provided + org.apache.tomcat tomcat-juli + ${tomcat-juli.version} provided + org.apache.logging.log4j log4j-api + diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/config/ConfigurationSourceTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/config/ConfigurationSourceTest.java index f17b3b2a55a..5001ad2d449 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/config/ConfigurationSourceTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/config/ConfigurationSourceTest.java @@ -16,6 +16,7 @@ */ package org.apache.logging.log4j.core.config; +import static java.util.Objects.requireNonNull; import static org.junit.jupiter.api.Assertions.assertEquals; import static org.junit.jupiter.api.Assertions.assertNotNull; import static org.junit.jupiter.api.Assertions.assertNull; @@ -32,21 +33,28 @@ import java.net.URL; import java.nio.file.Files; import java.nio.file.Path; -import java.nio.file.Paths; import java.util.jar.Attributes; import java.util.jar.JarEntry; import java.util.jar.JarOutputStream; import java.util.jar.Manifest; +import org.apache.commons.io.IOUtils; import org.apache.logging.log4j.core.net.UrlConnectionFactory; import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.io.TempDir; public class ConfigurationSourceTest { - private static final Path JAR_FILE = Paths.get("target", "test-classes", "jarfile.jar"); - private static final Path CONFIG_FILE = Paths.get("target", "test-classes", "log4j2-console.xml"); - private static final byte[] buffer = new byte[1024]; + /** + * The path inside the jar created by {@link #prepareJarConfigURL} containing the configuration. + */ + public static final String PATH_IN_JAR = "/config/console.xml"; + + private static final String CONFIG_FILE = "/config/ConfigurationSourceTest.xml"; + + @TempDir + private Path tempDir; @Test - public void testJira_LOG4J2_2770_byteArray() throws Exception { + void testJira_LOG4J2_2770_byteArray() throws Exception { final ConfigurationSource configurationSource = new ConfigurationSource(new ByteArrayInputStream(new byte[] {'a', 'b'})); assertNotNull(configurationSource.resetInputStream()); @@ -54,20 +62,19 @@ public void testJira_LOG4J2_2770_byteArray() throws Exception { /** * Checks if the usage of 'jar:' URLs does not increase the file descriptor - * count and the jar file can be deleted. - * - * @throws Exception + * count, and the jar file can be deleted. */ @Test - public void testNoJarFileLeak() throws Exception { - final URL jarConfigURL = prepareJarConfigURL(); + void testNoJarFileLeak() throws Exception { + final Path jarFile = prepareJarConfigURL(tempDir); + final URL jarConfigURL = new URL("jar:" + jarFile.toUri().toURL() + "!" + PATH_IN_JAR); final long expected = getOpenFileDescriptorCount(); UrlConnectionFactory.createConnection(jarConfigURL).getInputStream().close(); // This can only fail on UNIX assertEquals(expected, getOpenFileDescriptorCount()); // This can only fail on Windows try { - Files.delete(JAR_FILE); + Files.delete(jarFile); } catch (IOException e) { fail(e); } @@ -75,7 +82,8 @@ public void testNoJarFileLeak() throws Exception { @Test public void testLoadConfigurationSourceFromJarFile() throws Exception { - final URL jarConfigURL = prepareJarConfigURL(); + final Path jarFile = prepareJarConfigURL(tempDir); + final URL jarConfigURL = new URL("jar:" + jarFile.toUri().toURL() + "!" + PATH_IN_JAR); final long expectedFdCount = getOpenFileDescriptorCount(); ConfigurationSource configSource = ConfigurationSource.fromUri(jarConfigURL.toURI()); assertNotNull(configSource); @@ -90,7 +98,7 @@ public void testLoadConfigurationSourceFromJarFile() throws Exception { assertEquals(expectedFdCount, getOpenFileDescriptorCount()); // This can only fail on Windows try { - Files.delete(JAR_FILE); + Files.delete(jarFile); } catch (IOException e) { fail(e); } @@ -104,22 +112,18 @@ private long getOpenFileDescriptorCount() { return 0L; } - public static URL prepareJarConfigURL() throws IOException { - if (!Files.exists(JAR_FILE)) { - final Manifest manifest = new Manifest(); - manifest.getMainAttributes().put(Attributes.Name.MANIFEST_VERSION, "1.0"); - try (final OutputStream os = Files.newOutputStream(JAR_FILE); - final JarOutputStream jar = new JarOutputStream(os, manifest); - final InputStream config = Files.newInputStream(CONFIG_FILE)) { - final JarEntry jarEntry = new JarEntry("config/console.xml"); - jar.putNextEntry(jarEntry); - int len; - while ((len = config.read(buffer)) != -1) { - jar.write(buffer, 0, len); - } - jar.closeEntry(); - } + public static Path prepareJarConfigURL(Path dir) throws IOException { + Path jarFile = dir.resolve("jarFile.jar"); + final Manifest manifest = new Manifest(); + manifest.getMainAttributes().put(Attributes.Name.MANIFEST_VERSION, "1.0"); + try (final OutputStream os = Files.newOutputStream(jarFile); + final JarOutputStream jar = new JarOutputStream(os, manifest); + final InputStream config = + requireNonNull(ConfigurationSourceTest.class.getResourceAsStream(CONFIG_FILE))) { + final JarEntry jarEntry = new JarEntry("config/console.xml"); + jar.putNextEntry(jarEntry); + IOUtils.copy(config, os); } - return new URL("jar:" + JAR_FILE.toUri().toURL() + "!/config/console.xml"); + return jarFile; } } diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/filter/HttpThreadContextMapFilterTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/filter/HttpThreadContextMapFilterTest.java deleted file mode 100644 index 6782948a43d..00000000000 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/filter/HttpThreadContextMapFilterTest.java +++ /dev/null @@ -1,202 +0,0 @@ -/* - * Licensed to the Apache Software Foundation (ASF) under one or more - * contributor license agreements. See the NOTICE file distributed with - * this work for additional information regarding copyright ownership. - * The ASF licenses this file to you under the Apache License, Version 2.0 - * (the "License"); you may not use this file except in compliance with - * the License. You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - */ -package org.apache.logging.log4j.core.filter; - -import static org.junit.jupiter.api.Assertions.assertNotEquals; -import static org.junit.jupiter.api.Assertions.assertNotNull; -import static org.junit.jupiter.api.Assertions.assertTrue; -import static org.junit.jupiter.api.Assertions.fail; - -import java.io.File; -import java.io.IOException; -import java.nio.file.Files; -import java.nio.file.Path; -import java.nio.file.StandardCopyOption; -import java.util.Base64; -import java.util.Enumeration; -import java.util.concurrent.CountDownLatch; -import java.util.concurrent.TimeUnit; -import javax.servlet.ServletException; -import javax.servlet.http.HttpServletRequest; -import javax.servlet.http.HttpServletResponse; -import org.apache.logging.log4j.Logger; -import org.apache.logging.log4j.ThreadContext; -import org.apache.logging.log4j.core.Appender; -import org.apache.logging.log4j.core.LoggerContext; -import org.apache.logging.log4j.core.config.Configurator; -import org.apache.logging.log4j.core.test.appender.ListAppender; -import org.eclipse.jetty.http.HttpHeader; -import org.eclipse.jetty.server.Server; -import org.eclipse.jetty.server.ServerConnector; -import org.eclipse.jetty.servlet.DefaultServlet; -import org.eclipse.jetty.servlet.ServletContextHandler; -import org.eclipse.jetty.servlet.ServletHolder; -import org.junit.Assert; -import org.junit.jupiter.api.AfterAll; -import org.junit.jupiter.api.AfterEach; -import org.junit.jupiter.api.Assertions; -import org.junit.jupiter.api.BeforeAll; -import org.junitpioneer.jupiter.RetryingTest; - -/** - * Unit test for simple App. - */ -public class HttpThreadContextMapFilterTest implements MutableThreadContextMapFilter.FilterConfigUpdateListener { - - private static final String BASIC = "Basic "; - private static final String expectedCreds = "log4j:log4j"; - private static Server server; - private static final Base64.Decoder decoder = Base64.getDecoder(); - private static int port; - static final String CONFIG = "log4j2-mutableFilter.xml"; - static LoggerContext loggerContext = null; - static final File targetFile = new File("target/test-classes/testConfig.json"); - static final Path target = targetFile.toPath(); - CountDownLatch updated = new CountDownLatch(1); - - @BeforeAll - public static void startServer() throws Exception { - try { - server = new Server(0); - final ServletContextHandler context = new ServletContextHandler(); - final ServletHolder defaultServ = new ServletHolder("default", TestServlet.class); - defaultServ.setInitParameter("resourceBase", System.getProperty("user.dir")); - defaultServ.setInitParameter("dirAllowed", "true"); - context.addServlet(defaultServ, "/"); - server.setHandler(context); - - // Start Server - server.start(); - port = ((ServerConnector) server.getConnectors()[0]).getLocalPort(); - try { - Files.deleteIfExists(target); - } catch (IOException ioe) { - // Ignore this. - } - } catch (Throwable ex) { - ex.printStackTrace(); - throw ex; - } - } - - @AfterAll - public static void stopServer() throws Exception { - if (server != null) { - server.stop(); - } - } - - @AfterEach - public void after() { - try { - Files.deleteIfExists(target); - } catch (IOException ioe) { - // Ignore this. - } - if (loggerContext != null) { - loggerContext.stop(); - loggerContext = null; - } - } - - @RetryingTest(maxAttempts = 5, suspendForMs = 10) - public void filterTest() throws Exception { - System.setProperty("log4j2.Configuration.allowedProtocols", "http"); - System.setProperty("logging.auth.username", "log4j"); - System.setProperty("logging.auth.password", "log4j"); - System.setProperty("configLocation", "http://localhost:" + port + "/testConfig.json"); - ThreadContext.put("loginId", "rgoers"); - Path source = new File("target/test-classes/emptyConfig.json").toPath(); - Files.copy(source, target, StandardCopyOption.REPLACE_EXISTING); - final long fileTime = targetFile.lastModified() - 2000; - assertTrue(targetFile.setLastModified(fileTime)); - loggerContext = Configurator.initialize(null, CONFIG); - assertNotNull(loggerContext); - final Appender app = loggerContext.getConfiguration().getAppender("List"); - assertNotNull(app); - assertTrue(app instanceof ListAppender); - final MutableThreadContextMapFilter filter = - (MutableThreadContextMapFilter) loggerContext.getConfiguration().getFilter(); - assertNotNull(filter); - filter.registerListener(this); - final Logger logger = loggerContext.getLogger("Test"); - logger.debug("This is a test"); - Assertions.assertEquals(0, ((ListAppender) app).getEvents().size()); - source = new File("target/test-classes/filterConfig.json").toPath(); - Files.copy(source, target, StandardCopyOption.REPLACE_EXISTING); - assertNotEquals(fileTime, targetFile.lastModified()); - if (!updated.await(5, TimeUnit.SECONDS)) { - fail("File update was not detected"); - } - updated = new CountDownLatch(1); - logger.debug("This is a test"); - Assertions.assertEquals(1, ((ListAppender) app).getEvents().size()); - Assertions.assertTrue(Files.deleteIfExists(target)); - if (!updated.await(5, TimeUnit.SECONDS)) { - fail("File update for delete was not detected"); - } - } - - public static class TestServlet extends DefaultServlet { - - private static final long serialVersionUID = -2885158530511450659L; - - @Override - protected void doGet(final HttpServletRequest request, final HttpServletResponse response) - throws ServletException, IOException { - final Enumeration headers = request.getHeaders(HttpHeader.AUTHORIZATION.toString()); - if (headers == null) { - response.sendError(401, "No Auth header"); - return; - } - while (headers.hasMoreElements()) { - final String authData = headers.nextElement(); - Assert.assertTrue("Not a Basic auth header", authData.startsWith(BASIC)); - final String credentials = new String(decoder.decode(authData.substring(BASIC.length()))); - if (!expectedCreds.equals(credentials)) { - response.sendError(401, "Invalid credentials"); - return; - } - } - if (request.getServletPath().equals("/testConfig.json")) { - final File file = new File("target/test-classes/testConfig.json"); - if (!file.exists()) { - response.sendError(404, "File not found"); - return; - } - final long modifiedSince = request.getDateHeader(HttpHeader.IF_MODIFIED_SINCE.toString()); - final long lastModified = (file.lastModified() / 1000) * 1000; - if (modifiedSince > 0 && lastModified <= modifiedSince) { - response.setStatus(304); - return; - } - response.setDateHeader(HttpHeader.LAST_MODIFIED.toString(), lastModified); - response.setContentLengthLong(file.length()); - Files.copy(file.toPath(), response.getOutputStream()); - response.getOutputStream().flush(); - response.setStatus(200); - } else { - response.sendError(400, "Unsupported request"); - } - } - } - - @Override - public void onEvent() { - updated.countDown(); - } -} diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/filter/MutableThreadContextMapFilterTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/filter/MutableThreadContextMapFilterTest.java index 598ce46ac29..a2d3919d1dd 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/filter/MutableThreadContextMapFilterTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/filter/MutableThreadContextMapFilterTest.java @@ -16,94 +16,228 @@ */ package org.apache.logging.log4j.core.filter; -import static org.junit.jupiter.api.Assertions.assertNotEquals; +import static java.nio.charset.StandardCharsets.UTF_8; +import static org.apache.logging.log4j.core.net.WireMockUtil.createMapping; +import static org.assertj.core.api.Assertions.assertThat; import static org.junit.jupiter.api.Assertions.assertNotNull; -import static org.junit.jupiter.api.Assertions.assertTrue; -import static org.junit.jupiter.api.Assertions.fail; -import java.io.File; -import java.io.IOException; +import com.github.tomakehurst.wiremock.client.BasicCredentials; +import com.github.tomakehurst.wiremock.client.WireMock; +import com.github.tomakehurst.wiremock.junit5.WireMockRuntimeInfo; +import com.github.tomakehurst.wiremock.junit5.WireMockTest; +import java.io.ByteArrayInputStream; +import java.io.InputStream; import java.nio.file.Files; import java.nio.file.Path; import java.nio.file.StandardCopyOption; -import java.util.concurrent.CountDownLatch; +import java.nio.file.attribute.FileTime; +import java.time.Instant; +import java.time.LocalDateTime; +import java.time.ZoneOffset; +import java.time.ZonedDateTime; +import java.time.temporal.ChronoUnit; import java.util.concurrent.TimeUnit; +import java.util.concurrent.locks.Condition; +import java.util.concurrent.locks.ReentrantLock; import org.apache.logging.log4j.Logger; import org.apache.logging.log4j.ThreadContext; -import org.apache.logging.log4j.core.Appender; import org.apache.logging.log4j.core.LoggerContext; +import org.apache.logging.log4j.core.config.Configuration; +import org.apache.logging.log4j.core.config.ConfigurationFactory; +import org.apache.logging.log4j.core.config.ConfigurationSource; import org.apache.logging.log4j.core.config.Configurator; import org.apache.logging.log4j.core.test.appender.ListAppender; +import org.apache.logging.log4j.test.TestProperties; +import org.apache.logging.log4j.test.junit.SetTestProperty; +import org.apache.logging.log4j.test.junit.UsingTestProperties; import org.junit.jupiter.api.AfterEach; -import org.junit.jupiter.api.Assertions; -import org.junitpioneer.jupiter.RetryingTest; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.io.TempDir; /** * Unit test for simple App. */ -public class MutableThreadContextMapFilterTest implements MutableThreadContextMapFilter.FilterConfigUpdateListener { +@SetTestProperty(key = "log4j2.configurationAllowedProtocols", value = "http,https") +@SetTestProperty(key = "log4j2.configurationPassword", value = "log4j") +@SetTestProperty(key = "log4j2.configurationUsername", value = "log4j") +@UsingTestProperties +@WireMockTest +class MutableThreadContextMapFilterTest implements MutableThreadContextMapFilter.FilterConfigUpdateListener { - static final String CONFIG = "log4j2-mutableFilter.xml"; - static LoggerContext loggerContext = null; - static File targetFile = new File("target/test-classes/testConfig.json"); - static Path target = targetFile.toPath(); - CountDownLatch updated = new CountDownLatch(1); + private static final BasicCredentials CREDENTIALS = new BasicCredentials("log4j", "log4j"); + private static final String FILE_NAME = "testConfig.json"; + private static final String URL_PATH = "/" + FILE_NAME; + private static final String JSON = "application/json"; + + private static final byte[] EMPTY_CONFIG = ("{" // + + " \"configs\":{}" // + + "}") + .getBytes(UTF_8); + private static final byte[] FILTER_CONFIG = ("{" // + + " \"configs\": {" // + + " \"loginId\": [\"rgoers\", \"adam\"]," // + + " \"corpAcctNumber\": [\"30510263\"]" // + + " }" // + + "}") + .getBytes(UTF_8); + + private static final String CONFIG = "filter/MutableThreadContextMapFilterTest.xml"; + private static LoggerContext loggerContext = null; + private final ReentrantLock lock = new ReentrantLock(); + private final Condition filterUpdated = lock.newCondition(); + private final Condition resultVerified = lock.newCondition(); + private Exception exception; @AfterEach - public void after() { - try { - Files.deleteIfExists(target); - } catch (IOException ioe) { - // Ignore this. - } + void cleanup() { + exception = null; ThreadContext.clearMap(); - loggerContext.stop(); - loggerContext = null; + if (loggerContext != null) { + loggerContext.stop(); + loggerContext = null; + } } - @RetryingTest(maxAttempts = 5, suspendForMs = 10) - public void filterTest() throws Exception { - System.setProperty("configLocation", "target/test-classes/testConfig.json"); - ThreadContext.put("loginId", "rgoers"); - Path source = new File("target/test-classes/emptyConfig.json").toPath(); - Files.copy(source, target, StandardCopyOption.REPLACE_EXISTING); - final long fileTime = targetFile.lastModified() - 1000; - assertTrue(targetFile.setLastModified(fileTime)); - loggerContext = Configurator.initialize(null, CONFIG); - assertNotNull(loggerContext); - final Appender app = loggerContext.getConfiguration().getAppender("List"); - assertNotNull(app); - assertTrue(app instanceof ListAppender); - final MutableThreadContextMapFilter filter = - (MutableThreadContextMapFilter) loggerContext.getConfiguration().getFilter(); + @Test + void file_location_works(TestProperties properties, @TempDir Path dir) throws Exception { + // Set up the test file. + Instant now = Instant.now().truncatedTo(ChronoUnit.SECONDS); + Instant before = now.minus(1, ChronoUnit.MINUTES); + Instant after = now.plus(1, ChronoUnit.MINUTES); + Path testConfig = dir.resolve("testConfig.json"); + properties.setProperty("configLocation", testConfig.toString()); + try (final InputStream inputStream = new ByteArrayInputStream(EMPTY_CONFIG)) { + Files.copy(inputStream, testConfig); + Files.setLastModifiedTime(testConfig, FileTime.from(before)); + } + // Setup Log4j + ConfigurationSource source = + ConfigurationSource.fromResource(CONFIG, getClass().getClassLoader()); + Configuration configuration = ConfigurationFactory.getInstance().getConfiguration(null, source); + configuration.initialize(); // To create the components + final ListAppender app = configuration.getAppender("LIST"); + assertThat(app).isNotNull(); + final MutableThreadContextMapFilter filter = (MutableThreadContextMapFilter) configuration.getFilter(); assertNotNull(filter); filter.registerListener(this); - final Logger logger = loggerContext.getLogger("Test"); - logger.debug("This is a test"); - Assertions.assertEquals(0, ((ListAppender) app).getEvents().size()); - source = new File("target/test-classes/filterConfig.json").toPath(); - String msg = null; - boolean copied = false; - for (int i = 0; i < 5 && !copied; ++i) { - Thread.sleep(100 + (100 * i)); - try { - Files.copy(source, target, StandardCopyOption.REPLACE_EXISTING); - copied = true; - } catch (Exception ex) { - msg = ex.getMessage(); + + lock.lock(); + try { + // Starts the configuration + loggerContext = Configurator.initialize(getClass().getClassLoader(), configuration); + assertNotNull(loggerContext); + + final Logger logger = loggerContext.getLogger(MutableThreadContextMapFilterTest.class); + + assertThat(filterUpdated.await(20, TimeUnit.SECONDS)) + .as("Initial configuration was loaded") + .isTrue(); + ThreadContext.put("loginId", "rgoers"); + logger.debug("This is a test"); + assertThat(app.getEvents()).isEmpty(); + + // Prepare the second test case: updated config + try (final InputStream inputStream = new ByteArrayInputStream(FILTER_CONFIG)) { + Files.copy(inputStream, testConfig, StandardCopyOption.REPLACE_EXISTING); + Files.setLastModifiedTime(testConfig, FileTime.from(after)); } + resultVerified.signalAll(); + + assertThat(filterUpdated.await(20, TimeUnit.SECONDS)) + .as("Updated configuration was loaded") + .isTrue(); + logger.debug("This is a test"); + assertThat(app.getEvents()).hasSize(1); + + // Prepare the third test case: removed config + Files.delete(testConfig); + resultVerified.signalAll(); + + assertThat(filterUpdated.await(20, TimeUnit.SECONDS)) + .as("Configuration removal was detected") + .isTrue(); + logger.debug("This is a test"); + assertThat(app.getEvents()).hasSize(1); + resultVerified.signalAll(); + } finally { + lock.unlock(); } - assertTrue(copied, "File not copied: " + msg); - assertNotEquals(fileTime, targetFile.lastModified()); - if (!updated.await(5, TimeUnit.SECONDS)) { - fail("File update was not detected"); + assertThat(exception).as("Asynchronous exception").isNull(); + } + + @Test + void http_location_works(TestProperties properties, WireMockRuntimeInfo info) throws Exception { + WireMock wireMock = info.getWireMock(); + // Setup WireMock + // The HTTP Last-Modified header has a precision of 1 second + ZonedDateTime now = LocalDateTime.now().atZone(ZoneOffset.UTC); + ZonedDateTime before = now.minusMinutes(1); + ZonedDateTime after = now.plusMinutes(1); + properties.setProperty("configLocation", info.getHttpBaseUrl() + URL_PATH); + // Setup Log4j + ConfigurationSource source = + ConfigurationSource.fromResource(CONFIG, getClass().getClassLoader()); + Configuration configuration = ConfigurationFactory.getInstance().getConfiguration(null, source); + configuration.initialize(); // To create the components + final ListAppender app = configuration.getAppender("LIST"); + assertThat(app).isNotNull(); + final MutableThreadContextMapFilter filter = (MutableThreadContextMapFilter) configuration.getFilter(); + assertNotNull(filter); + filter.registerListener(this); + lock.lock(); + try { + // Prepare the first test case: original empty config + wireMock.importStubMappings(createMapping(URL_PATH, CREDENTIALS, EMPTY_CONFIG, JSON, before)); + // Starts the configuration + loggerContext = Configurator.initialize(getClass().getClassLoader(), configuration); + assertNotNull(loggerContext); + + final Logger logger = loggerContext.getLogger(MutableThreadContextMapFilterTest.class); + + assertThat(filterUpdated.await(2, TimeUnit.SECONDS)) + .as("Initial configuration was loaded") + .isTrue(); + ThreadContext.put("loginId", "rgoers"); + logger.debug("This is a test"); + assertThat(app.getEvents()).isEmpty(); + + // Prepare the second test case: updated config + wireMock.removeMappings(); + wireMock.importStubMappings(createMapping(URL_PATH, CREDENTIALS, FILTER_CONFIG, JSON, after)); + resultVerified.signalAll(); + + assertThat(filterUpdated.await(2, TimeUnit.SECONDS)) + .as("Updated configuration was loaded") + .isTrue(); + logger.debug("This is a test"); + assertThat(app.getEvents()).hasSize(1); + + // Prepare the third test case: removed config + wireMock.removeMappings(); + resultVerified.signalAll(); + + assertThat(filterUpdated.await(2, TimeUnit.SECONDS)) + .as("Configuration removal was detected") + .isTrue(); + logger.debug("This is a test"); + assertThat(app.getEvents()).hasSize(1); + resultVerified.signalAll(); + } finally { + lock.unlock(); } - logger.debug("This is a test"); - Assertions.assertEquals(1, ((ListAppender) app).getEvents().size()); + assertThat(exception).as("Asynchronous exception").isNull(); } @Override public void onEvent() { - updated.countDown(); + lock.lock(); + try { + filterUpdated.signalAll(); + resultVerified.await(); + } catch (final InterruptedException e) { + exception = e; + } finally { + lock.unlock(); + } } } diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/net/UrlConnectionFactoryTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/net/UrlConnectionFactoryTest.java index e6bb7d59281..265c538da88 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/net/UrlConnectionFactoryTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/net/UrlConnectionFactoryTest.java @@ -16,20 +16,24 @@ */ package org.apache.logging.log4j.core.net; -import static javax.servlet.http.HttpServletResponse.SC_BAD_REQUEST; +import static com.github.tomakehurst.wiremock.client.WireMock.aResponse; +import static java.util.Objects.requireNonNull; import static javax.servlet.http.HttpServletResponse.SC_INTERNAL_SERVER_ERROR; -import static javax.servlet.http.HttpServletResponse.SC_NOT_FOUND; import static javax.servlet.http.HttpServletResponse.SC_NOT_MODIFIED; import static javax.servlet.http.HttpServletResponse.SC_OK; -import static javax.servlet.http.HttpServletResponse.SC_UNAUTHORIZED; +import static org.apache.logging.log4j.core.config.ConfigurationSourceTest.PATH_IN_JAR; +import static org.apache.logging.log4j.core.net.WireMockUtil.createMapping; +import static org.assertj.core.api.Assertions.assertThat; import static org.junit.jupiter.api.Assertions.assertEquals; import static org.junit.jupiter.api.Assertions.assertNotNull; import static org.junit.jupiter.api.Assertions.assertNull; -import static org.junit.jupiter.api.Assertions.assertTrue; -import static org.junit.jupiter.api.Assertions.fail; +import com.github.tomakehurst.wiremock.client.BasicCredentials; +import com.github.tomakehurst.wiremock.client.WireMock; +import com.github.tomakehurst.wiremock.junit5.WireMockRuntimeInfo; +import com.github.tomakehurst.wiremock.junit5.WireMockTest; import com.sun.management.UnixOperatingSystemMXBean; -import java.io.File; +import java.io.ByteArrayOutputStream; import java.io.IOException; import java.io.InputStream; import java.lang.management.ManagementFactory; @@ -38,101 +42,102 @@ import java.net.URI; import java.net.URL; import java.nio.file.Files; -import java.util.Base64; -import java.util.Enumeration; -import javax.servlet.ServletException; -import javax.servlet.http.HttpServletRequest; -import javax.servlet.http.HttpServletResponse; +import java.nio.file.Path; +import java.nio.file.Paths; +import java.time.ZonedDateTime; +import java.time.temporal.ChronoUnit; +import java.util.List; +import java.util.stream.Collectors; +import java.util.stream.Stream; +import org.apache.commons.io.IOUtils; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.core.config.ConfigurationFactory; import org.apache.logging.log4j.core.config.ConfigurationSource; import org.apache.logging.log4j.core.config.ConfigurationSourceTest; -import org.eclipse.jetty.http.HttpHeader; -import org.eclipse.jetty.server.Server; -import org.eclipse.jetty.server.ServerConnector; -import org.eclipse.jetty.servlet.DefaultServlet; -import org.eclipse.jetty.servlet.ServletContextHandler; -import org.eclipse.jetty.servlet.ServletHolder; -import org.junit.jupiter.api.AfterAll; -import org.junit.jupiter.api.BeforeAll; +import org.apache.logging.log4j.core.util.AuthorizationProvider; +import org.apache.logging.log4j.test.junit.SetTestProperty; +import org.apache.logging.log4j.util.PropertiesUtil; +import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.Test; import org.junit.jupiter.api.condition.DisabledOnOs; import org.junit.jupiter.api.condition.OS; +import org.junit.jupiter.api.io.TempDir; import org.junitpioneer.jupiter.RetryingTest; /** * Tests the UrlConnectionFactory */ -public class UrlConnectionFactoryTest { +@WireMockTest +@SetTestProperty(key = "log4j2.configurationAllowedProtocols", value = "jar,http") +class UrlConnectionFactoryTest { private static final Logger LOGGER = LogManager.getLogger(UrlConnectionFactoryTest.class); - private static final String BASIC = "Basic "; - private static final String expectedCreds = "testuser:password"; - private static Server server; - private static final Base64.Decoder decoder = Base64.getDecoder(); - private static int port; - private static final int BUF_SIZE = 1024; - @BeforeAll - public static void startServer() throws Exception { - try { - server = new Server(0); - final ServletContextHandler context = new ServletContextHandler(); - final ServletHolder defaultServ = new ServletHolder("default", TestServlet.class); - defaultServ.setInitParameter("resourceBase", System.getProperty("user.dir")); - defaultServ.setInitParameter("dirAllowed", "true"); - context.addServlet(defaultServ, "/"); - server.setHandler(context); - - // Start Server - server.start(); - port = ((ServerConnector) server.getConnectors()[0]).getLocalPort(); - } catch (Throwable ex) { - ex.printStackTrace(); - throw ex; + private static final String URL_PATH = "/log4j2-config.xml"; + private static final BasicCredentials CREDENTIALS = new BasicCredentials("testUser", "password"); + private static final byte[] CONFIG_FILE_BODY; + private static final String CONTENT_TYPE = "application/xml"; + + static { + try (InputStream input = requireNonNull( + UrlConnectionFactoryTest.class.getClassLoader().getResourceAsStream("log4j2-config.xml"))) { + ByteArrayOutputStream output = new ByteArrayOutputStream(); + IOUtils.copy(input, output); + CONFIG_FILE_BODY = output.toByteArray(); + } catch (IOException e) { + throw new AssertionError(e); } } - @AfterAll - public static void stopServer() throws Exception { - server.stop(); + @AfterEach + void cleanup(WireMockRuntimeInfo info) { + info.getWireMock().removeMappings(); } @Test - public void testBadCrdentials() throws Exception { - System.setProperty("log4j2.Configuration.username", "foo"); - System.setProperty("log4j2.Configuration.password", "bar"); - System.setProperty("log4j2.Configuration.allowedProtocols", "http"); - final URI uri = new URI("http://localhost:" + port + "/log4j2-config.xml"); + @SetTestProperty(key = "log4j2.configurationUsername", value = "foo") + @SetTestProperty(key = "log4j2.configurationPassword", value = "bar") + void testBadCredentials(WireMockRuntimeInfo info) throws Exception { + WireMock wireMock = info.getWireMock(); + // RFC 1123 format rounds to full seconds + ZonedDateTime now = ZonedDateTime.now().truncatedTo(ChronoUnit.SECONDS); + wireMock.importStubMappings(createMapping(URL_PATH, CREDENTIALS, CONFIG_FILE_BODY, CONTENT_TYPE, now)); + final URI uri = new URI(info.getHttpBaseUrl() + URL_PATH); final ConfigurationSource source = ConfigurationSource.fromUri(uri); assertNull(source, "A ConfigurationSource should not have been returned"); } @Test - public void withAuthentication() throws Exception { - System.setProperty("log4j2.Configuration.username", "testuser"); - System.setProperty("log4j2.Configuration.password", "password"); - System.setProperty("log4j2.Configuration.allowedProtocols", "http"); - final URI uri = new URI("http://localhost:" + port + "/log4j2-config.xml"); + @SetTestProperty(key = "log4j2.configurationUsername", value = "testUser") + @SetTestProperty(key = "log4j2.configurationPassword", value = "password") + public void withAuthentication(WireMockRuntimeInfo info) throws Exception { + WireMock wireMock = info.getWireMock(); + // RFC 1123 format rounds to full seconds + ZonedDateTime now = ZonedDateTime.now().truncatedTo(ChronoUnit.SECONDS); + wireMock.importStubMappings(createMapping(URL_PATH, CREDENTIALS, CONFIG_FILE_BODY, CONTENT_TYPE, now)); + final URI uri = new URI(info.getHttpBaseUrl() + URL_PATH); final ConfigurationSource source = ConfigurationSource.fromUri(uri); assertNotNull(source, "No ConfigurationSource returned"); final InputStream is = source.getInputStream(); assertNotNull(is, "No data returned"); is.close(); final long lastModified = source.getLastModified(); + assertThat(lastModified).isEqualTo(now.toInstant().toEpochMilli()); int result = verifyNotModified(uri, lastModified); assertEquals(SC_NOT_MODIFIED, result, "File was modified"); - final File file = new File("target/classes/log4j2-config.xml"); - if (!file.setLastModified(System.currentTimeMillis())) { - fail("Unable to set last modified time"); - } + + wireMock.removeMappings(); + now = now.plusMinutes(5); + wireMock.importStubMappings(createMapping(URL_PATH, CREDENTIALS, CONFIG_FILE_BODY, CONTENT_TYPE, now)); result = verifyNotModified(uri, lastModified); assertEquals(SC_OK, result, "File was not modified"); } private int verifyNotModified(final URI uri, final long lastModifiedMillis) throws Exception { - final HttpURLConnection urlConnection = - UrlConnectionFactory.createConnection(uri.toURL(), lastModifiedMillis, null, null); + AuthorizationProvider provider = ConfigurationFactory.authorizationProvider(PropertiesUtil.getProperties()); + HttpURLConnection urlConnection = + UrlConnectionFactory.createConnection(uri.toURL(), lastModifiedMillis, null, provider); urlConnection.connect(); try { @@ -145,20 +150,39 @@ private int verifyNotModified(final URI uri, final long lastModifiedMillis) thro @RetryingTest(maxAttempts = 5, suspendForMs = 1000) @DisabledOnOs(value = OS.WINDOWS, disabledReason = "Fails frequently on Windows (#2011)") - public void testNoJarFileLeak() throws Exception { - ConfigurationSourceTest.prepareJarConfigURL(); - final URL url = new File("target/test-classes/jarfile.jar").toURI().toURL(); + @SetTestProperty(key = "log4j2.configurationUsername", value = "testUser") + @SetTestProperty(key = "log4j2.configurationPassword", value = "password") + void testNoJarFileLeak(@TempDir Path dir, WireMockRuntimeInfo info) throws Exception { + Path jarFile = ConfigurationSourceTest.prepareJarConfigURL(dir); // Retrieve using 'file:' - URL jarUrl = new URL("jar:" + url.toString() + "!/config/console.xml"); + URL jarUrl = new URL("jar:" + jarFile.toUri().toURL() + "!" + PATH_IN_JAR); long expected = getOpenFileDescriptorCount(); UrlConnectionFactory.createConnection(jarUrl).getInputStream().close(); assertEquals(expected, getOpenFileDescriptorCount()); + + // Prepare mock + ByteArrayOutputStream body = new ByteArrayOutputStream(); + try (InputStream inputStream = Files.newInputStream(jarFile)) { + IOUtils.copy(inputStream, body); + } + WireMock wireMock = info.getWireMock(); + wireMock.register(WireMock.get("/jarFile.jar") + .willReturn( + aResponse().withStatus(200).withBodyFile("jarFile.jar").withBody(body.toByteArray()))); // Retrieve using 'http:' - jarUrl = new URL("jar:http://localhost:" + port + "/jarfile.jar!/config/console.xml"); - final File tmpDir = new File(System.getProperty("java.io.tmpdir")); - expected = tmpDir.list().length; + jarUrl = new URL("jar:" + info.getHttpBaseUrl() + "/jarFile.jar!" + PATH_IN_JAR); + // URLConnection leaves JAR files in the temporary directory + Path tmpDir = Paths.get(System.getProperty("java.io.tmpdir")); + List expectedFiles; + try (Stream stream = Files.list(tmpDir)) { + expectedFiles = stream.collect(Collectors.toList()); + } UrlConnectionFactory.createConnection(jarUrl).getInputStream().close(); - assertEquals(expected, tmpDir.list().length, "File descriptor leak"); + List actualFiles; + try (Stream stream = Files.list(tmpDir)) { + actualFiles = stream.collect(Collectors.toList()); + } + assertThat(actualFiles).containsExactlyElementsOf(expectedFiles); } private long getOpenFileDescriptorCount() { @@ -168,53 +192,4 @@ private long getOpenFileDescriptorCount() { } return 0L; } - - public static class TestServlet extends DefaultServlet { - - private static final long serialVersionUID = -2885158530511450659L; - - @Override - protected void doGet(final HttpServletRequest request, final HttpServletResponse response) - throws ServletException, IOException { - final Enumeration headers = request.getHeaders(HttpHeader.AUTHORIZATION.toString()); - if (headers == null) { - response.sendError(SC_UNAUTHORIZED, "No Auth header"); - return; - } - while (headers.hasMoreElements()) { - final String authData = headers.nextElement(); - assertTrue(authData.startsWith(BASIC), "Not a Basic auth header"); - final String credentials = new String(decoder.decode(authData.substring(BASIC.length()))); - if (!expectedCreds.equals(credentials)) { - response.sendError(SC_UNAUTHORIZED, "Invalid credentials"); - return; - } - } - final String servletPath = request.getServletPath(); - if (servletPath != null) { - File file = new File("target/classes" + servletPath); - if (!file.exists()) { - file = new File("target/test-classes" + servletPath); - } - if (!file.exists()) { - response.sendError(SC_NOT_FOUND); - return; - } - final long modifiedSince = request.getDateHeader(HttpHeader.IF_MODIFIED_SINCE.toString()); - final long lastModified = (file.lastModified() / 1000) * 1000; - LOGGER.debug("LastModified: {}, modifiedSince: {}", lastModified, modifiedSince); - if (modifiedSince > 0 && lastModified <= modifiedSince) { - response.setStatus(SC_NOT_MODIFIED); - return; - } - response.setDateHeader(HttpHeader.LAST_MODIFIED.toString(), lastModified); - response.setContentLengthLong(file.length()); - Files.copy(file.toPath(), response.getOutputStream()); - response.getOutputStream().flush(); - response.setStatus(SC_OK); - } else { - response.sendError(SC_BAD_REQUEST, "Unsupported request"); - } - } - } } diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/net/WireMockUtil.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/net/WireMockUtil.java new file mode 100644 index 00000000000..f8655742320 --- /dev/null +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/net/WireMockUtil.java @@ -0,0 +1,84 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to you under the Apache License, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package org.apache.logging.log4j.core.net; + +import static com.github.tomakehurst.wiremock.client.WireMock.aResponse; +import static com.github.tomakehurst.wiremock.client.WireMock.absent; +import static com.github.tomakehurst.wiremock.client.WireMock.after; +import static com.github.tomakehurst.wiremock.client.WireMock.anyUrl; +import static com.github.tomakehurst.wiremock.client.WireMock.before; +import static com.github.tomakehurst.wiremock.client.WireMock.equalToDateTime; +import static com.github.tomakehurst.wiremock.client.WireMock.get; +import static com.github.tomakehurst.wiremock.client.WireMock.notContaining; +import static com.github.tomakehurst.wiremock.stubbing.StubImport.stubImport; +import static com.google.common.net.HttpHeaders.AUTHORIZATION; +import static com.google.common.net.HttpHeaders.CONTENT_TYPE; +import static com.google.common.net.HttpHeaders.IF_MODIFIED_SINCE; +import static com.google.common.net.HttpHeaders.LAST_MODIFIED; + +import com.github.tomakehurst.wiremock.client.BasicCredentials; +import com.github.tomakehurst.wiremock.stubbing.StubImport; +import java.time.ZoneOffset; +import java.time.ZonedDateTime; +import java.time.format.DateTimeFormatter; + +public class WireMockUtil { + + private static final DateTimeFormatter formatter = DateTimeFormatter.RFC_1123_DATE_TIME.withZone(ZoneOffset.UTC); + + /** + * Establishes a set of mapping to serve a file + * + * @param urlPath The URL path of the served file + * @param credentials The credentials to use for authentication + * @param body The body of the file + * @param contentType The MIME content type of the file + * @param lastModified The last modification date of the file + * @return A set of mappings + */ + public static StubImport createMapping( + String urlPath, BasicCredentials credentials, byte[] body, String contentType, ZonedDateTime lastModified) { + int idx = urlPath.lastIndexOf('/'); + String fileName = idx == -1 ? urlPath : urlPath.substring(idx + 1); + return stubImport() + // Lack of authentication data + .stub(get(anyUrl()) + .withHeader(AUTHORIZATION, absent()) + .willReturn(aResponse().withStatus(401).withStatusMessage("Not Authenticated"))) + // Wrong authentication data + .stub(get(anyUrl()) + .withHeader(AUTHORIZATION, notContaining(credentials.asAuthorizationHeaderValue())) + .willReturn(aResponse().withStatus(403).withStatusMessage("Not Authorized"))) + // Serves the file + .stub(get(urlPath) + .withBasicAuth(credentials.username, credentials.password) + .withHeader(IF_MODIFIED_SINCE, before(lastModified).or(absent())) + .willReturn(aResponse() + .withStatus(200) + .withBodyFile(fileName) + .withBody(body) + .withHeader(LAST_MODIFIED, formatter.format(lastModified)) + .withHeader(CONTENT_TYPE, contentType))) + // The file was not updated since lastModified + .stub(get(urlPath) + .withBasicAuth(credentials.username, credentials.password) + .withHeader(IF_MODIFIED_SINCE, after(lastModified).or(equalToDateTime(lastModified))) + .willReturn( + aResponse().withStatus(304).withHeader(LAST_MODIFIED, formatter.format(lastModified)))) + .build(); + } +} diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/HttpWatcherTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/HttpWatcherTest.java new file mode 100644 index 00000000000..774f36d5aa6 --- /dev/null +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/HttpWatcherTest.java @@ -0,0 +1,160 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to you under the Apache License, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package org.apache.logging.log4j.core.util; + +import static com.github.tomakehurst.wiremock.client.WireMock.aResponse; +import static com.github.tomakehurst.wiremock.client.WireMock.get; +import static java.util.Collections.singletonList; +import static org.assertj.core.api.Assertions.assertThat; + +import com.github.tomakehurst.wiremock.client.WireMock; +import com.github.tomakehurst.wiremock.junit5.WireMockRuntimeInfo; +import com.github.tomakehurst.wiremock.junit5.WireMockTest; +import com.github.tomakehurst.wiremock.stubbing.StubMapping; +import java.net.URL; +import java.time.Instant; +import java.time.ZoneOffset; +import java.time.format.DateTimeFormatter; +import java.time.temporal.ChronoUnit; +import java.util.List; +import java.util.Queue; +import java.util.concurrent.BlockingQueue; +import java.util.concurrent.LinkedBlockingQueue; +import java.util.concurrent.TimeUnit; +import org.apache.logging.log4j.core.config.AbstractConfiguration; +import org.apache.logging.log4j.core.config.Configuration; +import org.apache.logging.log4j.core.config.ConfigurationListener; +import org.apache.logging.log4j.core.config.ConfigurationSource; +import org.apache.logging.log4j.core.config.HttpWatcher; +import org.apache.logging.log4j.core.config.Reconfigurable; +import org.apache.logging.log4j.core.net.UrlConnectionFactory; +import org.apache.logging.log4j.test.junit.SetTestProperty; +import org.junit.jupiter.api.Test; + +/** + * Test the WatchManager + */ +@SetTestProperty(key = UrlConnectionFactory.ALLOWED_PROTOCOLS, value = "http,https") +@WireMockTest +class HttpWatcherTest { + + private static final DateTimeFormatter formatter = DateTimeFormatter.RFC_1123_DATE_TIME.withZone(ZoneOffset.UTC); + private static final String XML = "application/xml"; + + @Test + void testModified(final WireMockRuntimeInfo info) throws Exception { + final WireMock wireMock = info.getWireMock(); + + final BlockingQueue queue = new LinkedBlockingQueue<>(); + List listeners = singletonList(new TestConfigurationListener(queue, "log4j-test1.xml")); + // HTTP Last-Modified is in seconds + Instant now = Instant.now().truncatedTo(ChronoUnit.SECONDS); + Instant previous = now.minus(5, ChronoUnit.MINUTES); + final URL url = new URL(info.getHttpBaseUrl() + "/log4j-test1.xml"); + final Configuration configuration = createConfiguration(url); + + final StubMapping stubMapping = wireMock.register(get("/log4j-test1.xml") + .willReturn(aResponse() + .withBodyFile("log4j-test1.xml") + .withStatus(200) + .withHeader("Last-Modified", formatter.format(previous)) + .withHeader("Content-Type", XML))); + Watcher watcher = new HttpWatcher(configuration, null, listeners, previous.toEpochMilli()); + watcher.watching(new Source(url)); + try { + assertThat(watcher.isModified()).as("File was modified").isTrue(); + assertThat(watcher.getLastModified()).as("File modification time").isEqualTo(previous.toEpochMilli()); + // Check if listeners are correctly called + // Note: listeners are called asynchronously + watcher.modified(); + String str = queue.poll(1, TimeUnit.SECONDS); + assertThat(str).isEqualTo("log4j-test1.xml"); + ConfigurationSource configurationSource = configuration.getConfigurationSource(); + // Check that the last modified time of the ConfigurationSource was modified as well + // See: https://github.com/apache/logging-log4j2/issues/2937 + assertThat(configurationSource.getLastModified()) + .as("Last modification time of current ConfigurationSource") + .isEqualTo(0L); + configurationSource = configurationSource.resetInputStream(); + assertThat(configurationSource.getLastModified()) + .as("Last modification time of next ConfigurationSource") + .isEqualTo(previous.toEpochMilli()); + } finally { + wireMock.removeStubMapping(stubMapping); + } + } + + @Test + void testNotModified(final WireMockRuntimeInfo info) throws Exception { + final WireMock wireMock = info.getWireMock(); + + final BlockingQueue queue = new LinkedBlockingQueue<>(); + final List listeners = + singletonList(new TestConfigurationListener(queue, "log4j-test2.xml")); + // HTTP Last-Modified is in seconds + Instant now = Instant.now().truncatedTo(ChronoUnit.SECONDS); + Instant previous = now.minus(5, ChronoUnit.MINUTES); + final URL url = new URL(info.getHttpBaseUrl() + "/log4j-test2.xml"); + final Configuration configuration = createConfiguration(url); + + final StubMapping stubMapping = wireMock.register(get("/log4j-test2.xml") + .willReturn(aResponse() + .withStatus(304) + .withHeader("Last-Modified", formatter.format(now) + " GMT") + .withHeader("Content-Type", XML))); + Watcher watcher = new HttpWatcher(configuration, null, listeners, previous.toEpochMilli()); + watcher.watching(new Source(url)); + try { + assertThat(watcher.isModified()).as("File was modified").isFalse(); + // If the file was not modified, neither should be the last modification time + assertThat(watcher.getLastModified()).isEqualTo(previous.toEpochMilli()); + // Check that the last modified time of the ConfigurationSource was not modified either + ConfigurationSource configurationSource = configuration.getConfigurationSource(); + assertThat(configurationSource.getLastModified()) + .as("Last modification time of current ConfigurationSource") + .isEqualTo(0L); + configurationSource = configurationSource.resetInputStream(); + assertThat(configurationSource.getLastModified()) + .as("Last modification time of next ConfigurationSource") + .isEqualTo(0L); + } finally { + wireMock.removeStubMapping(stubMapping); + } + } + + // Creates a configuration with a predefined configuration source + private static Configuration createConfiguration(URL url) { + ConfigurationSource configurationSource = new ConfigurationSource(new Source(url), new byte[0], 0L); + return new AbstractConfiguration(null, configurationSource) {}; + } + + private static class TestConfigurationListener implements ConfigurationListener { + private final Queue queue; + private final String name; + + public TestConfigurationListener(final Queue queue, final String name) { + this.queue = queue; + this.name = name; + } + + @Override + public void onChange(final Reconfigurable reconfigurable) { + // System.out.println("Reconfiguration detected for " + name); + queue.add(name); + } + } +} diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/WatchHttpTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/WatchHttpTest.java deleted file mode 100644 index c433f834863..00000000000 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/WatchHttpTest.java +++ /dev/null @@ -1,156 +0,0 @@ -/* - * Licensed to the Apache Software Foundation (ASF) under one or more - * contributor license agreements. See the NOTICE file distributed with - * this work for additional information regarding copyright ownership. - * The ASF licenses this file to you under the Apache License, Version 2.0 - * (the "License"); you may not use this file except in compliance with - * the License. You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - */ -package org.apache.logging.log4j.core.util; - -import static com.github.tomakehurst.wiremock.client.WireMock.aResponse; -import static com.github.tomakehurst.wiremock.client.WireMock.get; -import static com.github.tomakehurst.wiremock.client.WireMock.urlPathEqualTo; -import static org.junit.Assert.assertNotNull; -import static org.junit.Assert.assertNull; -import static org.junit.jupiter.api.Assumptions.assumeTrue; - -import com.github.tomakehurst.wiremock.client.WireMock; -import com.github.tomakehurst.wiremock.junit5.WireMockRuntimeInfo; -import com.github.tomakehurst.wiremock.junit5.WireMockTest; -import com.github.tomakehurst.wiremock.stubbing.StubMapping; -import java.net.URL; -import java.util.ArrayList; -import java.util.Calendar; -import java.util.List; -import java.util.Queue; -import java.util.TimeZone; -import java.util.concurrent.BlockingQueue; -import java.util.concurrent.LinkedBlockingQueue; -import java.util.concurrent.TimeUnit; -import org.apache.logging.log4j.core.config.Configuration; -import org.apache.logging.log4j.core.config.ConfigurationListener; -import org.apache.logging.log4j.core.config.ConfigurationScheduler; -import org.apache.logging.log4j.core.config.DefaultConfiguration; -import org.apache.logging.log4j.core.config.HttpWatcher; -import org.apache.logging.log4j.core.config.Reconfigurable; -import org.apache.logging.log4j.core.net.UrlConnectionFactory; -import org.apache.logging.log4j.core.util.datetime.FastDateFormat; -import org.apache.logging.log4j.test.junit.SetTestProperty; -import org.apache.logging.log4j.util.PropertiesUtil; -import org.junit.jupiter.api.Test; - -/** - * Test the WatchManager - */ -@SetTestProperty(key = UrlConnectionFactory.ALLOWED_PROTOCOLS, value = "http,https") -@WireMockTest -public class WatchHttpTest { - - private static final String FORCE_RUN_KEY = WatchHttpTest.class.getSimpleName() + ".forceRun"; - private final String file = "log4j-test1.xml"; - private static final TimeZone UTC = TimeZone.getTimeZone("UTC"); - private static FastDateFormat formatter = FastDateFormat.getInstance("EEE, dd MMM yyyy HH:mm:ss", UTC); - private static final String XML = "application/xml"; - - private static final boolean IS_WINDOWS = PropertiesUtil.getProperties().isOsWindows(); - - @Test - public void testWatchManager(final WireMockRuntimeInfo info) throws Exception { - assumeTrue(!IS_WINDOWS || Boolean.getBoolean(FORCE_RUN_KEY)); - final WireMock wireMock = info.getWireMock(); - - final BlockingQueue queue = new LinkedBlockingQueue<>(); - final List listeners = new ArrayList<>(); - listeners.add(new TestConfigurationListener(queue, "log4j-test1.xml")); - final Calendar now = Calendar.getInstance(UTC); - final Calendar previous = now; - previous.add(Calendar.MINUTE, -5); - final Configuration configuration = new DefaultConfiguration(); - final URL url = new URL(info.getHttpBaseUrl() + "/log4j-test1.xml"); - final StubMapping stubMapping = wireMock.register(get(urlPathEqualTo("/log4j-test1.xml")) - .willReturn(aResponse() - .withBodyFile(file) - .withStatus(200) - .withHeader("Last-Modified", formatter.format(previous) + " GMT") - .withHeader("Content-Type", XML))); - final ConfigurationScheduler scheduler = new ConfigurationScheduler(); - scheduler.incrementScheduledItems(); - final WatchManager watchManager = new WatchManager(scheduler); - watchManager.setIntervalSeconds(1); - scheduler.start(); - watchManager.start(); - try { - watchManager.watch( - new Source(url), new HttpWatcher(configuration, null, listeners, previous.getTimeInMillis())); - final String str = queue.poll(3, TimeUnit.SECONDS); - assertNotNull("File change not detected", str); - } finally { - watchManager.stop(); - scheduler.stop(); - wireMock.removeStubMapping(stubMapping); - } - } - - @Test - public void testNotModified(final WireMockRuntimeInfo info) throws Exception { - assumeTrue(!IS_WINDOWS || Boolean.getBoolean(FORCE_RUN_KEY)); - final WireMock wireMock = info.getWireMock(); - - final BlockingQueue queue = new LinkedBlockingQueue<>(); - final List listeners = new ArrayList<>(); - listeners.add(new TestConfigurationListener(queue, "log4j-test2.xml")); - final TimeZone timeZone = TimeZone.getTimeZone("UTC"); - final Calendar now = Calendar.getInstance(timeZone); - final Calendar previous = now; - previous.add(Calendar.MINUTE, -5); - final Configuration configuration = new DefaultConfiguration(); - final URL url = new URL(info.getHttpBaseUrl() + "/log4j-test2.xml"); - final StubMapping stubMapping = wireMock.register(get(urlPathEqualTo("/log4j-test2.xml")) - .willReturn(aResponse() - .withBodyFile(file) - .withStatus(304) - .withHeader("Last-Modified", formatter.format(now) + " GMT") - .withHeader("Content-Type", XML))); - final ConfigurationScheduler scheduler = new ConfigurationScheduler(); - scheduler.incrementScheduledItems(); - final WatchManager watchManager = new WatchManager(scheduler); - watchManager.setIntervalSeconds(1); - scheduler.start(); - watchManager.start(); - try { - watchManager.watch( - new Source(url), new HttpWatcher(configuration, null, listeners, previous.getTimeInMillis())); - final String str = queue.poll(2, TimeUnit.SECONDS); - assertNull("File changed.", str); - } finally { - watchManager.stop(); - scheduler.stop(); - wireMock.removeStubMapping(stubMapping); - } - } - - private static class TestConfigurationListener implements ConfigurationListener { - private final Queue queue; - private final String name; - - public TestConfigurationListener(final Queue queue, final String name) { - this.queue = queue; - this.name = name; - } - - @Override - public void onChange(final Reconfigurable reconfigurable) { - // System.out.println("Reconfiguration detected for " + name); - queue.add(name); - } - } -} diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/WatchManagerTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/WatchManagerTest.java index 68b3baaca60..9e2b4e92cea 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/WatchManagerTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/WatchManagerTest.java @@ -18,6 +18,12 @@ import static org.junit.jupiter.api.Assertions.assertNotNull; import static org.junit.jupiter.api.Assertions.assertNull; +import static org.mockito.Mockito.clearInvocations; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.never; +import static org.mockito.Mockito.timeout; +import static org.mockito.Mockito.verify; +import static org.mockito.Mockito.when; import java.io.File; import java.io.FileOutputStream; @@ -30,6 +36,8 @@ import java.util.concurrent.LinkedBlockingQueue; import java.util.concurrent.TimeUnit; import org.apache.logging.log4j.core.config.ConfigurationScheduler; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; import org.junit.jupiter.api.condition.DisabledOnOs; import org.junit.jupiter.api.condition.EnabledIfSystemProperty; @@ -40,106 +48,111 @@ */ @DisabledOnOs(OS.WINDOWS) @EnabledIfSystemProperty(named = "WatchManagerTest.forceRun", matches = "true") -public class WatchManagerTest { +class WatchManagerTest { private final String testFile = "target/testWatchFile"; private final String originalFile = "target/test-classes/log4j-test1.xml"; private final String newFile = "target/test-classes/log4j-test1.yaml"; - @Test - public void testWatchManager() throws Exception { - final ConfigurationScheduler scheduler = new ConfigurationScheduler(); + private ConfigurationScheduler scheduler; + private WatchManager watchManager; + + @BeforeEach + void setUp() { + scheduler = new ConfigurationScheduler(); scheduler.incrementScheduledItems(); - final WatchManager watchManager = new WatchManager(scheduler); + watchManager = new WatchManager(scheduler); watchManager.setIntervalSeconds(1); scheduler.start(); watchManager.start(); - try { - final File sourceFile = new File(originalFile); - Path source = Paths.get(sourceFile.toURI()); - try (final FileOutputStream targetStream = new FileOutputStream(testFile)) { - Files.copy(source, targetStream); - } - final File updateFile = new File(newFile); - final File targetFile = new File(testFile); - final BlockingQueue queue = new LinkedBlockingQueue<>(); - watchManager.watchFile(targetFile, new TestWatcher(queue)); - Thread.sleep(1000); - source = Paths.get(updateFile.toURI()); - Files.copy(source, Paths.get(targetFile.toURI()), StandardCopyOption.REPLACE_EXISTING); - Thread.sleep(1000); - final File f = queue.poll(1, TimeUnit.SECONDS); - assertNotNull(f, "File change not detected"); - } finally { - watchManager.stop(); - scheduler.stop(); - } + } + + @AfterEach + void tearDown() { + watchManager.stop(); + scheduler.stop(); + watchManager = null; + scheduler = null; } @Test - public void testWatchManagerReset() throws Exception { - final ConfigurationScheduler scheduler = new ConfigurationScheduler(); - scheduler.incrementScheduledItems(); - final WatchManager watchManager = new WatchManager(scheduler); - watchManager.setIntervalSeconds(1); - scheduler.start(); - watchManager.start(); - try { - final File sourceFile = new File(originalFile); - Path source = Paths.get(sourceFile.toURI()); - try (final FileOutputStream targetStream = new FileOutputStream(testFile)) { - Files.copy(source, targetStream); - } - final File updateFile = new File(newFile); - final File targetFile = new File(testFile); - final BlockingQueue queue = new LinkedBlockingQueue<>(); - watchManager.watchFile(targetFile, new TestWatcher(queue)); - watchManager.stop(); - Thread.sleep(1000); - source = Paths.get(updateFile.toURI()); - Files.copy(source, Paths.get(targetFile.toURI()), StandardCopyOption.REPLACE_EXISTING); - watchManager.reset(); - watchManager.start(); - Thread.sleep(1000); - final File f = queue.poll(1, TimeUnit.SECONDS); - assertNull(f, "File change detected"); - } finally { - watchManager.stop(); - scheduler.stop(); + void testWatchManager() throws Exception { + final File sourceFile = new File(originalFile); + Path source = Paths.get(sourceFile.toURI()); + try (final FileOutputStream targetStream = new FileOutputStream(testFile)) { + Files.copy(source, targetStream); } + final File updateFile = new File(newFile); + final File targetFile = new File(testFile); + final BlockingQueue queue = new LinkedBlockingQueue<>(); + watchManager.watchFile(targetFile, new TestWatcher(queue)); + Thread.sleep(1000); + source = Paths.get(updateFile.toURI()); + Files.copy(source, Paths.get(targetFile.toURI()), StandardCopyOption.REPLACE_EXISTING); + Thread.sleep(1000); + final File f = queue.poll(1, TimeUnit.SECONDS); + assertNotNull(f, "File change not detected"); } @Test - public void testWatchManagerResetFile() throws Exception { - final ConfigurationScheduler scheduler = new ConfigurationScheduler(); - scheduler.incrementScheduledItems(); - final WatchManager watchManager = new WatchManager(scheduler); - watchManager.setIntervalSeconds(1); - scheduler.start(); + void testWatchManagerReset() throws Exception { + final File sourceFile = new File(originalFile); + Path source = Paths.get(sourceFile.toURI()); + try (final FileOutputStream targetStream = new FileOutputStream(testFile)) { + Files.copy(source, targetStream); + } + final File updateFile = new File(newFile); + final File targetFile = new File(testFile); + final BlockingQueue queue = new LinkedBlockingQueue<>(); + watchManager.watchFile(targetFile, new TestWatcher(queue)); + watchManager.stop(); + Thread.sleep(1000); + source = Paths.get(updateFile.toURI()); + Files.copy(source, Paths.get(targetFile.toURI()), StandardCopyOption.REPLACE_EXISTING); + watchManager.reset(); watchManager.start(); - try { - final File sourceFile = new File(originalFile); - Path source = Paths.get(sourceFile.toURI()); - try (final FileOutputStream targetStream = new FileOutputStream(testFile)) { - Files.copy(source, targetStream); - } - final File updateFile = new File(newFile); - final File targetFile = new File(testFile); - final BlockingQueue queue = new LinkedBlockingQueue<>(); - watchManager.watchFile(targetFile, new TestWatcher(queue)); - watchManager.stop(); - Thread.sleep(1000); - source = Paths.get(updateFile.toURI()); - Files.copy(source, Paths.get(targetFile.toURI()), StandardCopyOption.REPLACE_EXISTING); - watchManager.reset(targetFile); - watchManager.start(); - Thread.sleep(1000); - final File f = queue.poll(1, TimeUnit.SECONDS); - assertNull(f, "File change detected"); - } finally { - watchManager.stop(); - scheduler.stop(); + Thread.sleep(1000); + final File f = queue.poll(1, TimeUnit.SECONDS); + assertNull(f, "File change detected"); + } + + @Test + void testWatchManagerResetFile() throws Exception { + final File sourceFile = new File(originalFile); + Path source = Paths.get(sourceFile.toURI()); + try (final FileOutputStream targetStream = new FileOutputStream(testFile)) { + Files.copy(source, targetStream); } + final File updateFile = new File(newFile); + final File targetFile = new File(testFile); + final BlockingQueue queue = new LinkedBlockingQueue<>(); + watchManager.watchFile(targetFile, new TestWatcher(queue)); + watchManager.stop(); + Thread.sleep(1000); + source = Paths.get(updateFile.toURI()); + Files.copy(source, Paths.get(targetFile.toURI()), StandardCopyOption.REPLACE_EXISTING); + watchManager.reset(targetFile); + watchManager.start(); + Thread.sleep(1000); + final File f = queue.poll(1, TimeUnit.SECONDS); + assertNull(f, "File change detected"); + } + + /** + * Verify the + */ + @Test + void testWatchManagerCallsWatcher() { + Source source = mock(Source.class); + Watcher watcher = mock(Watcher.class); + when(watcher.isModified()).thenReturn(false); + watchManager.watch(source, watcher); + verify(watcher, timeout(2000)).isModified(); + verify(watcher, never()).modified(); + when(watcher.isModified()).thenReturn(true); + clearInvocations(watcher); + verify(watcher, timeout(2000)).isModified(); + verify(watcher).modified(); } private static class TestWatcher implements FileWatcher { diff --git a/log4j-core-test/src/test/resources/log4j2-mutableFilter.xml b/log4j-core-test/src/test/resources/config/ConfigurationSourceTest.xml similarity index 69% rename from log4j-core-test/src/test/resources/log4j2-mutableFilter.xml rename to log4j-core-test/src/test/resources/config/ConfigurationSourceTest.xml index 2f4e391d139..54c7f846f3f 100644 --- a/log4j-core-test/src/test/resources/log4j2-mutableFilter.xml +++ b/log4j-core-test/src/test/resources/config/ConfigurationSourceTest.xml @@ -15,21 +15,18 @@ ~ See the License for the specific language governing permissions and ~ limitations under the License. --> - - + - - + + - - - - - - - + + diff --git a/log4j-core-test/src/test/resources/emptyConfig.json b/log4j-core-test/src/test/resources/emptyConfig.json deleted file mode 100644 index 37086f2b1f6..00000000000 --- a/log4j-core-test/src/test/resources/emptyConfig.json +++ /dev/null @@ -1,4 +0,0 @@ -{ - "configs": { - } -} \ No newline at end of file diff --git a/log4j-core-test/src/test/resources/filter/MutableThreadContextMapFilterTest.xml b/log4j-core-test/src/test/resources/filter/MutableThreadContextMapFilterTest.xml new file mode 100644 index 00000000000..34eb059c4e0 --- /dev/null +++ b/log4j-core-test/src/test/resources/filter/MutableThreadContextMapFilterTest.xml @@ -0,0 +1,35 @@ + + + + + + + + + + + + + diff --git a/log4j-core-test/src/test/resources/filterConfig.json b/log4j-core-test/src/test/resources/filterConfig.json deleted file mode 100644 index 91c8143ec2b..00000000000 --- a/log4j-core-test/src/test/resources/filterConfig.json +++ /dev/null @@ -1,6 +0,0 @@ -{ - "configs": { - "loginId": ["rgoers", "adam"], - "corpAcctNumber": ["30510263"] - } -} \ No newline at end of file diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/LoggerContext.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/LoggerContext.java index ee8e7c6a3cd..88f66ac364d 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/LoggerContext.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/LoggerContext.java @@ -93,7 +93,7 @@ public class LoggerContext extends AbstractLifeCycle private volatile Configuration configuration = new DefaultConfiguration(); private static final String EXTERNAL_CONTEXT_KEY = "__EXTERNAL_CONTEXT_KEY__"; - private ConcurrentMap externalMap = new ConcurrentHashMap<>(); + private final ConcurrentMap externalMap = new ConcurrentHashMap<>(); private String contextName; private volatile URI configLocation; private Cancellable shutdownCallback; @@ -128,9 +128,7 @@ public LoggerContext(final String name, final Object externalContext) { */ public LoggerContext(final String name, final Object externalContext, final URI configLocn) { this.contextName = name; - if (externalContext == null) { - externalMap.remove(EXTERNAL_CONTEXT_KEY); - } else { + if (externalContext != null) { externalMap.put(EXTERNAL_CONTEXT_KEY, externalContext); } this.configLocation = configLocn; @@ -149,9 +147,7 @@ public LoggerContext(final String name, final Object externalContext, final URI justification = "The configLocn comes from a secure source (Log4j properties)") public LoggerContext(final String name, final Object externalContext, final String configLocn) { this.contextName = name; - if (externalContext == null) { - externalMap.remove(EXTERNAL_CONTEXT_KEY); - } else { + if (externalContext != null) { externalMap.put(EXTERNAL_CONTEXT_KEY, externalContext); } if (configLocn != null) { @@ -172,7 +168,7 @@ public void addShutdownListener(final LoggerContextShutdownAware listener) { if (listeners == null) { synchronized (this) { if (listeners == null) { - listeners = new CopyOnWriteArrayList(); + listeners = new CopyOnWriteArrayList<>(); } } } @@ -283,7 +279,7 @@ public void start() { * @param config The new Configuration. */ public void start(final Configuration config) { - LOGGER.debug("Starting LoggerContext[name={}, {}] with configuration {}...", getName(), this, config); + LOGGER.info("Starting {}[name={}] with configuration {}...", getClass().getSimpleName(), getName(), config); if (configLock.tryLock()) { try { if (this.isInitialized() || this.isStopped()) { @@ -297,7 +293,7 @@ public void start(final Configuration config) { } } setConfiguration(config); - LOGGER.debug("LoggerContext[name={}, {}] started OK with configuration {}.", getName(), this, config); + LOGGER.info("{}[name={}] started with configuration {}.", getClass().getSimpleName(), getName(), config); } private void setUpShutdownHook() { @@ -312,7 +308,6 @@ private void setUpShutdownHook() { this.shutdownCallback = ((ShutdownCallbackRegistry) factory).addShutdownCallback(new Runnable() { @Override public void run() { - @SuppressWarnings("resource") final LoggerContext context = LoggerContext.this; LOGGER.debug( SHUTDOWN_HOOK_MARKER, @@ -714,7 +709,7 @@ public void setConfigLocation(final URI configLocation) { */ private void reconfigure(final URI configURI) { final Object externalContext = externalMap.get(EXTERNAL_CONTEXT_KEY); - final ClassLoader cl = ClassLoader.class.isInstance(externalContext) ? (ClassLoader) externalContext : null; + final ClassLoader cl = externalContext instanceof ClassLoader ? (ClassLoader) externalContext : null; LOGGER.debug( "Reconfiguration started for context[name={}] at URI {} ({}) with optional ClassLoader: {}", contextName, diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/config/AbstractConfiguration.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/config/AbstractConfiguration.java index 3c5069f7661..3b301bde4d7 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/config/AbstractConfiguration.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/config/AbstractConfiguration.java @@ -17,10 +17,12 @@ package org.apache.logging.log4j.core.config; import java.io.ByteArrayOutputStream; +import java.io.File; import java.io.IOException; import java.io.InputStream; import java.io.Serializable; import java.lang.ref.WeakReference; +import java.net.URI; import java.util.ArrayList; import java.util.Arrays; import java.util.Collection; @@ -279,11 +281,12 @@ protected void initializeWatchers( if (configSource != null && (configSource.getFile() != null || configSource.getURL() != null)) { if (monitorIntervalSeconds > 0) { watchManager.setIntervalSeconds(monitorIntervalSeconds); - if (configSource.getFile() != null) { - final Source cfgSource = new Source(configSource); - final long lastModifeid = configSource.getFile().lastModified(); + File file = configSource.getFile(); + if (file != null) { + final Source cfgSource = new Source(file); + final long lastModified = file.lastModified(); final ConfigurationFileWatcher watcher = - new ConfigurationFileWatcher(this, reconfigurable, listeners, lastModifeid); + new ConfigurationFileWatcher(this, reconfigurable, listeners, lastModified); watchManager.watch(cfgSource, watcher); } else if (configSource.getURL() != null) { monitorSource(reconfigurable, configSource); @@ -297,8 +300,10 @@ protected void initializeWatchers( } private void monitorSource(final Reconfigurable reconfigurable, final ConfigurationSource configSource) { - if (configSource.getLastModified() > 0) { - final Source cfgSource = new Source(configSource); + URI uri = configSource.getURI(); + if (uri != null && configSource.getLastModified() > 0) { + File file = configSource.getFile(); + final Source cfgSource = file != null ? new Source(file) : new Source(uri); final Watcher watcher = WatcherFactory.getInstance(pluginPackages) .newWatcher(cfgSource, this, reconfigurable, listeners, configSource.getLastModified()); if (watcher != null) { @@ -318,9 +323,13 @@ public void start() { if (getState() == State.INITIALIZING) { initialize(); } - LOGGER.debug("Starting configuration {}", this); + LOGGER.info("Starting configuration {}...", this); this.setStarting(); if (watchManager.getIntervalSeconds() >= 0) { + LOGGER.info( + "Start watching for changes to {} every {} seconds", + getConfigurationSource(), + watchManager.getIntervalSeconds()); watchManager.start(); } if (hasAsyncLoggers()) { @@ -338,7 +347,7 @@ public void start() { root.start(); // LOG4J2-336 } super.start(); - LOGGER.debug("Started configuration {} OK.", this); + LOGGER.info("Configuration {} started.", this); } private boolean hasAsyncLoggers() { @@ -358,9 +367,9 @@ private boolean hasAsyncLoggers() { */ @Override public boolean stop(final long timeout, final TimeUnit timeUnit) { + LOGGER.info("Stopping configuration {}...", this); this.setStopping(); super.stop(timeout, timeUnit, false); - LOGGER.trace("Stopping {}...", this); // Stop the components that are closest to the application first: // 1. Notify all LoggerConfigs' ReliabilityStrategy that the configuration will be stopped. @@ -456,7 +465,7 @@ public boolean stop(final long timeout, final TimeUnit timeUnit) { advertiser.unadvertise(advertisement); } setStopped(); - LOGGER.debug("Stopped {} OK", this); + LOGGER.info("Configuration {} stopped.", this); return true; } @@ -484,6 +493,7 @@ public void setup() { // default does nothing, subclasses do work. } + @SuppressWarnings("deprecation") protected Level getDefaultStatus() { final PropertiesUtil properties = PropertiesUtil.getProperties(); String statusLevel = properties.getStringProperty(StatusLogger.DEFAULT_STATUS_LISTENER_LEVEL); diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/config/ConfigurationSource.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/config/ConfigurationSource.java index fbcf278a07b..c393329ff07 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/config/ConfigurationSource.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/config/ConfigurationSource.java @@ -16,6 +16,8 @@ */ package org.apache.logging.log4j.core.config; +import static java.util.Objects.requireNonNull; + import edu.umd.cs.findbugs.annotations.SuppressFBWarnings; import java.io.ByteArrayInputStream; import java.io.ByteArrayOutputStream; @@ -32,19 +34,23 @@ import java.net.URLConnection; import java.nio.file.Files; import java.nio.file.Path; -import java.util.Objects; +import org.apache.logging.log4j.Logger; import org.apache.logging.log4j.core.net.UrlConnectionFactory; import org.apache.logging.log4j.core.util.FileUtils; import org.apache.logging.log4j.core.util.Loader; import org.apache.logging.log4j.core.util.Source; +import org.apache.logging.log4j.status.StatusLogger; import org.apache.logging.log4j.util.Constants; import org.apache.logging.log4j.util.LoaderUtil; /** * Represents the source for the logging configuration. */ +/*@NullMarked*/ public class ConfigurationSource { + private static final Logger LOGGER = StatusLogger.getLogger(); + /** * ConfigurationSource to use with Configurations that do not require a "real" configuration source. */ @@ -57,8 +63,8 @@ public class ConfigurationSource { new ConfigurationSource(Constants.EMPTY_BYTE_ARRAY, null, 0); private final InputStream stream; - private volatile byte[] data; - private volatile Source source; + private volatile byte /*@Nullable*/[] data; + private final /*@Nullable*/ Source source; private final long lastModified; // Set when the configuration has been updated so reset can use it for the next lastModified timestamp. private volatile long modifiedMillis; @@ -71,16 +77,7 @@ public class ConfigurationSource { * @param file the file where the input stream originated */ public ConfigurationSource(final InputStream stream, final File file) { - this.stream = Objects.requireNonNull(stream, "stream is null"); - this.data = null; - this.source = new Source(file); - long modified = 0; - try { - modified = file.lastModified(); - } catch (Exception ex) { - // There is a problem with the file. It will be handled somewhere else. - } - this.lastModified = modified; + this(null, new Source(file), stream, getLastModified(file.toPath())); } /** @@ -91,16 +88,16 @@ public ConfigurationSource(final InputStream stream, final File file) { * @param path the path where the input stream originated. */ public ConfigurationSource(final InputStream stream, final Path path) { - this.stream = Objects.requireNonNull(stream, "stream is null"); - this.data = null; - this.source = new Source(path); - long modified = 0; + this(null, new Source(path), stream, getLastModified(path)); + } + + private static long getLastModified(Path path) { try { - modified = Files.getLastModifiedTime(path).toMillis(); - } catch (Exception ex) { + return Files.getLastModifiedTime(path).toMillis(); + } catch (Exception ignored) { // There is a problem with the file. It will be handled somewhere else. } - this.lastModified = modified; + return 0L; } /** @@ -111,10 +108,7 @@ public ConfigurationSource(final InputStream stream, final Path path) { * @param url the URL where the input stream originated */ public ConfigurationSource(final InputStream stream, final URL url) { - this.stream = Objects.requireNonNull(stream, "stream is null"); - this.data = null; - this.lastModified = 0; - this.source = new Source(url); + this(stream, url, 0); } /** @@ -125,11 +119,8 @@ public ConfigurationSource(final InputStream stream, final URL url) { * @param url the URL where the input stream originated * @param lastModified when the source was last modified. */ - public ConfigurationSource(final InputStream stream, final URL url, final long lastModified) { - this.stream = Objects.requireNonNull(stream, "stream is null"); - this.data = null; - this.lastModified = lastModified; - this.source = new Source(url); + public ConfigurationSource(InputStream stream, final URL url, final long lastModified) { + this(null, new Source(url), stream, lastModified); } /** @@ -139,7 +130,7 @@ public ConfigurationSource(final InputStream stream, final URL url, final long l * @param stream the input stream, the caller is responsible for closing this resource. * @throws IOException if an exception occurred reading from the specified stream */ - public ConfigurationSource(final InputStream stream) throws IOException { + public ConfigurationSource(InputStream stream) throws IOException { this(toByteArray(stream), null, 0); } @@ -150,23 +141,23 @@ public ConfigurationSource(final InputStream stream) throws IOException { * @param data data from the source * @param lastModified when the source was last modified. */ - public ConfigurationSource(final Source source, final byte[] data, final long lastModified) { - Objects.requireNonNull(source, "source is null"); - this.data = Objects.requireNonNull(data, "data is null"); - this.stream = new ByteArrayInputStream(data); - this.lastModified = lastModified; - this.source = source; + public ConfigurationSource(Source source, byte[] data, long lastModified) { + this(data, requireNonNull(source, "source is null"), lastModified); } - private ConfigurationSource(final byte[] data, final URL url, final long lastModified) { - this.data = Objects.requireNonNull(data, "data is null"); - this.stream = new ByteArrayInputStream(data); - this.lastModified = lastModified; - if (url == null) { - this.data = data; - } else { - this.source = new Source(url); - } + private ConfigurationSource(byte[] data, /*@Nullable*/ Source source, long lastModified) { + this(requireNonNull(data, "data is null"), source, new ByteArrayInputStream(data), lastModified); + } + + /** + * @throws NullPointerException if {@code stream} is {@code null}. + */ + private ConfigurationSource( + byte /*@Nullable*/[] data, /*@Nullable*/ Source source, InputStream stream, long lastModified) { + this.stream = requireNonNull(stream, "stream is null"); + this.data = data; + this.source = source; + this.modifiedMillis = this.lastModified = lastModified; } /** @@ -195,38 +186,26 @@ private static byte[] toByteArray(final InputStream inputStream) throws IOExcept * * @return the configuration source file, or {@code null} */ - public File getFile() { + public /*@Nullable*/ File getFile() { return source == null ? null : source.getFile(); } - private boolean isFile() { - return source == null ? false : source.getFile() != null; - } - - private boolean isURL() { - return source == null ? false : source.getURI() != null; - } - - private boolean isLocation() { - return source == null ? false : source.getLocation() != null; - } - /** * Returns the configuration source URL, or {@code null} if this configuration source is based on a file or has * neither a file nor an URL. * * @return the configuration source URL, or {@code null} */ - public URL getURL() { + public /*@Nullable*/ URL getURL() { return source == null ? null : source.getURL(); } /** - * @deprecated Not used internally, no replacement. TODO remove and make source final. + * @deprecated Not used internally, no replacement. */ @Deprecated - public void setSource(final Source source) { - this.source = source; + public void setSource(final Source ignored) { + LOGGER.warn("Ignoring call of deprecated method `ConfigurationSource#setSource()`."); } public void setData(final byte[] data) { @@ -241,7 +220,7 @@ public void setModifiedMillis(final long modifiedMillis) { * Returns a URI representing the configuration resource or null if it cannot be determined. * @return The URI. */ - public URI getURI() { + public /*@Nullable*/ URI getURI() { return source == null ? null : source.getURI(); } @@ -259,7 +238,7 @@ public long getLastModified() { * * @return a string describing the configuration source file or URL, or {@code null} */ - public String getLocation() { + public /*@Nullable*/ String getLocation() { return source == null ? null : source.getLocation(); } @@ -278,30 +257,36 @@ public InputStream getInputStream() { * @return a new {@code ConfigurationSource} * @throws IOException if a problem occurred while opening the new input stream */ - public ConfigurationSource resetInputStream() throws IOException { + public /*@Nullable*/ ConfigurationSource resetInputStream() throws IOException { + byte[] data = this.data; if (source != null && data != null) { - return new ConfigurationSource(source, data, this.lastModified); - } else if (isFile()) { - return new ConfigurationSource(new FileInputStream(getFile()), getFile()); - } else if (isURL() && data != null) { + return new ConfigurationSource(source, data, modifiedMillis); + } + File file = getFile(); + if (file != null) { + return new ConfigurationSource(Files.newInputStream(file.toPath()), getFile()); + } + URL url = getURL(); + if (url != null && data != null) { // Creates a ConfigurationSource without accessing the URL since the data was provided. - return new ConfigurationSource(data, getURL(), modifiedMillis == 0 ? lastModified : modifiedMillis); - } else if (isURL()) { - return fromUri(getURI()); - } else if (data != null) { - return new ConfigurationSource(data, null, lastModified); + return new ConfigurationSource(data, new Source(url), modifiedMillis); } - return null; + URI uri = getURI(); + if (uri != null) { + return fromUri(uri); + } + return data == null ? null : new ConfigurationSource(data, null, modifiedMillis); } @Override public String toString() { - if (isLocation()) { - return getLocation(); + if (source != null) { + return source.getLocation(); } if (this == NULL_SOURCE) { return "NULL_SOURCE"; } + byte[] data = this.data; final int length = data == null ? -1 : data.length; return "stream (" + length + " bytes, unknown location)"; } @@ -309,9 +294,9 @@ public String toString() { /** * Loads the configuration from a URI. * @param configLocation A URI representing the location of the configuration. - * @return The ConfigurationSource for the configuration. + * @return The ConfigurationSource for the configuration or {@code null}. */ - public static ConfigurationSource fromUri(final URI configLocation) { + public static /*@Nullable*/ ConfigurationSource fromUri(final URI configLocation) { final File configFile = FileUtils.fileFromUri(configLocation); if (configFile != null && configFile.exists() && configFile.canRead()) { try { @@ -344,18 +329,15 @@ public static ConfigurationSource fromUri(final URI configLocation) { * @param loader The default ClassLoader to use. * @return The ConfigurationSource for the configuration. */ - public static ConfigurationSource fromResource(final String resource, final ClassLoader loader) { + public static /*@Nullable*/ ConfigurationSource fromResource(String resource, /*@Nullable*/ ClassLoader loader) { final URL url = Loader.getResource(resource, loader); - if (url == null) { - return null; - } - return getConfigurationSource(url); + return url == null ? null : getConfigurationSource(url); } @SuppressFBWarnings( value = "PATH_TRAVERSAL_IN", justification = "The name of the accessed files is based on a configuration value.") - private static ConfigurationSource getConfigurationSource(final URL url) { + private static /*@Nullable*/ ConfigurationSource getConfigurationSource(final URL url) { try { final File file = FileUtils.fileFromUri(url.toURI()); final URLConnection urlConnection = UrlConnectionFactory.createConnection(url); diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/config/HttpWatcher.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/config/HttpWatcher.java index 08e840d93bf..b6d7f57d663 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/config/HttpWatcher.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/config/HttpWatcher.java @@ -16,16 +16,19 @@ */ package org.apache.logging.log4j.core.config; +import static java.util.Objects.requireNonNull; +import static org.apache.logging.log4j.core.util.internal.HttpInputStreamUtil.readStream; +import static org.apache.logging.log4j.util.Strings.toRootUpperCase; + import java.io.IOException; import java.net.MalformedURLException; import java.net.URISyntaxException; import java.net.URL; +import java.time.Instant; import java.util.List; import org.apache.logging.log4j.Logger; import org.apache.logging.log4j.core.config.plugins.Plugin; import org.apache.logging.log4j.core.config.plugins.PluginAliases; -import org.apache.logging.log4j.core.net.ssl.SslConfiguration; -import org.apache.logging.log4j.core.net.ssl.SslConfigurationFactory; import org.apache.logging.log4j.core.util.AbstractWatcher; import org.apache.logging.log4j.core.util.AuthorizationProvider; import org.apache.logging.log4j.core.util.Source; @@ -44,7 +47,6 @@ public class HttpWatcher extends AbstractWatcher { private final Logger LOGGER = StatusLogger.getLogger(); - private final SslConfiguration sslConfiguration; private AuthorizationProvider authorizationProvider; private URL url; private volatile long lastModifiedMillis; @@ -57,7 +59,6 @@ public HttpWatcher( final List configurationListeners, final long lastModifiedMillis) { super(configuration, reconfigurable, configurationListeners); - sslConfiguration = SslConfigurationFactory.getSslConfiguration(); this.lastModifiedMillis = lastModifiedMillis; } @@ -103,34 +104,50 @@ private boolean refreshConfiguration() { try { final LastModifiedSource source = new LastModifiedSource(url.toURI(), lastModifiedMillis); final HttpInputStreamUtil.Result result = HttpInputStreamUtil.getInputStream(source, authorizationProvider); + // Update lastModifiedMillis + // https://github.com/apache/logging-log4j2/issues/2937 + lastModifiedMillis = source.getLastModified(); + // The result of the HTTP/HTTPS request is already logged at `DEBUG` by `HttpInputStreamUtil` + // We only log the important events at `INFO` or more. switch (result.getStatus()) { case NOT_MODIFIED: { - LOGGER.debug("Configuration Not Modified"); return false; } case SUCCESS: { final ConfigurationSource configSource = getConfiguration().getConfigurationSource(); try { - configSource.setData(HttpInputStreamUtil.readStream(result.getInputStream())); + // In this case `result.getInputStream()` is not null. + configSource.setData(readStream(requireNonNull(result.getInputStream()))); configSource.setModifiedMillis(source.getLastModified()); - LOGGER.debug("Content was modified for {}", url.toString()); + LOGGER.info( + "{} resource at {} was modified on {}", + () -> toRootUpperCase(url.getProtocol()), + () -> url.toExternalForm(), + () -> Instant.ofEpochMilli(source.getLastModified())); return true; } catch (final IOException e) { - LOGGER.error("Error accessing configuration at {}: {}", url, e.getMessage()); + // Dead code since result.getInputStream() is a ByteArrayInputStream + LOGGER.error("Error accessing configuration at {}", url.toExternalForm(), e); return false; } } case NOT_FOUND: { - LOGGER.info("Unable to locate configuration at {}", url.toString()); + LOGGER.warn( + "{} resource at {} was not found", + () -> toRootUpperCase(url.getProtocol()), + () -> url.toExternalForm()); return false; } default: { - LOGGER.warn("Unexpected error accessing configuration at {}", url.toString()); + LOGGER.warn( + "Unexpected error retrieving {} resource at {}", + () -> toRootUpperCase(url.getProtocol()), + () -> url.toExternalForm()); return false; } } } catch (final URISyntaxException ex) { - LOGGER.error("Bad configuration URL: {}, {}", url.toString(), ex.getMessage()); + LOGGER.error("Bad configuration file URL {}", url.toExternalForm(), ex); return false; } } diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/config/package-info.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/config/package-info.java index 1a8b3df5989..111d1644f68 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/config/package-info.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/config/package-info.java @@ -18,7 +18,7 @@ * Configuration of Log4j 2. */ @Export -@Version("2.24.0") +@Version("2.24.1") package org.apache.logging.log4j.core.config; import org.osgi.annotation.bundle.Export; diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/config/xml/XmlConfiguration.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/config/xml/XmlConfiguration.java index 48502de22e5..31e42d843f4 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/config/xml/XmlConfiguration.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/config/xml/XmlConfiguration.java @@ -18,9 +18,9 @@ import edu.umd.cs.findbugs.annotations.SuppressFBWarnings; import java.io.ByteArrayInputStream; -import java.io.File; import java.io.IOException; import java.io.InputStream; +import java.time.Instant; import java.util.ArrayList; import java.util.Arrays; import java.util.List; @@ -73,7 +73,6 @@ public class XmlConfiguration extends AbstractConfiguration implements Reconfigu justification = "The `newDocumentBuilder` method disables DTD processing.") public XmlConfiguration(final LoggerContext loggerContext, final ConfigurationSource configSource) { super(loggerContext, configSource); - final File configFile = configSource.getFile(); byte[] buffer = null; try { @@ -175,7 +174,7 @@ public XmlConfiguration(final LoggerContext loggerContext, final ConfigurationSo * * @param xIncludeAware enabled XInclude * @return a new DocumentBuilder - * @throws ParserConfigurationException + * @throws ParserConfigurationException if a DocumentBuilder cannot be created, which satisfies the configuration requested. */ static DocumentBuilder newDocumentBuilder(final boolean xIncludeAware) throws ParserConfigurationException { final DocumentBuilderFactory factory = DocumentBuilderFactory.newInstance(); @@ -241,7 +240,7 @@ public void setup() { return; } constructHierarchy(rootNode, rootElement); - if (status.size() > 0) { + if (!status.isEmpty()) { for (final Status s : status) { LOGGER.error("Error processing element {} ({}): {}", s.name, s.element, s.errorType); } @@ -295,7 +294,7 @@ private void constructHierarchy(final Node node, final Element element) { } final String text = buffer.toString().trim(); - if (text.length() > 0 || (!node.hasChildren() && !node.isRoot())) { + if (!text.isEmpty() || (!node.hasChildren() && !node.isRoot())) { node.setValue(text); } } @@ -337,7 +336,8 @@ private Map processAttributes(final Node node, final Element ele @Override public String toString() { - return getClass().getSimpleName() + "[location=" + getConfigurationSource() + "]"; + return getClass().getSimpleName() + "[location=" + getConfigurationSource() + ", lastModified=" + + Instant.ofEpochMilli(getConfigurationSource().getLastModified()) + "]"; } /** diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/filter/MutableThreadContextMapFilter.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/filter/MutableThreadContextMapFilter.java index 3ceb4599b76..b9061fe0158 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/filter/MutableThreadContextMapFilter.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/filter/MutableThreadContextMapFilter.java @@ -20,9 +20,9 @@ import com.fasterxml.jackson.databind.ObjectMapper; import edu.umd.cs.findbugs.annotations.SuppressFBWarnings; import java.io.File; -import java.io.FileInputStream; import java.io.InputStream; import java.net.URI; +import java.nio.file.Files; import java.util.ArrayList; import java.util.List; import java.util.Map; @@ -65,6 +65,9 @@ @PerformanceSensitive("allocation") public class MutableThreadContextMapFilter extends AbstractFilter { + private static final String HTTP = "http"; + private static final String HTTPS = "https"; + private static final ObjectMapper MAPPER = new ObjectMapper().configure(DeserializationFeature.FAIL_ON_UNKNOWN_PROPERTIES, false); private static final KeyValuePair[] EMPTY_ARRAY = {}; @@ -364,23 +367,36 @@ private class FileMonitor implements Runnable { @Override public void run() { final ConfigResult result = getConfig(source, authorizationProvider); - if (result.status == Status.SUCCESS) { - filter = ThreadContextMapFilter.createFilter(result.pairs, "or", getOnMatch(), getOnMismatch()); - LOGGER.info("Filter configuration was updated: {}", filter.toString()); - for (FilterConfigUpdateListener listener : listeners) { - listener.onEvent(); - } - } else if (result.status == Status.NOT_FOUND) { - if (!(filter instanceof NoOpFilter)) { - LOGGER.info("Filter configuration was removed"); + switch (result.status) { + case SUCCESS: + filter = ThreadContextMapFilter.createFilter(result.pairs, "or", getOnMatch(), getOnMismatch()); + LOGGER.info("MutableThreadContextMapFilter configuration was updated: {}", filter.toString()); + break; + case NOT_FOUND: + if (!(filter instanceof NoOpFilter)) { + LOGGER.info("MutableThreadContextMapFilter configuration was removed"); + filter = new NoOpFilter(); + } + break; + case EMPTY: + LOGGER.debug("MutableThreadContextMapFilter configuration is empty"); filter = new NoOpFilter(); + break; + } + switch (result.status) { + // These results cause changes in the filter + // We call the listeners + case SUCCESS: + case NOT_FOUND: + case EMPTY: for (FilterConfigUpdateListener listener : listeners) { listener.onEvent(); } - } - } else if (result.status == Status.EMPTY) { - LOGGER.debug("Filter configuration is empty"); - filter = new NoOpFilter(); + break; + // These results do no cause changes in the filter + case ERROR: + case NOT_MODIFIED: + break; } } } @@ -389,7 +405,7 @@ public void run() { value = "PATH_TRAVERSAL_IN", justification = "The location of the file comes from a configuration value.") private static LastModifiedSource getSource(final String configLocation) { - LastModifiedSource source = null; + LastModifiedSource source; try { final URI uri = new URI(configLocation); if (uri.getScheme() != null) { @@ -408,14 +424,15 @@ private static ConfigResult getConfig( final LastModifiedSource source, final AuthorizationProvider authorizationProvider) { final File inputFile = source.getFile(); InputStream inputStream = null; - HttpInputStreamUtil.Result result = null; + HttpInputStreamUtil.Result result; final long lastModified = source.getLastModified(); + URI uri = source.getURI(); if (inputFile != null && inputFile.exists()) { try { final long modified = inputFile.lastModified(); if (modified > lastModified) { source.setLastModified(modified); - inputStream = new FileInputStream(inputFile); + inputStream = Files.newInputStream(inputFile.toPath()); result = new HttpInputStreamUtil.Result(Status.SUCCESS); } else { result = new HttpInputStreamUtil.Result(Status.NOT_MODIFIED); @@ -423,7 +440,7 @@ private static ConfigResult getConfig( } catch (Exception ex) { result = new HttpInputStreamUtil.Result(Status.ERROR); } - } else if (source.getURI() != null) { + } else if (uri != null && (HTTP.equalsIgnoreCase(uri.getScheme()) || HTTPS.equalsIgnoreCase(uri.getScheme()))) { try { result = HttpInputStreamUtil.getInputStream(source, authorizationProvider); inputStream = result.getInputStream(); @@ -440,7 +457,7 @@ private static ConfigResult getConfig( final KeyValuePairConfig keyValuePairConfig = MAPPER.readValue(inputStream, KeyValuePairConfig.class); if (keyValuePairConfig != null) { final Map configs = keyValuePairConfig.getConfigs(); - if (configs != null && configs.size() > 0) { + if (configs != null && !configs.isEmpty()) { final List pairs = new ArrayList<>(); for (Map.Entry entry : configs.entrySet()) { final String key = entry.getKey(); @@ -452,7 +469,7 @@ private static ConfigResult getConfig( } } } - if (pairs.size() > 0) { + if (!pairs.isEmpty()) { configResult.pairs = pairs.toArray(EMPTY_ARRAY); configResult.status = Status.SUCCESS; } else { diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/Loader.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/Loader.java index b4e035c9fbd..64ee6be3599 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/Loader.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/Loader.java @@ -23,6 +23,7 @@ import org.apache.logging.log4j.status.StatusLogger; import org.apache.logging.log4j.util.LoaderUtil; import org.apache.logging.log4j.util.PropertiesUtil; +import org.jspecify.annotations.Nullable; /** * Load resources (or images) from various sources. @@ -84,9 +85,9 @@ public static ClassLoader getClassLoader(final Class class1, final Class c * * @param resource The resource to load. * @param defaultLoader The default ClassLoader. - * @return A URL to the resource. + * @return A URL to the resource or {@code null}. */ - public static URL getResource(final String resource, final ClassLoader defaultLoader) { + public static @Nullable URL getResource(final String resource, final ClassLoader defaultLoader) { try { ClassLoader classLoader = getThreadContextClassLoader(); if (classLoader != null) { diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/Source.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/Source.java index 580d3b73d4d..5a79ab8b9ab 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/Source.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/Source.java @@ -16,6 +16,8 @@ */ package org.apache.logging.log4j.core.util; +import static java.util.Objects.requireNonNull; + import edu.umd.cs.findbugs.annotations.SuppressFBWarnings; import java.io.File; import java.io.IOException; @@ -30,10 +32,13 @@ import org.apache.logging.log4j.core.config.ConfigurationSource; import org.apache.logging.log4j.status.StatusLogger; import org.apache.logging.log4j.util.Strings; +import org.jspecify.annotations.NullMarked; +import org.jspecify.annotations.Nullable; /** * Represents the source for the logging configuration as an immutable object. */ +@NullMarked public class Source { private static final Logger LOGGER = StatusLogger.getLogger(); @@ -45,9 +50,9 @@ private static String normalize(final File file) { } } - private static File toFile(final Path path) { + private static @Nullable File toFile(Path path) { try { - return Objects.requireNonNull(path, "path").toFile(); + return requireNonNull(path, "path").toFile(); } catch (final UnsupportedOperationException e) { return null; } @@ -57,9 +62,9 @@ private static File toFile(final Path path) { @SuppressFBWarnings( value = "PATH_TRAVERSAL_IN", justification = "The URI should be specified in a configuration file.") - private static File toFile(final URI uri) { + private static @Nullable File toFile(URI uri) { try { - final String scheme = Objects.requireNonNull(uri, "uri").getScheme(); + final String scheme = requireNonNull(uri, "uri").getScheme(); if (Strings.isBlank(scheme) || scheme.equals("file")) { return new File(uri.getPath()); } else { @@ -67,20 +72,20 @@ private static File toFile(final URI uri) { return null; } } catch (final Exception e) { - LOGGER.debug("uri is malformed: " + uri.toString()); + LOGGER.debug("uri is malformed: " + uri); return null; } } private static URI toURI(final URL url) { try { - return Objects.requireNonNull(url, "url").toURI(); + return requireNonNull(url, "url").toURI(); } catch (final URISyntaxException e) { throw new IllegalArgumentException(e); } } - private final File file; + private final @Nullable File file; private final URI uri; private final String location; @@ -88,21 +93,23 @@ private static URI toURI(final URL url) { * Constructs a Source from a ConfigurationSource. * * @param source The ConfigurationSource. + * @throws NullPointerException if {@code source} is {@code null}. */ public Source(final ConfigurationSource source) { this.file = source.getFile(); - this.uri = source.getURI(); - this.location = source.getLocation(); + this.uri = requireNonNull(source.getURI()); + this.location = requireNonNull(source.getLocation()); } /** * Constructs a new {@code Source} with the specified file. * file. * - * @param file the file where the input stream originated + * @param file the file where the input stream originated. + * @throws NullPointerException if {@code file} is {@code null}. */ public Source(final File file) { - this.file = Objects.requireNonNull(file, "file"); + this.file = requireNonNull(file, "file"); this.location = normalize(file); this.uri = file.toURI(); } @@ -111,9 +118,10 @@ public Source(final File file) { * Constructs a new {@code Source} from the specified Path. * * @param path the Path where the input stream originated + * @throws NullPointerException if {@code path} is {@code null}. */ public Source(final Path path) { - final Path normPath = Objects.requireNonNull(path, "path").normalize(); + final Path normPath = requireNonNull(path, "path").normalize(); this.file = toFile(normPath); this.uri = normPath.toUri(); this.location = normPath.toString(); @@ -123,9 +131,10 @@ public Source(final Path path) { * Constructs a new {@code Source} from the specified URI. * * @param uri the URI where the input stream originated + * @throws NullPointerException if {@code uri} is {@code null}. */ public Source(final URI uri) { - final URI normUri = Objects.requireNonNull(uri, "uri").normalize(); + final URI normUri = requireNonNull(uri, "uri").normalize(); this.uri = normUri; this.location = normUri.toString(); this.file = toFile(normUri); @@ -135,11 +144,12 @@ public Source(final URI uri) { * Constructs a new {@code Source} from the specified URI. * * @param uri the URI where the input stream originated - * @param lastModified Not used. + * @param ignored Not used. * @deprecated Use {@link Source#Source(URI)}. + * @throws NullPointerException if {@code uri} is {@code null}. */ @Deprecated - public Source(final URI uri, final long lastModified) { + public Source(URI uri, long ignored) { this(uri); } @@ -147,6 +157,7 @@ public Source(final URI uri, final long lastModified) { * Constructs a new {@code Source} from the specified URL. * * @param url the URL where the input stream originated + * @throws NullPointerException if this URL is {@code null}. * @throws IllegalArgumentException if this URL is not formatted strictly according to RFC2396 and cannot be * converted to a URI. */ @@ -174,7 +185,7 @@ public boolean equals(final Object obj) { * * @return the configuration source file, or {@code null} */ - public File getFile() { + public @Nullable File getFile() { return file; } @@ -197,7 +208,7 @@ public String getLocation() { value = "PATH_TRAVERSAL_IN", justification = "The `file`, `uri` and `location` fields come from Log4j properties.") public Path getPath() { - return file != null ? file.toPath() : uri != null ? Paths.get(uri) : Paths.get(location); + return file != null ? file.toPath() : Paths.get(uri); } /** diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/WatchManager.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/WatchManager.java index 15e9009b75c..3f2856340fd 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/WatchManager.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/WatchManager.java @@ -20,6 +20,7 @@ import aQute.bnd.annotation.Resolution; import aQute.bnd.annotation.spi.ServiceConsumer; import java.io.File; +import java.time.Instant; import java.util.Date; import java.util.HashMap; import java.util.List; @@ -49,8 +50,9 @@ @ServiceConsumer(value = WatchEventService.class, resolution = Resolution.OPTIONAL, cardinality = Cardinality.MULTIPLE) public class WatchManager extends AbstractLifeCycle { - private final class ConfigurationMonitor { + private static final class ConfigurationMonitor { private final Watcher watcher; + // Only used for logging private volatile long lastModifiedMillis; public ConfigurationMonitor(final long lastModifiedMillis, final Watcher watcher) { @@ -76,7 +78,6 @@ private static class LocalUUID { private static final long LOW_MASK = 0xffffffffL; private static final long MID_MASK = 0xffff00000000L; private static final long HIGH_MASK = 0xfff000000000000L; - private static final int NODE_SIZE = 8; private static final int SHIFT_2 = 16; private static final int SHIFT_4 = 32; private static final int SHIFT_6 = 48; @@ -84,8 +85,6 @@ private static class LocalUUID { private static final long NUM_100NS_INTERVALS_SINCE_UUID_EPOCH = 0x01b21dd213814000L; private static final AtomicInteger COUNT = new AtomicInteger(0); private static final long TYPE1 = 0x1000L; - private static final byte VARIANT = (byte) 0x80; - private static final int SEQUENCE_MASK = 0x3FFF; public static UUID get() { final long time = @@ -112,15 +111,11 @@ public void run() { final ConfigurationMonitor monitor = entry.getValue(); if (monitor.getWatcher().isModified()) { final long lastModified = monitor.getWatcher().getLastModified(); - if (logger.isInfoEnabled()) { - logger.info( - "Source '{}' was modified on {} ({}), previous modification was on {} ({})", - source, - millisToString(lastModified), - lastModified, - millisToString(monitor.lastModifiedMillis), - monitor.lastModifiedMillis); - } + logger.info( + "Configuration source at `{}` was modified on `{}`, previous modification was on `{}`", + () -> source, + () -> Instant.ofEpochMilli(lastModified), + () -> Instant.ofEpochMilli(monitor.lastModifiedMillis)); monitor.lastModifiedMillis = lastModified; monitor.getWatcher().modified(); } @@ -200,7 +195,7 @@ public Map getWatchers() { } public boolean hasEventListeners() { - return eventServiceList.size() > 0; + return !eventServiceList.isEmpty(); } private String millisToString(final long millis) { diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/HttpInputStreamUtil.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/HttpInputStreamUtil.java index c146958f9fe..2c25ed2d255 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/HttpInputStreamUtil.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/HttpInputStreamUtil.java @@ -16,17 +16,24 @@ */ package org.apache.logging.log4j.core.util.internal; +import static org.apache.logging.log4j.util.Strings.toRootUpperCase; + import java.io.ByteArrayInputStream; import java.io.ByteArrayOutputStream; import java.io.IOException; import java.io.InputStream; import java.net.HttpURLConnection; +import java.time.Instant; import org.apache.logging.log4j.Logger; import org.apache.logging.log4j.core.config.ConfigurationException; import org.apache.logging.log4j.core.net.UrlConnectionFactory; import org.apache.logging.log4j.core.net.ssl.SslConfigurationFactory; import org.apache.logging.log4j.core.util.AuthorizationProvider; +import org.apache.logging.log4j.core.util.Source; import org.apache.logging.log4j.status.StatusLogger; +import org.apache.logging.log4j.util.Supplier; +import org.jspecify.annotations.NullMarked; +import org.jspecify.annotations.Nullable; /** * Utility method for reading data from an HTTP InputStream. @@ -36,10 +43,21 @@ public final class HttpInputStreamUtil { private static final Logger LOGGER = StatusLogger.getLogger(); private static final int NOT_MODIFIED = 304; private static final int NOT_AUTHORIZED = 401; + private static final int FORBIDDEN = 403; private static final int NOT_FOUND = 404; private static final int OK = 200; private static final int BUF_SIZE = 1024; + /** + * Retrieves an HTTP resource if it has been modified. + *

+ * Side effects: if the request is successful, the last modified time of the {@code source} + * parameter is modified. + *

+ * @param source The location of the HTTP resource + * @param authorizationProvider The authentication data for the HTTP request + * @return A {@link Result} object containing the status code and body of the response + */ public static Result getInputStream( final LastModifiedSource source, final AuthorizationProvider authorizationProvider) { final Result result = new Result(); @@ -55,12 +73,16 @@ public static Result getInputStream( final int code = connection.getResponseCode(); switch (code) { case NOT_MODIFIED: { - LOGGER.debug("Configuration not modified"); + LOGGER.debug( + "{} resource {}: not modified since {}", + formatProtocol(source), + () -> source, + () -> Instant.ofEpochMilli(lastModified)); result.status = Status.NOT_MODIFIED; return result; } case NOT_FOUND: { - LOGGER.debug("Unable to access {}: Not Found", source.toString()); + LOGGER.debug("{} resource {}: not found", formatProtocol(source), () -> source); result.status = Status.NOT_FOUND; return result; } @@ -68,45 +90,65 @@ public static Result getInputStream( try (final InputStream is = connection.getInputStream()) { source.setLastModified(connection.getLastModified()); LOGGER.debug( - "Content was modified for {}. previous lastModified: {}, new lastModified: {}", - source.toString(), - lastModified, - connection.getLastModified()); + "{} resource {}: last modified on {}", + formatProtocol(source), + () -> source, + () -> Instant.ofEpochMilli(connection.getLastModified())); result.status = Status.SUCCESS; - result.inputStream = new ByteArrayInputStream(readStream(is)); + result.bytes = readStream(is); return result; } catch (final IOException e) { try (final InputStream es = connection.getErrorStream()) { - LOGGER.info( - "Error accessing configuration at {}: {}", source.toString(), readStream(es)); + if (LOGGER.isDebugEnabled()) { + LOGGER.debug( + "Error accessing {} resource at {}: {}", + formatProtocol(source).get(), + source, + readStream(es), + e); + } } catch (final IOException ioe) { - LOGGER.error( - "Error accessing configuration at {}: {}", source.toString(), e.getMessage()); + LOGGER.debug( + "Error accessing {} resource at {}", + formatProtocol(source), + () -> source, + () -> e); } - throw new ConfigurationException("Unable to access " + source.toString(), e); + throw new ConfigurationException("Unable to access " + source, e); } } case NOT_AUTHORIZED: { - throw new ConfigurationException("Authorization failed"); + throw new ConfigurationException("Authentication required for " + source); + } + case FORBIDDEN: { + throw new ConfigurationException("Access denied to " + source); } default: { if (code < 0) { - LOGGER.info("Invalid response code returned"); + LOGGER.debug("{} resource {}: invalid response code", formatProtocol(source), source); } else { - LOGGER.info("Unexpected response code returned {}", code); + LOGGER.debug( + "{} resource {}: unexpected response code {}", + formatProtocol(source), + source, + code); } - throw new ConfigurationException("Unable to access " + source.toString()); + throw new ConfigurationException("Unable to access " + source); } } } finally { connection.disconnect(); } } catch (IOException e) { - LOGGER.warn("Error accessing {}: {}", source.toString(), e.getMessage()); - throw new ConfigurationException("Unable to access " + source.toString(), e); + LOGGER.debug("Error accessing {} resource at {}", formatProtocol(source), source, e); + throw new ConfigurationException("Unable to access " + source, e); } } + private static Supplier formatProtocol(Source source) { + return () -> toRootUpperCase(source.getURI().getScheme()); + } + public static byte[] readStream(final InputStream is) throws IOException { final ByteArrayOutputStream result = new ByteArrayOutputStream(); final byte[] buffer = new byte[BUF_SIZE]; @@ -117,19 +159,29 @@ public static byte[] readStream(final InputStream is) throws IOException { return result.toByteArray(); } + @NullMarked public static class Result { - private InputStream inputStream; + private byte @Nullable [] bytes = null; private Status status; - public Result() {} + public Result() { + this(Status.ERROR); + } public Result(final Status status) { this.status = status; } - public InputStream getInputStream() { - return inputStream; + /** + * Returns the data if the status is {@link Status#SUCCESS}. + *

+ * In any other case the result is {@code null}. + *

+ * @return The contents of the HTTP response or null if empty. + */ + public @Nullable InputStream getInputStream() { + return bytes != null ? new ByteArrayInputStream(bytes) : null; } public Status getStatus() { diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/package-info.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/package-info.java index 6c602546054..73ad2271ba6 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/package-info.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/package-info.java @@ -18,7 +18,7 @@ * Log4j 2 helper classes. */ @Export -@Version("2.24.0") +@Version("2.24.1") package org.apache.logging.log4j.core.util; import org.osgi.annotation.bundle.Export; diff --git a/log4j-parent/pom.xml b/log4j-parent/pom.xml index e41e585c506..1faa00a7101 100644 --- a/log4j-parent/pom.xml +++ b/log4j-parent/pom.xml @@ -105,7 +105,6 @@ 1.7.0 4.0.5 0.6.0 - 9.4.55.v20240627 3.5.12 1.37 2.40.1 @@ -131,7 +130,6 @@ 2.7.18 5.3.39 2.0.3 - 10.0.27 1.7 2.35.2 2.10.0 @@ -197,14 +195,6 @@ import - - org.eclipse.jetty - jetty-bom - ${jetty.version} - pom - import - - org.junit junit-bom @@ -786,12 +776,6 @@ ${system-stubs.version} - - org.apache.tomcat - tomcat-juli - ${tomcat-juli.version} - - org.apache.velocity velocity diff --git a/pom.xml b/pom.xml index dcd499d2d38..35d64db194e 100644 --- a/pom.xml +++ b/pom.xml @@ -230,7 +230,7 @@ log4j-parent - + log4j-api-java9 log4j-core-java9 @@ -370,6 +370,10 @@ + + org.apache.logging.log4j log4j-1.2-api @@ -961,6 +965,7 @@ + java8-tests @@ -969,11 +974,23 @@ true + org.apache.maven.plugins maven-surefire-plugin + + + + org.jspecify + jspecify + ${jspecify.version} + + diff --git a/src/changelog/.2.x.x/2937-http-watcher.xml b/src/changelog/.2.x.x/2937-http-watcher.xml new file mode 100644 index 00000000000..ec3e1a14263 --- /dev/null +++ b/src/changelog/.2.x.x/2937-http-watcher.xml @@ -0,0 +1,8 @@ + + + + Fix reloading of the configuration from an HTTP(S) source +