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
The following commit(s) were added to refs/heads/release-2.x by this push:
new e392c79 LOG4J2-1906 Second attempt at a fix
e392c79 is described below
commit e392c79274ab5cd545d59d7e8fa3b744c7367d16
Author: Ralph Goers <rgo...@apache.org>
AuthorDate: Wed Nov 28 06:32:46 2018 -0700
LOG4J2-1906 Second attempt at a fix
---
.../rolling/DirectWriteRolloverStrategy.java | 3 +--
.../rolling/OnStartupTriggeringPolicy.java | 1 +
.../core/appender/rolling/PatternProcessor.java | 6 ++---
.../core/appender/rolling/RollingFileManager.java | 27 +++++++++++++++++++++-
.../rolling/TimeBasedTriggeringPolicy.java | 8 +++++--
.../rolling/OnStartupTriggeringPolicyTest.java | 4 +++-
...ava => RollingAppenderDirectWrite1906Test.java} | 9 ++++----
...rect-1903.xml => log4j-rolling-direct-1906.xml} | 4 ++--
8 files changed, 46 insertions(+), 16 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 658c67f..530b3a9 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
@@ -316,8 +316,7 @@ 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, usePrevTime, fileIndex);
- usePrevTime = true;
+ 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();
currentFileName = name;
diff --git
a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/OnStartupTriggeringPolicy.java
b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/OnStartupTriggeringPolicy.java
index 4c8ae1c..77b673a 100644
---
a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/OnStartupTriggeringPolicy.java
+++
b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/OnStartupTriggeringPolicy.java
@@ -76,6 +76,7 @@ public class OnStartupTriggeringPolicy extends
AbstractTriggeringPolicy {
@Override
public void initialize(final RollingFileManager manager) {
if (manager.getFileTime() < JVM_START_TIME && manager.getFileSize() >=
minSize) {
+ StatusLogger.getLogger().debug("Initiating rollover at startup");
if (minSize == 0) {
manager.setRenameEmptyFiles(true);
}
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 0d41f00..b5a5aa3 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, false, obj);
+ formatFileName(subst, buf, 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 boolean usePrevTime, final Object
obj) {
+ 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 :
- usePrevTime && prevFileTime != 0 ? prevFileTime :
System.currentTimeMillis();
+ 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/RollingFileManager.java
b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/RollingFileManager.java
index 87d2cb5..23ada53 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
@@ -22,6 +22,12 @@ import java.io.IOException;
import java.io.OutputStream;
import java.io.Serializable;
import java.nio.ByteBuffer;
+import java.nio.file.Files;
+import java.nio.file.Path;
+import java.nio.file.attribute.BasicFileAttributes;
+import java.nio.file.attribute.FileTime;
+import java.time.Instant;
+import java.time.ZoneId;
import java.util.Collection;
import java.util.concurrent.ArrayBlockingQueue;
import java.util.concurrent.ExecutorService;
@@ -53,6 +59,7 @@ public class RollingFileManager extends FileManager {
private static RollingFileManagerFactory factory = new
RollingFileManagerFactory();
private static final int MAX_TRIES = 3;
private static final int MIN_DURATION = 100;
+ private static final FileTime EPOCH = FileTime.fromMillis(0);
protected long size;
private long initialTime;
@@ -640,7 +647,7 @@ public class RollingFileManager extends FileManager {
final OutputStream os = data.createOnDemand || data.fileName
== null ? null :
new FileOutputStream(data.fileName, data.append);
final long time = data.createOnDemand || file == null ?
- System.currentTimeMillis() : file.lastModified(); //
LOG4J2-531 create file first so time has valid value
+ 0 : initialFileTime(file); // LOG4J2-531 create file
first so time has valid value
final RollingFileManager rm = new
RollingFileManager(data.getLoggerContext(), data.fileName, data.pattern, os,
data.append, data.createOnDemand, size, time, data.policy,
data.strategy, data.advertiseURI,
@@ -657,6 +664,24 @@ public class RollingFileManager extends FileManager {
}
}
+ private static long initialFileTime(File file) {
+ Path path = file.toPath();
+ if (Files.exists(path)) {
+ try {
+ BasicFileAttributes attrs = Files.readAttributes(path,
BasicFileAttributes.class);
+ FileTime fileTime = attrs.creationTime();
+ if (fileTime.compareTo(EPOCH) > 0) {
+ return fileTime.toMillis();
+ } else {
+ LOGGER.info("Unable to obtain file creation time for " +
file.getAbsolutePath());
+ }
+ } catch (Exception ex) {
+ LOGGER.info("Unable to calculate file creation time for " +
file.getAbsolutePath() + ": " + ex.getMessage());
+ }
+ }
+ return file.lastModified();
+ }
+
private static class EmptyQueue extends ArrayBlockingQueue<Runnable> {
/**
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 3201429..d53b58a 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
@@ -108,12 +108,16 @@ public final class TimeBasedTriggeringPolicy extends
AbstractTriggeringPolicy {
@Override
public void initialize(final RollingFileManager aManager) {
this.manager = aManager;
+ long current = aManager.getFileTime();
+ if (current == 0) {
+ current = System.currentTimeMillis();
+ }
// LOG4J2-531: call getNextTime twice to force initialization of both
prevFileTime and nextFileTime
- aManager.getPatternProcessor().getNextTime(aManager.getFileTime(),
interval, modulate);
+ aManager.getPatternProcessor().getNextTime(current, interval,
modulate);
nextRolloverMillis = ThreadLocalRandom.current().nextLong(0, 1 +
maxRandomDelayMillis)
- +
aManager.getPatternProcessor().getNextTime(aManager.getFileTime(), interval,
modulate);
+ + aManager.getPatternProcessor().getNextTime(current,
interval, modulate);
}
/**
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 7a3c5ca..72ae6f0 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
@@ -56,11 +56,13 @@ public class OnStartupTriggeringPolicyTest {
@Test
public void testPolicy() throws Exception {
+ //System.setProperty("log4j2.debug", "true");
+ //System.setProperty("log4j2.StatusLogger.level", "trace");
final Configuration configuration = new DefaultConfiguration();
final Path target = Paths.get(TARGET_FILE);
Assert.assertFalse(Files.exists(target));
target.toFile().getParentFile().mkdirs();
- final long timeStamp = System.currentTimeMillis();
+ final long timeStamp = System.currentTimeMillis() - (1000 * 60 * 60 *
24);
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/RollingAppenderDirectWrite1903Test.java
b/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderDirectWrite1906Test.java
similarity index 96%
rename from
log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderDirectWrite1903Test.java
rename to
log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderDirectWrite1906Test.java
index 4855725..64ab892 100644
---
a/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderDirectWrite1903Test.java
+++
b/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/rolling/RollingAppenderDirectWrite1906Test.java
@@ -18,7 +18,6 @@ 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;
@@ -40,11 +39,11 @@ import static org.junit.Assert.assertEquals;
/**
*
*/
-public class RollingAppenderDirectWrite1903Test {
+public class RollingAppenderDirectWrite1906Test {
- private static final String CONFIG = "log4j-rolling-direct-1903.xml";
+ private static final String CONFIG = "log4j-rolling-direct-1906.xml";
- private static final String DIR = "target/rolling-direct-1903";
+ private static final String DIR = "target/rolling-direct-1906";
public static LoggerContextRule loggerContextRule =
LoggerContextRule.createShutdownTimeoutLoggerContextRule(CONFIG);
@@ -55,7 +54,7 @@ public class RollingAppenderDirectWrite1903Test {
@Before
public void setUp() throws Exception {
- this.logger =
loggerContextRule.getLogger(RollingAppenderDirectWrite1903Test.class.getName());
+ this.logger =
loggerContextRule.getLogger(RollingAppenderDirectWrite1906Test.class.getName());
}
@Test
diff --git a/log4j-core/src/test/resources/log4j-rolling-direct-1903.xml
b/log4j-core/src/test/resources/log4j-rolling-direct-1906.xml
similarity index 79%
rename from log4j-core/src/test/resources/log4j-rolling-direct-1903.xml
rename to log4j-core/src/test/resources/log4j-rolling-direct-1906.xml
index 4c7494a..326d0ca 100644
--- a/log4j-core/src/test/resources/log4j-rolling-direct-1903.xml
+++ b/log4j-core/src/test/resources/log4j-rolling-direct-1906.xml
@@ -1,7 +1,7 @@
<?xml version="1.0" encoding="UTF-8"?>
-<Configuration status="trace" monitorInterval="30">
+<Configuration status="WARN" monitorInterval="30">
<Properties>
- <Property name="baseDir">target/rolling-direct-1903</Property>
+ <Property name="baseDir">target/rolling-direct-1906</Property>
</Properties>
<Appenders>
<RollingFile name="RollingFile"
filePattern="${baseDir}/rollingfile.%d{yyyy-MM-dd-HH-mm-ss}.log">
