You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@logging.apache.org by ck...@apache.org on 2019/12/23 23:13:12 UTC

[logging-log4j2] branch master updated: LOG4J2-2677: Rollover and Deletion handle file deletions gracefully

This is an automated email from the ASF dual-hosted git repository.

ckozak pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/logging-log4j2.git


The following commit(s) were added to refs/heads/master by this push:
     new 9b77a9f  LOG4J2-2677: Rollover and Deletion handle file deletions gracefully
9b77a9f is described below

commit 9b77a9f8e533daf55b59e0374ae53c0e61ef77e9
Author: Carter Kozak <ck...@apache.org>
AuthorDate: Sun Dec 22 16:54:00 2019 -0500

    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.
---
 .../appender/rolling/action/DeletingVisitor.java   | 13 +++++++++++
 .../appender/rolling/action/SortingVisitor.java    | 17 +++++++++++++++
 .../rolling/action/DeletingVisitorTest.java        | 25 ++++++++++++++++++++++
 .../rolling/action/SortingVisitorTest.java         | 24 +++++++++++++++++++++
 src/changes/changes.xml                            |  3 +++
 5 files changed, 82 insertions(+)

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 @@ package org.apache.logging.log4j.core.appender.rolling.action;
 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 @@ public class DeletingVisitor extends SimpleFileVisitor<Path> {
         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 @@ import java.util.Objects;
  */
 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 @@ public class SortingVisitor extends SimpleFileVisitor<Path> {
         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 @@ public class DeletingVisitorTest {
         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 @@ public class SortingVisitorTest {
         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">