[vharseko]

Fixes #343.

Construction order

SecureCsvWriter constructed its RotatableWriter first, and the RotatableWriter constructor schedules the rotation and retention checks. Only then did the constructor read the keys and verify the file it resumes. A check due on the resumed file, by maxFileSize or by rotationInterval from its lastModified(), could run during the construction: it renamed the file and its keystore, and postRotationAction wrote new keys into a new keystore, through the secureStorage that the verifier reads. A valid file, already archived, then failed verification, and the topic did not start.

The writer is now constructed last, once the keys are read and the file it resumes is verified. The first check runs one check interval after the construction, on a writer that holds the keys and the last signature of the file.

A file that cannot be opened

The file is still opened, and closed at once, before the keys. A file that cannot be opened, as one in a directory that cannot be created, fails with an IOException, which CsvAuditEventHandler.startup() logs for the topic. Without that, a new file would fail first when its keystore is stored, with a SecureStorageException that the constructor wraps in a RuntimeException, and the startup would fail for every topic. Opening for append leaves the file and its lastModified() as they are.

A writer whose check interval is invalid

Found in the review. The RotatableWriter constructor opened its file before it rejected an unlimited or zero rotation and retention check interval, and the caller of a constructor that throws gets no writer to close: the file stayed open until its stream was collected. An interval under one millisecond passed that check, and failed after the open with the IllegalArgumentException of scheduleAtFixedRate, which CsvAuditEventHandler.startup() does not catch for the topic. The constructor now builds the policies and checks the interval before it opens the file, and rejects an interval under one millisecond with the same IOException. That includes a negative one: Duration adds the parts of a composite without an overflow check, and 9223372036854775807 ms, 1 ms parses to a negative interval.

Tests

• SecureCsvWriterTest.shouldNotRotateResumedFileWhileVerifyingIt: a written file is resumed with rotation and a 50 ms check interval, with a rotation due at the first check: its size at maxFileSize, or its lastModified() two hours back with a 1 hour rotationInterval. A CommentMatcher in the CsvPreference holds the verification for 500 ms on the first line. The construction succeeds, and the first check after it rotates the file. The archive passes verification, and so does the live file, with one event after the rotation. On Windows a file that the verifier holds open cannot be renamed, and a rotation that fails to rename it still resets the time of the last rotation: there, only the rotationInterval row is sure to fail with the writer constructed first.
• SecureCsvWriterTest.shouldFailWithIOExceptionWhenFileCannotBeOpened: a file under a regular file fails with an IOException.
• SecureCsvWriterTest.shouldFailWithIOExceptionWhenCheckIntervalIsInvalidForNewFile: a new file with rotation and an unlimited check interval fails with the IOException of the RotatableWriter.
• RotatableWriterTest.testRejectsInvalidRotationRetentionCheckIntervalBeforeOpeningTheFile: an unlimited, zero, 500 microseconds or overflowed 9223372036854775807 ms, 1 ms check interval fails with an IOException, and the file is not created. testRejectsInvalidRotationRetentionCheckIntervalWithRetentionOnlyBeforeOpeningTheFile does the same with a retention policy alone.
• RotatableWriterTest.testAcceptsAnyRotationRetentionCheckIntervalWithoutPolicy: with no policy, no check is scheduled, and the same intervals are accepted. testAcceptsOneMillisecondRotationRetentionCheckInterval: one millisecond is accepted.

Measured on JDK 27:

• With the SecureCsvWriter of master, both rows fail with "The CSV file was tampered: The file contains no CSV header": with a 50 ms interval, the first check runs while the keys are read, and renames the file before the verifier opens it. With a 1 s interval and a 3 s hold, both rows fail with the reason given in the issue, "Final HMAC key doesn't match expected value".
• Without the open and close before the keys, shouldFailWithIOExceptionWhenFileCannotBeOpened fails with the RuntimeException, and so does CsvAuditEventHandlerTest.canConfigureCsvHandlerFromJsonAndRegisterWithAuditService, whose log directory /path/to/audit/files/ cannot be created.
• With the writer constructed in the try block, shouldFailWithIOExceptionWhenCheckIntervalIsInvalidForNewFile fails with "RuntimeException: Error when initializing a secure CSV writer".
• With the RotatableWriter of master, both testRejectsInvalidRotationRetentionCheckInterval… tests fail in their four rows: the file exists for unlimited and zero, and 500 microseconds and the overflowed interval throw an IllegalArgumentException. With a guard that rejects only zero milliseconds, the overflowed row fails in both with the IllegalArgumentException.
• Three mutants of the guard each fail only their own test: without the retention clause, the retention-only test in its four rows; without the policy clause, testAcceptsAnyRotationRetentionCheckIntervalWithoutPolicy in its four rows; with <= 1, testAcceptsOneMillisecondRotationRetentionCheckInterval.
• audit/core and audit/handler-csv pass locally, and the new tests passed 3 runs in a row.

