Skip to content

[#345] CSV audit: compare the header lengths when resuming a CSV file - #353

Merged
vharseko merged 2 commits into
OpenIdentityPlatform:masterfrom
vharseko:issue-345-csv-resume-header-length
Oct 19, 2026
Merged

vharseko merged 2 commits into
OpenIdentityPlatform:masterfrom
vharseko:issue-345-csv-resume-header-length

Conversation

@vharseko

@vharseko vharseko commented Oct 17, 2026 •

Copy link
Copy Markdown
Member

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 [#344] Tamper-evident CSV audit: sign the column names and the value lengths in the row HMAC #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.

… resuming a CSV file

StandardCsvWriter compared the header of the file it resumes with the
headers of the topic schema over the length of the file header only; the
length check was commented out. A file with more columns threw
ArrayIndexOutOfBoundsException, which escaped CsvAuditEventHandler.startup(),
and a file with fewer columns was resumed with rows longer than its header.
It now throws the IOException in both cases, as SecureCsvWriter does, and
checks the headers for null before it reads the file.
@vharseko vharseko added bug tests Test code changes java Pull requests that update java code labels Oct 17, 2026
@vharseko
vharseko requested a review from maximthomas October 17, 2026 07:33

@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 length check closes both resume failures where they start, and each new test is shown to fail without it.

  • StandardCsvWriter.java:65-67 rejects a length mismatch before the per-column loop, so the more-columns file no longer throws ArrayIndexOutOfBoundsException out of CsvAuditEventHandler.startup(); checkNotNull(headers, ...) now runs before the file is read (:56).
  • With StandardCsvWriter.java reverted to the base, all four new cases fail: both rows of CsvWriterTest.shouldNotResumeCsvFileWithHeadersOfOtherLength, shouldRejectNullHeadersWhenResumingCsvFile, and CsvAuditEventHandlerTest.testStartupWithAuditFileOfMoreColumnsThanTopicSchema.

issue (non-blocking): A resumed header with the right number of columns but an empty column name still throws NullPointerException out of startup.

commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/StandardCsvWriter.java:69

super-csv 2.4.0 getHeader(true) reads an empty header cell (_id,,transactionId or "_id","","transactionId") as null, checked with a probe. That header passes the new length check, and actualHeaders[idx].equals(headers[idx]) throws an NPE. CsvAuditEventHandler.startup() catches only IOException (:222), and AuditServiceImpl.startup() catches only ResourceException (AuditServiceImpl.java:399-400), so the whole audit service fails to start instead of the one topic. This is the same kind of escape the PR closes for the length mismatch, reached through a different input. The base has the same behaviour, so it can be fixed here or in a follow-up.

for (int idx = 0; idx < actualHeaders.length; idx++) {
    if (!headers[idx].equals(actualHeaders[idx])) {
        throw new IOException("Resuming an existing CSV file but the headers do not match.");
    }
}

Pin: a CsvWriterTest case that resumes a file with the header child1,,child3 against the headers {child1, child2, child3} and expects the IOException. At the head it fails with the NPE.

…n resuming a CSV file

Super CSV reads an empty column name as null. Such a header passed the
length check, and the comparison called equals() on it, so
StandardCsvWriter and SecureCsvWriter threw NullPointerException instead
of the IOException that CsvAuditEventHandler.startup() reports for the
topic. Call equals() on the headers of the topic schema, which hold no
null.
@vharseko

Copy link
Copy Markdown
Member Author

Fixed in 4ed28b856: both writers now call equals() on the headers of the topic schema (headers[idx].equals(actualHeaders[idx])), which hold no null, so a header with an empty column name gets the IOException. CsvWriterTest.shouldNotResumeCsvFileWithHeadersThatDoNotMatch (renamed from …WithHeadersOfOtherLength) has two more rows, child1,,child3 and child1,child2,; at 99f3a5de1 both fail with the NPE.

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. CsvWriterTest.shouldNotResumeCsvSecureFileWithEmptyColumnName pins it, and fails at 99f3a5de1 with the NPE wrapped in the RuntimeException of the constructor. Once #369 covers the column names in the row HMAC, the same file fails the verification instead, so the test accepts either IOException.

@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 round-2 commit fixes the empty-column-name NPE where it starts, and the new test is measured to pin it.

  • headers[idx].equals(actualHeaders[idx]) at StandardCsvWriter.java:70 and SecureCsvWriter.java:146 puts the topic-schema header, which cannot be null, on the receiver side; for every non-null pair the result is unchanged.
  • CsvWriterTest.shouldNotResumeCsvSecureFileWithEmptyColumnName fails 1/10 with the NPE against a reverted SecureCsvWriter.java:146, with every sibling module built from this head's sources (-am, JDK 26).

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
vharseko merged commit a60659e into OpenIdentityPlatform:master Oct 19, 2026
14 checks passed
@vharseko
vharseko deleted the issue-345-csv-resume-header-length branch October 19, 2026 08:03
vharseko added a commit to vharseko/commons that referenced this pull request Oct 19, 2026
…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 added a commit that referenced this pull request Oct 19, 2026
#347)

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](#334 (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 (#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:

- the retry under the write lock fails with a
`ServiceUnavailableException`, so the event is reported as lost, and is
written neither to a closed writer nor to a new one. A topic that has a
writer still resets it after a failed write, as `startup()` may have
reopened it already;
- the `rotate` action finds no writer, and fails with a
`ServiceUnavailableException`, as a publish does (#364, below).

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
(#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 (#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` (#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

- The `rotate` action with rotation enabled against a concurrent reset:
the reset needs a write that fails with an `IOException`, which a test
cannot cause with rotation enabled. The same lock covers that path, by
reasoning only.
- The retry of the handler after a write failure with rotation disabled
(#349): a test cannot make the file stream of a writer fail without a
full disk, so the writer tests close the stream instead, and
`TextWriterTest` uses a stream that fails.
- The close in the `StandardCsvWriter` constructor when the header
cannot be written, for the same reason.
- The retry of the handler after a failure with buffering enabled
(#363), for the same reason, and the log of `AsynchronousTextWriter`:
the tests of `audit/core` log through `slf4j-simple`, which a test
cannot read.
- The rotation checks after a failure (#365) run on a timer; they go
through the same `rotate()` as `forceRotation()`, which the test covers.

## 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

- #348 makes `TextWriter.Stream` write in UTF-8. The two conflict in the
imports and the constructor of `TextWriter.Stream`; the merge is `new
FailFastWriter(stream, StandardCharsets.UTF_8)`.
- #341 and #353, merged meanwhile, add tests that expect a
`BadRequestException` for a topic whose file cannot be opened or resumed
(`testStartupOpensOtherTopicsWhenTamperEvidentFileCannotBeResumed`,
`testStartupWithAuditFileOfMoreColumnsThanTopicSchema`). With #364 the
handler answers an `InternalServerErrorException` there, and since the
rebase onto them they expect it. With #341, a file that cannot be
resumed fails with an `IOException`, and `startup()` opens the other
topics, so the restart test now fails the writer with a keystore that
cannot be stored, which is still a `RuntimeException`
(`testRestartLetsOtherTopicsPublishWhenTamperEvidentKeyStoreCannotBeStored`).
- #342 changes the condition that schedules a signature in
`SecureCsvWriter.writeEvent()`, two lines below the key store that this
PR stops throwing for. The two merge without a conflict, and so do this
PR and #355.

## Not in this PR

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

- #340, fixed by #341: a `RuntimeException` from `createCsvWriter()`
escapes `startup()`, `publishEvent()` and `handleAction()`.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

bug java Pull requests that update java code tests Test code changes

Projects

None yet

Development

Successfully merging this pull request may close these issues.

CSV audit: resuming a file with more columns than the topic schema throws ArrayIndexOutOfBoundsException

2 participants