[LOG4J2-2483] CronTriggeringPolicy fails with $${date} in path

• Type: Bug
• Status: Open
• Priority: Major
• Resolution: Unresolved
• Affects Version/s: 2.11.1
• Component/s: Core
• Flags: Patch
• Assignee: Unassigned
• Reporter: Stephen Dawkins
• Created: 22/Oct/18 16:19
• Updated: 10/May/21 07:10

Description

CronTriggeringPolicy fails when the path of the filePattern contains $${date} in a directory. Eg:

<RollingFile name="file" filePattern="logs/$${date:yyyy-MM-dd-HH-mm}/requests.log.%d{yyyy-MM-dd-HH-mm}">
   <PatternLayout charset="UTF-8"><Pattern>%m%n</Pattern></PatternLayout>
   <CronTriggeringPolicy schedule="0 * * * * ?" />
</RollingFile>

Give this exception when rolling the file:

2018-10-22 16:48:30,615 main DEBUG Now writing to logs/2018-10-22-16-48/requests.log.2018-10-22-16-48 at 2018-10-22T16:48:30.615+0100
2018-10-22 16:48:30,615 DEBUG foo  [main] hello: 2018-10-22 16:48:30
2018-10-22 16:48:40,621 DEBUG foo  [main] hello: 2018-10-22 16:48:40
2018-10-22 16:48:50,621 DEBUG foo  [main] hello: 2018-10-22 16:48:50
2018-10-22 16:49:00,024 Log4j2-TF-2-Scheduled-1 DEBUG Setting prev file time to 2018-10-22T16:48:00.000+0100
2018-10-22 16:49:00,024 Log4j2-TF-2-Scheduled-1 DEBUG Rolling logs/2018-10-22-16-48/requests.log.2018-10-22-16-48
2018-10-22 16:49:00,024 Log4j2-TF-2-Scheduled-1 DEBUG Found 0 eligible files, max is  2147483647
2018-10-22 16:49:00,040 Log4j2-TF-2-Scheduled-1 DEBUG Now writing to logs/2018-10-22-16-49/requests.log.2018-10-22-16-49 at 2018-10-22T16:49:00.040+0100
2018-10-22 16:49:00,040 Log4j2-TF-2-Scheduled-1 ERROR RollingFileManager null Failed to create file after rollover: java.io.FileNotFoundException: logs\2018-10-22-16-49\requests.log.2018-10-22-16-49 (The system cannot find the path specified) java.io.FileNotFoundException: logs\2018-10-22-16-49\requests.log.2018-10-22-16-49 (The system cannot find the path specified)
    at java.io.FileOutputStream.open0(Native Method)
    at java.io.FileOutputStream.open(FileOutputStream.java:270)
    at java.io.FileOutputStream.<init>(FileOutputStream.java:213)
    at java.io.FileOutputStream.<init>(FileOutputStream.java:133)
    at org.apache.logging.log4j.core.appender.FileManager.createOutputStream(FileManager.java:188)
    at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.createFileAfterRollover(RollingFileManager.java:324)
    at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.rollover(RollingFileManager.java:316)
    at org.apache.logging.log4j.core.appender.rolling.CronTriggeringPolicy.rollover(CronTriggeringPolicy.java:151)
    at org.apache.logging.log4j.core.appender.rolling.CronTriggeringPolicy.access$100(CronTriggeringPolicy.java:41)
    at org.apache.logging.log4j.core.appender.rolling.CronTriggeringPolicy$CronTrigger.run(CronTriggeringPolicy.java:174)
    at org.apache.logging.log4j.core.config.ConfigurationScheduler$CronRunnable.run(ConfigurationScheduler.java:239)

This seems to be because CronTriggerPolicy used both prevFileTime and currentFileTime in the PatternProcessor, however the parent directories only get created for the files generated with prevFileTime.

As currentFIleTime is only used by CronTriggerPolicy, the code can be simplified to just used prevFileTime, avoiding this problem. I've attached a patch.