[
https://issues.apache.org/jira/browse/LOG4J2-2610?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Ralph Goers resolved LOG4J2-2610.
---------------------------------
Resolution: Fixed
A fix has been applied to both the release-2.x and master branches. Please
verify and close.
> Windows - File creationTime issue for RollingFileAppender, combined time/size
> policy
> ------------------------------------------------------------------------------------
>
> Key: LOG4J2-2610
> URL: https://issues.apache.org/jira/browse/LOG4J2-2610
> Project: Log4j 2
> Issue Type: Bug
> Components: Core
> Affects Versions: 2.11.2
> Environment: Windows 10, JDK 7u79, Log4J2 2.11.2
> Reporter: James Chaplin
> Priority: Major
> Labels: pull-request-available
> Fix For: 2.12.0
>
> Time Spent: 3h
> Remaining Estimate: 0h
>
> Hello Apache Log4j Team.
> Recently I encountered a boundary-condition issue with RollingFileAppender on
> Windows. Due to the nature of the issue it can be difficult to reproduce
> consistently, but I was able to do so using some files with old creation
> dates.
> It was reproduced with a configuration like this modified from one of the
> unit tests:
> {code:xml}
> <RollingFile name="RollingFile"
> fileName="target/rolling3/rollingtest.log"
> filePattern="target/rolling3/rollingtest_%d\{yyyy-MM-dd}_%i_.log"
> append="true" bufferedIO="true" bufferSize="8192" immediateFlush="true">
> <PatternLayout pattern="%d\{yyyy-MM-dd-HH-mm-ss} [%level] [%c] %msg%n"/>
> <Policies>
> <TimeBasedTriggeringPolicy interval="1" modulate="true" />
> <SizeBasedTriggeringPolicy size="3500KB" />
> </Policies>
> <DefaultRolloverStrategy max="3"/>
> </RollingFile>
> {code}
> where the +current and rollover files both share the same directory+. It is
> easier to see when the date/time of the initial log file "rollingtest.log"
> has a creationTime that is a few days in the past (simulating a gap in
> processing between logs due to downtime).
> When the rolling append rolls the file over into one matching filePattern, it
> creates a +new "rollingtest.log" file+ which has a +creationTIme equal to+
> the +old file's creationTime+ (instead of the current system time).
> For example if the current date is 2019-05-30 and the old file's creationTime
> is sometime in 2019-05-28 (2 days previous), after the rollover the newly
> created "rolingtest.log" will still have a creationTime of 2019-05-28 ...
> even though it was just re-created on 2019-05-30. This creates some strange
> behaviour the next time a rollover is processed by the RollingFileAppender
> (since the current log file appears to be a "2-day-old file" the 2nd rollover
> filename is incorrect).
> Going through some of the Log4j2 code it doesn't appear to be a direct bug in
> Log4j2, but rather due to a Windows behaviour called "File System Tunneling"
> (see blog [https://devblogs.microsoft.com/oldnewthing/20050715-14/?p=34923]
> for some details).
> While trying to figure out what was happening I also noticed that the unit
> test RollingAppenderSizeWithTimeTest.+testAppender()+ was +consistently
> failing+ under Windows too. Since that test involves very rapid rollovers it
> could be related to the "tunneling" behaviour in Windows or could be
> something entirely different.
> I've attempted two mitigation fixes for both issues described in this Jira
> against the code for 2.12.0-SNAPSHOT. A GitHub PR with an initial fix attempt
> and unit test should follow soon.
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
