Fix startup delay and direct write file naming in CronTriggeringPolicy

[tupelo-schneck]

Two defects in CronTriggeringPolicy, both hit by an appender configured without a fileName. Originally split across this PR and #4227; consolidated here at @ramanathan1504's request, and #4227 is closed in favour of this one.

Reproduced with:

<RollingFile name="errorLogAppender" filePattern="${LOG_DIR}/error.log-%d{yyyyMMdd}">
    <PatternLayout pattern="%m%n"/>
    <CronTriggeringPolicy schedule="0 0 0 ? * SUN" evaluateOnStartup="true"/>
</RollingFile>

---

1. Roughly three seconds of startup delay per appender

initialize() looks up the previous fire time relative to RollingFileManager#getFileTime():

final Date lastRollForFile = cronExpression.getPrevFireTime(new Date(this.manager.getFileTime()));

That value is 0 when there is no current file yet (file == null || !file.exists() ? 0 : initialFileTime(file)), which is the case on every startup of an appender that writes directly to the file its pattern resolves to. The lookup therefore runs against the epoch.

CronExpression.getTimeBefore() walks backwards one findMinIncrement() step at a time, calling getTimeAfter() until the result precedes the target. getTimeAfter() clamps its result to 1970, because an expression without a year field gets a year set starting there. For a target at the epoch the exit condition can therefore never be satisfied: every iteration returns the same 1970 fire time, which is neither null, nor before MIN_DATE, nor before the target. The search grinds back through several millennia of candidate dates until the calendar's era flips and getTimeAfter() bails out at its YEAR > 2999 guard, returning null.

A stack sample, taken once a second, with the main thread pinned at 100% CPU throughout:

"main" #3 prio=5 os_prio=31 cpu=749.54ms elapsed=103.85s runnable
	at org.apache.logging.log4j.core.util.CronExpression.getTimeAfter(CronExpression.java:1201)
	at org.apache.logging.log4j.core.util.CronExpression.getTimeBefore(CronExpression.java:1584)
	at org.apache.logging.log4j.core.util.CronExpression.getPrevFireTime(CronExpression.java:1594)
	at org.apache.logging.log4j.core.appender.rolling.CronTriggeringPolicy.initialize(CronTriggeringPolicy.java:67)
	at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.initialize(RollingFileManager.java:246)
	...
	at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:311)

Note that evaluateOnStartup="false" does not avoid the cost: the lookup runs unconditionally and only its result is guarded by that flag.

Fix. Bound the backward search at the epoch, and skip the lookup when there is no current file. Both paths already returned null here, so behaviour is unchanged and only the cost differs.

getPrevFireTime(new Date(0)) for 0 0 0 ? * SUN:

	duration
before	2854–3040 ms
after	0.03–0.06 ms

The two-appender configuration above goes from ~6.0 s to ~0.2 s.

The bound is the epoch rather than MIN_DATE, per @ramanathan1504's review. MIN_CAL.set(1970, 0, 1) leaves the time fields alone, so MIN_DATE carries the JVM's start time of day — two JVMs seconds apart print 09:40:09 and 09:40:17. Bounding the candidate on it would make results depend on when the process started, and would lose real fire times just after the epoch: for 0 0 0 * * ? at 1970-01-02 06:00, 2.x returns 1970-01-02 00:00 where a MIN_DATE bound returns null. A bound on the local 1970 instant in the expression's own zone was also tried, since getTime() < 0 is a UTC-instant test while getTimeAfter() floors at local 1970; it gave identical results across America/New_York, UTC and Australia/Sydney, so the simpler form is used.

2. The direct write file is named after process start, not the rollover period

The file an appender writes to covers a whole rollover period, but it was named after the moment the appender started. Starting on Tuesday 2026-07-28 under the weekly schedule above writes to error.log-20260728, though the period began on Sunday 2026-07-26, so a restart on Wednesday opens error.log-20260729 instead of continuing the same file. A week with daily restarts leaves seven files where the schedule implies one, and rollover only ever closes out whichever fragment is current.

