You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@logging.apache.org by rg...@apache.org on 2022/06/27 05:42:42 UTC

[logging-log4j2] branch master updated: LOG4J2-3339 - DirectWriteRolloverStrategy should use the current time when creating files

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

rgoers 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 6bd41c98af LOG4J2-3339 - DirectWriteRolloverStrategy should use the current time when creating files
6bd41c98af is described below

commit 6bd41c98afc1004bd14531b297dd7a88cdbd4f9d
Author: Ralph Goers <rg...@apache.org>
AuthorDate: Sun Jun 26 22:42:33 2022 -0700

    LOG4J2-3339 - DirectWriteRolloverStrategy should use the current time when creating files
---
 .../rolling/RollingAppenderDirectCronTest.java     | 120 +++++++++++++++++++++
 .../test/resources/log4j-rolling-direct-cron.xml   |  48 +++++++++
 .../rolling/DirectWriteRolloverStrategy.java       |   2 +
 .../core/appender/rolling/RollingFileManager.java  |   1 +
 .../org/apache/logging/log4j/core/util/Source.java |  14 ++-
 src/changes/changes.xml                            |   6 ++
 6 files changed, 190 insertions(+), 1 deletion(-)

diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderDirectCronTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderDirectCronTest.java
new file mode 100644
index 0000000000..e700303f41
--- /dev/null
+++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderDirectCronTest.java
@@ -0,0 +1,120 @@
+/*
+ * 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 java.io.File;
+import java.io.IOException;
+import java.nio.file.Files;
+import java.nio.file.Path;
+import java.util.List;
+import java.util.concurrent.CountDownLatch;
+import java.util.concurrent.TimeUnit;
+import java.util.regex.Pattern;
+
+import org.apache.logging.log4j.Logger;
+import org.apache.logging.log4j.core.appender.RollingFileAppender;
+
+import org.apache.logging.log4j.core.test.junit.LoggerContextRule;
+import org.junit.Rule;
+import org.junit.Test;
+import org.junit.rules.RuleChain;
+
+import static org.junit.Assert.assertTrue;
+import static org.junit.Assert.fail;
+
+/**
+ *
+ */
+public class RollingAppenderDirectCronTest {
+
+    private static final String CONFIG = "log4j-rolling-direct-cron.xml";
+    private static final String DIR = "target/rolling-direct-cron";
+
+    private final LoggerContextRule loggerContextRule = LoggerContextRule.createShutdownTimeoutLoggerContextRule(CONFIG);
+
+    @Rule
+    public RuleChain chain = loggerContextRule.withCleanFoldersRule(DIR);
+
+    private final Pattern filePattern = Pattern.compile(".*(\\d\\d-\\d\\d-\\d\\d-\\d\\d-\\d\\d-\\d\\d).*$");
+
+    @Test
+    public void testAppender() throws Exception {
+        // TODO Is there a better way to test than putting the thread to sleep all over the place?
+        RollingFileAppender app = loggerContextRule.getAppender("RollingFile");
+        final Logger logger = loggerContextRule.getLogger();
+        logger.debug("This is test message number 1");
+        RolloverDelay delay = new RolloverDelay(app.getManager());
+        delay.waitForRollover();
+        final File dir = new File(DIR);
+        File[] files = dir.listFiles();
+        assertTrue("Directory not created", dir.exists() && files != null && files.length > 0);
+        delay.reset(3);
+
+        final int MAX_TRIES = 30;
+        for (int i = 0; i < MAX_TRIES; ++i) {
+            logger.debug("Adding new event {}", i);
+            Thread.sleep(100);
+        }
+        delay.waitForRollover();
+    }
+
+
+
+    private class RolloverDelay implements RolloverListener {
+        private volatile CountDownLatch latch;
+
+        public RolloverDelay(RollingFileManager manager) {
+            latch = new CountDownLatch(1);
+            manager.addRolloverListener(this);
+        }
+
+        public void waitForRollover() {
+            try {
+                if (!latch.await(3, TimeUnit.SECONDS)) {
+                    fail("failed to rollover");
+                }
+            } catch (InterruptedException ex) {
+                fail("failed to rollover");
+            }
+        }
+
+        public void reset(int count) {
+            latch = new CountDownLatch(count);
+        }
+
+        @Override
+        public void rolloverTriggered(String fileName) {
+
+        }
+
+        @Override
+        public void rolloverComplete(String fileName) {
+            java.util.regex.Matcher matcher = filePattern.matcher(fileName);
+            assertTrue("Invalid file name: " + fileName, matcher.matches());
+            Path path = new File(fileName).toPath();
+            try {
+                List<String> lines = Files.readAllLines(path);
+                assertTrue("Not enough lines in " + fileName + ":" + lines.size(), lines.size() > 0);
+                assertTrue("log and file times don't match. file: " + matcher.group(1) + ", log: "
+                        + lines.get(0), lines.get(0).startsWith(matcher.group(1)));
+            } catch (IOException ex) {
+                fail("Unable to read file " + fileName + ": " + ex.getMessage());
+            }
+            latch.countDown();
+        }
+    }
+}
diff --git a/log4j-core-test/src/test/resources/log4j-rolling-direct-cron.xml b/log4j-core-test/src/test/resources/log4j-rolling-direct-cron.xml
new file mode 100644
index 0000000000..85d528ed0d
--- /dev/null
+++ b/log4j-core-test/src/test/resources/log4j-rolling-direct-cron.xml
@@ -0,0 +1,48 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<!--
+ 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.
+
+-->
+<Configuration status="WARN" name="RollingCronTest" monitorInterval="1">
+
+  <Appenders>
+    <Console name="STDOUT">
+      <PatternLayout pattern="%m%n"/>
+    </Console>
+    <RollingFile name="RollingFile" filePattern="target/rolling-direct-cron/test1-%d{MM-dd-yy-HH-mm-ss}.log">
+      <PatternLayout>
+        <Pattern>%d{MM-dd-yy-HH-mm-ss} %p %C{1.} [%t] %m%n</Pattern>
+      </PatternLayout>
+      <CronTriggeringPolicy schedule="* * * * * ?"/>
+    </RollingFile>
+    <List name="List">
+      <Filters>
+        <ThresholdFilter level="error"/>
+      </Filters>
+    </List>
+  </Appenders>
+
+  <Loggers>
+    <Logger name="org.apache.logging.log4j.core.appender.rolling" level="debug" additivity="false">
+      <AppenderRef ref="RollingFile"/>
+    </Logger>
+
+    <Root level="error">
+      <AppenderRef ref="STDOUT"/>
+    </Root>
+  </Loggers>
+
+</Configuration>
\ No newline at end of file
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/DirectWriteRolloverStrategy.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/DirectWriteRolloverStrategy.java
index b77b39ba33..cb8b7cbcff 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/DirectWriteRolloverStrategy.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/DirectWriteRolloverStrategy.java
@@ -270,6 +270,8 @@ public class DirectWriteRolloverStrategy extends AbstractRolloverStrategy implem
             final int fileIndex = eligibleFiles.size() > 0 ? (nextIndex > 0 ? nextIndex :
                     eligibleFiles.lastKey()) : 1;
             final StringBuilder buf = new StringBuilder(255);
