Round initialTime in RollingFileManager

[kelunik]

Caching of filesystem timestamps (at least in ext4 on Linux) results in non-accurate creation timestamps.

Thus, let's round it to the second.

Rounding is also applied for the lastModified time, but I'm not sure whether it's needed there.

Fixes #3068.

✅ Required checks

• License: I confirm that my changes are submitted under the Apache License, Version 2.0.
• Commit signatures: All commits are signed and verifiable. (See GitHub Docs on Commit Signature Verification).
• Code formatting: The code is formatted according to the project’s style guide.
• Build & Test: I verified that the project builds and all unit tests pass.

🧪 Tests (select one)

• I have added or updated tests to cover my changes.
• No additional tests are needed for this change.

📝 Changelog (select one)

• I added a changelog entry in src/changelog/.2.x.x. (See Changelog Entry File Guide).
• This is a trivial change and does not require a changelog entry.

[vy]

While @ppkarwasz is the main figure stewarding #3068 and this one, I'd appreciate one or more new tests and a changelog entry.

[kelunik]

@vy If you have an idea on how to test this properly, I'm happy to write a test.

[github-actions]

Job	Requested goals	Build Tool Version	Build Outcome	Build Scan®
build-macos-latest	clean install	3.9.8	✅
build-ubuntu-latest	clean install	3.9.8	✅
build-windows-latest	clean install	3.9.8	✅

Generated by gradle/develocity-actions

[vy]

If you have an idea on how to test this properly, I'm happy to write a test.

@kelunik, create a package-private initialFileTime(File,FileTime) that initialFileTime(File) delegates to, and write a unit test against initialFileTime(File,FileTime) verifying that the sub-second precision FileTime arguments are rounded as expected?

[kelunik]

@vy I've added a test now in a similar way like you suggested. It tests the rounding now, but doesn't test the fact that initial time actually rounds. I've also modified the test in the second commit to actually call initialFileTime, which I had to also make package private.

[ppkarwasz]

@kelunik,

Rounding the creation date from the filesystem might address the immediate issue, but I was wondering if it might be more robust to initialize the policy using the file’s last modification date instead:

• If the rotation interval remains unchanged, the last modification time should still fall within the same rotation period as the creation timestamp, only further away from the interval boundaries. That means the small uncertainties caused by filesystem timestamp caching shouldn’t matter.
• The JDK already falls back to the last modification date when it can’t determine the creation date, so this approach is both well-tested and consistent with existing behavior.

Would you see any downsides to this alternative?

[kelunik]

Would you see any downsides to this alternative?

Yes, see #3068 (comment)

but I was wondering if it might be more robust to initialize the policy using the file’s last modification date instead

Additionally, relying on the creation date isn't a known issue, so no action needed here IMO.

[kelunik]

@ppkarwasz Seems like the same caching also applies to the modification time, as I suspected, see https://stackoverflow.com/q/14392975/2373138.

[ppkarwasz]

Would you see any downsides to this alternative?

Yes, see #3068 (comment)

To counteract this problem the RollingFileAppender could change programmatically the last modification date of the old log file.

My point here is that no Java API allows us to change the creation date, but with the last modification date we have full control.

[kelunik]

My point here is that no Java API allows us to change the creation date, but with the last modification date we have full control.

I know, but we don't need that full control if rounding to the full second is acceptable for the initial time. I'd prefer to see the bug finally fixed, unless you see a major downside with this approach.

Relying on the birth time seems much more appropriate than back-dating the last modification time. Back-dating the modification time can still be implemented later if someone on a system not supporting birth time has a need for that.

[vy]

[@ppkarwasz writes] My point here is that no Java API allows us to change the creation date, but with the last modification date we have full control.

[@kelunik writes] I know, but we don't need that full control if rounding to the full second is acceptable for the initial time. I'd prefer to see the bug finally fixed, unless you see a major downside with this approach.

Relying on the birth time seems much more appropriate than back-dating the last modification time.

I agree with @kelunik here for following reasons:

• He has already explained using the last modification time has problems
• Resetting the last modification time to creation time – i.e., altering the truth – to make it work with Log4j does not sound right to me.
• Using creation time without its sub-second components already fixes the issue

@ppkarwasz, I'm inclined to accept this patch. Do you have objections?

[ppkarwasz]

@ppkarwasz, I'm inclined to accept this patch. Do you have objections?

Go ahead!

I still think we should not rely on the creation time at all (the JDK falls back on the last modification time in many versions and filesystems; we experienced this directly when the OnStartupTriggeringPolicyTest started failing on the CI and was disabled on UNIX in 7b92b6f), but let's fix the immediate now.