LOG4J2-2677: Rollover and Deletion handle file deletions gracefully
It's common for multiple appenders to write (and roll) log files
into a single directory. When these appenders are also responsible
for cleaning up after themselves, they must also search that
directory for files to delete. These searches are executed in
parallel by multiple appenders and have a chance to delete files
the other is checking before the file can be checked against
a regex or glob.
Missing files can safely be assumed to have been deleted.
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/DeletingVisitor.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/DeletingVisitor.java
index 825e774..78ae1cf 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/DeletingVisitor.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/DeletingVisitor.java
@@ -20,6 +20,7 @@
import java.io.IOException;
import java.nio.file.FileVisitResult;
import java.nio.file.Files;
+import java.nio.file.NoSuchFileException;
import java.nio.file.Path;
import java.nio.file.SimpleFileVisitor;
import java.nio.file.attribute.BasicFileAttributes;
@@ -75,6 +76,18 @@
return FileVisitResult.CONTINUE;
}
+ @Override
+ public FileVisitResult visitFileFailed(Path file, IOException ioException) throws IOException {
+ // LOG4J2-2677: Appenders may rollover and purge in parallel. SimpleVisitor rethrows exceptions from
+ // failed attempts to load file attributes.
+ if (ioException instanceof NoSuchFileException) {
+ LOGGER.info("File {} could not be accessed, it has likely already been deleted", file, ioException);
+ return FileVisitResult.CONTINUE;
+ } else {
+ return super.visitFileFailed(file, ioException);
+ }
+ }
+
/**
* Deletes the specified file.
*
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/SortingVisitor.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/SortingVisitor.java
index 7bf76b6..0b9f1ca 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/SortingVisitor.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/action/SortingVisitor.java
@@ -17,8 +17,12 @@
package org.apache.logging.log4j.core.appender.rolling.action;
+import org.apache.logging.log4j.Logger;
+import org.apache.logging.log4j.status.StatusLogger;
+
import java.io.IOException;
import java.nio.file.FileVisitResult;
+import java.nio.file.NoSuchFileException;
import java.nio.file.Path;
import java.nio.file.SimpleFileVisitor;
import java.nio.file.attribute.BasicFileAttributes;
@@ -32,6 +36,7 @@
*/
public class SortingVisitor extends SimpleFileVisitor<Path> {
+ private static final Logger LOGGER = StatusLogger.getLogger();
private final PathSorter sorter;
private final List<PathWithAttributes> collected = new ArrayList<>();
@@ -50,6 +55,18 @@
collected.add(new PathWithAttributes(path, attrs));
return FileVisitResult.CONTINUE;
}
+
+ @Override
+ public FileVisitResult visitFileFailed(Path file, IOException ioException) throws IOException {
+ // LOG4J2-2677: Appenders may rollover and purge in parallel. SimpleVisitor rethrows exceptions from
+ // failed attempts to load file attributes.
+ if (ioException instanceof NoSuchFileException) {
+ LOGGER.info("File {} could not be accessed, it has likely already been deleted", file, ioException);
+ return FileVisitResult.CONTINUE;
+ } else {
+ return super.visitFileFailed(file, ioException);
+ }
+ }
public List<PathWithAttributes> getSortedPaths() {
Collections.sort(collected, sorter);
diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/action/DeletingVisitorTest.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/action/DeletingVisitorTest.java
index 7258c23..ed472ad 100644
--- a/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/action/DeletingVisitorTest.java
+++ b/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/action/DeletingVisitorTest.java
@@ -18,11 +18,14 @@
package org.apache.logging.log4j.core.appender.rolling.action;
import java.io.IOException;
+import java.nio.file.FileVisitResult;
+import java.nio.file.NoSuchFileException;
import java.nio.file.Path;
import java.nio.file.Paths;
import java.nio.file.attribute.BasicFileAttributes;
import java.util.ArrayList;
import java.util.Arrays;
+import java.util.Collections;
import java.util.List;
import org.junit.Test;
@@ -132,4 +135,26 @@
final Path child = Paths.get("/a/b/c/relative");
visitor.visitFile(child, null);
}
+
+ @Test
+ public void testNoSuchFileFailure() throws IOException {
+ final DeletingVisitorHelper visitor =
+ new DeletingVisitorHelper(Paths.get("/a/b/c"), Collections.emptyList(), true);
+ assertEquals(
+ FileVisitResult.CONTINUE,
+ visitor.visitFileFailed(Paths.get("doesNotExist"), new NoSuchFileException("doesNotExist")));
+ }
+
+ @Test
+ public void testIOException() {
+ final DeletingVisitorHelper visitor =
+ new DeletingVisitorHelper(Paths.get("/a/b/c"), Collections.emptyList(), true);
+ IOException exception = new IOException();
+ try {
+ visitor.visitFileFailed(Paths.get("doesNotExist"), exception);
+ fail();
+ } catch (IOException e) {
+ assertSame(exception, e);
+ }
+ }
}
diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/action/SortingVisitorTest.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/action/SortingVisitorTest.java
index dd32a0c..06ee1ce 100644
--- a/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/action/SortingVisitorTest.java
+++ b/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/action/SortingVisitorTest.java
@@ -17,9 +17,13 @@
package org.apache.logging.log4j.core.appender.rolling.action;
+import java.io.IOException;
import java.nio.file.FileVisitOption;
+import java.nio.file.FileVisitResult;
import java.nio.file.Files;
+import java.nio.file.NoSuchFileException;
import java.nio.file.Path;
+import java.nio.file.Paths;
import java.nio.file.attribute.FileAttribute;
import java.nio.file.attribute.FileTime;
import java.util.Collections;
@@ -91,4 +95,24 @@
assertEquals("2nd; sorted=" + found, bbb, found.get(1).getPath());
assertEquals("3rd: most recent sorted; list=" + found, ccc, found.get(2).getPath());
}
+
+ @Test
+ public void testNoSuchFileFailure() throws IOException {
+ SortingVisitor visitor = new SortingVisitor(new PathSortByModificationTime(false));
+ assertEquals(
+ FileVisitResult.CONTINUE,
+ visitor.visitFileFailed(Paths.get("doesNotExist"), new NoSuchFileException("doesNotExist")));
+ }
+
+ @Test
+ public void testIOException() {
+ SortingVisitor visitor = new SortingVisitor(new PathSortByModificationTime(false));
+ IOException exception = new IOException();
+ try {
+ visitor.visitFileFailed(Paths.get("doesNotExist"), exception);
+ fail();
+ } catch (IOException e) {
+ assertSame(exception, e);
+ }
+ }
}
diff --git a/src/changes/changes.xml b/src/changes/changes.xml
index f4ad3a5..bcb403b 100644
--- a/src/changes/changes.xml
+++ b/src/changes/changes.xml
@@ -169,6 +169,9 @@
<action issue="LOG4J2-2415" dev="ckozak" type="fix" due-to="Andrey Turbanov">
Fix lock contention in the classloader using new versions of slf4j without EventData on slf4j logger creation.
</action>
+ <action issue="LOG4J2-2677" dev="ckozak" type="fix">
+ Rollover handles parallel file deletion gracefully.
+ </action>
</release>
<release version="2.13.0" date="2019-12-11" description="GA Release 2.13.0">
<action issue="LOG4J2-2058" dev="rgoers" type="fix">
