This is an automated email from the ASF dual-hosted git repository. vy pushed a commit to branch rollMaxRandomDelay in repository https://gitbox.apache.org/repos/asf/logging-log4j2.git
commit 330998e3b579b0966444ed5aec93ada625e854e6 Author: Volkan Yazıcı <[email protected]> AuthorDate: Mon Jun 29 09:44:06 2026 +0200 Rework random delay for Rolling Appender action chain --- .../rolling/FileExtensionCompressDelayTest.java | 179 ---------------- .../rolling/RollingAppenderRandomDelayTest.java | 235 +++++++++++++++++++++ .../rolling/action/GzCompressActionTest.java | 70 ++---- .../rolling/action/ZipCompressActionTest.java | 70 ++---- .../log4j/core/appender/RollingFileAppender.java | 17 +- .../appender/RollingRandomAccessFileAppender.java | 12 ++ .../logging/log4j/core/appender/package-info.java | 2 +- .../appender/rolling/DefaultRolloverStrategy.java | 77 +------ .../log4j/core/appender/rolling/FileExtension.java | 108 +--------- .../core/appender/rolling/RollingFileManager.java | 167 ++++++++++----- .../rolling/RollingRandomAccessFileManager.java | 38 +++- .../appender/rolling/action/AbstractAction.java | 19 -- .../rolling/action/CommonsCompressAction.java | 27 --- .../appender/rolling/action/GzCompressAction.java | 45 +--- .../appender/rolling/action/ZipCompressAction.java | 31 +-- .../core/appender/rolling/action/package-info.java | 2 +- ...ion_delay.xml => 4012_add_max_random_delay.xml} | 2 +- .../ROOT/pages/manual/appenders/rolling-file.adoc | 24 ++- 18 files changed, 486 insertions(+), 639 deletions(-) diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/FileExtensionCompressDelayTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/FileExtensionCompressDelayTest.java deleted file mode 100644 index 98ebf8a691..0000000000 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/FileExtensionCompressDelayTest.java +++ /dev/null @@ -1,179 +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.appender.rolling; - -import static org.junit.jupiter.api.Assertions.assertFalse; -import static org.junit.jupiter.api.Assertions.assertInstanceOf; -import static org.junit.jupiter.api.Assertions.assertThrows; -import static org.junit.jupiter.api.Assertions.assertTrue; - -import java.io.File; -import java.io.FileWriter; -import java.io.IOException; -import org.apache.logging.log4j.core.appender.rolling.action.Action; -import org.apache.logging.log4j.core.appender.rolling.action.GzCompressAction; -import org.apache.logging.log4j.core.appender.rolling.action.ZipCompressAction; -import org.junit.jupiter.api.Test; -import org.junit.jupiter.api.io.TempDir; - -/** - * Issue #4012 — verifies that FileExtension.GZ and FileExtension.ZIP correctly pass - * maxCompressionDelaySeconds through to the compression action. - * - * This was the root cause of the bug: the 5-argument createCompressAction() in GZ and ZIP - * fell back to the 4-argument version, silently dropping the delay value. - */ -class FileExtensionCompressDelayTest { - - @Test - void testGzCreateCompressActionRejectsInvalidCompressionLevel(@TempDir File tempDir) { - File source = new File(tempDir, "invalid-level.log"); - File dest = new File(tempDir, "invalid-level.log.gz"); - - assertThrows( - IllegalArgumentException.class, - () -> FileExtension.GZ.createCompressAction(source.getPath(), dest.getPath(), true, -2, 0)); - assertThrows( - IllegalArgumentException.class, - () -> FileExtension.GZ.createCompressAction(source.getPath(), dest.getPath(), true, 10, 0)); - } - - @Test - void testZipCreateCompressActionRejectsInvalidCompressionLevel(@TempDir File tempDir) { - File source = new File(tempDir, "invalid-level.log"); - File dest = new File(tempDir, "invalid-level.log.zip"); - - assertThrows( - IllegalArgumentException.class, - () -> FileExtension.ZIP.createCompressAction(source.getPath(), dest.getPath(), true, -2, 0)); - assertThrows( - IllegalArgumentException.class, - () -> FileExtension.ZIP.createCompressAction(source.getPath(), dest.getPath(), true, 10, 0)); - } - - // ── GZ ──────────────────────────────────────────────────────────────── - - /** - * FileExtension.GZ.createCompressAction(5-args) must produce a GzCompressAction - * that applies the random delay — not fall back to 0. - */ - @Test - void testGzCreateCompressActionWithDelay(@TempDir File tempDir) throws Exception { - File source = new File(tempDir, "app.log"); - File dest = new File(tempDir, "app.log.gz"); - writeContent(source, "gz test content"); - - int maxDelay = 2; - Action action = FileExtension.GZ.createCompressAction(source.getPath(), dest.getPath(), true, -1, maxDelay); - - // Must return a GzCompressAction (not some other type) - assertInstanceOf(GzCompressAction.class, action, "Expected GzCompressAction"); - - long start = System.currentTimeMillis(); - action.execute(); - long elapsed = System.currentTimeMillis() - start; - - // Must finish within maxDelay + margin (delay IS applied via FileExtension) - assertTrue( - elapsed <= (maxDelay * 1000L) + 500, - "GZ compress via FileExtension exceeded maxDelay=" + maxDelay + "s: " + elapsed + "ms"); - assertTrue(dest.exists(), "Compressed .gz file must exist"); - assertFalse(source.exists(), "Source must be deleted after compression"); - } - - /** - * FileExtension.GZ.createCompressAction(5-args, delay=0) must behave identically - * to the 4-arg version — instant compression, no delay. - */ - @Test - void testGzCreateCompressActionNoDelay(@TempDir File tempDir) throws Exception { - File source = new File(tempDir, "app-nodelay.log"); - File dest = new File(tempDir, "app-nodelay.log.gz"); - writeContent(source, "gz no-delay content"); - - Action action = FileExtension.GZ.createCompressAction(source.getPath(), dest.getPath(), true, -1, 0); - - assertInstanceOf(GzCompressAction.class, action); - - long start = System.currentTimeMillis(); - action.execute(); - long elapsed = System.currentTimeMillis() - start; - - assertTrue(elapsed < 500, "GZ with delay=0 should be instant, took " + elapsed + "ms"); - assertTrue(dest.exists(), "Compressed .gz file must exist"); - assertFalse(source.exists(), "Source must be deleted"); - } - - // ── ZIP ─────────────────────────────────────────────────────────────── - - /** - * FileExtension.ZIP.createCompressAction(5-args) must produce a ZipCompressAction - * that applies the random delay — not fall back to 0. - */ - @Test - void testZipCreateCompressActionWithDelay(@TempDir File tempDir) throws Exception { - File source = new File(tempDir, "app.log"); - File dest = new File(tempDir, "app.log.zip"); - writeContent(source, "zip test content"); - - int maxDelay = 2; - Action action = FileExtension.ZIP.createCompressAction(source.getPath(), dest.getPath(), true, 0, maxDelay); - - assertInstanceOf(ZipCompressAction.class, action, "Expected ZipCompressAction"); - - long start = System.currentTimeMillis(); - action.execute(); - long elapsed = System.currentTimeMillis() - start; - - assertTrue( - elapsed <= (maxDelay * 1000L) + 500, - "ZIP compress via FileExtension exceeded maxDelay=" + maxDelay + "s: " + elapsed + "ms"); - assertTrue(dest.exists(), "Compressed .zip file must exist"); - assertFalse(source.exists(), "Source must be deleted after compression"); - } - - /** - * FileExtension.ZIP.createCompressAction(5-args, delay=0) must behave identically - * to the 4-arg version — instant compression, no delay. - */ - @Test - void testZipCreateCompressActionNoDelay(@TempDir File tempDir) throws Exception { - File source = new File(tempDir, "app-nodelay.log"); - File dest = new File(tempDir, "app-nodelay.log.zip"); - writeContent(source, "zip no-delay content"); - - Action action = FileExtension.ZIP.createCompressAction(source.getPath(), dest.getPath(), true, 0, 0); - - assertInstanceOf(ZipCompressAction.class, action); - - long start = System.currentTimeMillis(); - action.execute(); - long elapsed = System.currentTimeMillis() - start; - - assertTrue(elapsed < 500, "ZIP with delay=0 should be instant, took " + elapsed + "ms"); - assertTrue(dest.exists(), "Compressed .zip file must exist"); - assertFalse(source.exists(), "Source must be deleted"); - } - - // ── helpers ─────────────────────────────────────────────────────────── - - private static void writeContent(final File file, final String content) throws IOException { - try (FileWriter writer = new FileWriter(file)) { - writer.write(content); - } - } -} diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderRandomDelayTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderRandomDelayTest.java new file mode 100644 index 0000000000..9fd691d261 --- /dev/null +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderRandomDelayTest.java @@ -0,0 +1,235 @@ +/* + * 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.appender.rolling; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertNotNull; +import static org.junit.jupiter.api.Assertions.assertTrue; + +import java.io.ByteArrayOutputStream; +import java.io.File; +import java.io.IOException; +import java.nio.ByteBuffer; +import java.util.Arrays; +import java.util.concurrent.CountDownLatch; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicInteger; +import org.apache.logging.log4j.core.appender.RollingFileAppender; +import org.apache.logging.log4j.core.appender.RollingRandomAccessFileAppender; +import org.apache.logging.log4j.core.appender.rolling.action.AbstractAction; +import org.apache.logging.log4j.core.appender.rolling.action.Action; +import org.apache.logging.log4j.core.appender.rolling.action.CompositeAction; +import org.apache.logging.log4j.core.config.Configuration; +import org.apache.logging.log4j.core.config.NullConfiguration; +import org.apache.logging.log4j.core.layout.PatternLayout; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.io.TempDir; + +class RollingAppenderRandomDelayTest { + + @Test + void testRollingFileAppenderPassesMaxRandomDelayToManager(@TempDir File tempDir) { + final Configuration configuration = new NullConfiguration(); + final int maxRandomDelay = 17; + final RollingFileAppender appender = RollingFileAppender.newBuilder() + .setName("RollingFileAppender") + .setFileName(new File(tempDir, "app.log").getAbsolutePath()) + .setFilePattern(new File(tempDir, "app-%i.log.gz").getAbsolutePath()) + .setPolicy(NoOpTriggeringPolicy.INSTANCE) + .setConfiguration(configuration) + .setMaxRandomDelay(maxRandomDelay) + .build(); + assertNotNull(appender); + try { + assertEquals(maxRandomDelay, appender.getManager().getMaxRandomDelay()); + } finally { + appender.stop(); + } + } + + @Test + void testRollingRandomAccessFileAppenderPassesMaxRandomDelayToManager(@TempDir File tempDir) { + final Configuration configuration = new NullConfiguration(); + final int maxRandomDelay = 19; + final RollingRandomAccessFileAppender appender = RollingRandomAccessFileAppender.newBuilder() + .setName("RollingRandomAccessFileAppender") + .setFileName(new File(tempDir, "app-ra.log").getAbsolutePath()) + .setFilePattern(new File(tempDir, "app-ra-%i.log.gz").getAbsolutePath()) + .setPolicy(NoOpTriggeringPolicy.INSTANCE) + .setConfiguration(configuration) + .setMaxRandomDelay(maxRandomDelay) + .build(); + assertNotNull(appender); + try { + assertEquals(maxRandomDelay, appender.getManager().getMaxRandomDelay()); + } finally { + appender.stop(); + } + } + + @Test + void testRollingFileManagerSchedulesAsyncActionAfterDelayAndKeepsActionsSequential(@TempDir File tempDir) + throws Exception { + final long delayMillis = 150; + final CountDownLatch completed = new CountDownLatch(2); + final AtomicInteger executionOrder = new AtomicInteger(); + final RecordingAction firstAction = new RecordingAction(executionOrder, completed); + final RecordingAction secondAction = new RecordingAction(executionOrder, completed); + final Action asyncAction = new CompositeAction(Arrays.asList(firstAction, secondAction), true); + final RolloverStrategy strategy = + manager -> new RolloverDescriptionImpl(manager.getFileName(), false, null, asyncAction); + final File file = new File(tempDir, "scheduled.log"); + + try (TestRollingFileManager manager = new TestRollingFileManager(file, strategy, delayMillis)) { + final long rolloverStartNanos = System.nanoTime(); + manager.rollover(); + + assertTrue(completed.await(3, TimeUnit.SECONDS), "Async rollover actions did not complete"); + final long actualDelayMillis = TimeUnit.NANOSECONDS.toMillis(firstAction.startNanos - rolloverStartNanos); + assertTrue( + actualDelayMillis >= delayMillis - 10, + "Async rollover action started before the configured scheduling delay"); + assertEquals(1, firstAction.order); + assertEquals(2, secondAction.order); + assertTrue(secondAction.startNanos >= firstAction.endNanos, "Composite actions must execute sequentially"); + } + } + + @Test + void testRollingFileManagerUsesNoAsyncActionDelayByDefault(@TempDir File tempDir) { + final RolloverStrategy strategy = + manager -> new RolloverDescriptionImpl(manager.getFileName(), false, null, null); + final File file = new File(tempDir, "immediate.log"); + + try (TestRollingFileManager manager = new TestRollingFileManager(file, strategy)) { + assertEquals(0, manager.getMaxRandomDelay()); + assertEquals(0, manager.getAsyncActionDelayMillis()); + } + } + + @Test + void testRollingFileManagerRandomAsyncActionDelayDoesNotRequireCompression(@TempDir File tempDir) { + final int maxRandomDelay = 2; + final long maxDelayMillis = TimeUnit.SECONDS.toMillis(maxRandomDelay); + final RolloverStrategy strategy = + manager -> new RolloverDescriptionImpl(manager.getFileName(), false, null, null); + final File file = new File(tempDir, "no-compression-pattern.log"); + + try (TestRollingFileManager manager = new TestRollingFileManager(file, strategy)) { + manager.setMaxRandomDelay(maxRandomDelay); + boolean nonZeroDelayObserved = false; + for (int index = 0; index < 100; index++) { + final long delayMillis = manager.getAsyncActionDelayMillis(); + assertTrue(delayMillis >= 0, "Async rollover delay must not be negative"); + assertTrue(delayMillis <= maxDelayMillis, "Async rollover delay exceeded configured maximum"); + nonZeroDelayObserved |= delayMillis > 0; + } + assertTrue(nonZeroDelayObserved, "Configured async rollover delay should not require compression"); + } + } + + @Test + void testRollingFileManagerRandomAsyncActionDelayFallsWithinConfiguredRangeForCompression(@TempDir File tempDir) { + final int maxRandomDelay = 2; + final long maxDelayMillis = TimeUnit.SECONDS.toMillis(maxRandomDelay); + final RolloverStrategy strategy = + manager -> new RolloverDescriptionImpl(manager.getFileName(), false, null, null); + final File file = new File(tempDir, "random-compression-pattern.log"); + + try (TestRollingFileManager manager = + new TestRollingFileManager(file, file.getAbsolutePath() + ".%i.gz", strategy)) { + manager.setMaxRandomDelay(maxRandomDelay); + for (int index = 0; index < 100; index++) { + final long delayMillis = manager.getAsyncActionDelayMillis(); + assertTrue(delayMillis >= 0, "Async rollover delay must not be negative"); + assertTrue(delayMillis <= maxDelayMillis, "Async rollover delay exceeded configured maximum"); + } + } + } + + private static final class TestRollingFileManager extends RollingFileManager { + + private final long asyncActionDelayMillis; + + private TestRollingFileManager(final File file, final RolloverStrategy strategy) { + this(file, file.getAbsolutePath() + ".%i", strategy, -1); + } + + private TestRollingFileManager( + final File file, final RolloverStrategy strategy, final long asyncActionDelayMillis) { + this(file, file.getAbsolutePath() + ".%i", strategy, asyncActionDelayMillis); + } + + private TestRollingFileManager(final File file, final String pattern, final RolloverStrategy strategy) { + this(file, pattern, strategy, -1); + } + + private TestRollingFileManager( + final File file, + final String pattern, + final RolloverStrategy strategy, + final long asyncActionDelayMillis) { + super( + null, + file.getAbsolutePath(), + pattern, + new ByteArrayOutputStream(), + true, + false, + 0, + System.currentTimeMillis(), + NoOpTriggeringPolicy.INSTANCE, + strategy, + null, + PatternLayout.createDefaultLayout(), + null, + null, + null, + false, + ByteBuffer.allocate(256)); + this.asyncActionDelayMillis = asyncActionDelayMillis; + } + + @Override + long getAsyncActionDelayMillis() { + return asyncActionDelayMillis >= 0 ? asyncActionDelayMillis : super.getAsyncActionDelayMillis(); + } + } + + private static final class RecordingAction extends AbstractAction { + + private final AtomicInteger executionOrder; + private final CountDownLatch completed; + private volatile int order; + private volatile long startNanos; + private volatile long endNanos; + + private RecordingAction(final AtomicInteger executionOrder, final CountDownLatch completed) { + this.executionOrder = executionOrder; + this.completed = completed; + } + + @Override + public boolean execute() throws IOException { + startNanos = System.nanoTime(); + order = executionOrder.incrementAndGet(); + endNanos = System.nanoTime(); + completed.countDown(); + return true; + } + } +} diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/action/GzCompressActionTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/action/GzCompressActionTest.java index 14d72c56dd..1ac77c4bbd 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/action/GzCompressActionTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/action/GzCompressActionTest.java @@ -34,7 +34,7 @@ class GzCompressActionTest { File source = new File(tempDir, "invalid-low.log"); File dest = new File(tempDir, "invalid-low.log.gz"); - assertThrows(IllegalArgumentException.class, () -> new GzCompressAction(source, dest, true, -2, 0)); + assertThrows(IllegalArgumentException.class, () -> new GzCompressAction(source, dest, true, -2)); } @Test @@ -42,7 +42,7 @@ class GzCompressActionTest { File source = new File(tempDir, "invalid-high.log"); File dest = new File(tempDir, "invalid-high.log.gz"); - assertThrows(IllegalArgumentException.class, () -> new GzCompressAction(source, dest, true, 10, 0)); + assertThrows(IllegalArgumentException.class, () -> new GzCompressAction(source, dest, true, 10)); } @Test @@ -50,71 +50,39 @@ class GzCompressActionTest { File source = new File(tempDir, "valid.log"); File dest = new File(tempDir, "valid.log.gz"); - new GzCompressAction(source, dest, true, Deflater.DEFAULT_COMPRESSION, 0); - new GzCompressAction(source, dest, true, Deflater.BEST_COMPRESSION, 0); + new GzCompressAction(source, dest, true, Deflater.DEFAULT_COMPRESSION); + new GzCompressAction(source, dest, true, Deflater.BEST_COMPRESSION); } - /** Issue #4012 — when maxDelaySeconds > 0, compression must be deferred by a random 0..max seconds. */ @Test - void testRandomDelayBeforeCompression(@TempDir File tempDir) throws IOException { + void testCompression(@TempDir File tempDir) throws IOException { File source = new File(tempDir, "test.log"); File dest = new File(tempDir, "test.log.gz"); - try (FileWriter writer = new FileWriter(source)) { - writer.write("test data"); - } - int maxDelay = 2; // seconds - GzCompressAction action = new GzCompressAction(source, dest, true, 0, maxDelay); - long start = System.currentTimeMillis(); - action.execute(); - long elapsed = System.currentTimeMillis() - start; - - // Must complete within maxDelay + small margin - assertTrue( - elapsed <= (maxDelay * 1000L) + 500, - "Compression should not exceed maxDelay=" + maxDelay + "s, but took " + elapsed + "ms"); - // Destination must be created - assertTrue(dest.exists(), "Compressed file must exist after execute()"); - // Source must be deleted (deleteSource=true) - assertFalse(source.exists(), "Source file must be deleted after compression"); - } + writeContent(source, "test data"); - /** - * Issue #4012 — when maxDelaySeconds=0, no delay is applied (backward compatibility). - * Compression must complete well under 500ms. - */ - @Test - void testNoDelayWhenMaxDelayIsZero(@TempDir File tempDir) throws IOException { - File source = new File(tempDir, "test-nodelay.log"); - File dest = new File(tempDir, "test-nodelay.log.gz"); - try (FileWriter writer = new FileWriter(source)) { - writer.write("test data no delay"); - } - GzCompressAction action = new GzCompressAction(source, dest, true, 0, 0); - long start = System.currentTimeMillis(); - action.execute(); - long elapsed = System.currentTimeMillis() - start; + GzCompressAction action = new GzCompressAction(source, dest, true, Deflater.DEFAULT_COMPRESSION); - // No delay: must complete in well under 500ms - assertTrue(elapsed < 500, "Compression with maxDelay=0 should be instant, but took " + elapsed + "ms"); + assertTrue(action.execute()); assertTrue(dest.exists(), "Compressed file must exist after execute()"); assertFalse(source.exists(), "Source file must be deleted after compression"); } - /** Legacy 4-arg constructor must still work with no delay (backward compatibility). */ @Test - void testLegacyConstructorNoDelay(@TempDir File tempDir) throws IOException { + void testLegacyConstructor(@TempDir File tempDir) throws IOException { File source = new File(tempDir, "test-legacy.log"); File dest = new File(tempDir, "test-legacy.log.gz"); - try (FileWriter writer = new FileWriter(source)) { - writer.write("legacy test data"); - } - GzCompressAction action = new GzCompressAction(source, dest, true, 0); - long start = System.currentTimeMillis(); - action.execute(); - long elapsed = System.currentTimeMillis() - start; + writeContent(source, "legacy test data"); + + GzCompressAction action = new GzCompressAction(source, dest, true); - assertTrue(elapsed < 500, "Legacy constructor should have no delay, but took " + elapsed + "ms"); + assertTrue(action.execute()); assertTrue(dest.exists(), "Compressed file must exist"); assertFalse(source.exists(), "Source file must be deleted"); } + + private static void writeContent(final File file, final String content) throws IOException { + try (FileWriter writer = new FileWriter(file)) { + writer.write(content); + } + } } diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/action/ZipCompressActionTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/action/ZipCompressActionTest.java index b8bc76ce53..16b8e71f4b 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/action/ZipCompressActionTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/action/ZipCompressActionTest.java @@ -23,6 +23,7 @@ import static org.junit.jupiter.api.Assertions.assertTrue; import java.io.File; import java.io.FileWriter; import java.io.IOException; +import java.util.zip.Deflater; import org.junit.jupiter.api.Test; import org.junit.jupiter.api.io.TempDir; @@ -33,7 +34,7 @@ class ZipCompressActionTest { File source = new File(tempDir, "invalid-low.log"); File dest = new File(tempDir, "invalid-low.log.zip"); - assertThrows(IllegalArgumentException.class, () -> new ZipCompressAction(source, dest, true, -2, 0)); + assertThrows(IllegalArgumentException.class, () -> new ZipCompressAction(source, dest, true, -2)); } @Test @@ -41,7 +42,7 @@ class ZipCompressActionTest { File source = new File(tempDir, "invalid-high.log"); File dest = new File(tempDir, "invalid-high.log.zip"); - assertThrows(IllegalArgumentException.class, () -> new ZipCompressAction(source, dest, true, 10, 0)); + assertThrows(IllegalArgumentException.class, () -> new ZipCompressAction(source, dest, true, 10)); } @Test @@ -49,72 +50,27 @@ class ZipCompressActionTest { File source = new File(tempDir, "valid.log"); File dest = new File(tempDir, "valid.log.zip"); - new ZipCompressAction(source, dest, true, -1, 0); - new ZipCompressAction(source, dest, true, 0, 0); - new ZipCompressAction(source, dest, true, 9, 0); + new ZipCompressAction(source, dest, true, Deflater.DEFAULT_COMPRESSION); + new ZipCompressAction(source, dest, true, Deflater.NO_COMPRESSION); + new ZipCompressAction(source, dest, true, Deflater.BEST_COMPRESSION); } - /** Issue #4012 — when maxDelaySeconds > 0, compression must be deferred by a random 0..max seconds. */ @Test - void testRandomDelayBeforeCompression(@TempDir File tempDir) throws IOException { + void testCompression(@TempDir File tempDir) throws IOException { File source = new File(tempDir, "test.log"); File dest = new File(tempDir, "test.log.zip"); - try (FileWriter writer = new FileWriter(source)) { - writer.write("test data"); - } - int maxDelay = 2; // seconds - ZipCompressAction action = new ZipCompressAction(source, dest, true, 0, maxDelay); - long start = System.currentTimeMillis(); - action.execute(); - long elapsed = System.currentTimeMillis() - start; + writeContent(source, "test data"); - // Must complete within maxDelay + small margin - assertTrue( - elapsed <= (maxDelay * 1000L) + 500, - "Compression should not exceed maxDelay=" + maxDelay + "s, but took " + elapsed + "ms"); - // Destination must be created - assertTrue(dest.exists(), "Compressed file must exist after execute()"); - // Source must be deleted (deleteSource=true) - assertFalse(source.exists(), "Source file must be deleted after compression"); - } + ZipCompressAction action = new ZipCompressAction(source, dest, true, Deflater.DEFAULT_COMPRESSION); - /** - * Issue #4012 — when maxDelaySeconds=0, no delay is applied (backward compatibility). - * Compression must complete well under 500ms. - */ - @Test - void testNoDelayWhenMaxDelayIsZero(@TempDir File tempDir) throws IOException { - File source = new File(tempDir, "test-nodelay.log"); - File dest = new File(tempDir, "test-nodelay.log.zip"); - try (FileWriter writer = new FileWriter(source)) { - writer.write("test data no delay"); - } - ZipCompressAction action = new ZipCompressAction(source, dest, true, 0, 0); - long start = System.currentTimeMillis(); - action.execute(); - long elapsed = System.currentTimeMillis() - start; - - // No delay: must complete in well under 500ms - assertTrue(elapsed < 500, "Compression with maxDelay=0 should be instant, but took " + elapsed + "ms"); + assertTrue(action.execute()); assertTrue(dest.exists(), "Compressed file must exist after execute()"); assertFalse(source.exists(), "Source file must be deleted after compression"); } - /** Legacy 4-arg constructor must still work with no delay (backward compatibility). */ - @Test - void testLegacyConstructorNoDelay(@TempDir File tempDir) throws IOException { - File source = new File(tempDir, "test-legacy.log"); - File dest = new File(tempDir, "test-legacy.log.zip"); - try (FileWriter writer = new FileWriter(source)) { - writer.write("legacy test data"); + private static void writeContent(final File file, final String content) throws IOException { + try (FileWriter writer = new FileWriter(file)) { + writer.write(content); } - ZipCompressAction action = new ZipCompressAction(source, dest, true, 0); - long start = System.currentTimeMillis(); - action.execute(); - long elapsed = System.currentTimeMillis() - start; - - assertTrue(elapsed < 500, "Legacy constructor should have no delay, but took " + elapsed + "ms"); - assertTrue(dest.exists(), "Compressed file must exist"); - assertFalse(source.exists(), "Source file must be deleted"); } } diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/RollingFileAppender.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/RollingFileAppender.java index a78be3e4c5..4323661a3d 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/RollingFileAppender.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/RollingFileAppender.java @@ -103,6 +103,9 @@ public final class RollingFileAppender extends AbstractOutputStreamAppender<Roll @PluginBuilderAttribute private String fileGroup; + @PluginBuilderAttribute + private int maxRandomDelay; + @Override public RollingFileAppender build() { if (!isValid()) { @@ -151,11 +154,11 @@ public final class RollingFileAppender extends AbstractOutputStreamAppender<Roll advertiseUri, layout, bufferSize, - isImmediateFlush(), createOnDemand, filePermissions, fileOwner, fileGroup, + maxRandomDelay, getConfiguration()); if (manager == null) { return null; @@ -212,6 +215,10 @@ public final class RollingFileAppender extends AbstractOutputStreamAppender<Roll return fileGroup; } + public int getMaxRandomDelay() { + return maxRandomDelay; + } + /** * @since 2.26.0 */ @@ -374,6 +381,14 @@ public final class RollingFileAppender extends AbstractOutputStreamAppender<Roll return asBuilder(); } + /** + * @since 2.27.0 + */ + public B setMaxRandomDelay(final int maxRandomDelay) { + this.maxRandomDelay = maxRandomDelay; + return asBuilder(); + } + /** * @deprecated since 2.26.0 use {@link #setFilePattern(String)}. */ diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/RollingRandomAccessFileAppender.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/RollingRandomAccessFileAppender.java index 5e7361f68f..e08deea992 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/RollingRandomAccessFileAppender.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/RollingRandomAccessFileAppender.java @@ -93,6 +93,9 @@ public final class RollingRandomAccessFileAppender @PluginBuilderAttribute private String fileGroup; + @PluginBuilderAttribute + private int maxRandomDelay; + @Override public RollingRandomAccessFileAppender build() { final String name = getName(); @@ -147,6 +150,7 @@ public final class RollingRandomAccessFileAppender filePermissions, fileOwner, fileGroup, + maxRandomDelay, getConfiguration()); if (manager == null) { return null; @@ -248,6 +252,14 @@ public final class RollingRandomAccessFileAppender return asBuilder(); } + /** + * @since 2.27.0 + */ + public B setMaxRandomDelay(final int maxRandomDelay) { + this.maxRandomDelay = maxRandomDelay; + return asBuilder(); + } + /** * @deprecated since 2.26.0 use {@link #setFileName(String)}. */ diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/package-info.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/package-info.java index a18b7715e4..5f5331549c 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/package-info.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/package-info.java @@ -18,7 +18,7 @@ * Log4j 2 Appenders. */ @Export -@Version("2.26.0") +@Version("2.27.0") package org.apache.logging.log4j.core.appender; import org.osgi.annotation.bundle.Export; diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/DefaultRolloverStrategy.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/DefaultRolloverStrategy.java index 74fbbf8359..06eefa84ce 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/DefaultRolloverStrategy.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/DefaultRolloverStrategy.java @@ -109,9 +109,6 @@ public class DefaultRolloverStrategy extends AbstractRolloverStrategy { @PluginBuilderAttribute(value = "tempCompressedFilePattern") private String tempCompressedFilePattern; - @PluginBuilderAttribute("maxCompressionDelaySeconds") - private int maxCompressionDelaySeconds = 0; - @PluginConfiguration private Configuration config; @@ -159,8 +156,7 @@ public class DefaultRolloverStrategy extends AbstractRolloverStrategy { nonNullStrSubstitutor, customActions, stopCustomActionsOnError, - tempCompressedFilePattern, - maxCompressionDelaySeconds); + tempCompressedFilePattern); } public String getMax() { @@ -363,18 +359,6 @@ public class DefaultRolloverStrategy extends AbstractRolloverStrategy { this.config = config; return this; } - - /** - * Defines maximum delay in seconds before compression. - * - * @param maxCompressionDelaySeconds maximum delay in seconds before compression. - * @return This builder for chaining convenience - * @since 2.27.0 - */ - public Builder setMaxCompressionDelaySeconds(final int maxCompressionDelaySeconds) { - this.maxCompressionDelaySeconds = maxCompressionDelaySeconds; - return this; - } } @PluginBuilderFactory @@ -438,7 +422,6 @@ public class DefaultRolloverStrategy extends AbstractRolloverStrategy { private final List<Action> customActions; private final boolean stopCustomActionsOnError; private final PatternProcessor tempCompressedFilePattern; - private final int maxCompressionDelaySeconds; /** * Constructs a new instance. @@ -466,8 +449,7 @@ public class DefaultRolloverStrategy extends AbstractRolloverStrategy { strSubstitutor, customActions, stopCustomActionsOnError, - null, - 0); + null); } /** @@ -489,40 +471,6 @@ public class DefaultRolloverStrategy extends AbstractRolloverStrategy { final Action[] customActions, final boolean stopCustomActionsOnError, final String tempCompressedFilePatternString) { - this( - minIndex, - maxIndex, - useMax, - compressionLevel, - strSubstitutor, - customActions, - stopCustomActionsOnError, - tempCompressedFilePatternString, - 0); - } - - /** - * Constructs a new instance. - * - * @param minIndex The minimum index. - * @param maxIndex The maximum index. - * @param customActions custom actions to perform asynchronously after rollover - * @param stopCustomActionsOnError whether to stop executing asynchronous actions if an error occurs - * @param tempCompressedFilePatternString File pattern of the working file - * used during compression, if null no temporary file are used - * @param maxCompressionDelaySeconds maximum delay in seconds before compression. - * @since 2.27.0 - */ - protected DefaultRolloverStrategy( - final int minIndex, - final int maxIndex, - final boolean useMax, - final int compressionLevel, - final StrSubstitutor strSubstitutor, - final Action[] customActions, - final boolean stopCustomActionsOnError, - final String tempCompressedFilePatternString, - final int maxCompressionDelaySeconds) { super(strSubstitutor); this.minIndex = minIndex; this.maxIndex = maxIndex; @@ -532,7 +480,6 @@ public class DefaultRolloverStrategy extends AbstractRolloverStrategy { this.customActions = customActions == null ? Collections.<Action>emptyList() : Arrays.asList(customActions); this.tempCompressedFilePattern = tempCompressedFilePatternString != null ? new PatternProcessor(tempCompressedFilePatternString) : null; - this.maxCompressionDelaySeconds = maxCompressionDelaySeconds; } public int getCompressionLevel() { @@ -563,16 +510,6 @@ public class DefaultRolloverStrategy extends AbstractRolloverStrategy { return tempCompressedFilePattern; } - /** - * Returns the maximum delay in seconds before compression. - * - * @return maximum delay in seconds before compression. - * @since 2.27.0 - */ - public int getMaxCompressionDelaySeconds() { - return maxCompressionDelaySeconds; - } - private int purge(final int lowIndex, final int highIndex, final RollingFileManager manager) { return useMax ? purgeAscending(lowIndex, highIndex, manager) : purgeDescending(lowIndex, highIndex, manager); } @@ -746,17 +683,11 @@ public class DefaultRolloverStrategy extends AbstractRolloverStrategy { } compressAction = new CompositeAction( Arrays.asList( - fileExtension.createCompressAction( - renameTo, - tmpCompressedName, - true, - compressionLevel, - maxCompressionDelaySeconds), + fileExtension.createCompressAction(renameTo, tmpCompressedName, true, compressionLevel), new FileRenameAction(tmpCompressedNameFile, renameToFile, true)), true); } else { - compressAction = fileExtension.createCompressAction( - renameTo, compressedName, true, compressionLevel, maxCompressionDelaySeconds); + compressAction = fileExtension.createCompressAction(renameTo, compressedName, true, compressionLevel); } } diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/FileExtension.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/FileExtension.java index eb453628e8..e62419b685 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/FileExtension.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/FileExtension.java @@ -35,22 +35,7 @@ public enum FileExtension { final String compressedName, final boolean deleteSource, final int compressionLevel) { - return createCompressAction(renameTo, compressedName, deleteSource, compressionLevel, 0); - } - - @Override - public Action createCompressAction( - final String renameTo, - final String compressedName, - final boolean deleteSource, - final int compressionLevel, - final int maxCompressionDelaySeconds) { - return new ZipCompressAction( - new File(renameTo), - new File(compressedName), - deleteSource, - compressionLevel, - maxCompressionDelaySeconds); + return new ZipCompressAction(source(renameTo), target(compressedName), deleteSource, compressionLevel); } }, GZ(".gz") { @@ -60,22 +45,7 @@ public enum FileExtension { final String compressedName, final boolean deleteSource, final int compressionLevel) { - return createCompressAction(renameTo, compressedName, deleteSource, compressionLevel, 0); - } - - @Override - public Action createCompressAction( - final String renameTo, - final String compressedName, - final boolean deleteSource, - final int compressionLevel, - final int maxCompressionDelaySeconds) { - return new GzCompressAction( - new File(renameTo), - new File(compressedName), - deleteSource, - compressionLevel, - maxCompressionDelaySeconds); + return new GzCompressAction(source(renameTo), target(compressedName), deleteSource, compressionLevel); } }, BZIP2(".bz2") { @@ -85,19 +55,8 @@ public enum FileExtension { final String compressedName, final boolean deleteSource, final int compressionLevel) { - return createCompressAction(renameTo, compressedName, deleteSource, compressionLevel, 0); - } - - @Override - public Action createCompressAction( - final String renameTo, - final String compressedName, - final boolean deleteSource, - final int compressionLevel, - final int maxCompressionDelaySeconds) { // One of "gz", "bzip2", "xz", "zst", "pack200", or "deflate". - return new CommonsCompressAction( - "bzip2", source(renameTo), target(compressedName), deleteSource, maxCompressionDelaySeconds); + return new CommonsCompressAction("bzip2", source(renameTo), target(compressedName), deleteSource); } }, DEFLATE(".deflate") { @@ -107,19 +66,8 @@ public enum FileExtension { final String compressedName, final boolean deleteSource, final int compressionLevel) { - return createCompressAction(renameTo, compressedName, deleteSource, compressionLevel, 0); - } - - @Override - public Action createCompressAction( - final String renameTo, - final String compressedName, - final boolean deleteSource, - final int compressionLevel, - final int maxCompressionDelaySeconds) { // One of "gz", "bzip2", "xz", "zst", "pack200", or "deflate". - return new CommonsCompressAction( - "deflate", source(renameTo), target(compressedName), deleteSource, maxCompressionDelaySeconds); + return new CommonsCompressAction("deflate", source(renameTo), target(compressedName), deleteSource); } }, PACK200(".pack200") { @@ -129,19 +77,8 @@ public enum FileExtension { final String compressedName, final boolean deleteSource, final int compressionLevel) { - return createCompressAction(renameTo, compressedName, deleteSource, compressionLevel, 0); - } - - @Override - public Action createCompressAction( - final String renameTo, - final String compressedName, - final boolean deleteSource, - final int compressionLevel, - final int maxCompressionDelaySeconds) { - // One of "gz", "bzip2", "xz", "zstd", "pack200", or "deflate". - return new CommonsCompressAction( - "pack200", source(renameTo), target(compressedName), deleteSource, maxCompressionDelaySeconds); + // One of "gz", "bzip2", "xz", "zst", "pack200", or "deflate". + return new CommonsCompressAction("pack200", source(renameTo), target(compressedName), deleteSource); } }, XZ(".xz") { @@ -151,19 +88,8 @@ public enum FileExtension { final String compressedName, final boolean deleteSource, final int compressionLevel) { - return createCompressAction(renameTo, compressedName, deleteSource, compressionLevel, 0); - } - - @Override - public Action createCompressAction( - final String renameTo, - final String compressedName, - final boolean deleteSource, - final int compressionLevel, - final int maxCompressionDelaySeconds) { // One of "gz", "bzip2", "xz", "zstd", "pack200", or "deflate". - return new CommonsCompressAction( - "xz", source(renameTo), target(compressedName), deleteSource, maxCompressionDelaySeconds); + return new CommonsCompressAction("xz", source(renameTo), target(compressedName), deleteSource); } }, ZSTD(".zst") { @@ -173,19 +99,8 @@ public enum FileExtension { final String compressedName, final boolean deleteSource, final int compressionLevel) { - return createCompressAction(renameTo, compressedName, deleteSource, compressionLevel, 0); - } - - @Override - public Action createCompressAction( - final String renameTo, - final String compressedName, - final boolean deleteSource, - final int compressionLevel, - final int maxCompressionDelaySeconds) { // One of "gz", "bzip2", "xz", "zstd", "pack200", or "deflate". - return new CommonsCompressAction( - "zstd", source(renameTo), target(compressedName), deleteSource, maxCompressionDelaySeconds); + return new CommonsCompressAction("zstd", source(renameTo), target(compressedName), deleteSource); } }; @@ -217,13 +132,6 @@ public enum FileExtension { public abstract Action createCompressAction( String renameTo, String compressedName, boolean deleteSource, int compressionLevel); - public abstract Action createCompressAction( - String renameTo, - String compressedName, - boolean deleteSource, - int compressionLevel, - int maxCompressionDelaySeconds); - public String getExtension() { return extension; } diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/RollingFileManager.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/RollingFileManager.java index 0c62bfac96..75b7df81cf 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/RollingFileManager.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/RollingFileManager.java @@ -26,13 +26,12 @@ import java.nio.file.Files; import java.nio.file.Path; import java.nio.file.attribute.BasicFileAttributes; import java.nio.file.attribute.FileTime; -import java.util.Collection; import java.util.Date; -import java.util.concurrent.ArrayBlockingQueue; import java.util.concurrent.CopyOnWriteArrayList; -import java.util.concurrent.ExecutorService; +import java.util.concurrent.ScheduledExecutorService; +import java.util.concurrent.ScheduledThreadPoolExecutor; import java.util.concurrent.Semaphore; -import java.util.concurrent.ThreadPoolExecutor; +import java.util.concurrent.ThreadLocalRandom; import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicReferenceFieldUpdater; import org.apache.logging.log4j.core.Layout; @@ -70,12 +69,12 @@ public class RollingFileManager extends FileManager { private volatile boolean initialized; private volatile String fileName; private final boolean directWrite; + private volatile int maxRandomDelay; private final CopyOnWriteArrayList<RolloverListener> rolloverListeners = new CopyOnWriteArrayList<>(); - /* This executor pool will create a new Thread for every work async action to be performed. Using it allows - us to make sure all the Threads are completed when the Manager is stopped. */ - private final ExecutorService asyncExecutor = - new ThreadPoolExecutor(0, Integer.MAX_VALUE, 0, TimeUnit.MILLISECONDS, new EmptyQueue(), threadFactory); + /* This executor service schedules asynchronous rollover actions and ensures they are completed when the manager + is stopped. */ + private final ScheduledExecutorService asyncExecutor = new ScheduledThreadPoolExecutor(1, threadFactory); private static final AtomicReferenceFieldUpdater<RollingFileManager, TriggeringPolicy> triggeringPolicyUpdater = AtomicReferenceFieldUpdater.newUpdater( @@ -294,6 +293,60 @@ public class RollingFileManager extends FileManager { final String fileOwner, final String fileGroup, final Configuration configuration) { + return getFileManager( + fileName, + pattern, + append, + bufferedIO, + policy, + strategy, + advertiseURI, + layout, + bufferSize, + createOnDemand, + filePermissions, + fileOwner, + fileGroup, + 0, + configuration); + } + + /** + * Returns a RollingFileManager. + * @param fileName The file name. + * @param pattern The pattern for rolling file. + * @param append true if the file should be appended to. + * @param bufferedIO true if data should be buffered. + * @param policy The TriggeringPolicy. + * @param strategy The RolloverStrategy. + * @param advertiseURI the URI to use when advertising the file + * @param layout The Layout. + * @param bufferSize buffer size to use if bufferedIO is true + * @param createOnDemand true if you want to lazy-create the file (a.k.a. on-demand.) + * @param filePermissions File permissions + * @param fileOwner File owner + * @param fileGroup File group + * @param maxRandomDelay maximum random delay in seconds before executing the asynchronous rollover action chain + * @param configuration The configuration. + * @return A RollingFileManager. + * @since 2.27.0 + */ + public static RollingFileManager getFileManager( + final String fileName, + final String pattern, + final boolean append, + final boolean bufferedIO, + final TriggeringPolicy policy, + final RolloverStrategy strategy, + final String advertiseURI, + final Layout<? extends Serializable> layout, + final int bufferSize, + final boolean createOnDemand, + final String filePermissions, + final String fileOwner, + final String fileGroup, + final int maxRandomDelay, + final Configuration configuration) { if (strategy instanceof DirectWriteRolloverStrategy && fileName != null) { LOGGER.error("The fileName attribute must not be specified with the DirectWriteRolloverStrategy"); return null; @@ -351,6 +404,7 @@ public class RollingFileManager extends FileManager { fileGroup, writeHeader, buffer); + rm.setMaxRandomDelay(data.getMaxRandomDelay()); if (os != null && rm.isAttributeViewEnabled()) { rm.defineAttributeView(file.toPath()); } @@ -361,7 +415,7 @@ public class RollingFileManager extends FileManager { } return null; }, - new FactoryData(pattern, policy, strategy, configuration))); + new FactoryData(pattern, policy, strategy, maxRandomDelay, configuration))); } /** @@ -426,6 +480,26 @@ public class RollingFileManager extends FileManager { return renameEmptyFiles; } + /** + * Returns the maximum random delay in seconds before the asynchronous rollover action chain is executed. + * + * @return the maximum random delay in seconds. + * @since 2.27.0 + */ + public int getMaxRandomDelay() { + return maxRandomDelay; + } + + /** + * Sets the maximum random delay in seconds before the asynchronous rollover action chain is executed. + * + * @param maxRandomDelay the maximum random delay in seconds. + * @since 2.27.0 + */ + public void setMaxRandomDelay(final int maxRandomDelay) { + this.maxRandomDelay = Math.max(0, maxRandomDelay); + } + public void setRenameEmptyFiles(final boolean renameEmptyFiles) { this.renameEmptyFiles = renameEmptyFiles; } @@ -670,8 +744,13 @@ public class RollingFileManager extends FileManager { } if (syncActionSuccess && descriptor.getAsynchronous() != null) { - LOGGER.debug("RollingFileManager executing async {}", descriptor.getAsynchronous()); - asyncExecutor.execute(new AsyncAction(descriptor.getAsynchronous(), this)); + final long delayMillis = getAsyncActionDelayMillis(); + LOGGER.debug( + "RollingFileManager executing async {} with delay {} ms", + descriptor.getAsynchronous(), + delayMillis); + asyncExecutor.schedule( + new AsyncAction(descriptor.getAsynchronous(), this), delayMillis, TimeUnit.MILLISECONDS); asyncActionStarted = false; } } @@ -683,6 +762,13 @@ public class RollingFileManager extends FileManager { } } + long getAsyncActionDelayMillis() { + final int maxRandomDelayCopy = maxRandomDelay; + return maxRandomDelayCopy > 0 + ? ThreadLocalRandom.current().nextLong(TimeUnit.SECONDS.toMillis(maxRandomDelayCopy) + 1) + : 0; + } + /** * Performs actions asynchronously. */ @@ -762,6 +848,7 @@ public class RollingFileManager extends FileManager { private final String pattern; private final TriggeringPolicy policy; private final RolloverStrategy strategy; + private final int maxRandomDelay; /** * Creates the data for the factory. @@ -773,10 +860,20 @@ public class RollingFileManager extends FileManager { final TriggeringPolicy policy, final RolloverStrategy strategy, final Configuration configuration) { + this(pattern, policy, strategy, 0, configuration); + } + + public FactoryData( + final String pattern, + final TriggeringPolicy policy, + final RolloverStrategy strategy, + final int maxRandomDelay, + final Configuration configuration) { super(configuration); this.pattern = pattern; this.policy = policy; this.strategy = strategy; + this.maxRandomDelay = maxRandomDelay; } public TriggeringPolicy getTriggeringPolicy() { @@ -790,6 +887,10 @@ public class RollingFileManager extends FileManager { public String getPattern() { return pattern; } + + public int getMaxRandomDelay() { + return maxRandomDelay; + } } /** @@ -804,6 +905,7 @@ public class RollingFileManager extends FileManager { setRolloverStrategy(factoryData.getRolloverStrategy()); setPatternProcessor(new PatternProcessor(factoryData.getPattern(), getPatternProcessor())); setTriggeringPolicy(factoryData.getTriggeringPolicy()); + setMaxRandomDelay(factoryData.getMaxRandomDelay()); } static long initialFileTime(final File file) { @@ -833,47 +935,4 @@ public class RollingFileManager extends FileManager { static long alignMillisToSecond(long millis) { return Math.round(millis / 1000d) * 1000; } - - private static class EmptyQueue extends ArrayBlockingQueue<Runnable> { - - /** - * - */ - private static final long serialVersionUID = 1L; - - EmptyQueue() { - super(1); - } - - @Override - public int remainingCapacity() { - return 0; - } - - @Override - public boolean add(final Runnable runnable) { - throw new IllegalStateException("Queue is full"); - } - - @Override - public void put(final Runnable runnable) throws InterruptedException { - /* No point in going into a permanent wait */ - throw new InterruptedException("Unable to insert into queue"); - } - - @Override - public boolean offer(final Runnable runnable, final long timeout, final TimeUnit timeUnit) - throws InterruptedException { - Thread.sleep(timeUnit.toMillis(timeout)); - return false; - } - - @Override - public boolean addAll(final Collection<? extends Runnable> collection) { - if (collection.size() > 0) { - throw new IllegalArgumentException("Too many items in collection"); - } - return false; - } - } } diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/RollingRandomAccessFileManager.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/RollingRandomAccessFileManager.java index abb50f587f..66c54d2641 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/RollingRandomAccessFileManager.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/RollingRandomAccessFileManager.java @@ -160,6 +160,41 @@ public class RollingRandomAccessFileManager extends RollingFileManager { final String fileOwner, final String fileGroup, final Configuration configuration) { + return getRollingRandomAccessFileManager( + fileName, + filePattern, + append, + immediateFlush, + bufferSize, + policy, + strategy, + advertiseURI, + layout, + filePermissions, + fileOwner, + fileGroup, + 0, + configuration); + } + + /** + * @since 2.27.0 + */ + public static RollingRandomAccessFileManager getRollingRandomAccessFileManager( + final String fileName, + final String filePattern, + final boolean append, + final boolean immediateFlush, + final int bufferSize, + final TriggeringPolicy policy, + final RolloverStrategy strategy, + final String advertiseURI, + final Layout<? extends Serializable> layout, + final String filePermissions, + final String fileOwner, + final String fileGroup, + final int maxRandomDelay, + final Configuration configuration) { if (strategy instanceof DirectWriteRolloverStrategy && fileName != null) { LOGGER.error("The fileName attribute must not be specified with the DirectWriteRolloverStrategy"); return null; @@ -230,12 +265,13 @@ public class RollingRandomAccessFileManager extends RollingFileManager { fileOwner, fileGroup, writeHeader); + rrm.setMaxRandomDelay(data.getMaxRandomDelay()); if (rrm.isAttributeViewEnabled()) { rrm.defineAttributeView(file.toPath()); } return rrm; }, - new FactoryData(filePattern, policy, strategy, configuration))); + new FactoryData(filePattern, policy, strategy, maxRandomDelay, configuration))); } /** diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/AbstractAction.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/AbstractAction.java index 14258eec3f..2ca052835a 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/AbstractAction.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/AbstractAction.java @@ -82,25 +82,6 @@ public abstract class AbstractAction implements Action { interrupted = true; } - /** - * Blocks the current thread for a random delay up to {@code maxDelaySeconds}. - * - * @param maxDelaySeconds maximum delay in seconds before returning. - * @since 2.27.0 - */ - static void blockThread(final int maxDelaySeconds) { - if (maxDelaySeconds > 0) { - int delay = java.util.concurrent.ThreadLocalRandom.current().nextInt(maxDelaySeconds + 1); - if (delay > 0) { - try { - Thread.sleep(delay * 1000L); - } catch (InterruptedException e) { - Thread.currentThread().interrupt(); - } - } - } - } - /** * Tests if the action is complete. * diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/CommonsCompressAction.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/CommonsCompressAction.java index c01b2cb992..1688969578 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/CommonsCompressAction.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/CommonsCompressAction.java @@ -54,11 +54,6 @@ public final class CommonsCompressAction extends AbstractAction { */ private final boolean deleteSource; - /** - * Maximum delay in seconds before compression. - */ - private final int maxDelaySeconds; - /** * Creates new instance of Bzip2CompressAction. * @@ -70,33 +65,12 @@ public final class CommonsCompressAction extends AbstractAction { */ public CommonsCompressAction( final String name, final File source, final File destination, final boolean deleteSource) { - this(name, source, destination, deleteSource, 0); - } - - /** - * Creates new instance of Bzip2CompressAction. - * - * @param name the compressor name. One of "gz", "bzip2", "xz", "zst", "pack200", or "deflate". - * @param source file to compress, may not be null. - * @param destination compressed file, may not be null. - * @param deleteSource if true, attempt to delete file on completion. Failure to delete does not cause an exception - * to be thrown or affect return value. - * @param maxDelaySeconds maximum delay in seconds before compression. - * @since 2.27.0 - */ - public CommonsCompressAction( - final String name, - final File source, - final File destination, - final boolean deleteSource, - final int maxDelaySeconds) { Objects.requireNonNull(source, "source"); Objects.requireNonNull(destination, "destination"); this.name = name; this.source = source; this.destination = destination; this.deleteSource = deleteSource; - this.maxDelaySeconds = maxDelaySeconds; } /** @@ -107,7 +81,6 @@ public final class CommonsCompressAction extends AbstractAction { */ @Override public boolean execute() throws IOException { - blockThread(maxDelaySeconds); return execute(name, source, destination, deleteSource); } diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/GzCompressAction.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/GzCompressAction.java index 5747c638cd..4166f7b12e 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/GzCompressAction.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/GzCompressAction.java @@ -55,11 +55,6 @@ public final class GzCompressAction extends AbstractAction { */ private final int compressionLevel; - /** - * Maximum delay in seconds before compression. - */ - private final int maxDelaySeconds; - private static int checkCompressionLevel(final int compressionLevel) { final int minCompressionLevel = Deflater.DEFAULT_COMPRESSION; final int maxCompressionLevel = Deflater.BEST_COMPRESSION; @@ -76,24 +71,14 @@ public final class GzCompressAction extends AbstractAction { } /** - * Create new instance of GzCompressAction. - * - * @param source file to compress, may not be null. - * @param destination compressed file, may not be null. - * @param deleteSource if true, attempt to delete file on completion. Failure to delete - * does not cause an exception to be thrown or affect return value. - * @param compressionLevel - * Gzip deflater compression level. - * @since 2.27.0 - * @param maxDelaySeconds - * Maximum delay in seconds before compression. + * Creates a new instance. + * @param source file to compress, may not be null. + * @param destination compressed file, may not be null. + * @param deleteSource if true, attempt to delete file on completion. + * @param compressionLevel Gzip deflater compression level. */ public GzCompressAction( - final File source, - final File destination, - final boolean deleteSource, - final int compressionLevel, - final int maxDelaySeconds) { + final File source, final File destination, final boolean deleteSource, final int compressionLevel) { Objects.requireNonNull(source, "source"); Objects.requireNonNull(destination, "destination"); @@ -101,29 +86,16 @@ public final class GzCompressAction extends AbstractAction { this.destination = destination; this.deleteSource = deleteSource; this.compressionLevel = checkCompressionLevel(compressionLevel); - this.maxDelaySeconds = maxDelaySeconds; - } - - /** - * Creates a new instance. - * @param source file to compress, may not be null. - * @param destination compressed file, may not be null. - * @param deleteSource if true, attempt to delete file on completion. - * @param compressionLevel Gzip deflater compression level. - */ - public GzCompressAction( - final File source, final File destination, final boolean deleteSource, final int compressionLevel) { - this(source, destination, deleteSource, compressionLevel, 0); } /** * Prefer the constructor with compression level. * - * @deprecated Prefer {@link GzCompressAction#GzCompressAction(File, File, boolean, int, int)}. + * @deprecated Prefer {@link GzCompressAction#GzCompressAction(File, File, boolean, int)}. */ @Deprecated public GzCompressAction(final File source, final File destination, final boolean deleteSource) { - this(source, destination, deleteSource, Deflater.DEFAULT_COMPRESSION, 0); + this(source, destination, deleteSource, Deflater.DEFAULT_COMPRESSION); } /** @@ -134,7 +106,6 @@ public final class GzCompressAction extends AbstractAction { */ @Override public boolean execute() throws IOException { - blockThread(maxDelaySeconds); return execute(source, destination, deleteSource, compressionLevel); } diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/ZipCompressAction.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/ZipCompressAction.java index d8e7c39738..f3bd48e2ce 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/ZipCompressAction.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/ZipCompressAction.java @@ -51,11 +51,6 @@ public final class ZipCompressAction extends AbstractAction { */ private final int level; - /** - * Maximum delay in seconds before compression. - */ - private final int maxDelaySeconds; - /** * Validates that the compression level is in the valid range [-1, 9]. * @@ -71,22 +66,15 @@ public final class ZipCompressAction extends AbstractAction { } /** - * Creates new instance of GzCompressAction. + * Creates new instance. * * @param source file to compress, may not be null. * @param destination compressed file, may not be null. * @param deleteSource if true, attempt to delete file on completion. Failure to delete does not cause an exception * to be thrown or affect return value. * @param level the compression level - * @param maxDelaySeconds maximum delay in seconds before compression. - * @since 2.27.0 */ - public ZipCompressAction( - final File source, - final File destination, - final boolean deleteSource, - final int level, - final int maxDelaySeconds) { + public ZipCompressAction(final File source, final File destination, final boolean deleteSource, final int level) { Objects.requireNonNull(source, "source"); Objects.requireNonNull(destination, "destination"); @@ -94,20 +82,6 @@ public final class ZipCompressAction extends AbstractAction { this.destination = destination; this.deleteSource = deleteSource; this.level = checkLevel(level); - this.maxDelaySeconds = maxDelaySeconds; - } - - /** - * Creates new instance. - * - * @param source file to compress, may not be null. - * @param destination compressed file, may not be null. - * @param deleteSource if true, attempt to delete file on completion. Failure to delete does not cause an exception - * to be thrown or affect return value. - * @param level the compression level - */ - public ZipCompressAction(final File source, final File destination, final boolean deleteSource, final int level) { - this(source, destination, deleteSource, level, 0); } /** @@ -118,7 +92,6 @@ public final class ZipCompressAction extends AbstractAction { */ @Override public boolean execute() throws IOException { - blockThread(maxDelaySeconds); return execute(source, destination, deleteSource, level); } diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/package-info.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/package-info.java index 85222541ad..3737053030 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/package-info.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/package-info.java @@ -18,7 +18,7 @@ * Support classes for the Rolling File Appender. */ @Export -@Version("2.27.0") +@Version("2.26.0") package org.apache.logging.log4j.core.appender.rolling.action; import org.osgi.annotation.bundle.Export; diff --git a/src/changelog/.2.x.x/4012_add_max_compression_delay.xml b/src/changelog/.2.x.x/4012_add_max_random_delay.xml similarity index 74% rename from src/changelog/.2.x.x/4012_add_max_compression_delay.xml rename to src/changelog/.2.x.x/4012_add_max_random_delay.xml index 39cc883a15..128a8472e1 100644 --- a/src/changelog/.2.x.x/4012_add_max_compression_delay.xml +++ b/src/changelog/.2.x.x/4012_add_max_random_delay.xml @@ -8,7 +8,7 @@ <issue id="4012" link="https://github.com/apache/logging-log4j2/issues/4012"/> <issue id="4071" link="https://github.com/apache/logging-log4j2/pull/4071"/> <description format="asciidoc"> - Added support for `maxCompressionDelaySeconds` in compression actions to proactively defer compression and reduce disk I/O pressure during rollover. + Added support for `maxRandomDelay` on rolling appenders to start the asynchronous rollover action chain with a random delay and reduce disk I/O pressure during compression. </description> </entry> diff --git a/src/site/antora/modules/ROOT/pages/manual/appenders/rolling-file.adoc b/src/site/antora/modules/ROOT/pages/manual/appenders/rolling-file.adoc index 8dd9c91c0c..deb0ff99a0 100644 --- a/src/site/antora/modules/ROOT/pages/manual/appenders/rolling-file.adoc +++ b/src/site/antora/modules/ROOT/pages/manual/appenders/rolling-file.adoc @@ -280,6 +280,14 @@ If `true`, Log4j will lock the log file at **each** log event. Note that the effects of this setting depend on the Operating System: some systems like most POSIX OSes do not offer mandatory locking, but only advisory file locking. This setting can also reduce the performance of the appender. + +| [[RollingFileAppender-attr-maxRandomDelay]]maxRandomDelay +| `int` +| `0` +a| +Maximum random delay, in seconds, before the asynchronous rollover action chain starts. +This can spread compression workload if many applications roll over at the same time. +A value of `0` starts asynchronous actions immediately. |=== xref:plugin-reference.adoc#org-apache-logging-log4j_log4j-core_org-apache-logging-log4j-core-appender-RollingFileAppender[{plugin-reference-marker} Plugin reference for `RollingFile`] @@ -304,6 +312,14 @@ If `true`, the appender starts writing at the end of the file. This setting does not give the same atomicity guarantees as for the <<RollingFileAppender-attr-append,`RollingFile` Appender>>. The log file cannot be opened by multiple applications at the same time. + +| [[RollingRandomAccessFile-attr-maxRandomDelay]]maxRandomDelay +| `int` +| `0` +a| +Maximum random delay, in seconds, before the asynchronous rollover action chain starts. +This can spread compression workload if many applications roll over at the same time. +A value of `0` starts asynchronous actions immediately. |=== xref:plugin-reference.adoc#org-apache-logging-log4j_log4j-core_org-apache-logging-log4j-core-appender-RollingRandomAccessFileAppender[{plugin-reference-marker} Plugin reference for `RollingRandomAccessFile`] @@ -714,14 +730,6 @@ Maximum value for the <<conversion-pattern-integer,`%i`>> conversion pattern. This attribute is **ignored** if <<DefaultRolloverStrategy-attr-fileIndex,`fileIndex`>> is set to `nomax`. -| [[DefaultRolloverStrategy-attr-maxCompressionDelaySeconds]]maxCompressionDelaySeconds -| `int` -| `0` -| -Maximum random delay, in seconds, before compressing archived log files. - -Use this attribute to spread compression workload when many applications roll over at the same time. -A value of `0` disables the delay and starts compression immediately. |=== xref:plugin-reference.adoc#org-apache-logging-log4j_log4j-core_org-apache-logging-log4j-core-appender-rolling-DefaultRolloverStrategy[{plugin-reference-marker} Plugin reference for `DefaultRolloverStrategy`]