initialize() records the period start correctly:

final Date lastRegularRoll = cronExpression.getPrevFireTime(new Date());
aManager.getPatternProcessor().setCurrentFileTime(lastRegularRoll.getTime());

DirectWriteRolloverStrategy.getCurrentFileName() then discarded it:

// LOG4J2-3339 - Always use the current time for new direct write files.
manager.getPatternProcessor().setCurrentFileTime(System.currentTimeMillis());

That override compensated for a different problem: rollover() passed lastRollDate, the previous period's start, as the new file's time, so each replacement file was named after the file just rolled. Substituting the current time hid that, and works only because at the instant of a rollover "now" is approximately the new period's start. At startup "now" is an arbitrary point inside the period, which is where it breaks.

Fix. Pass the roll time rather than the previous roll date, so the replacement file is named after the period it opens, and let getCurrentFileName() use the period start already recorded.

Blast radius is limited to policies that track a period. PatternProcessor.formatFileName() already falls back to the current time when the current file time is 0, and updateTime() resets it to 0, so TimeBasedTriggeringPolicy, which never sets it, is unchanged. Appenders configured with a fileName are unaffected, since getCurrentFileName() is only consulted on the direct write path.

Compatibility. This changes the names of direct write files for cron based appenders, from the process start time to the start of the rollover period — error.log-20260726 rather than error.log-20260728 above. Existing files are untouched, neither read nor renamed; a restart after upgrading simply begins writing to the period's file. The changelog entry calls this out.

RollingAppenderDirectCronTest, the regression test added with LOG4J2-3339, still passes: it asserts that a rolled file's name matches the timestamp of its first line, which this change preserves.

---

Testing

Four tests, each confirmed to fail without its corresponding fix and pass with it:

• CronExpressionTest#testPrevFireTimeAtEpochReturnsNullPromptly — asserts null within a 1 s timeout, deliberately well below the ~2.9 s the unfixed path takes, since a generous timeout would pass with the defect present.
• CronExpressionTest#testPrevFireTimeJustAfterEpochIsUnaffectedByBound — pins the near-epoch behaviour above, in a fixed zone so it does not depend on the CI host.
• CronTriggeringPolicyTest#testBuilderWithoutFileNameInitializesPromptly — builds an appender without a fileName on a weekly schedule.
• CronTriggeringPolicyTest#testDirectWriteFileNameUsesPeriodStart — asserts the manager's file name matches the period start computed independently from the same expression. Without the fix: expected: <target/testcmd5.log-20260726> but was: <target/testcmd5.log-20260728>.

./mvnw verify passes across all 41 modules.

Checklist

• Based on 2.x
• ./mvnw verify succeeds
• Changelog entries in src/changelog/.2.x.x
• Tests are provided

[ramanathan1504]

@tupelo-schneck Thanks for the contribution. I seen the #4227 that's also relate to this, can You close the follow up Pr and work it out here?

[ramanathan1504]

testBuilderWithoutFileNameInitializesPromptly passes with either fix alone (0.134 s / 0.143 s) and fails only when both are reverted, so nothing pins this guard — is it load-bearing, or documentation like TimeBasedTriggeringPolicy.initialize()'s getFileTime() == 0?

[tupelo-schneck]

Documentation, not load-bearing — your second reading is right, and thank you for checking it rather than assuming.

I confirmed it: with the epoch bound in CronExpression in place and this guard reverted, CronTriggeringPolicyTest and CronExpressionTest pass in 0.18 s. Once the search is bounded, getPrevFireTime(new Date(0)) returns null in microseconds for any expression, so nothing here depends on the guard for speed.

I have kept it, for the reason you name: it mirrors TimeBasedTriggeringPolicy.initialize()'s getFileTime() == 0 check, and it makes lastRollForFile null by construction rather than by a lookup that happens to return null for a meaningless input. Happy to drop it if you would rather keep the diff minimal — no functional difference either way.