Merging

• With [#340] Tamper-evident CSV audit: close the file of a writer that fails to resume it #341: a conflict in the constructor. A failure in its try block now comes before the writer is constructed, so no file or rotator thread is left open (Tamper-evident CSV audit: a writer that fails to resume its file leaks it, and stops the audit service from starting #340), and the close that [#340] Tamper-evident CSV audit: close the file of a writer that fails to resume it #341 adds in the catch block would find csvWriter still null: the close goes, and the rest of [#340] Tamper-evident CSV audit: close the file of a writer that fails to resume it #341 applies as is. Its tests that the rotator thread terminates still hold, as the rotator does not start.
• With [#339] Resume a tamper-evident CSV file with no event since the last rotation #342, [#334] CSV audit: the rotate action waits for the events being written #347 and [#344] Tamper-evident CSV audit: sign the column names and the value lengths in the row HMAC #369: no conflict.

Not in this PR

• RotatableWriter schedules its checks in its constructor, and registerRotationHooks() sets the hooks after it, in a field that is not volatile. The first check runs one check interval later. Not observed; it follows from the memory model only.
• A new secure topic whose check interval is invalid stores new keys for its empty file on each publish attempt, and a resumed one verifies its file, before the writer fails. master leaked a FileOutputStream on each attempt instead.

[maximthomas]

praise: The change sits where the bug is, and its pin fails without it.

• constructWriter now runs at SecureCsvWriter.java:183, after the keys are read and the resumed file is verified, so the checks the RotatableWriter schedules (RotatableWriter.java:131) cannot rename the file during the construction.
• shouldNotRotateResumedFileWhileVerifyingIt fails in both rows with the SecureCsvWriter of master ("The CSV file was tampered: The file contains no CSV header", JDK 26, macOS) and passes at the head.
• The open and close at SecureCsvWriter.java:106 keeps a file that cannot be opened an IOException for its topic.

---

question (non-blocking): Should a new topic whose RotatableWriter constructor fails leave its .keystore behind?

commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/SecureCsvWriter.java:183, :163

For a new file the try block now writes InitialKey and CurrentKey into <file>.keystore (:163; KeyStoreSecureStorage.writeKey stores the keystore on each write) before constructWriter runs. With rotation enabled, maxFileSize 1000 and rotationRetentionCheckInterval "unlimited" (or "disabled"), the RotatableWriter constructor throws the same IOException as on master ("Rotation and retention check interval set to an invalid value", RotatableWriter.java:369-371), but master threw it before any key was written. The next start with a fixed config sees an empty file and overwrites both keys, so nothing is lost. If the leftover is acceptable, nothing changes; if a failed construction should leave nothing on disk, delete the keystore of a new file when constructWriter throws. Minor either way (traced, not run).

---

suggestion (non-blocking): No test pins what a failed construction of a new topic leaves on disk.

commons/audit/handler-csv/src/test/java/org/forgerock/audit/handlers/csv/SecureCsvWriterTest.java:355, SecureCsvWriter.java:183

shouldNotRotateResumedFileWhileVerifyingIt pins the order on a resumed file, and shouldFailWithIOExceptionWhenFileCannotBeOpened fails at the open (SecureCsvWriter.java:106), before any key is written; nothing covers a new file whose writer fails after :163. The case below goes red if the key writes move back after the writer (the last assertion) or if the interval stops failing the construction. Set its last assertion by the answer to the question above. Not run.

@Test
public void shouldFailWithIOExceptionWhenCheckIntervalIsInvalidForNewFile() throws Exception {
    final Path logDirectory = Files.createTempDirectory("SecureCsvWriterTest");
    final File actual =
            new File(logDirectory.toFile(), CsvAuditEventHandler.SECURE_CSV_FILENAME_PREFIX + "access.csv");
    final CsvAuditEventHandlerConfiguration config = createBasicSecureConfig("5 minutes");
    config.getFileRotation().setRotationEnabled(true);
    config.getFileRotation().setMaxFileSize(1000);
    config.setRotationRetentionCheckInterval("unlimited");
    assertThatThrownBy(() -> new SecureCsvWriter(actual, new String[]{"FOO"}, CsvPreference.EXCEL_PREFERENCE,
            config, keyStoreHandler, random))
            .isInstanceOf(IOException.class)
            .hasMessageContaining("Rotation and retention check interval set to an invalid value");
    // the head leaves the keystore of the new file; master did not create it
    assertThat(CsvSecureUtils.keyStoreFile(actual)).exists();
}

---

suggestion (non-blocking): The resumed SecureCsvWriter in shouldNotRotateResumedFileWhileVerifyingIt is closed only when the test passes.

commons/audit/handler-csv/src/test/java/org/forgerock/audit/handlers/csv/SecureCsvWriterTest.java:322-333

The writer built at :322 is closed at :333, outside any try, while the first writer of the same test (:290) is in try-with-resources. If the assertion at :324, the wait or writeEvent fails, its RotatableWriter rotator (Executors.newScheduledThreadPool(1), non-daemon, RotatableWriter.java:373) goes on checking every 50 ms for the rest of the surefire JVM, and on Windows the file stays open. fileNamingPolicy moves before the writer, as the verification after the block reads it.

        final FileNamingPolicy fileNamingPolicy = new TimeStampFileNamingPolicy(actual, rotationFileSuffix, "");
        try (SecureCsvWriter secureCsvWriter = new SecureCsvWriter(
                actual, new String[]{header}, slowToVerify, config, keyStoreHandler, random)) {
            assertThat(held.get()).as("verification held").isTrue();

            // the first check after the construction rotates the file
            final long deadline = System.nanoTime() + TimeUnit.SECONDS.toNanos(10);
            while (fileNamingPolicy.listFiles().isEmpty() && System.nanoTime() < deadline) {
                Thread.sleep(10);
            }
            secureCsvWriter.writeEvent(singletonMap(header, "after"));
        }

---

suggestion (non-blocking): On Windows, only the rotationInterval row is sure to catch a reverted order.

commons/audit/handler-csv/src/test/java/org/forgerock/audit/handlers/csv/SecureCsvWriterTest.java:273-281, :301

With the SecureCsvWriter of master on Windows, a check during the 500 ms hold cannot rename the file the verifier holds open (FileInputStream does not share delete), and RotatableWriter.rotate still resets lastRotationTime. The rotationInterval row then rotates no more within the hour and fails hasSize(1). The maxFileSize row stays over its size and rotates at the next check after verify() closed its reader, usually once the constructor has returned, so it fails only when a check renames the file before the verifier opens it. Traced, not run on Windows. A line in the data provider's comment saying which row pins the order on Windows keeps that from being lost.

[vharseko]

Round 1 is in 7ede4f2, on a branch rebased onto the current master.

Question: the .keystore that a new topic leaves when its writer fails. Left as is. master did not leave the disk clean either: the RotatableWriter constructor opened the file (RotatableWriter.java:128) before it threw for the interval (:370), so the empty .csv stays on both; the head adds its keystore. The next start with a fixed interval reads the empty file as a new one and overwrites both keys: run against both, the file written at that start passes verification. A cleanup there would add a file delete to a configuration error path, with no effect on the next start.

Suggestion: a test for a new file whose writer fails. Added as shouldFailWithIOExceptionWhenCheckIntervalIsInvalidForNewFile, without the last assertion: the keystore it leaves is not a contract, and a reverted order is pinned by shouldNotRotateResumedFileWhileVerifyingIt. What the test pins is the IOException: with the writer constructed in the try block, it fails with "RuntimeException: Error when initializing a secure CSV writer", which CsvAuditEventHandler.startup() does not catch for the topic.

Suggestion: the resumed writer is closed only when the test passes. Done as proposed.

Suggestion: on Windows, only the rotationInterval row is sure to catch a reverted order. The data provider says so now, and that the maxFileSize row fails there when a check renames the file before the verifier opens it.

Found while tracing the question. The RotatableWriter constructor opened its file before it rejected the interval, and the caller of a constructor that throws gets no writer to close, so the case of the new test left the file open. An interval under one millisecond passed that check, and failed after the open with the IllegalArgumentException of scheduleAtFixedRate. The constructor now checks the interval before it opens the file, and rejects an interval under one millisecond with the same IOException: RotatableWriterTest.testRejectsInvalidRotationRetentionCheckIntervalBeforeOpeningTheFile, which fails in its three rows with the RotatableWriter of master. The description has a section on it.

[maximthomas]

praise: The writer now starts its checks only on a file it has verified, and an invalid interval fails before anything is opened.

• SecureCsvWriter constructs its RotatableWriter last (SecureCsvWriter.java:183), after the keys are read and the resumed file verified; on windows-latest JDK 11 and 27 both rows of shouldNotRotateResumedFileWhileVerifyingIt rotate once and pass.
• RotatableWriter.getRotationCheckInterval (RotatableWriter.java:365-377) rejects the interval before constructWriter opens the file (:132), so a throwing constructor leaves no stream open, and "500 microseconds" becomes an IOException the handler reports for the topic.
• The append probe at SecureCsvWriter.java:106 keeps lastModified() on Windows too: the rotationInterval row, due only from an mtime set two hours back, rotates on both Windows rows.

---

issue (non-blocking): The interval guard lets an overflowed, negative check interval through to the IllegalArgumentException after the open.

commons/audit/core/src/main/java/org/forgerock/audit/events/handlers/writers/RotatableWriter.java:371-372, :132, :383

Duration.merge adds the parts of a composite without an overflow check (commons/util/util/src/main/java/org/forgerock/util/time/Duration.java:223, :227): "9223372036854775807 ms, 1 ms" parses to an interval that is neither unlimited nor zero, with to(MILLISECONDS) = Long.MIN_VALUE (probed against this head's Duration). The guard's == 0 lets it pass, constructWriter opens the file, and scheduleAtFixedRate throws IllegalArgumentException for a period <= 0, which CsvAuditEventHandler.startup() does not catch for the topic. master does the same, so this is no regression and the input is contrived; but the commit says the constructor rejects any interval under one millisecond.

        // RotatableWriter.java:371-372
        if ((!rotationPolicies.isEmpty() || !retentionPolicies.isEmpty())
                && (rotationCheckInterval.isUnlimited() || rotationCheckInterval.to(TimeUnit.MILLISECONDS) <= 0)) {

                // RotatableWriterTest.invalidRotationRetentionCheckIntervals
                // Duration adds its parts without an overflow check: this one is negative
                {"9223372036854775807 ms, 1 ms"}

Pin: with == 0 the new row gets the IllegalArgumentException and an existing file instead of the IOException (by reading, not run); with <= 0 it passes.

---

suggestion (non-blocking): A new secure topic with an invalid check interval rewrites its .keystore on every publish attempt.

commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/SecureCsvWriter.java:163, :183, commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/CsvAuditEventHandler.java:299-308, :463-469

Your round-1 answer covers the keystore left after startup. With no writer for the topic, each publish runs getWriter → resetAndReopenWriter → a new SecureCsvWriter, which stores fresh random keys (:163, the keystore written twice) before constructWriter fails (:183), and the event fails with a BadRequestException. master leaked one FileOutputStream per attempt instead, so this is not worse in kind and leaving it is reasonable; checking the interval before the keys are stored would remove the churn.

---

suggestion (non-blocking): The check-interval guard is pinned only with a rotation policy.

commons/audit/core/src/test/java/org/forgerock/audit/events/handlers/writers/RotatableWriterTest.java:244, commons/audit/core/src/main/java/org/forgerock/audit/events/handlers/writers/RotatableWriter.java:371-372

All three rows of testRejectsInvalidRotationRetentionCheckIntervalBeforeOpeningTheFile set setRotationEnabled(true) and setMaxFileSize, so three mutants of the guard line survive: dropping || !retentionPolicies.isEmpty() (a retention-only config with "zero" opens the file and gets the IllegalArgumentException again), dropping the policy clause (a config with no policy and "zero" is rejected), and == 0 → <= 1 ("1 millisecond" is rejected). By reading; the mutants were not run.

    @Test(dataProvider = "invalidRotationRetentionCheckIntervals")
    public void testRejectsInvalidCheckIntervalWithRetentionOnlyBeforeOpeningTheFile(
            String rotationRetentionCheckInterval) throws IOException {
        final File file = getTempFile();
        Files.delete(file.toPath());
        final FileBasedEventHandlerConfiguration configuration = new DefaultFileBasedAuditEventHandlerConfiguration();
        configuration.setRotationRetentionCheckInterval(rotationRetentionCheckInterval);
        configuration.getFileRetention().setMaxNumberOfHistoryFiles(1);

        assertThatThrownBy(() -> new RotatableWriter(file, configuration, true))
                .isInstanceOf(IOException.class)
                .hasMessageContaining("Rotation and retention check interval set to an invalid value");
        assertThat(file).doesNotExist();
    }

    @Test(dataProvider = "invalidRotationRetentionCheckIntervals")
    public void testAcceptsAnyCheckIntervalWithoutPolicy(String rotationRetentionCheckInterval) throws IOException {
        final FileBasedEventHandlerConfiguration configuration = new DefaultFileBasedAuditEventHandlerConfiguration();
        configuration.setRotationRetentionCheckInterval(rotationRetentionCheckInterval);

        new RotatableWriter(getTempFile(), configuration, true).close();
    }

    @Test
    public void testAcceptsOneMillisecondCheckInterval() throws IOException {
        final FileBasedEventHandlerConfiguration configuration = new DefaultFileBasedAuditEventHandlerConfiguration();
        configuration.setRotationRetentionCheckInterval("1 millisecond");
        configuration.getFileRotation().setRotationEnabled(true);
        configuration.getFileRotation().setMaxFileSize(MAX_BYTES_TO_WRITE);

        new RotatableWriter(getTempFile(), configuration, true).close();
    }

Pin: the first test kills the dropped retention clause, the second the dropped policy clause, the third <= 1.

[vharseko]

Round 2 is in 40c56b2, on the current master.

Issue: an overflowed, negative check interval passes the guard. Fixed: the guard rejects an interval of <= 0 milliseconds, and invalidRotationRetentionCheckIntervals has the row "9223372036854775807 ms, 1 ms". With == 0, the row fails in both tests that take the provider, with the IllegalArgumentException of scheduleAtFixedRate; with <= 0 it passes.

Suggestion: a new secure topic with an invalid check interval rewrites its .keystore on every publish attempt. Left as is. Each attempt finds the file the probe left empty, so the keys it stores are those of an empty file, and the first start with a valid interval stores its own. A resumed topic verifies its file on each attempt before the writer fails, for the same reason. Checking the interval before the keys would need the guard of RotatableWriter made public in audit/core, or copied into SecureCsvWriter, for a configuration that fails every event of the topic either way; master leaked a FileOutputStream on each attempt instead.

Suggestion: the check-interval guard is pinned only with a rotation policy. Added as proposed, with each writer assigned to the rotatableWriter field that tearDown() closes, as the other tests of the class do:

• testRejectsInvalidRotationRetentionCheckIntervalWithRetentionOnlyBeforeOpeningTheFile: without || !retentionPolicies.isEmpty(), it fails in its four rows.
• testAcceptsAnyRotationRetentionCheckIntervalWithoutPolicy: without the policy clause, it fails in its four rows.
• testAcceptsOneMillisecondRotationRetentionCheckInterval: with <= 1, it fails.

Each mutant was run, and only its test failed. With the RotatableWriter of master, both tests that reject fail in their four rows, and both tests that accept pass.

[vharseko]

@maximthomas, rebased onto the current master (28afe37, with #341, #353 and #369): the head is 8104030.

The conflict was in the SecureCsvWriter constructor, with #341, and is resolved as the Merging section of the description says:

• the file is still opened and closed at once before the keys, and the RotatableWriter is constructed last, after the try block;
• the HmacCalculator is created inside the try block, as [#340] Tamper-evident CSV audit: close the file of a writer that fails to resume it #341 has it;
• the csvWriter.close() that [#340] Tamper-evident CSV audit: close the file of a writer that fails to resume it #341 added to the catch block is gone: no writer is constructed yet when that block runs. The rethrow of an IOException as is stays.

The comment on the open and close still holds with #341: a keystore that cannot be stored fails with a SecureStorageException, which is not an IOException, so the constructor still wraps it into a RuntimeException.

audit/handler-csv and RotatableWriterTest pass locally (82 and 31 tests).

[maximthomas]

praise: The rebase keeps the construction order and closes the round-2 gaps in the check-interval guard.

• RotatableWriter.getRotationCheckInterval rejects an overflowed composite interval with <= 0 (RotatableWriter.java:373), and the "9223372036854775807 ms, 1 ms" row (RotatableWriterTest.java:240) runs through both rejection tests.
• The retention-only rejection test (RotatableWriterTest.java:266), the no-policy acceptance test (:285) and the 1 ms test (:301) pin each clause of the guard; on ubuntu-latest JDK 27, audit.core runs 13 more tests than master, all green.
• The conflict resolution drops #341's catch-block csvWriter.close() (SecureCsvWriter.java:213), since the writer is now constructed after the try (:223); the #341 tests and the PR's four handler-csv invocations pass on all nine build rows.