[ 
https://issues.apache.org/jira/browse/LOG4J2-2575?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Carter Kozak updated LOG4J2-2575:
---------------------------------
    Fix Version/s:     (was: 2.12.1)
                   2.13.1

> CronExpression.getTimeBefore() returns incorrect result
> -------------------------------------------------------
>
>                 Key: LOG4J2-2575
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-2575
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 2.11.2
>            Reporter: Nathan Friess
>            Assignee: Carter Kozak
>            Priority: Critical
>             Fix For: 2.13.1
>
>         Attachments: cronexpression.patch, cronexpressiontest.patch
>
>
> The method getTimeBefore(targetDate) of 
> org.apache.logging.log4j.core.util.CronExpression incorrectly returns the 
> targetDate argument instead of one time increment before targetDate when 
> running in OpenJDK 1.8.0_191.
> When CronTiggeringPolicy calls this method the targetDate object contains a 
> time with milliseconds, but prevFireTime is always computed with zero 
> milliseconds which causes the comparison at line 1586:
> {code:java}
>   ... while (prevFireTime.compareTo(targetDate) >= 0);{code}
> to be false on the first time through the loop and so targetDate (with zero 
> milliseconds) is returned.
>  
> Configuration example:
> {code:java}
> <RollingFile name="my_log" fileName="/var/log/my.log"
>  filePattern="/var/log/my.log.%d{yyyy-MM-dd}">
> <PatternLayout pattern="[%d{EEE MMM dd HH:mm:ss yyyy}] [%p] %x [%X{user}] 
> %m{nolookups}%n" />
>  <CronTriggeringPolicy schedule="0 0 0 * * ?" evaluateOnStartup="true" />
>  </RollingFile>{code}
>  
> Adding some extra debugging, we can see the behaviour:
>  
> {noformat}
> DEBUG StatusLogger getTimeBefore(targetDate=2019-03-22T00:00:00.002-0600
> DEBUG StatusLogger in loop preFireTime=2019-03-22T00:00:00.000-0600
> DEBUG StatusLogger return 2019-03-22T00:00:00.000-0600{noformat}
> Sometimes the file rolling will run at exactly zero milliseconds and 
> getTimeBefore() will correctly returns the previous day in the above example, 
> masking this issue during those runs.  I marked this issue as critical 
> because in combination with FileRenameAction's procedure of replacing 
> existing files, log files will be lost at seemingly random rolls when this 
> method returns the current date on one run, but then reverts back to the 
> previous date on the next run, causing a filename collision.
> A patch is attached.  This issue may be related to LOG4J2-2246 since that bug 
> mentions issues with milliseconds in Date objects as well, but I have not 
> investigated that part of the file rolling code.
>  
>  
>  



--
This message was sent by Atlassian Jira
(v8.3.4#803005)

Reply via email to