rgoers opened a new pull request, #4406: URL: https://github.com/apache/logging-log4j2/pull/4406
CronExpressionTest intermittently fails because of the time of day the test JVM starts, not because of the machine, the JDK or the timezone data. It only fails when the default timezone is west of UTC and the run starts late enough in the day. Cause: in CronExpression.java:256-263, the lower bound is built like this: MIN_CAL = Calendar.getInstance(); // now, in the default zone MIN_CAL.set(1970, 0, 1); // changes only year/month/day; time of day stays MIN_DATE = MIN_CAL.getTime(); So MIN_DATE ends up as 1970-01-01 at whatever local time the JVM started, not the epoch. getTimeBefore (line 1588) returns null for any previous fire time before MIN_DATE. The test expects 1970-01-02T00:00Z. In America/Phoenix (UTC-7), which this Mac uses, that instant is 1970-01-01 17:00 local. So a run started after 17:00 gets null and the test errors. In Los Angeles the cutoff is 16:00, and in UTC or any zone east of it the test never fails. The test passed on a different computer because of when it ran or which zone it’s set to, not because it’s newer. Evidence from the investigation session: The real test passed when run at 13:33 MST. A simulation that set MIN_DATE to the value it would get at different start times failed in Phoenix from 17:30 on, and never failed in UTC or Berlin. The code and the test assertion were checked by Claude (who created this fix) and they match this explanation. Fix: make the bound the epoch, for example with MIN_CAL.setTimeInMillis(0) or MIN_DATE = new Date(0). That affects real getPrevFireTime calls near 1970 too, not just this test. After the fix that was applied to 2.x was cherry-picked into main it was noticed that several tests would hang. Why it was hanging: CronTriggeringPolicy.initialize calls getPrevFireTime with the file time, which can be 0 (the epoch). In America/Phoenix, the first fire time after the epoch is later than the epoch itself. So getTimeBefore kept stepping backwards past 1970 without ever finding an earlier fire time, and looped forever. The old, buggy MIN_DATE happened to end that loop. Once MIN_DATE became the epoch, nothing on main ended it. 2.x was never affected because it already has the prevCheckDate < 0 guard from #4226. Thread dumps of both spinning test JVMs showed exactly this call in CronTriggeringPolicy.initialize. What changed on main: amended into c6e49514e9, still only on the local main branch and not pushed. CronExpression.getTimeBefore: returns null once the search would go before the epoch, the same guard 2.x has. New test, testPrevFireTimeAtEpochReturnsNullPromptly: pins the zone to America/Phoenix, so it reproduces the problem whatever your machine’s zone is. I ran it without the guard and it hung the same way, so it does catch the bug. That run also showed a plain @Timeout can’t stop a loop like this, so the test uses threadMode = SEPARATE_THREAD to fail after 1 second instead of hanging the build. Changelog: the entry now also mentions the getPrevFireTime fix. -- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. To unsubscribe, e-mail: [email protected] For queries about this service, please contact Infrastructure at: [email protected]
