Skip to content

[#334] CSV audit: the rotate action waits for the events being written - #347

Merged
vharseko merged 15 commits into
OpenIdentityPlatform:masterfrom
vharseko:issue-334-csv-rotate-race
Oct 19, 2026
Merged

vharseko merged 15 commits into
OpenIdentityPlatform:masterfrom
vharseko:issue-334-csv-rotate-race

Conversation

@vharseko

@vharseko vharseko commented Oct 17, 2026 •

Copy link
Copy Markdown
Member

Fixes #334.
Fixes #350.
Fixes #349.
Fixes #365.
Fixes #363.
Fixes #364.
Fixes #351.

The race

CsvAuditEventHandler looked up the writer of a topic without a lock; only the reset after a failed write and the rotations took the handler monitor. A publisher that had the writer when the rotate action closed it wrote into the closed writer. With rotation and buffering disabled, TextWriter.Stream wrote through a PrintWriter, which swallows the IOException, so the retry never ran: the event was lost and publishEvent() reported success. A stale SecureCsvWriter also stored its keystore over the one of the new file.

With rotation enabled (comment), the rotate action looked up the writer without the monitor too, and could call forceRotation() on a writer that a concurrent reset had closed.

The fix

The issue offers two ways out: make a write to a closed writer fail, so that the retry opens the current writer, or make rotate wait for the publishers that are already writing. This PR does the latter. A closed writer that throws would not cover the path with rotation enabled, and would leave the gap between the final signature and the close of the stream in SecureCsvWriter.close() that #337 left to this issue. A write to a closed writer now fails as well (#349, below), but only the lock covers both paths.

A ReentrantReadWriteLock per topic guards the writer of the topic, and replaces the handler monitor:

  • a publisher looks up the writer and writes the event under the read lock. If the topic has no writer, or the write fails, it retries under the write lock, with a new writer unless another thread has replaced the writer meanwhile;
  • the rotate action with rotation enabled holds the read lock during forceRotation(): publishers keep writing, and a reset cannot close the writer meanwhile;
  • the default rotation, startup() and shutdown() take the write lock, so they wait for the events being written. The rotated file is still compressed after the lock is released ([#331] Tamper-evident CSV audit: verify compressed archives, rename the keystore on the rotate action #332).

With a lock per topic, the other topics keep publishing while the writer of one topic is replaced. With a single lock they would not: new readers of a ReentrantReadWriteLock also queue behind a waiting writer, so one event being written plus a waiting rotation would stop every topic. The retry now also opens a writer when a failed reset of another thread has left the topic without one, where it threw a NullPointerException before.

Events after shutdown() (#350)

shutdown() closed the writers but left them in the map, and nothing marked the handler as shut down. An event published afterwards went to the closed writer of its topic. With rotation disabled, it was lost while publishEvent() reported success, and a tamper-evident writer still stored its next key, so the file failed verification and could not be resumed. With rotation enabled, the closed RotatableWriter threw, and the retry opened a new writer that nothing closed. The rotate action after shutdown() also rotated the file and opened a new writer, in both modes.

shutdown() now marks the handler as shut down before it takes the first write lock, and removes each writer it closes from the map. A topic without a writer then gets no new one:

An event that has the read lock of its topic when shutdown() gets there is still written, and shutdown() waits for it. startup() clears the mark once it has opened the writers, also when a writer throws a RuntimeException (#340), so that a restarted handler opens a writer again, at the next event, for a topic whose file it could not open. Until startup() returns, an event or a rotate action on a topic that it has not opened yet fails with a ServiceUnavailableException, as the Javadoc of startup() now states. Before, such an event went to the closed writer of its topic, as above, and with rotation enabled startup() then replaced the writer that the retry had opened, without closing it. startup() now closes a writer that an event opened before it, or after a startup() that threw, before it opens a new one.

The retry under the write lock also rethrows a ResourceException as is. ResourceException is an IOException, so the ServiceUnavailableException would have become an InternalServerErrorException, and the InternalServerErrorException of a failed reset would have been wrapped into another one, since the reset moved into that try.

Write failures (#349)

With rotation disabled, StandardCsvWriter and SecureCsvWriter write through TextWriter.Stream, which wrote through a PrintWriter. A PrintWriter never throws: it sets an error flag, which nothing read. A write that failed, on a full disk, on an I/O error or on a closed stream, was lost while publishEvent() reported success, the retry never ran, and a tamper-evident writer still stored the next key after the lost row, so the file failed verification and could not be resumed.

TextWriter.Stream now writes through a BufferedWriter over an OutputStreamWriter, the two writers that the PrintWriter wrapped, so the buffering and the charset are the same, and write() and flush() throw the IOException of the stream with its message:

  • the retry of the handler opens a new writer for the event, as it does with rotation enabled, where RotatableWriter already threw;
  • a tamper-evident writer stores the next key only after the row is flushed, so it no longer stores the key of a row it could not write;
  • with buffering enabled, AsynchronousTextWriter logs the failure, which was silent before;
  • a failure to close the stream is logged, as RotatableWriter does.

After a failure, the buffers of these writers are unusable: the encoder of the OutputStreamWriter is left with its buffer flipped, so the next flush writes nothing and returns, and a close writes a part of a failed text longer than the buffers. Several publishers write to the same StandardCsvWriter under the read lock, so the flush of the next one would report success for an event that the failure dropped. TextWriter.Stream therefore fails every write and flush after the first failure, with that failure as the cause, and shutdown() then closes the stream without writing what the buffers hold. A write or a flush checks for a failure, and records its own, under the lock of the writer: a flush that waits for a flush that fails would otherwise find the buffers empty, and return. Every publisher whose event was in the buffers gets the IOException, and the handler retries the event with a new writer. A close that fails records its failure as well, and closes the stream, which the close of the buffers leaves open on JDK 8 and 11, and on older updates of 17 and 21. A caller that logs or throws only the next failure, such as the flush in the finally block of SecureCsvWriter.writeSignature(), still gives the first one, such as a full disk.

StandardCsvWriter writes the header of a new file in its constructor, which can now throw; it then closes the file, and the rotator thread with rotation, as the caller gets no writer to close.

write() and flush() of TextWriter.Stream now declare IOException. In this repository only the two CSV writers use the class, through the TextWriter interface, which declared it already; code that calls them on a TextWriter.Stream reference has to handle it. write(null) throws a NullPointerException, where PrintWriter.print(null) wrote null.

RotatableWriter after a failure (#365)

RotatableWriter, which writes when rotation is enabled, had the same buffers and the same flaw: with two publishers, the flush of the second one returned after the flush of the first one failed; close(), which the reset calls, wrote 8192 bytes of a failed event into the file; and a rotation went on with a new writer, on which the flush of an event that the failure dropped succeeded.

TextWriter.Stream and RotatableWriter now share FailFastWriter, a package-private Writer that holds the logic above: it fails every write and flush after the first write, flush or close that fails, with that failure as the cause, and closes the stream without writing what the buffers hold. RotatableWriter does not rotate a file after a failure: the rotation checks log the failure, and forceRotation() throws it, until the writer is replaced. It keeps the writer of the failure until then, so its later flushes fail too.

RotatableWriter gets a package-private constructor that opens the file through a FileStreamOpener, so that the tests can open a stream that fails.

RotationContext.getWriter() now returns the FailFastWriter, which is not a BufferedWriter. Its declared type is Writer, which the hooks of this repository use; a RotationHooks that casts it to BufferedWriter gets a ClassCastException.

Buffered writes (#363)

With buffering enabled, AsynchronousTextWriter writes the records on its own thread, and only logged a failure of the wrapped writer: the handler never learned of it, never replaced the writer, and each record logged a stack trace while the failure lasted.

AsynchronousTextWriter now keeps the first failure of the wrapped writer, and fails the next write() and flush() with it as the cause, so that the retry of the handler opens a new writer. It logs the first failure with its stack trace, the next ones at debug level, and, at shutdown, the number of records that could not be written. flush() now throws the failure of the wrapped writer instead of logging it, and declares IOException: code that calls it on an AsynchronousTextWriter reference has to handle it. The first failure is kept for the life of the writer, as the class Javadoc now states: the caller replaces the writer after a failure, as the handler does. The writers of this package that it wraps fail their later writes after a failure too, so a writer that went on would not write again either.

shutdown() of a buffered handler now fails with an InternalServerErrorException when the wrapped writer has failed already, or fails to flush the records handed to it, as the handler does without buffering when the flush fails. The records still queued are written while the writer closes, after that flush: a failure there is only logged, with their number. Every writer is still closed.

Server errors (#364)

CsvAuditEventHandler reported an IOException of the audit file as a BadRequestException (400): a failed write after the reset, a writer that could not be opened, a file that could not be read or queried, and a rotation that failed. These are failures of the server, which a client may retry. They are now InternalServerErrorException (500), and queryEvents() adapts its failure with ResourceExceptionsUtil.adapt(), which keeps a ResourceException and turns a JsonValueException into a BadRequestException. The rotate action after shutdown() fails with a ServiceUnavailableException (503), as a publish does. BadRequestException stays for an action without a topic, an unknown action and an unknown topic. The rotate action throws the exception of a rotation that does not happen after the try of forceRotation(): a ResourceException is an IOException, so its catch wrapped the exception into another one, whatever its status.

Failures after the event is written (#351)

The handler takes an IOException of a write for an event that is not in the file: it closes the writer, opens a new one and writes the event again. Two writers threw after the event was written:

  • SecureCsvWriter.writeEvent() writes and flushes the row, then stores the next HMAC key in the keystore of the file. When the key could not be stored, the reset closed a writer whose file was intact, and the new writer verified the file against the keystore, which still held the previous key: it failed with "Final HMAC key doesn't match expected value", and so did every later event of the topic, also once the keystore could be written again. The writer now logs the failure and goes on: the next row stores the key, and the event is reported as published, as it is in the file.
  • RotatableWriter.write() applies the rotation policies after it writes the text, so a rotation that failed threw after the event was written, and the handler wrote the event again to a new writer. With tamper-evident logging, the rotation signs the file first, and a keystore that cannot be stored failed it, so the reset broke the topic as above. write() now logs the failure of the rotation, as the scheduled checks do. A rotation that fails because the file cannot be written, also when the file fails to close, leaves the writer failed (RotatableWriter: after a failed write, the next flush reports success for events that the failure dropped #365): the flush that follows the write then fails, and the handler writes the event again, which the failure dropped.

CsvWriter.writeEvent() now states that it does not throw once the row is written, which the retry of the handler relies on.

Tests

  • CsvAuditEventHandlerTest.testActionToRotateFileKeepsEventBeingPublished, standard and tamper-evident: a publisher stops while it serializes a field of its event, after it has the writer and before it writes to it, and the rotate action runs meanwhile. Every event is then written once, to the archive or to the new file, and with tamper-evident logging both files pass verification with their own keystores. Without the fix, the event being published is lost in both variants.
  • CsvAuditEventHandlerTest.testActionToRotateFileLetsOtherTopicsPublish: an event of activity is written while the rotate action of access waits for an event being written. With one lock for all topics, it times out.
  • testActionToRotateFileCompressesOutsideHandlerMonitor is renamed to testActionToRotateFileCompressesOutsideWriteLock, as there is no monitor any more.
  • CsvAuditEventHandlerTest.testPublishEventAfterShutdownFails, standard and tamper-evident, each with rotation disabled and enabled: an event published after shutdown() fails with a ServiceUnavailableException and is not in the file, and the tamper-evident file passes verification. Without the fix, all four variants report success.
  • CsvAuditEventHandlerTest.testActionToRotateFileAfterShutdownFails, with rotation enabled and disabled: the rotate action after shutdown() fails and leaves the file as it is. Without the fix, it rotates the file in both modes.
  • CsvAuditEventHandlerTest.testPublishEventAfterShutdownAndStartup: after shutdown() and startup(), a topic whose file could not be opened at startup opens it at its next event.
  • TextWriterTest (new, audit/core): a failure of the output stream is thrown by flush() with its message; a write after shutdown() throws; after a failed flush of two events, the next flush and write throw too; the next failures have the first one as their cause; after a failed write of a text longer than the buffers, shutdown() writes nothing of it; a text written and flushed reaches the stream with its byte count. Without the fix, all but the last fail: with the plain BufferedWriter, the next flush returns, and shutdown() writes 8192 bytes of the failed text.
  • TextWriterTest.testStreamFailsTheFlushThatWaitsForAFailingFlush: two publishers flush at the same time, and the write of the first flush to the stream fails while the second flush waits for it. Both flushes fail, and nothing reaches the stream. Without the check under the lock, the second flush returns.
  • TextWriterTest.testStreamFailsTheWriteThatWaitsForAFailingFlush: a publisher writes while the write of a flush to the stream fails. Both fail, and nothing reaches the stream. Without the lock around the write, the write returns, and puts its event into the buffers that the failure left unusable.
  • TextWriterTest.testStreamClosesTheOutputStreamWhenTheShutdownFails: the close that writes the buffers fails, and the stream is closed. Without the fix, the stream stays open on JDK 11. A probe of BufferedWriter.close() over a stream that fails leaves the stream open on 1.8.0_402 and 11.0.32 too, and closes it on 17.0.20, 21.0.12 and 27.
  • RotatableWriterTest.testFailsEveryWriteAndFlushAfterAFailure, testDoesNotWriteTheTextOfAFailedWriteWhenClosed and testDoesNotRotateAfterAFailure, through a stream whose first write fails. Without the fix, the second flush returns, close() writes 8192 bytes of the failed event, and forceRotation() rotates the file.
  • RotatableWriterTest.testDoesNotRotateAfterTheRotationFailsToCloseTheFile: the close of a size rotation that write() triggers fails to write the text, and the disk works again before the flush of the text. forceRotation() and the flush fail, the file holds only the text written before, and there is no archive. Without the fix, forceRotation() rotates the file, and the flush succeeds on the new file for the text that the failed close dropped.
  • AsynchronousTextWriterTest (new, audit/core): after the wrapped writer fails a write, a later write() fails with that failure as the cause; flush() throws the failure of the wrapped writer, and the next write() fails. Without the fix, no write fails, and flush() returns.
  • CsvAuditEventHandlerTest.testFailuresOfAuditFileAreServerErrors: with a directory in place of the audit file, a publish, a read, a query and the rotate action fail with an InternalServerErrorException. Without the fix, all four fail with a BadRequestException. testActionToRotateFileAfterShutdownFails now expects a ServiceUnavailableException, and testActionToRotateTamperEvidentFileKeepsFileWhenKeyStoreCannotBeRenamed an InternalServerErrorException.
  • CsvAuditEventHandlerTest.testActionsThatTheRequestGetsWrongAreBadRequests: an action without a topic, an unknown action, and the rotate action of an unknown topic fail with a BadRequestException.
  • CsvAuditEventHandlerTest.testActionToRotateFileThatFailsIsServerError: with rotation enabled, the rotate action fails with an InternalServerErrorException for a writer whose forceRotation() throws an IOException, and for one whose forceRotation() returns false, with the message of a rotation that does not happen. The writers are put into the handler by reflection.
  • CsvAuditEventHandlerTest.testPublishEventOpensWriterWhenTopicIsLeftWithoutOne: the writer of the topic removes itself from the handler, as a failed reset of another publisher does, and fails the write. The event is written once, to a new writer. Without the newCsvWriter == null check, the publish fails with a NullPointerException.
  • CsvAuditEventHandlerTest.testPublishEventDuringStartupResetsWriterOfReopenedTopic: after shutdown(), a writer is put into the handler by reflection, as when startup() has reopened the topic and not returned yet, and fails the write. The event is written once, to a new writer. Without the fix, it fails with a ServiceUnavailableException.
  • CsvAuditEventHandlerTest.testStartupClosesTheWriterThatItReplaces: a writer put into the handler by reflection, as one that an event opened after a startup() that threw, is closed by the next startup(). Without the fix, startup() replaces it and leaves it open.
  • CsvAuditEventHandlerTest.testRestartLetsOtherTopicsPublishWhenTamperEvidentKeyStoreCannotBeStored: after shutdown(), the file of the topic that startup() opens first is deleted and its keystore made read-only, so the writer loads the keystore but cannot store the first keys of the new file, and startup() throws (Tamper-evident CSV audit: a writer that fails to resume its file leaks it, and stops the audit service from starting #340). An event of the other topic is then published. Without the fix, it fails with a ServiceUnavailableException. The test fails if startup() does not throw, so that it does not pass without the fix, and is skipped where the keystore cannot be made read-only, as for root.
  • CsvWriterTest.shouldFailToWriteEventToClosedStandardCsvWriter and shouldKeepSecureCsvFileVerifiableWhenWriteToClosedWriterFails: an event written to a closed writer fails with an IOException, and the tamper-evident file still passes verification with its keystore. Without the fix, both writes report success.
  • CsvAuditEventHandlerTest.testPublishEventKeepsTamperEvidentWriterWhenKeyStoreCannotBeStored, with rotation enabled and disabled: a directory replaces the keystore during one event, then the keystore is restored. Every event is published and written once, and the file passes verification with its keystore. Without the fix, that event fails with RuntimeException: Error when initializing a secure CSV writer (Tamper-evident CSV audit: a writer that fails to resume its file leaks it, and stops the audit service from starting #340), from the reset.
  • CsvAuditEventHandlerTest.testPublishEventKeepsTamperEvidentWriterWhenRotationAfterItFails: with a size-based rotation, a directory replaces the keystore during the event whose write rotates the file, so the signature of the rotation fails. Every event is published and written once, to the archive that the next event rotates, and the archive passes verification with its keystore. Without the fix, the event fails the same way.
  • RotatableWriterTest.testDoesNotFailTheWriteOfATextWhenTheRotationAfterItFails: a rotation hook fails at the write that follows a file of the maximum size; the write and the flush return, and the text is in the file once. Without the fix, the write throws the failure of the hook.

The default rotation under the read lock is caught by the first test, and the compression under the write lock by the third. For #350, keeping the closed writers in the map fails the last three tests, dropping the check under the write lock fails the four variants of testPublishEventAfterShutdownFails, and a startup() that does not clear the mark fails the last test. For #349, storing the key before the row is written fails shouldKeepSecureCsvFileVerifiableWhenWriteToClosedWriterFails with "Final HMAC key doesn't match expected value". For #351, throwing the failure to store the key fails both variants of testPublishEventKeepsTamperEvidentWriterWhenKeyStoreCannotBeStored and testPublishEventKeepsTamperEvidentWriterWhenRotationAfterItFails, and throwing the failure of the rotation from write() fails testPublishEventKeepsTamperEvidentWriterWhenRotationAfterItFails and testDoesNotFailTheWriteOfATextWhenTheRotationAfterItFails. A rotation that logs the failed close of the file and goes on fails testDoesNotRotateAfterTheRotationFailsToCloseTheFile. A BadRequestException for the IOException of forceRotation(), or for a rotation that does not happen, fails testActionToRotateFileThatFailsIsServerError, and an InternalServerErrorException for an unknown topic fails testActionsThatTheRequestGetsWrongAreBadRequests. Throwing the exception of a rotation that does not happen inside the try fails testActionToRotateFileThatFailsIsServerError on its message. A retry under the write lock that fails for any topic once the handler is shut down fails testPublishEventDuringStartupResetsWriterOfReopenedTopic, a startup() that does not close the writer it replaces fails testStartupClosesTheWriterThatItReplaces, and a FailFastWriter.write() outside the lock fails testStreamFailsTheWriteThatWaitsForAFailingFlush. audit/core, audit/handler-csv, audit/handler-json and audit/handler-syslog pass locally on JDK 11 and 27, and the new tests of #334 passed 20 runs in a row. One full run on JDK 11 failed CsvWriterTest.shouldCreateNewAuditFileAfterRotation, on the archive of an event that rotated the file after a periodic signature, which #342 fixes.

Not covered by a test

Known limits

  • A write that fails after part of its bytes reached the file leaves a partial row, which the retry follows with the whole event.
  • A tamper-evident writer computes the HMAC of a row, and moves to the next key, before it writes the row. After a failed write, the reset closes it: when a signature is due, the final signature covers the HMAC of the row that is not in the file, and its write fails as well. The file then ends with events that no signature covers, and the new writer cannot resume it: the topic fails loudly, where it lost the row and stored a key that broke the file silently before.
  • With buffering enabled, the records queued before the failure shows are reported as published, and are lost: their number is logged when the writer is replaced. shutdown() does not fail for the records still queued when it is called: their failure is only logged.
  • Until the writer is replaced, the rotation checks log the failure at each check interval.
  • Until the keystore can be stored again, it holds the key of an earlier row: the file fails verification meanwhile, and a handler stopped before the next row cannot resume it. Each row logs the failure.
  • A rotation that fails after it has renamed the file leaves the writer half rotated. When the new file cannot be created or opened, the writer keeps the closed one: the flush that follows the write fails, and the handler writes the event again to a new file, while it is in the archive already, as it did before. When a rotation hook fails after the rename, the writer goes on with the new file, which may lack its header or, with tamper-evident logging, the keys of its keystore; before, the write threw, and the reset made the topic fail. The scheduled checks leave the writer in the same states.

Merging

Not in this PR

Found in the review of this change, older than it, and filed separately:

@maximthomas maximthomas left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

praise: The lock per topic and the shutdown mark fix the races where they happen.

  • writerLockByTopic keeps the other topics publishing while one topic's writer is replaced, and testActionToRotateFileLetsOtherTopicsPublish pins it.
  • cleanup() removes every writer it closes from writers and closes all of them even when a flush fails, so after shutdown() neither an event nor the rotate action reaches a closed writer.

issue (blocking): FailFastWriter checks failure outside the buffer's lock, so a flush that is already waiting on that lock when another flush fails returns normally and loses its event.

commons/audit/core/src/main/java/org/forgerock/audit/events/handlers/writers/FailFastWriter.java:73, :53, :63, :84

Two publishers share one StandardCsvWriter under the topic read lock, and nothing above FailFastWriter serialises their flushes: TextWriterAdapter.flush() and TextWriter.Stream.flush() are unsynchronized, and RotatableWriter.flush() takes only the read lock. While A's flush is failing inside the BufferedWriter, B has already passed checkNotFailed() and waits on the BufferedWriter's lock. fail() records A's failure only after that lock is released. B then finds nextChar == 0 and the encoder's buffer flipped, writes nothing and returns, so B's publishEvent() succeeds for a row that is in no file. The description says this case is closed ("Every publisher whose event was in the buffers gets the IOException"). A probe of this class gave A=IOException, B=returned, 0 bytes written, 3/3 runs on each of JDK 8, 11, 17, 21, 24, 25 and 26. With the change below, B throws on every one of those JDKs except 24, which was not re-run. close() has the same gap: it can read failure == null and then flush the broken buffers. RotatableWriter takes its own lock before this one, so the locks are always taken in the same order. getFailure() can stay an unsynchronized volatile read.

    @Override
    public void write(final char[] cbuf, final int off, final int len) throws IOException {
        synchronized (lock) {
            checkNotFailed();
            try {
                writer.write(cbuf, off, len);
            } catch (IOException e) {
                throw fail(e);
            }
        }
    }

    @Override
    public void write(final String str, final int off, final int len) throws IOException {
        synchronized (lock) {
            checkNotFailed();
            try {
                writer.write(str, off, len);
            } catch (IOException e) {
                throw fail(e);
            }
        }
    }

    @Override
    public void flush() throws IOException {
        synchronized (lock) {
            // Also fails the flush of a text written before the failure, which the failure may have dropped.
            checkNotFailed();
            try {
                writer.flush();
            } catch (IOException e) {
                throw fail(e);
            }
        }
    }

    @Override
    public void close() throws IOException {
        synchronized (lock) {
            if (failure != null) {
                // What the buffers still hold is not written: the events of the failed texts are retried.
                stream.close();
            } else {
                writer.close();
            }
        }
    }

Pin: in TextWriterTest, use a stream whose write blocks on a latch and then throws. Thread A flushes. Once A is inside the stream, thread B flushes. Wait until B is BLOCKED or WAITING (on JDK 21 it parks), then release the latch, and assert that B's flush throws IOException. At the head, B's flush returns normally.


issue (non-blocking): A close() that fails does not record the failure, so a rotation can run in the gap and the dropped row's flush succeeds on the new file.

commons/audit/core/src/main/java/org/forgerock/audit/events/handlers/writers/FailFastWriter.java:84, RotatableWriter.java:199, :214, :336

Take StandardCsvWriter with rotation on. A publisher's write triggers a rotation, and writer.close() (:214) fails on a full disk. write() logs that failure, and getFailure() stays null (probe, JDK 8-26). If the scheduled check or the rotate action runs rotate() before the publisher's flush, and the I/O works again, the guard at :199 passes. close() is then a no-op, the file is renamed and a new writer is installed. The publisher's flush succeeds, and its row, which the failed close dropped, is reported as published. In the usual order, the flush hits "Stream closed" and the event is retried.

    @Override
    public void close() throws IOException {
        synchronized (lock) {
            if (failure != null) {
                // What the buffers still hold is not written: the events of the failed texts are retried.
                stream.close();
                return;
            }
            try {
                writer.close();
            } catch (IOException e) {
                // the rotation checks and the next flush fail with it
                fail(e);
                try {
                    // up to JDK 21, BufferedWriter.close() leaves the stream open when its flush fails
                    stream.close();
                } catch (IOException suppressed) {
                    e.addSuppressed(suppressed);
                }
                throw e;
            }
        }
    }

issue (non-blocking): On JDK 8-21, a close() whose final flush fails leaves the file stream open.

commons/audit/core/src/main/java/org/forgerock/audit/events/handlers/writers/FailFastWriter.java:84

If the final flush in BufferedWriter.close() fails, StreamEncoder skips out.close(). A rotation or a shutdown() on a full disk then leaks the file descriptor. Probe: the stream stays open on JDK 8, 11, 17 and 21, and is closed on 24, 25 and 26. 22 and 23 were not checked. At BASE the chain is the same, but FailFastWriter holds the stream and can close it: that is the stream.close() in the catch of the block above.


issue (non-blocking): If startup() after shutdown() throws a RuntimeException, shutDown stays set, so topics that are healthy answer 503.

commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/CsvAuditEventHandler.java:239-251

The loop catches only IOException. When a tamper-evident file cannot be resumed, SecureCsvWriter's constructor throws a RuntimeException (SecureCsvWriter.java:176-177, #340), which skips shutDown = false. The topics after it are not opened, and every publish or rotate on them fails with ServiceUnavailableException until another startup() succeeds. At BASE they opened at their next event. This happens only on a restart, and only while #340 is open. Whether #341 removes the path was not checked.

        try {
            for (String topic : eventTopicsMetaData.getTopics()) {
                // ... unchanged
            }
        } finally {
            shutDown = false;
        }

suggestion (non-blocking): No test fails writer.close() inside a rotation that write() triggers.

commons/audit/core/src/test/java/org/forgerock/audit/events/handlers/writers/RotatableWriterTest.java:481

testDoesNotFailTheWriteOfATextWhenTheRotationAfterItFails makes preRotationAction fail, which happens before RotatableWriter.java:214. A mutant that catches and logs the failed close at :214, then goes on to rename and constructWriter, leaves every test green while the next flush succeeds and the row is lost.

Pin: through the FileStreamOpener constructor, open a stream that fails once the file has reached the maximum size, and write() a text that triggers the size rotation. Assert that write() returns, that the next flush() throws IOException, and that forceRotation() throws.


suggestion (non-blocking): The #364 status mapping is pinned on two of its paths only.

commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/CsvAuditEventHandler.java:330, :474-477, :434, :440, :451

testFailuresOfAuditFileAreServerErrors reaches the 500 of a publish through resetAndReopenWriter (:515), and the 500 of rotate through the branch with no writer (:469). No test reaches :330 or the forceRotation() branches, and no test asserts the BadRequestException that stays for a null topic, an unknown action or an unknown topic. Reverting :477 to a 400, or turning :451 into a 500, survives the suite.

Pin: (a) call handleAction with a null topic, with an unknown action, and with rotate on an unknown topic, and assert isInstanceOf(BadRequestException.class); (b) with rotation enabled, put a CsvWriter whose forceRotation() throws IOException into writers by reflection, and assert that rotate fails with InternalServerErrorException.


suggestion (non-blocking): The newCsvWriter == null || operand that fixes the NPE of the retry is not pinned.

commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/CsvAuditEventHandler.java:317

Without the operand, writeEvent(topic, null, event) throws a NullPointerException, which publishEvent() does not catch. That is the NPE the description says this change fixes. No test reaches this state, and "Not covered by a test" does not list it.

Pin: put a CsvWriter into writers by reflection whose writeEvent() removes its own entry from writers and then throws IOException. Assert that publishEvent() writes the event to a newly opened writer. Without the operand it fails with a NullPointerException.


question (non-blocking): Is it intended that shutdown() of a buffered handler throws InternalServerErrorException once its last records failed?

commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/CsvAuditEventHandler.java:661

AsynchronousTextWriter.flush() now throws the failure of the wrapped writer, and no event has replaced that writer. For the same input, shutdown() returned at BASE and throws a 500 at the head. AuditServiceImpl logs it, but a direct caller of the handler gets it, and every writer is still closed. This matches the unbuffered path. If it is intended, one line in the description covers it. If not, it is a Minor: log the failure instead.


question (non-blocking): Is a 503 intended for an event that is published, during a startup() after shutdown(), to a topic that is not reopened yet?

commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/CsvAuditEventHandler.java:251

The publisher finds no writer and sees shutDown == true, because the mark is cleared after the loop. At BASE the same event succeeded. No caller in this repo restarts a handler, and clearing the mark early would let a racing event open a writer that startup() then overwrites. If the 503 is intended, a Javadoc line on startup() saying not to publish meanwhile settles it.


question (non-blocking): Is an AsynchronousTextWriter that fails for good after one failure acceptable for callers that do not replace it?

commons/audit/core/src/main/java/org/forgerock/audit/events/handlers/writers/AsynchronousTextWriter.java:222

The first failure is kept for the life of the instance. A caller outside this repo that keeps the writer after a transient failure stops writing for good, where BASE logged the failure and went on. Code that calls flush() on the concrete type no longer compiles. The description gives this handler's retry as the reason, and says nothing about other callers. If it is acceptable, say in the class Javadoc that the caller must replace the writer after a failure.


question (non-blocking): Should the API notes say that RotationContext.getWriter() now returns a FailFastWriter instead of a BufferedWriter?

commons/audit/core/src/main/java/org/forgerock/audit/events/handlers/writers/RotatableWriter.java:388

The declared type is Writer, and the hooks in this repo use only Writer. A RotationHooks outside the repo that casts the writer to BufferedWriter, for example to call newLine(), now gets a ClassCastException.

vharseko added a commit that referenced this pull request Oct 18, 2026
… yet (#354)

Fixes #346.

`SecureCsvWriter` writes the CSV header with the first event, so the
audit file of a tamper-evident topic is empty after startup, and after
the `rotate` action of a topic without file rotation, until an event is
published. `CsvAuditEventHandler.getEntries()` passed the `null` header
of such a file to `convertDotNotationToSlashes()`:

- `readEvent()` threw the `NullPointerException` out of the call instead
of answering a promise;
- `queryEvents()` answered `BadRequestException`.

`getEntries()` now returns no entry for a file without a header:
`readEvent()` answers `NotFoundException`, and `queryEvents()` answers
an empty result. This also covers the empty file that a rotation before
the first signature leaves with #342.

## Tests


`CsvAuditEventHandlerTest.testReadingTamperEvidentAuditLogWithNoEventYet`
and `testQueryOnTamperEvidentAuditLogWithNoEventYet`, after startup and
after the `rotate` action. Each case first checks that the audit file is
empty, and fails without the fix as the issue describes. `audit/core`
and `audit/handler-csv` pass locally on JDK 11 and 27.

The change applies cleanly on #341, #342, #347 and #348.
@vharseko
vharseko force-pushed the issue-334-csv-rotate-race branch from 23d9f79 to 1435b55 Compare October 18, 2026 09:51
@vharseko

Copy link
Copy Markdown
Member Author

Round 2: b99fea3, aca5c5a and 1435b55, on top of the earlier commits rebased onto master (#354 and #361 were merged meanwhile; the rebase had no conflict).

issue (blocking): FailFastWriter checks failure outside the buffer's lock. Fixed as you propose: each write and flush checks for a failure, writes, and records its own failure under lock, and so does close(). A probe reproduced it first on JDK 11.0.32, 17.0.20, 21.0.12 and 27: flush A threw, flush B returned, and 0 bytes were written. Pinned by TextWriterTest.testStreamFailsTheFlushThatWaitsForAFailingFlush, which follows your recipe; at the previous head, the second flush returns.

issue: a close() that fails does not record the failure. Fixed as you propose: close() records its failure, so the rotation checks, forceRotation() and the next flush fail with it. Pinned by RotatableWriterTest.testDoesNotRotateAfterTheRotationFailsToCloseTheFile (your suggestion below).

issue: on JDK 8-21, a close() whose final flush fails leaves the file stream open. Fixed by the stream.close() in the catch of the block above. My probes reproduced it on JDK 11.0.32 only. On 17.0.20 and 21.0.12 the stream was closed, both when the final write of the encoder fails and when the flush of a buffer longer than the encoder's fails; your 17 and 21 may be older updates. Pinned by TextWriterTest.testStreamClosesTheOutputStreamWhenTheShutdownFails, which fails at the previous head on JDK 11.

issue: if startup() after shutdown() throws a RuntimeException, shutDown stays set. Fixed with the try/finally you propose. #341 does not remove the path: it turns the failures to resume a file and to load its keystore into an IOException, but other failures of the constructor still throw RuntimeException("Error when initializing a secure CSV writer"). Pinned by CsvAuditEventHandlerTest.testRestartLetsOtherTopicsPublishWhenTamperEvidentFileCannotBeResumed: after a restart where the topic that startup() opens first cannot resume its file, an event of the other topic is published. At the previous head it fails with the ServiceUnavailableException. With #341, startup() opens the other topic, and the test passes as well.

suggestion: no test fails writer.close() inside a rotation that write() triggers. Added as RotatableWriterTest.testDoesNotRotateAfterTheRotationFailsToCloseTheFile: the close of a size rotation that write() triggers fails, and the disk works again before the flush. write() returns, forceRotation() and the flush throw, the file holds only the text written before, and there is no archive. At the previous head, forceRotation() rotates the file. Your mutant, which logs the failed close at :214 and goes on, fails it as well.

suggestion: the #364 status mapping is pinned on two of its paths only. Added testActionsThatTheRequestGetsWrongAreBadRequests (no topic, an unknown action, rotate on an unknown topic) and testActionToRotateFileThatFailsIsServerError (with rotation enabled, a writer whose forceRotation() throws an IOException, and one whose forceRotation() returns false, put into writers by reflection). The second one showed that the false branch could not be pinned: its exception was thrown inside the try whose catch (IOException e) wraps it, as a ResourceException is an IOException, so a 400 there also came out as a 500. The check now runs after the try. A 400 for either branch of forceRotation(), and a 500 for the unknown topic, fail the new tests.

suggestion: the newCsvWriter == null || operand is not pinned. Added testPublishEventOpensWriterWhenTopicIsLeftWithoutOne, as you propose: a writer whose writeEvent() removes its own entry from writers and throws. The event is written once, to a new writer; without the operand, the publish fails with the NullPointerException.

question: shutdown() of a buffered handler throws an InternalServerErrorException once its last records failed. Intended: those records are lost, which shutdown() used to report as a success, and every writer is still closed, as without buffering. The #363 section of the description now says so.

question: a 503 for an event published, during a startup() after shutdown(), to a topic that is not reopened yet. Intended. Before, shutdown() left the closed writers in writers, so that event did not really succeed: with rotation disabled it went to the closed writer and was lost while publishEvent() reported success (#350), and with rotation enabled the retry opened a writer that startup() then replaced in the map without closing it. The Javadoc of startup() now says that until it returns, an event or a rotate action on a topic that it has not opened yet fails with a ServiceUnavailableException; so does the #350 section of the description.

question: an AsynchronousTextWriter that fails for good after one failure. Acceptable, I think: the writers of this package that it wraps, TextWriter.Stream and RotatableWriter, also fail every later write after a failure, so an AsynchronousTextWriter that went on would not write again either. The class Javadoc now states that the caller replaces the writer after a failure, and the #363 section of the description says that code calling flush() on an AsynchronousTextWriter reference has to handle the IOException.

question: RotationContext.getWriter() returns a FailFastWriter instead of a BufferedWriter. Yes, it should be noted: the #365 section of the description now says it, and that a hook that casts it to BufferedWriter gets a ClassCastException.

audit/core, audit/handler-csv, audit/handler-json and audit/handler-syslog pass locally on JDK 11 and 27. One full run on JDK 11 failed CsvWriterTest.shouldCreateNewAuditFileAfterRotation: the 3-second periodic signature ran during the test, and the next event rotated the file, so the archive ended with that event unsigned. That is the case that #342 fixes, unrelated to this PR; the test passed 5 runs in a row on its own, and the next full run passed.

@maximthomas maximthomas left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

praise: Round 2 closes the round-1 race and pins it where a test can.

  • FailFastWriter now checks and records each failure under lock in both write overloads, flush and close (FailFastWriter.java:57-118). A flush that waits for a failing flush now fails, and testStreamFailsTheFlushThatWaitsForAFailingFlush pins it.
  • startup() clears shutDown in a finally (CsvAuditEventHandler.java:256-259), so a restart that throws no longer leaves the handler shut down.
  • testStreamClosesTheOutputStreamWhenTheShutdownFails pins the extra stream.close() in FailFastWriter.close().

issue (non-blocking): shutdown() of a buffered handler still returns normally when the records still queued at shutdown cannot be written.

commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/CsvAuditEventHandler.java:666-695, commons/audit/core/src/main/java/org/forgerock/audit/events/handlers/writers/AsynchronousTextWriter.java:227-233, :263-290

cleanup() turns only the IOException of writer.flush() into the 500. AsynchronousTextWriter.flush() checks the recorded failure and flushes the wrapped writer, but it does not wait for the queue. The records still queued are written by the drain in shutdown(true), inside the close() of the try-with-resources, and a failure there is only counted and logged ("N buffered records could not be written"). Example: the disk fills, the last events are still queued, and the wrapped buffers are empty. Then cleanup's flush succeeds, the drain fails, and shutdown() returns normally. The #363 section says this shutdown() now fails. BASE behaves the same, and AuditServiceImpl.shutdown() only logs a handler's failure (AuditServiceImpl.java:433-437), so this is not a regression.

Or: qualify the #363 sentence to say that shutdown() fails when the records already handed to the wrapped writer could not be written, and that records still queued are counted in the log. I would take this one. The other way is to have cleanup check for a failure only after the queue is drained.


issue (non-blocking): During a startup() after shutdown(), a failed write on a topic that startup() has already reopened gets a 503 instead of the reset and retry.

commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/CsvAuditEventHandler.java:318-326, :224-227

The retry under the write lock throws ServiceUnavailableException whenever shutDown is set, before it looks at the writer. startup() keeps shutDown set until it has opened every topic. So when topic A is reopened and a publish on A fails with a transient IOException while startup() is still opening B, the publish gets a 503 with no reset. BASE reset the writer and wrote the event. The startup() Javadoc promises the 503 only for a topic "that it has not opened yet". The fix is to check shutDown only when the topic has no writer, as the rotate action already does (:470-477):

            // Lookup the current writer directly from the map so we can check if another thread has reset it.
            CsvWriter newCsvWriter = writers.get(topic);
            if (shutDown && newCsvWriter == null) {
                // shutdown() removes the writers it closes, so the event ends here instead of in a new writer
                throw new ServiceUnavailableException("Unable to publish event for topic: " + topic
                        + ", the handler is shut down");
            }
            if (newCsvWriter == null || newCsvWriter == csvWriter) {

A topic that is not opened yet, or one that cleanup() has closed and removed (:675), still gets the 503. The read path (:302-313) stays as it is, since it has no shutDown check.


suggestion (non-blocking): No test pins the synchronized (lock) around FailFastWriter.write().

commons/audit/core/src/main/java/org/forgerock/audit/events/handlers/writers/FailFastWriter.java:69-79, commons/audit/core/src/test/java/org/forgerock/audit/events/handlers/writers/TextWriterTest.java:108

testStreamFailsTheFlushThatWaitsForAFailingFlush races two flushes. Nothing races a write against a failing flush, so a mutant that drops the lock from write(String, int, int) passes the suite. Under that mutant, a publisher that passed checkNotFailed waits on the BufferedWriter lock while the other flush fails, then writes into the broken buffers and returns normally. If its row is longer than the 8192-char buffer, part of the row reaches the file before the retry. A probe on JDK 11.0.25, 17.0.11, 21.0.2, 25.0.2 and 26 showed that a write that long after a failed flush returns normally and its bytes reach the sink.

Pin: a sibling of testStreamFailsTheFlushThatWaitsForAFailingFlush whose second thread calls write(...) instead of flush() while the first flush is held failing, and asserts that the write throws an IOException. At the head the write waits on the FailFastWriter lock and fails in checkNotFailed. Under the mutant it returns normally. On JDK 21 and later it parks on BufferedWriter's InternalLock, so a wait that accepts only BLOCKED times out instead; either way the mutant fails the test.


suggestion (non-blocking): testActionToRotateFileThatFailsIsServerError does not pin the !rotated throw being outside the try.

commons/audit/handler-csv/src/test/java/org/forgerock/audit/handlers/csv/CsvAuditEventHandlerTest.java:709-711, commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/CsvAuditEventHandler.java:480-488

The test pins the status: a 400 on either branch fails it. Moving the throw back inside the try survives, though. The catch (IOException e) wraps the InternalServerErrorException (a ResourceException is an IOException) into InternalServerErrorException("Error when rotating file for topic: access", e), which is still a 500. Only the message and cause that the client sees change.

            AssertJPromiseAssert.assertThat(csvHandler.handleAction(context, "access", rotateRequest))
                    .failedWithException()
                    .isInstanceOf(InternalServerErrorException.class)
                    .hasMessage("Unable to rotate file for topic: access");

suggestion (non-blocking): A startup() retried without shutdown() now leaks the writer that an event opened for a topic the failed startup() did not reach.

commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/CsvAuditEventHandler.java:249, :256-259, :361-364

Take rotation disabled and this sequence: shutdown(), a startup() that throws at topic A, a publish on B, then startup() again. The finally lets the publish open a writer for B, and the second startup() puts its own writer over it without closing it. B's file stream leaks, and with tamper evidence so does its non-daemon signature scheduler. BASE lost that event instead. No owner in this repo or the sibling products does this, since AuditServiceImpl retries startup() only before the first shutdown(). openWriter puts without closing only when it is called from startup(), because resetAndReopenWriter already calls closeWriter first (:522-524). Closing there also covers the writer that a publish before the first startup() opens:

                try {
                    closeWriter(topic);
                    openWriter(topic, auditLogFile);
                } catch (IOException e) {

suggestion (non-blocking): testRestartLetsOtherTopicsPublishWhenTamperEvidentFileCannotBeResumed does not assert that startup() threw.

commons/audit/handler-csv/src/test/java/org/forgerock/audit/handlers/csv/CsvAuditEventHandlerTest.java:623-627

Today the test fails without the finally. Once #341 turns that row into a per-topic IOException, startup() opens the other topic and the test passes without the finally too. Put an assertion that the call threw, a fail(...) right after csvHandler.startup() (the catch (RuntimeException e) does not catch the AssertionError). Then the test fails the day #341 lands, instead of silently passing, and it can be moved to a constructor failure that still throws RuntimeException.


suggestion (non-blocking): TextWriter.Stream.write/flush and AsynchronousTextWriter.flush now declare throws IOException, a source-compatibility change that the description does not mention.

commons/audit/core/src/main/java/org/forgerock/audit/events/handlers/writers/TextWriter.java:82, :87, commons/audit/core/src/main/java/org/forgerock/audit/events/handlers/writers/AsynchronousTextWriter.java:227

Code that calls these public methods through the concrete classes, in a method that does not handle IOException, compiled against master and no longer compiles. Already-compiled callers still link. Callers through the TextWriter interface handled it already. One sentence in the #349/#363 sections would cover it, as #365 does for the RotationContext.getWriter() cast.


nitpick (non-blocking): The comment on the rotate branch for a topic without a writer names only one cause.

commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/CsvAuditEventHandler.java:476

A default rotation whose renameTo fails (:538-544) also leaves the topic without a writer until the next publish. Suggested wording: // no writer: it could not be opened, or a default rotation could not rename the file.


nitpick (non-blocking): "on JDK 11" understates where the close of the buffers leaves the stream open.

commons/audit/core/src/main/java/org/forgerock/audit/events/handlers/writers/FailFastWriter.java:107, commons/audit/core/src/test/java/org/forgerock/audit/events/handlers/writers/TextWriterTest.java:142

The stream was left open on 1.8.0_362, 11.0.25, 17.0.11 and 21.0.2, and closed on 24.0.2 and later. Your probe closed it on 17.0.20 and 21.0.12, so on 17 and 21 it depends on the update. Suggested wording: "on JDK 8 and 11, and on older updates of 17 and 21", here and in the description.

@vharseko

Copy link
Copy Markdown
Member Author

Round 3: 94a5f45, e98592c and da7821c, on top of 1435b55 (master has not moved since round 2).

issue: shutdown() of a buffered handler still returns normally when the records still queued cannot be written. Taken your first way, the description: the #363 section now says that shutdown() fails when the wrapped writer has failed already, or fails to flush the records handed to it, and that the records still queued are written while the writer closes, where a failure is only logged, with their number. Known limits says it too. A flush() that waits for the queue would hold every auto-flushed event until the queue is empty, and TextWriter.shutdown() declares no exception that could carry the failure out of the drain.

issue: during a startup() after shutdown(), a failed write on a reopened topic gets a 503. Fixed as you propose: the retry under the write lock throws the ServiceUnavailableException only when the topic has no writer, and the Javadoc of publishEventWithRetry() says so. Pinned by testPublishEventDuringStartupResetsWriterOfReopenedTopic: after shutdown(), a writer whose write fails is put into writers, as when startup() has reopened the topic; the event is written once, to a new writer. At the previous head it fails with the ServiceUnavailableException. When the same retry runs while shutdown() is in progress, the topic still has its writer, so cleanup() has not reached it yet, and closes the new writer when it does.

suggestion: no test pins the synchronized (lock) around FailFastWriter.write(). Added TextWriterTest.testStreamFailsTheWriteThatWaitsForAFailingFlush, the sibling you describe; both tests now wait through awaitWaiting(), which takes BLOCKED and WAITING. With the lock dropped from write(String, int, int), the new test fails ("Expecting code to raise a throwable") on JDK 27, and the other tests of TextWriterTest, RotatableWriterTest and AsynchronousTextWriterTest pass, as you found.

suggestion: testActionToRotateFileThatFailsIsServerError does not pin the !rotated throw being outside the try. Added your .hasMessage("Unable to rotate file for topic: access"). With the throw moved back inside the try, the test now fails on the message.

suggestion: a startup() retried without shutdown() leaks the writer that an event opened. Fixed as you propose: startup() closes the writer of a topic before it opens a new one. This also covers an older path: AuditServiceImpl.startup() catches only ResourceException, so a RuntimeException of the CSV handler (#340) leaves the service in STARTING, and its next startup() starts the handler again, which replaced the writers of the topics it had opened already without closing them. Pinned by testStartupClosesTheWriterThatItReplaces: a writer put into writers is closed by startup(). At the previous head it is not ("Wanted but not invoked").

suggestion: testRestartLetsOtherTopicsPublishWhenTamperEvidentFileCannotBeResumed does not assert that startup() threw. Added the fail(...) after startup(). The Merging section of the description now says that with #341 the test fails, and that whichever of the two is merged second moves it to a failure of the writer that is still a RuntimeException.

suggestion: the throws IOException of TextWriter.Stream and AsynchronousTextWriter.flush() is not in the description. It has been there since round 2. The #349 section: "write() and flush() of TextWriter.Stream now declare IOException. In this repository only the two CSV writers use the class, through the TextWriter interface, which declared it already; code that calls them on a TextWriter.Stream reference has to handle it." The #363 section: "flush() now throws the failure of the wrapped writer instead of logging it, and declares IOException: code that calls it on an AsynchronousTextWriter reference has to handle it." No change.

nitpick: the comment on the rotate branch for a topic without a writer. Taken your wording.

nitpick: "on JDK 11" understates where the close of the buffers leaves the stream open. Taken your wording, in FailFastWriter, TextWriterTest and the description. A probe of BufferedWriter.close() over a stream that fails left the stream open on 1.8.0_402 and 11.0.32, and closed it on 17.0.20, 21.0.12 and 27, which fits your older updates of 17 and 21.

audit/core, audit/handler-csv, audit/handler-json and audit/handler-syslog pass locally on JDK 11 and 27. The two new tests of CsvAuditEventHandlerTest fail with the fixes reverted.

@vharseko
vharseko requested a review from maximthomas October 19, 2026 07:45
vharseko added a commit that referenced this pull request Oct 19, 2026
…s to resume it (#341)

Fixes #340.

## Failed construction

The `SecureCsvWriter` constructor opened the audit file, and with
rotation a `RotatableWriter` with its rotator thread, before it read the
keys and verified a file it resumes, and closed neither when that
failed. It now closes the writer in its `catch` block; a
`RuntimeException` from that close is added to the original one as
suppressed (`TextWriterAdapter.close()` logs an `IOException` of the
close instead of throwing it). `new HmacCalculator(...)` moves into the
`try` block, since it can fail after the file is opened too.

## Exception type

An `IOException` raised during the construction is now thrown as is
instead of being wrapped in `RuntimeException: Error when initializing a
secure CSV writer`. A topic whose file cannot be resumed, or whose
keystore cannot be loaded, now always fails this way:

- its file fails verification;
- its file cannot be parsed or decoded, as a crash while a row is
written leaves it: a row with fewer columns than the header or an
unclosed quote (`SuperCsvException`), a final signature cut short so
that it no longer decodes as Base64 (`NullPointerException`), a header
cut short to one column (`ArrayIndexOutOfBoundsException`).
`CsvSecureVerifier.verify()` lets these through; the constructor turns
them into an `IOException` that keeps the cause, as
`CsvSecureArchiveVerifier` turns any exception of the verification into
a failed result;
- its headers do not match;
- its keystore is missing or holds no initial key. `JcaKeyStoreHandler`
reads a missing keystore file as an empty keystore, and
`CsvSecureVerifier` failed on it with an `IllegalStateException`. The
constructor now checks the initial key before it verifies the file, and
fails with an `IOException` that names the keystore;
- its keystore cannot be opened or loaded, whether the file is resumed
or not: a directory or a file that cannot be read in its place
(`FileNotFoundException`), an empty keystore, as a crash while it was
stored leaves it, or a keystore stored under another password
(`KeyStoreBuilder` throws an `IllegalStateException` for both), or a
corrupted keystore, on which `KeyStore.load` can throw a
`RuntimeException`, such as a `ClassCastException` or a
`NullPointerException`, before it checks the digest of the keystore. The
constructor turns it into an `IOException` that names the keystore and
keeps the cause. This is not only a file to resume: the keystore is
stored when the writer is constructed, the header only with the first
event, so a topic that got no event keeps an empty file next to its
keystore;
- its keystore holds no current key. The verifier already rejects such a
file ("Final HMAC key is null"); the check after it now throws an
`IOException` too, instead of an `IllegalStateException`.

`CsvAuditEventHandler` catches only an `IOException` there:

- `startup()` logs the failure for the topic and opens the other topics.
Before, the exception left the loop over the topics and
`AuditServiceImpl.startup()`, which catches only a `ResourceException`,
and the audit service stayed in the `STARTING` state.
- A writer reopened at runtime fails with a `BadRequestException`
through `resetAndReopenWriter()`, and `publishEvent()` returns it as a
failed promise. #347 turns it into an `InternalServerErrorException`
(#364).

Behaviour change: the password of a topic's keystore is derived from the
`Password` key of the handler keystore. After that key changes, every
topic that has a keystore, a topic that got no event yet included, now
fails on its own with an `IOException`, which `startup()` logs, instead
of failing the whole startup; a topic without a keystore still starts
with a new one.

Behaviour change: a topic whose file fails verification at startup no
longer keeps the audit service in the `STARTING` state, where every
request got a 503. Its publishes fail, but a read or a query of the
topic returns the rows of the file as they are: `getEntries()` reads the
file through `CsvSecureMapReader`, which drops the HMAC and signature
columns and verifies nothing. Reads have never verified a tamper-evident
file; a row changed while the service runs is returned the same way. The
file is verified by `CsvSecureArchiveVerifier` and when a writer resumes
it.

Other failures, such as a handler keystore without the `Password` or
`Signature` key, or a JVM that cannot create a JCEKS keystore
(`KeyStoreBuilder` throws an `IllegalStateException` whose cause is a
`KeyStoreException`, or a `NoSuchAlgorithmException` for the digest that
checks the keystore), are still wrapped in a `RuntimeException`, so a
misconfiguration still fails the startup.

## Tests

-
`SecureCsvWriterTest.shouldStopRotatorAndFailWithIOExceptionWhenFileCannotBeResumed`:
a written file is resumed with rotation and a size policy, from a thread
of its own `ThreadGroup`, where the rotator creates its thread. Before,
one of the following is done to it: an event row changed after it was
signed, its keystore deleted, the current key removed from its keystore,
its keystore truncated to 0 bytes, its keystore stored under another
password, its keystore replaced by a corrupted one, a row with fewer
columns than the header appended, a quoted value cut short appended, its
final signature cut short by 3 characters, its header cut short to one
column. The construction fails with an `IOException` that gives the
reason, and the rotator thread terminates.
-
`SecureCsvWriterTest.shouldStopRotatorAndFailWithIOExceptionWhenKeystoreOfEmptyFileCannotBeLoaded`:
the same for the empty file of a writer that got no event, whose
keystore is replaced by a directory, stored under another password, or
replaced by a corrupted one.
- The corrupted keystore is a JCEKS keystore whose secret key entry
holds a string in place of the sealed key: `KeyStore.load` throws a
`ClassCastException` on it, checked on JDK 11, 17, 21 and 27.
- Both tests have a 60 s `timeOut`, so a constructor that deadlocks
fails them instead of hanging the fork.
-
`CsvAuditEventHandlerTest.testStartupOpensOtherTopicsWhenTamperEvidentFileCannotBeResumed`:
a tamper-evident handler with two topics, whose file of the topic opened
first fails verification. The `AuditService` reaches the running state,
the other topic accepts an event, and a publish to the failing topic
returns a `BadRequestException`.
- `CsvWriterTest`: a header mismatch on resume is now an `IOException`.

Measured on JDK 27:

- With the `SecureCsvWriter` of `master`, every case of both writer
tests fails, and so do the handler test and
`CsvWriterTest.shouldResumeExistingCsvSecureFile`.
- Dropping the close fails every case of both writer tests
(`[pool-N-thread-1 alive]`).
- Catching only a `SuperCsvException` from the verifier fails the
signature-cut-short and header-cut-short cases.
- Rethrowing the `IllegalStateException` of an unloadable keystore when
the file is not resumed fails the empty-file case with the keystore
stored under another password.
- Catching only the `IOException` and the `IllegalStateException` of the
keystore fails the corrupted-keystore case of both writer tests.
- `audit/handler-csv` passes locally; `SecureCsvWriterTest` also on JDK
11.

Not covered by a test: the open file handle itself, which cannot be
observed portably on POSIX; the path without rotation; and a JVM that
cannot create a JCEKS keystore.

## Not in this PR

- While a topic's file cannot be resumed, every publish to it still
constructs a writer under the handler monitor and verifies the whole
file again; it no longer leaks.
- The `RotatableWriter` constructor leaks its file when
`scheduleRotationAndRetentionChecks()` rejects the check interval: #355.
- The rotator can rotate a resumed file while the constructor still
verifies it: #343, in #355.
- A resumed header with an empty column name fails with a
`NullPointerException`: #353.
vharseko added a commit that referenced this pull request Oct 19, 2026
…#353)

Fixes #345.

`StandardCsvWriter` compared the header of the CSV file it resumes with
the headers of the topic schema in a loop over the header of the file;
the length check before the loop was commented out.

- A file with more columns than the schema, whose first columns match it
(after the last field was removed from the topic schema), threw
`ArrayIndexOutOfBoundsException`. `CsvAuditEventHandler.startup()` logs
an `IOException` and goes on with the next topic, but this exception
escaped it, so the handler failed to start.
- A file with fewer columns than the schema (after a field was added to
the end of the topic schema) was resumed, and the rows appended to it
had more cells than its header, which Super CSV rejects when the topic
is read or queried.
- A header with as many columns as the schema but an empty column name
threw `NullPointerException`, which escaped `startup()` too: Super CSV
reads an empty column name as `null`, and the loop called `equals()` on
the header of the file.
- `null` headers threw a `NullPointerException` without the message of
`checkNotNull`, which ran after the comparison.

`StandardCsvWriter` now compares the lengths and throws "Resuming an
existing CSV file but the headers do not match." when they differ, as
`SecureCsvWriter` does, calls `equals()` on the headers of the topic
schema, which hold no `null`, and checks the headers for `null` before
it reads the file.

`SecureCsvWriter` had the same loop. A tamper-evident file passes the
verification with an emptied column name when that column is empty in
every row, since the row HMAC covers the values only; it now gets the
same `IOException` instead of the `NullPointerException`, which the
constructor wraps in its `RuntimeException` until #341.

## Behavior change

A plain CSV file with fewer columns than the topic schema is no longer
resumed. As with a file whose columns differ in name or order, the
handler logs the error at startup and rejects the events of the topic
with `BadRequestException` until the file is moved away; the writer then
starts a new file with the current header.

## Tests

- `CsvWriterTest.shouldNotResumeCsvFileWithHeadersThatDoNotMatch`, with
one column more and one column less than the schema, and with an empty
column name in the middle and at the end (`child1,,child3`,
`child1,child2,`): the writer throws the `IOException` and leaves the
file as it was.
- `CsvWriterTest.shouldRejectNullHeadersWhenResumingCsvFile`.
- `CsvWriterTest.shouldNotResumeCsvSecureFileWithEmptyColumnName`: a
tamper-evident file whose header lost the name of a column that is empty
in every row. The test accepts the `IOException` of the header check or
of the verification: once #369 covers the column names in the row HMAC,
the same file fails the verification.
-
`CsvAuditEventHandlerTest.testStartupWithAuditFileOfMoreColumnsThanTopicSchema`:
the handler starts, and the events of the topic are rejected with
`BadRequestException`.

Each case fails without the fix. `audit/core` and `audit/handler-csv`
pass locally.

#341, #347, #348 and #369 change the same files; each merges with this
one without conflicts.
… events being written

CsvAuditEventHandler looked up the writer of a topic without a lock. A
publisher that had the writer when the rotate action closed it wrote into
the closed writer: TextWriter.Stream swallows the IOException, so the event
was lost and publishEvent() reported success, and a stale SecureCsvWriter
stored its keystore over the one of the new file. With rotation enabled,
the rotate action could call forceRotation() on a writer that a concurrent
reset had closed.

A read-write lock per topic now guards the writer of the topic and replaces
the handler monitor. Publishers write, and the rotate action rotates a
writer with rotation enabled, under the read lock. The writer is opened,
closed and replaced under the write lock: by the default rotation, the
reset after a failed write, startup and shutdown. The other topics keep
publishing meanwhile. The rotated file is still compressed outside the
lock.

Fixes OpenIdentityPlatform#334
…wn fails instead of being lost

shutdown() closed the writers but left them in the map, and nothing
marked the handler as shut down. An event published afterwards went to
the closed writer of its topic: with rotation disabled it was lost while
publishEvent() reported success, and a tamper-evident writer still
stored its next key, so the file failed verification. With rotation
enabled, the retry opened a new writer that nothing closed. The rotate
action after shutdown rotated the file and opened a new writer too.

shutdown() now marks the handler as shut down before it takes the first
write lock, and removes each writer it closes from the map. A topic
without a writer then gets no new one until startup() has opened the
writers again: the event fails with a ServiceUnavailableException, and
the rotate action finds no writer and fails. The retry under the write
lock rethrows a ResourceException as is, instead of wrapping it into a
BadRequestException.

Fixes OpenIdentityPlatform#350
…ite errors instead of swallowing them

With rotation disabled, the CSV writers write through TextWriter.Stream,
which wrote through a PrintWriter. A PrintWriter never throws: it sets an
error flag that nothing read. A write that failed, on a full disk, on an
I/O error or on a closed stream, was therefore lost while publishEvent()
reported success, the retry never ran, and a tamper-evident writer still
stored the next key after the lost row, so the file failed verification.

TextWriter.Stream now writes through a BufferedWriter over an
OutputStreamWriter, the writers that the PrintWriter wrapped, so write()
and flush() throw the IOException of the stream. The buffers of these
writers are unusable after a failure: the next flush may write nothing
and return, and a close may write a part of the failed text. The stream
therefore fails every write and flush after the first failure, so that
every publisher whose event was in the buffers is told, and shutdown()
then closes the stream without writing what the buffers hold. The
handler retries the events with a new writer, and a tamper-evident
writer no longer stores the key of a row it could not write.

StandardCsvWriter closes its file when it cannot write the header of a
new file in its constructor, which can now fail.

Fixes OpenIdentityPlatform#349
… the cause of the next ones

After a failure, TextWriter.Stream fails every write and flush with "A
previous write to the stream failed". A caller that logs or throws only
the next failure, such as the flush in the finally block of
SecureCsvWriter.writeSignature(), lost the first one, such as a full
disk. The first failure is now the cause of the next ones.

Refs OpenIdentityPlatform#349
…h after a failure

RotatableWriter wrote through a BufferedWriter over an
OutputStreamWriter, whose buffers are unusable after an IOException: the
next flush writes nothing and returns, and a close writes a part of the
failed text. Publishers share the writer, so the flush of the next one
reported success for an event that the failure dropped, the reset after
the failure wrote a truncated row into the file, and a rotation went on
with a new writer, on which such a flush succeeded.

RotatableWriter and TextWriter.Stream now share FailFastWriter, which
fails every write and flush after the first failure, with that failure
as the cause, and closes the stream without writing what the buffers
hold. RotatableWriter does not rotate a file after a failure: the
rotation checks log it, and forceRotation() throws it, until the writer
is replaced. A package-private constructor lets the tests open the file
through a stream that fails.

Fixes OpenIdentityPlatform#365
…records fails the next ones

With buffering enabled, AsynchronousTextWriter writes the records on its
own thread, and only logged a failure of the wrapped writer: the handler
never learned of it, never replaced the writer, and each record logged a
stack trace while the failure lasted.

AsynchronousTextWriter now keeps the first failure of the wrapped writer
and fails the next write() and flush() with it as the cause, so that the
handler retries the event with a new writer. It logs the first failure
with its stack trace, the next ones at debug level, and, at shutdown,
the number of records that could not be written. flush() throws the
failure of the wrapped writer instead of logging it.

Fixes OpenIdentityPlatform#363
…ile as a server error

CsvAuditEventHandler reported an IOException of the audit file as a
BadRequestException (400): a failed write after the reset, a writer that
could not be opened, a file that could not be read or queried, and a
rotation that failed. These are failures of the server, which a client
may retry.

They are now InternalServerErrorException (500), and queryEvents()
adapts its failure with ResourceExceptionsUtil.adapt(). The rotate
action after shutdown() fails with a ServiceUnavailableException (503),
as a publish does. BadRequestException stays for an action without a
topic, an unknown action and an unknown topic.

Fixes OpenIdentityPlatform#364
…ten no longer resets the writer

The handler takes every IOException of a write for an event that is not
in the file, and writes the event again to a new writer. Two writers
threw after the event was written.

SecureCsvWriter stores the next HMAC key after the row is flushed. When
the key could not be stored, the reset closed a writer whose file was
intact, and the new writer failed to verify the file against the stale
keystore, so every later event of the topic failed. The writer now logs
the failure, and the next row stores the key.

RotatableWriter.write() applies the rotation policies after it writes
the text, so a rotation that failed made the handler write the event a
second time. write() now logs the failure, as the scheduled checks do;
a failure of the writer itself still fails the next flush.

Fixes OpenIdentityPlatform#351
… under the writer lock, also when the close fails

A flush that waited for a flush that failed had passed the check for a failure before the failure was recorded, found the buffers empty, and returned: its event was reported as written. Each write and flush now checks for a failure, writes, and records its own failure under the lock of the writer.

A close that failed did not record its failure, so a rotation that ran before the next flush went on with a new writer, on which that flush succeeded for the text that the close had dropped. The close now records its failure, and closes the stream, which the close of the buffers leaves open on JDK 11.
…re fails the writer for good

The class Javadoc states that once the wrapped writer fails, every later write() and flush() fails with that first failure as its cause, so that the caller replaces the writer, as it replaces the writers of this package that it wraps.
…artup() throws, and pin the status of the rotate action

- startup() clears the shutdown mark in a finally block: a writer that throws a RuntimeException (OpenIdentityPlatform#340) left the handler shut down, and every topic that startup() had not opened answered 503 (OpenIdentityPlatform#350). Its Javadoc states that until it returns, an event or a rotate action on a topic that it has not opened yet fails with a ServiceUnavailableException.
- The rotate action throws the exception of a rotation that does not happen after the try of forceRotation(): a ResourceException is an IOException, so the catch wrapped it into another one, whatever its status (OpenIdentityPlatform#364).
- Tests for the BadRequestException of an action that the request gets wrong, the InternalServerErrorException of a rotation that fails, the restart with a file that cannot be resumed, and the retry that opens a writer for a topic left without one.
…topic during startup(), and close the writer that startup() replaces

While startup() reopens the topics after shutdown(), the handler is still shut down, and the retry of a failed write threw a ServiceUnavailableException before it looked at the writer: a transient failure on a topic that startup() had reopened already got a 503 instead of the reset. The retry now fails only for a topic without a writer.

startup() replaced the writer of a topic without closing it: a writer that an event opened before startup(), or after a startup() that threw, was left open, with its file and, with tamper-evident logging, its signature thread. startup() now closes it first.

testRestartLetsOtherTopicsPublishWhenTamperEvidentFileCannotBeResumed now fails if startup() does not throw, so that it does not pass without the fix once OpenIdentityPlatform#341 lands.
…ailing flush fails

Pins the lock around FailFastWriter.write(): without it, a write that waits while a flush fails returns, and puts its event into the buffers that the failure left unusable.

The comments name the JDKs whose BufferedWriter.close() leaves the stream open when its write fails: 8 and 11, and older updates of 17 and 21.
…hat does not happen

testActionToRotateFileThatFailsIsServerError checks the message of the rotate action whose forceRotation() returns false, so that the throw cannot move back into the try whose catch wraps it: the status stays a 500 there, only the message changes.

The comment on the rotate branch for a topic without a writer also names the default rotation that could not rename the file.
…Platform#341 and OpenIdentityPlatform#353 to the server errors

The tests that OpenIdentityPlatform#341 and OpenIdentityPlatform#353 add expect a BadRequestException for a topic
whose file cannot be opened or resumed: with OpenIdentityPlatform#364 the handler answers an
InternalServerErrorException there.

With OpenIdentityPlatform#341, a file that cannot be resumed fails with an IOException, which
startup() reports for the topic, so the restart test no longer saw
startup() throw. It now uses a keystore that the writer loads but cannot
store the first keys of a new file into, which is still a RuntimeException.
@vharseko
vharseko force-pushed the issue-334-csv-rotate-race branch from da7821c to 9934ba6 Compare October 19, 2026 08:25
@vharseko

Copy link
Copy Markdown
Member Author

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

The only conflict of the rebase was in the imports of CsvAuditEventHandlerTest (PublicKey and ArrayList). One more commit, 9934ba6, does what the Merging section said the second of this PR and #341/#353 would have to do:

audit/handler-csv (100 tests), TextWriterTest, AsynchronousTextWriterTest and RotatableWriterTest pass locally. The rebased PR still merges with #342 and #355 without a conflict. The Tests and Merging sections of the description are updated.

@maximthomas maximthomas left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

praise: the new commits fix the round-2 findings in the code that had them.

  • startup() closes the writer it replaces before openWriter() (CsvAuditEventHandler.java:251), so the writer an event opened is no longer leaked.
  • shutDown && newCsvWriter == null (CsvAuditEventHandler.java:324) lets a topic that startup() has already reopened reset its writer instead of answering 503, and testPublishEventDuringStartupResetsWriterOfReopenedTopic pins it.
  • The "JDK 8 and 11, and older updates of 17 and 21" scope of the stream-close comments matches upstream: the JDK-8136895 backport is in jdk-17.0.17-ga and jdk-21.0.8-ga, and not in jdk-17.0.16-ga or jdk-21.0.7-ga.

vharseko added a commit that referenced this pull request Oct 19, 2026
…rotation (#342)

Fixes #339. Fixes #372. Fixes #373.

## Resuming a file with no event since the last rotation

After a rotation, the live file holds the header and the signature
chained from the archive. `CsvSecureVerifier` kept that signature for
the chain but did not count it as a final signature, so the file failed
with `Missing final signature`, and `SecureCsvWriter` could not resume
it after a restart. The signature chained into row 2 now counts as the
final one until an event follows. A file truncated to these two rows
after later events is still rejected, as the current key in its keystore
no longer matches.

## Signatures around a rotation

`SecureCsvWriter` now tracks whether events were written since the last
signature, and signs only then:

- A rotation signs them whether or not the scheduled signature could be
cancelled. When the event that rotated the file was the first one since
a periodic signature, no signature was scheduled yet, and the archive
ended with that event unsigned: `Final HMAC key doesn't match expected
value` (#372).
- No signature is written or scheduled with no event to cover. After a
rotation on write, `writeEvent()` scheduled a signature that `close()`
wrote into the new file over the last HMAC of the previous file, which
the new file does not hold, so it failed at row 3. This is the failure
that `shouldRotateCsvAndKeyStoreFile` asserted for its last archive
(CAUD-225), and such a live file could not be resumed either.
- A rotation before any signature, by the `rotate` action or by a
time-based rotation of a topic with no event since startup, leaves the
new file empty instead of writing an empty chained signature (`,,`), on
which the verifier threw a `NullPointerException` when the writer
resumed the file.
- The header goes in the same write as the first event. Written on its
own, it could rotate the file when a time-based rotation was due, and
that rotation had no event to sign: the archive held only the header and
failed with `Missing final signature`, and the event went into the new
file without a header. This is likely after a restart over the empty
live file that the rotation above leaves: its modification time counts
as the last rotation, and the first event can come before the first
rotation check.

A second `close()` does nothing. As `close()` now always runs the
signature step, which flushes the writer, a second call with rotation
threw `IOException: Stream closed`.

## An event written while the periodic signature completes

`writeEvent()` scheduled a signature only when the scheduled one was
done. The periodic task releases `signatureLock` and flushes the writer
before its `FutureTask` is done, so an event written in this window
scheduled none, and stayed unsigned until the next event, a rotation or
`close()` (#373). A process killed meanwhile left a live file that
failed verification at the next start.

The writer now keeps the scheduled task until it starts signing, in
`pendingSignature`. `writeEvent()` schedules a signature for unsigned
events when no task is pending, and a task clears `pendingSignature`
once it holds the lock, before it signs: an event written after that
comes after its signature, and schedules the next one, whether the task
is done or not. A rotation or `close()` that cancels the scheduled task
clears it too.

A task clears `pendingSignature` only if it is that task.
`cancel(false)` returns `true` for a task that has started and waits for
the lock, as a `FutureTask` stays `NEW` until its `run()` returns, and
the task still runs. With a plain flag, this gives the interleaving that
#373 notes: an event schedules a second task, the first one clears the
flag when it gets the lock, and the next event schedules a third;
`close()` cancels only the last one, and waits for the second up to the
signature interval. The signature task is now one `SignatureTask` per
schedule instead of one shared `Runnable`, so that a task can tell
whether it is the pending one.

## Verifier

`CsvSecureVerifier` also:

- accepts an empty file whose keys match, as the rotation above archives
one;

This replaces the rule of #332, which rejected every file without a
header: a file truncated to nothing after events still fails, as the
current key of its keystore moved on.
`CsvSecureVerifierTest.shouldNotVerifyEmptyFile` now asserts that
failure reason.

- rejects a row 2 signature that is not base64;
- rejects a signature row that holds other values: the data and HMAC
columns of signature rows were not checked, so an event could be written
into them;
- reports a row with neither an HMAC nor a signature as an incorrect
HMAC instead of throwing.

## Tests

- `SecureCsvWriterTest`: resuming after a forced rotation and after a
rotation on write, an event that rotates the file after a periodic
signature, a rotation before the first event, a file truncated to the
chained signature, a malformed or empty chained signature, signature
rows that hold other values, a first event whose write rotates the file,
a second `close()`. `shouldRotateCsvAndKeyStoreFile` now expects every
archive and the live file to pass, with the plain and the `.gz` suffix;
it has 5 archives instead of 6, as the 6th came from the redundant
signature of `close()`.
- `SecureCsvWriterTest.shouldGenerateHMACColumn` has a 60 s time-out. It
fails when `unsignedEvents` is cleared after the signature row is
written instead of before: that row then schedules another signature,
and `close()` waits for it for the whole signature interval.
- `SecureCsvWriterTest`, for #373:
- `shouldSignAnEventWrittenWhileThePeriodicSignatureCompletes`: the
writer's `flush()`, which `writeSignature()` calls once the signature
row is written, writes a second event the first time it runs. A
signature must follow that event, and the live file must pass
verification while the writer is still open. With the `isDone()`
condition it fails: no second signature within 10 s.
-
`shouldSignPeriodicallyAnEventWrittenAfterARotationCancelledTheScheduledSignature`:
a forced rotation cancels the scheduled signature, and the next event
must get a periodic one. It fails when the cancel leaves
`pendingSignature` set.
-
`shouldScheduleNoOtherSignatureWhenARotationSignsWhileTheScheduledOneWaitsForTheLock`:
the test holds the lock until the scheduled signature waits for it,
rotates and writes events, and `close()` must return in less than half
the 3 s interval. When a task clears `pendingSignature` whatever it
holds, `close()` takes 2.7 s.
- `CsvWriterTest.shouldCreateNewAuditFileAfterRotation` verifies the
live file, in place of a commented-out TODO.
- The temporary directories of the `SecureCsvWriterTest` tests this PR
adds or changes are under `target`.

Each fix was disabled in turn, and its test failed. `audit/core` and
`audit/handler-csv` pass locally, and `SecureCsvWriterTest` passed 5
runs in a row.

## Known limits

- The signature chained into row 2 is not authenticated: a live file
with no event since the rotation passes with any base64 value there. No
tool checks the link between files (`CsvSecureArchiveVerifier` verifies
each file on its own), the row can hold no event, and a truncation is
caught by the keys.
- Files written by earlier versions with a signature over the HMAC of
the previous file at row 3, or with an empty chained signature, still
fail verification: the first needs the HMAC of the previous archive, the
second holds nothing to verify. To resume such a live file, move it and
its `.keystore` aside before the restart.

Merging with #347 or #348 does not conflict, and #362 does not touch
these files. #355 conflicts with `master` in the constructor of
`SecureCsvWriter`, and with this PR in no other place.
vharseko added a commit that referenced this pull request Oct 19, 2026
…the resumed file is verified (#355)

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 #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 (#340), and the close that #341 adds in the `catch` block
would find `csvWriter` still `null`: the close goes, and the rest of
#341 applies as is. Its tests that the rotator thread terminates still
hold, as the rotator does not start.
- With #342, #347 and #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.
@vharseko
vharseko merged commit 0d69e94 into OpenIdentityPlatform:master Oct 19, 2026
14 checks passed
@vharseko
vharseko deleted the issue-334-csv-rotate-race branch October 19, 2026 16:43
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment