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 2018/11/25 21:40:50 UTC

[logging-log4j2] branch release-2.x updated (53b1fc7 -> 795c4d5)

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

rgoers pushed a change to branch release-2.x
in repository https://gitbox.apache.org/repos/asf/logging-log4j2.git.


    from 53b1fc7  LOG4J2-2453 - Add Log4j-slf4j18-impl dependency to bom pom
     new cdff007  LOG4J2-1906 - direct write was creating files with the wrong date/time
     new 795c4d5  LOG4J2-1906 - direct write was creating files with the wrong date/time

The 2 revisions listed above as "new" are entirely new to this
repository and will be described in separate emails.  The revisions
listed as "add" were already present in the repository and have only
been added to this reference.


Summary of changes:
 .../rolling/DirectWriteRolloverStrategy.java       |  4 +-
 .../core/appender/rolling/PatternProcessor.java    |  6 +--
 .../rolling/TimeBasedTriggeringPolicy.java         |  1 +
 .../rolling/OnStartupTriggeringPolicyTest.java     |  2 +-
 ...ava => RollingAppenderDirectWrite1903Test.java} | 50 ++++++++++++++++------
 .../rolling/RollingAppenderDirectWriteTest.java    | 28 +++++++++++-
 .../test/resources/log4j-rolling-direct-1903.xml   | 20 +++++++++
 .../src/test/resources/log4j-rolling-direct.xml    |  2 +-
 src/changes/changes.xml                            |  3 ++
 9 files changed, 95 insertions(+), 21 deletions(-)
 copy log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/{RollingAppenderTimeAndSizeTest.java => RollingAppenderDirectWrite1903Test.java} (65%)
 create mode 100644 log4j-core/src/test/resources/log4j-rolling-direct-1903.xml


[logging-log4j2] 02/02: LOG4J2-1906 - direct write was creating files with the wrong date/time

Posted by rg...@apache.org.
This is an automated email from the ASF dual-hosted git repository.

rgoers pushed a commit to branch release-2.x
in repository https://gitbox.apache.org/repos/asf/logging-log4j2.git

commit 795c4d53551c393ece5d46e0a204b05a8a667f19
Author: Ralph Goers <rg...@apache.org>
AuthorDate: Sun Nov 25 14:40:38 2018 -0700

    LOG4J2-1906 - direct write was creating files with the wrong date/time
---
 src/changes/changes.xml | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/src/changes/changes.xml b/src/changes/changes.xml
index 4f3698c..289f0de 100644
--- a/src/changes/changes.xml
+++ b/src/changes/changes.xml
@@ -31,6 +31,9 @@
          - "remove" - Removed
     -->
     <release version="2.11.2" date="2018-MM-DD" description="GA Release 2.11.2">
+      <action issue="LOG4J2-1906" dev="rgoers" type="fix">
+        Direct write was creating files with the wrong date/time.
+      </action>
       <action issue="LOG4J2-2453" dev="rgoers" type="fix" due-to="theit">
         Add Log4j-slf4j18-impl dependency to bom pom.
       </action>


[logging-log4j2] 01/02: LOG4J2-1906 - direct write was creating files with the wrong date/time

Posted by rg...@apache.org.
This is an automated email from the ASF dual-hosted git repository.

rgoers pushed a commit to branch release-2.x
in repository https://gitbox.apache.org/repos/asf/logging-log4j2.git

commit cdff0075e05e4a62fcf02652fbc923ddb19f8799
Author: Ralph Goers <rg...@apache.org>
AuthorDate: Sun Nov 25 14:38:53 2018 -0700

    LOG4J2-1906 - direct write was creating files with the wrong date/time
---
 .../rolling/DirectWriteRolloverStrategy.java       |  4 ++-
 .../core/appender/rolling/PatternProcessor.java    |  6 ++--
 .../rolling/TimeBasedTriggeringPolicy.java         |  1 +
 .../rolling/OnStartupTriggeringPolicyTest.java     |  2 +-
 ...ava => RollingAppenderDirectWrite1903Test.java} | 39 ++++++++++++++++++----
 .../rolling/RollingAppenderDirectWriteTest.java    | 28 +++++++++++++++-
 .../test/resources/log4j-rolling-direct-1903.xml   | 20 +++++++++++
 .../src/test/resources/log4j-rolling-direct.xml    |  2 +-
 8 files changed, 88 insertions(+), 14 deletions(-)

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 8c6d259..658c67f 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
@@ -236,6 +236,7 @@ public class DirectWriteRolloverStrategy extends AbstractRolloverStrategy implem
     private volatile String currentFileName;
     private int nextIndex = -1;
     private final PatternProcessor tempCompressedFilePattern;
+    private volatile boolean usePrevTime = false;
 
     /**
      * Constructs a new instance.
@@ -315,7 +316,8 @@ public class DirectWriteRolloverStrategy extends AbstractRolloverStrategy implem
             final SortedMap<Integer, Path> eligibleFiles = getEligibleFiles(manager);
             final int fileIndex = eligibleFiles.size() > 0 ? (nextIndex > 0 ? nextIndex : eligibleFiles.size()) : 1;
             final StringBuilder buf = new StringBuilder(255);
-            manager.getPatternProcessor().formatFileName(strSubstitutor, buf, true, fileIndex);
+            manager.getPatternProcessor().formatFileName(strSubstitutor, buf, true, usePrevTime, fileIndex);
+            usePrevTime = true;
             final int suffixLength = suffixLength(buf.toString());
             final String name = suffixLength > 0 ? buf.substring(0, buf.length() - suffixLength) : buf.toString();
             currentFileName = name;
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/PatternProcessor.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/PatternProcessor.java
index b5a5aa3..0d41f00 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/PatternProcessor.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/PatternProcessor.java
@@ -253,7 +253,7 @@ public class PatternProcessor {
      * @param obj object to be evaluated in formatting, may not be null.
      */
     public final void formatFileName(final StrSubstitutor subst, final StringBuilder buf, final Object obj) {
-        formatFileName(subst, buf, false, obj);
+        formatFileName(subst, buf, false, false, obj);
     }
 
     /**
@@ -263,11 +263,11 @@ public class PatternProcessor {
      * @param obj object to be evaluated in formatting, may not be null.
      */
     public final void formatFileName(final StrSubstitutor subst, final StringBuilder buf, final boolean useCurrentTime,
-                                     final Object obj) {
+                                     final boolean usePrevTime, final Object obj) {
         // LOG4J2-628: we deliberately use System time, not the log4j.Clock time
         // for creating the file name of rolled-over files.
         final long time = useCurrentTime && currentFileTime != 0 ? currentFileTime :
-                prevFileTime != 0 ? prevFileTime : System.currentTimeMillis();
+                usePrevTime && prevFileTime != 0 ? prevFileTime : System.currentTimeMillis();
         formatFileName(buf, new Date(time), obj);
         final LogEvent event = new Log4jLogEvent.Builder().setTimeMillis(time).build();
         final String fileName = subst.replace(event, buf);
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/TimeBasedTriggeringPolicy.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/TimeBasedTriggeringPolicy.java
index 3cadd42..3201429 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/TimeBasedTriggeringPolicy.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/TimeBasedTriggeringPolicy.java
@@ -130,6 +130,7 @@ public final class TimeBasedTriggeringPolicy extends AbstractTriggeringPolicy {
         if (nowMillis >= nextRolloverMillis) {
             nextRolloverMillis = ThreadLocalRandom.current().nextLong(0, 1 + maxRandomDelayMillis)
                     + manager.getPatternProcessor().getNextTime(nowMillis, interval, modulate);
+            manager.getPatternProcessor().setCurrentFileTime(System.currentTimeMillis());
             return true;
         }
         return false;
diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/OnStartupTriggeringPolicyTest.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/OnStartupTriggeringPolicyTest.java
index f05e4e2..5b47fd1 100644
--- a/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/OnStartupTriggeringPolicyTest.java
+++ b/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/OnStartupTriggeringPolicyTest.java
@@ -59,7 +59,7 @@ public class OnStartupTriggeringPolicyTest {
         final Configuration configuration = new DefaultConfiguration();
         final Path target = Paths.get(TARGET_FILE);
         target.toFile().getParentFile().mkdirs();
-        final long timeStamp = System.currentTimeMillis() - (1000 * 60 * 60 * 24);
+        final long timeStamp = System.currentTimeMillis();
         final String expectedDate = formatter.format(timeStamp);
         final String rolledFileName = ROLLED_FILE_PREFIX + expectedDate + ROLLED_FILE_SUFFIX;
         final Path rolled = Paths.get(rolledFileName);
diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderDirectWriteTest.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderDirectWrite1903Test.java
similarity index 61%
copy from log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderDirectWriteTest.java
copy to log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderDirectWrite1903Test.java
index b2c3606..4855725 100644
--- a/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderDirectWriteTest.java
+++ b/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderDirectWrite1903Test.java
@@ -16,7 +16,10 @@
  */
 package org.apache.logging.log4j.core.appender.rolling;
 
+import java.io.BufferedReader;
 import java.io.File;
+import java.io.FileInputStream;
+import java.io.FileReader;
 
 import org.apache.logging.log4j.Logger;
 import org.apache.logging.log4j.junit.LoggerContextRule;
@@ -24,20 +27,24 @@ import org.junit.Before;
 import org.junit.Rule;
 import org.junit.Test;
 import org.junit.rules.RuleChain;
+
 import static org.apache.logging.log4j.hamcrest.Descriptors.that;
 import static org.apache.logging.log4j.hamcrest.FileMatchers.hasName;
 import static org.hamcrest.Matchers.endsWith;
 import static org.hamcrest.Matchers.hasItemInArray;
-import static org.junit.Assert.*;
+import static org.junit.Assert.assertNotNull;
+import static org.junit.Assert.assertThat;
+import static org.junit.Assert.assertTrue;
+import static org.junit.Assert.assertEquals;
 
 /**
  *
  */
-public class RollingAppenderDirectWriteTest {
+public class RollingAppenderDirectWrite1903Test {
 
-    private static final String CONFIG = "log4j-rolling-direct.xml";
+    private static final String CONFIG = "log4j-rolling-direct-1903.xml";
 
-    private static final String DIR = "target/rolling-direct";
+    private static final String DIR = "target/rolling-direct-1903";
 
     public static LoggerContextRule loggerContextRule = LoggerContextRule.createShutdownTimeoutLoggerContextRule(CONFIG);
 
@@ -48,19 +55,37 @@ public class RollingAppenderDirectWriteTest {
 
     @Before
     public void setUp() throws Exception {
-        this.logger = loggerContextRule.getLogger(RollingAppenderDirectWriteTest.class.getName());
+        this.logger = loggerContextRule.getLogger(RollingAppenderDirectWrite1903Test.class.getName());
     }
 
     @Test
     public void testAppender() throws Exception {
-        for (int i=0; i < 100; ++i) {
+        int count = 100;
+        for (int i=0; i < count; ++i) {
             logger.debug("This is test message number " + i);
+            Thread.sleep(50);
         }
         Thread.sleep(50);
         final File dir = new File(DIR);
         assertTrue("Directory not created", dir.exists() && dir.listFiles().length > 0);
         final File[] files = dir.listFiles();
         assertNotNull(files);
-        assertThat(files, hasItemInArray(that(hasName(that(endsWith(".gz"))))));
+        assertThat(files, hasItemInArray(that(hasName(that(endsWith(".log"))))));
+        int found = 0;
+        for (File file: files) {
+            String actual = file.getName();
+            BufferedReader reader = new BufferedReader(new FileReader(file));
+            String line;
+            while ((line = reader.readLine()) != null) {
+                assertNotNull("No log event in file " + actual, line);
+                String[] parts = line.split((" "));
+                String expected = "rollingfile." + parts[0] + ".log";
+
+                assertEquals("Incorrect file name. Expected: " + expected + " Actual: " + actual, expected, actual);
+                ++found;
+            }
+        }
+        assertEquals("Incorrect number of events read. Expected " + count + ", Actual " + found, count, found);
+
     }
 }
diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderDirectWriteTest.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderDirectWriteTest.java
index b2c3606..dec87b5 100644
--- a/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderDirectWriteTest.java
+++ b/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderDirectWriteTest.java
@@ -16,7 +16,12 @@
  */
 package org.apache.logging.log4j.core.appender.rolling;
 
+import java.io.BufferedReader;
 import java.io.File;
+import java.io.FileInputStream;
+import java.io.FileReader;
+import java.io.InputStreamReader;
+import java.util.zip.GZIPInputStream;
 
 import org.apache.logging.log4j.Logger;
 import org.apache.logging.log4j.junit.LoggerContextRule;
@@ -53,7 +58,8 @@ public class RollingAppenderDirectWriteTest {
 
     @Test
     public void testAppender() throws Exception {
-        for (int i=0; i < 100; ++i) {
+        int count = 100;
+        for (int i=0; i < count; ++i) {
             logger.debug("This is test message number " + i);
         }
         Thread.sleep(50);
@@ -62,5 +68,25 @@ public class RollingAppenderDirectWriteTest {
         final File[] files = dir.listFiles();
         assertNotNull(files);
         assertThat(files, hasItemInArray(that(hasName(that(endsWith(".gz"))))));
+        int found = 0;
+        for (File file: files) {
+            String actual = file.getName();
+            BufferedReader reader;
+            if (file.getName().endsWith(".gz")) {
+                reader = new BufferedReader(new InputStreamReader(new GZIPInputStream(new FileInputStream(file))));
+            } else {
+                reader = new BufferedReader(new FileReader(file));
+            }
+            String line;
+            while ((line = reader.readLine()) != null) {
+                assertNotNull("No log event in file " + actual, line);
+                String[] parts = line.split((" "));
+                String expected = "test1-" + parts[0];
+                assertTrue("Incorrect file name. Expected file prefix: " + expected + " Actual: " + actual,
+                    actual.startsWith(expected));
+                ++found;
+            }
+        }
+        assertEquals("Incorrect number of events read. Expected " + count + ", Actual " + found, count, found);
     }
 }
diff --git a/log4j-core/src/test/resources/log4j-rolling-direct-1903.xml b/log4j-core/src/test/resources/log4j-rolling-direct-1903.xml
new file mode 100644
index 0000000..4c7494a
--- /dev/null
+++ b/log4j-core/src/test/resources/log4j-rolling-direct-1903.xml
@@ -0,0 +1,20 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<Configuration status="trace" monitorInterval="30">
+  <Properties>
+    <Property name="baseDir">target/rolling-direct-1903</Property>
+  </Properties>
+  <Appenders>
+    <RollingFile name="RollingFile" filePattern="${baseDir}/rollingfile.%d{yyyy-MM-dd-HH-mm-ss}.log">
+      <PatternLayout pattern="%d{yyyy-MM-dd-HH-mm-ss} [%level] [%c] %msg%n" />
+      <Policies>
+        <TimeBasedTriggeringPolicy />
+      </Policies>
+      <DirectWriteRolloverStrategy />
+    </RollingFile>
+  </Appenders>
+  <Loggers>
+    <Root level="trace">
+      <AppenderRef ref="RollingFile" />
+    </Root>
+  </Loggers>
+</Configuration>
\ No newline at end of file
diff --git a/log4j-core/src/test/resources/log4j-rolling-direct.xml b/log4j-core/src/test/resources/log4j-rolling-direct.xml
index a16d86a..c3a7006 100644
--- a/log4j-core/src/test/resources/log4j-rolling-direct.xml
+++ b/log4j-core/src/test/resources/log4j-rolling-direct.xml
@@ -28,7 +28,7 @@
     </Console>
     <RollingFile name="RollingFile" filePattern="${logDir}/test1-%d{MM-dd-yy-HH-mm}-%i.log.gz">
       <PatternLayout>
-        <Pattern>%d %p %C{1.} [%t] %m%n</Pattern>
+        <Pattern>%d{MM-dd-yy-HH-mm} %p %C{1.} [%t] %m%n</Pattern>
       </PatternLayout>
       <Policies>
         <TimeBasedTriggeringPolicy />