+            // LOG4J2-3339 - Always use the current time for new direct write files.
+            manager.getPatternProcessor().setCurrentFileTime(System.currentTimeMillis());
             manager.getPatternProcessor().formatFileName(strSubstitutor, buf, true, fileIndex);
             final int suffixLength = suffixLength(buf.toString());
             final String name = suffixLength > 0 ? buf.substring(0, buf.length() - suffixLength) : buf.toString();
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 5b5dbec7ce..f7d9dcc07b 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
@@ -303,6 +303,7 @@ public class RollingFileManager extends FileManager {
     }
 
 	public synchronized void rollover(final long prevFileTime, final long prevRollTime) {
+        LOGGER.debug("Rollover PrevFileTime: {}, PrevRollTime: {}", prevFileTime, prevRollTime);
 		getPatternProcessor().setPrevFileTime(prevFileTime);
 		getPatternProcessor().setCurrentFileTime(prevRollTime);
 		rollover();
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 f28c8f85e1..e612634a62 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
@@ -27,12 +27,16 @@ import java.nio.file.Path;
 import java.nio.file.Paths;
 import java.util.Objects;
 
+import org.apache.logging.log4j.Logger;
 import org.apache.logging.log4j.core.config.ConfigurationSource;
+import org.apache.logging.log4j.status.StatusLogger;
+import org.apache.logging.log4j.util.Strings;
 
 /**
  * Represents the source for the logging configuration as an immutable object.
  */
 public class Source {
+    private static final Logger LOGGER = StatusLogger.getLogger();
 
     private static String normalize(final File file) {
         try {
@@ -50,10 +54,18 @@ public class Source {
         }
     }
 
+    // LOG4J2-3527 - Don't use Paths.get().
     private static File toFile(final URI uri) {
         try {
-            return toFile(Paths.get(Objects.requireNonNull(uri, "uri")));
+            final String scheme = Objects.requireNonNull(uri, "uri").getScheme();
+            if (Strings.isBlank(scheme) || scheme.equals("file")) {
+                return new File(uri.getPath());
+            } else {
+                LOGGER.debug("uri does not represent a local file: " + uri);
+                return null;
+            }
         } catch (final Exception e) {
+            LOGGER.debug("uri is malformed: " + uri.toString());
             return null;
         }
     }
diff --git a/src/changes/changes.xml b/src/changes/changes.xml
index 6ddbaeb4cb..14647547e4 100644
--- a/src/changes/changes.xml
+++ b/src/changes/changes.xml
@@ -202,6 +202,12 @@
       </action>
     </release>
     <release version="2.18.0" date="20YY-MM-DD" description="GA Release 2.18.0">
+      <action issue="LOG4J2-3339" dev="rgoers" type="fix">
+        DirectWriteRolloverStrategy should use the current time when creating files.
+      </action>
+      <action issue="LOG4J2-3527" dev="rgoers" type="fix">
+        Don't use Paths.get() to avoid circular file systems.
+      </action>
       <action issue="LOG4J2-3490" dev="rgoers" type="fix">
         The DirectWriteRolloverStrategy was not detecting the correct index to use during startup.
       </action>