Repository navigation
[#340] Tamper-evident CSV audit: close the file of a writer that fails to resume it - #341
Conversation
cf066a4 to
2cd5fa8
Compare
maximthomas
left a comment
There was a problem hiding this comment.
praise: The close is placed exactly where the leak was, and the tests measure it.
- The
SecureCsvWriterconstructor'scatchnow closescsvWriter, which stops theRotatableWriterrotator. Removing that close turns all five rows ofshouldStopRotatorAndFailWithIOExceptionWhenFileCannotBeResumedred ([pool-N-thread-1 alive]). Measured on JDK 26. - Restoring the
RuntimeExceptionwrapping turnstestStartupOpensOtherTopicsWhenTamperEvidentFileCannotBeResumedred. Measured on JDK 26. readInitialKey() == nullis checked beforeverify(), so a missing keystore fails with a message that names the keystore, not with anIllegalStateExceptionfrom the verifier.
issue (blocking): A resumed file with a row cut short, a wrong column count or an unclosed quote still fails the whole startup, not only its topic.
commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/SecureCsvWriter.java:150, :201-205; commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/CsvSecureVerifier.java:97, :108
CsvSecureVerifier.verify() catches only SecureStorageException. super-csv's SuperCsvException from csvReader.read(header) therefore reaches the constructor's catch, which wraps it in RuntimeException. A probe against super-csv 2.4.0 got "the nameMapping array and the sourceList should be the same size" for a short row and "unexpected end of file while reading quoted column" for an unclosed quote. CsvAuditEventHandler.startup() catches only IOException, so the loop over the topics ends and AuditServiceImpl.startup() leaves the service in STARTING. A crash or a full disk during a write leaves the last row cut short, which is a common way for a file to become unresumable. The description says such a file "now always fails" with an IOException. A header line with one column fails on the same path: header[header.length - 2] throws ArrayIndexOutOfBoundsException.
// SecureCsvWriter.java:149-150 — import org.supercsv.exception.SuperCsvException;
CsvSecureVerifier verifier = new CsvSecureVerifier(csvFile, csvPreference, secureStorage);
final CsvSecureVerifier.VerificationResult verificationResult;
try {
verificationResult = verifier.verify();
} catch (SuperCsvException e) {
// A row cut short by a crash while it was written, or a row with a missing or extra column.
throw new IOException("Resuming an existing CSV file but it cannot be parsed: " + csvFile, e);
}
// CsvSecureVerifier.java:97 — a header with fewer than two columns fails verification
if (header.length < 2 || !(HEADER_HMAC.equals(header[header.length - 2])
&& HEADER_SIGNATURE.equals(header[header.length - 1]))) {Pin: add an unresumableFiles row that appends a line with fewer columns than the header to a written file. At this head it fails with the RuntimeException. With the fix it fails with the IOException.
question (non-blocking): Should an unreadable .keystore next to a new file fail the whole startup, as the description says, or only its topic, as the code now does?
commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/SecureCsvWriter.java:118, :201-203
JcaKeyStoreHandler.init() opens an existing keystore path with KeyStoreBuilder.withKeyStoreFile(). For a mode-000 file or a directory, its new FileInputStream throws FileNotFoundException before anything is wrapped in IllegalStateException. The inner catch takes only IllegalStateException, so this IOException now passes through for a new file too, and startup() logs it for the topic. At base it was wrapped, and the startup failed. The description says a new file next to a keystore that cannot be loaded "still fails as before". Either answer is minor. If per-topic is intended, only the sentence changes. If "as before" is intended, the inner catch also takes IOException and wraps it when !fileAlreadyInitialized.
Pin: a 0-byte CSV next to a directory named <csv>.keystore, asserting the outcome you choose.
question (non-blocking): Is it intended that a topic that never got an event still fails the whole startup after a Password change?
commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/SecureCsvWriter.java:123-125
A topic's keystore is stored when its writer is constructed, but its header is written only with the first event. An idle topic therefore leaves a 0-byte CSV next to a keystore. After the Password key changes, that keystore no longer loads. fileAlreadyInitialized is false, so the IllegalStateException is rethrown and wrapped, and the startup fails, the same as at base. The description says "a topic without a file still starts with a new keystore", which holds only when no keystore is left behind. If this is intended, the sentence needs "and no keystore". If not, dropping the rethrow at :123-125 makes such a topic fail on its own.
issue (non-blocking): The rotator can rotate a resumed file while the file is still being verified. This is pre-existing and not changed by this PR.
commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/SecureCsvWriter.java:104, :239-240, :443-451
constructWriter() builds the RotatableWriter and registers the rotation hooks before the keys are read and verify() runs. The first rotation check runs one check interval later (default 5s). Take a resumed file that is already over maxFileSize or maxFileLifetime and takes longer than that interval to verify. It is renamed while it is being verified, and postRotationAction renames .keystore and swaps in random keys. verify() then reports "Final HMAC key doesn't match" for a valid file that has already been archived. This was traced in the code, not run. Suggested follow-up issue: start the rotation checks only once construction has succeeded.
nitpick (non-blocking): The IOException arm of the new close catch can never fire.
commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/SecureCsvWriter.java:198
TextWriterAdapter.close() calls shutdown(). With rotation, RotatableWriter.shutdown() logs the IOException from its close(). Without rotation, TextWriter.Stream closes a PrintWriter, which swallows the exception. A failed close is therefore logged and not added as suppressed; only a RuntimeException can be. The catch has to stay because the compiler requires it. The description's "a failure of that close is added to the original one as suppressed" could say "a RuntimeException from that close".
2cd5fa8 to
7327f11
Compare
|
Addressed in 7327f11, on top of a rebase onto 1. issue (blocking), a resumed file that cannot be parsed. Fixed, and more widely than the 2. question, an unreadable 3. question, an idle topic after a 4. issue (non-blocking), the rotator during the verification. Agreed, opened as #343, and listed under "Not in this PR". 5. nitpick, the |
maximthomas
left a comment
There was a problem hiding this comment.
praise: The constructor now cleans up after itself, and the round 1 gap on unparseable files is closed.
- The catch closes the writer and keeps a close failure as suppressed (
SecureCsvWriter.java:202-206), so a failed resume no longer leaves the file open or the non-daemon rotator thread running. verify()'sRuntimeExceptions become anIOExceptionthat keeps the cause (SecureCsvWriter.java:151-156), asCsvSecureArchiveVerifierdoes. The rows "row cut short", "quoted value cut short", "signature cut short" and "header cut short" pass on every CI row.assertReopeningFailsWithIOExceptionruns each writer in its ownThreadGroupand asserts that the rotator thread terminates, for resumed files and for empty ones.
issue (non-blocking): A topic keystore with a corrupted byte still fails the whole audit startup.
commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/SecureCsvWriter.java:118-126
For a corrupted JCEKS file, KeyStore.load can throw ClassCastException or NullPointerException (JDK 11 to 26), NegativeArraySizeException (11, 17) or InvalidPathException (25, 26). KeyStoreBuilder.build() wraps only CertificateException | NoSuchAlgorithmException | IOException | KeyStoreException. These exceptions get past the catch at :120, the outer catch wraps them in RuntimeException, and the service stays in STARTING. That is the case this PR already fixes for the CSV file around verify(). A probe over 8196 corrupted variants of a two-key JCEKS found 14 to 64 per JDK that escape as unchecked exceptions. Every truncation is an EOFException and is caught. JDK 27 was not probed. The same block also handles the question on :120 below.
final KeyStoreHandler hmacKeyStoreHandler;
try {
hmacKeyStoreHandler = new JcaKeyStoreHandler(CsvSecureConstants.KEYSTORE_TYPE, keyStoreFile.getPath(),
keyStorePassword);
} catch (IllegalStateException e) {
if (e.getCause() instanceof KeyStoreException || e.getCause() instanceof NoSuchAlgorithmException) {
// The JVM cannot create or check a keystore of this type: a configuration error, not the file.
throw e;
}
// KeyStoreBuilder throws it for a keystore it cannot load: an empty one, left by a crash while it was
// stored, or one stored under another password, after a change of the Password key.
throw new IOException("The keystore " + keyStoreFile + " of the CSV file cannot be loaded.", e);
} catch (IOException | RuntimeException e) {
// A directory or a file it may not read; KeyStore.load also lets a ClassCastException or a
// NullPointerException through for a corrupted file.
throw new IOException("The keystore " + keyStoreFile + " of the CSV file cannot be loaded.", e);
}It needs import java.security.KeyStoreException; and import java.security.NoSuchAlgorithmException;. The keystore reopened after a rotation (:456) is not part of this PR and stays as is.
issue (non-blocking): A resumed file whose header has an empty column name still fails the whole startup.
commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/SecureCsvWriter.java:168
super-csv reads an empty header name as null. verify() checks only the last two header names, and the HMAC skips null values. So a header edited to "" over a column that is empty in every row passes verify(). Then actualHeaders[idx].equals(headers[idx]) throws an NPE outside the verify try, and the outer catch wraps it in RuntimeException. The startup fails, and on a runtime reopen the exception leaves publishEvent(). The line predates this PR, but the comment at :152-154 says that an edited file fails the same way as a file that fails verification.
for (int idx = 0; idx < actualHeaders.length; idx++) {
if (!Objects.equals(actualHeaders[idx], headers[idx])) {
throw new IOException("Resuming an existing CSV file but the headers do not match.");
}
}It needs import java.util.Objects;.
question (non-blocking): Is the IllegalStateException catch meant to cover a JVM that cannot create a JCEKS keystore at all?
commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/SecureCsvWriter.java:120
KeyStoreBuilder.build() calls KeyStore.getInstance inside the same try. It turns that call's KeyStoreException into the same IllegalStateException("Unable to load keystore") (KeyStoreBuilder.java:172-188), on the missing-file branch of JcaKeyStoreHandler too. Take a JVM whose providers lack JCEKS (a FIPS provider list without SunJCE) and a handler keystore that is not JCEKS. Before this PR the startup failed. Now every tamper-evident topic logs "cannot be loaded" and the service starts. The description says a misconfiguration still fails the startup. This is minor either way. If the catch was meant for the file only, the block in the first issue rethrows these failures by their cause. I did not check whether a real FIPS configuration has this provider set.
question (non-blocking): Should read and query refuse a topic whose file failed verification at startup?
commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/CsvAuditEventHandler.java:222-223, :530-554
Before this PR, a file with a row changed after signing kept the service in STARTING, so create, read and query all got 503. Now the service runs. Creates on the topic get 400, or an empty success plus a WARN when CSV is not the query handler (AuditServiceImpl.java:284, :296-298). A query goes through getEntries, which reads the file with a plain CsvMapReader and returns the forged row. The description covers the running service and the per-topic failure, but not the reads. Minor; no change needed in this PR.
question (non-blocking): Is 400 intended when a writer reopened at runtime finds that its file cannot be resumed?
commons/audit/handler-csv/src/main/java/org/forgerock/audit/handlers/csv/CsvAuditEventHandler.java:467-468
The IOException now reaches catch (IOException e) { throw new BadRequestException(e); } in resetAndReopenWriter. Before this PR, the RuntimeException went through the catch in AuditServiceImpl and ResourceExceptionsUtil.adapt and came out as a 500. With CSV as the query handler, a client now gets 400 for a tampered or truncated file on the server. A client that retries on 5xx and drops on 4xx drops the event. Mapping these to InternalServerErrorException in resetAndReopenWriter would also change the existing 400 for the IOExceptions of StandardCsvWriter. Minor.
suggestion (non-blocking): The two new parameterised tests can hang the fork instead of failing.
commons/audit/handler-csv/src/test/java/org/forgerock/audit/handlers/csv/SecureCsvWriterTest.java:407, :426, :473
callInThreadGroup waits with thread.join() and no timeout, and neither test sets timeOut, unlike shouldForceRotationWhileAnotherThreadWritesAnEvent (:277). If a regression deadlocks the constructor, the surefire fork hangs until the CI job times out.
@Test(dataProvider = "unresumableFiles", timeOut = 60_000)
// ...
@Test(dataProvider = "unloadableKeystoresOfEmptyFiles", timeOut = 60_000)note (non-blocking): The Tests section of the description is out of date.
- PR description: the bullet on
withSecureLoggingEnabled()(test keystore, 5-minute signature interval) describes a builder that is already on master. The diff does not change it.
… 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.
…f a writer that fails to resume it When the keys cannot be read or the resumed file fails verification, the SecureCsvWriter constructor now closes the file, and with rotation the RotatableWriter with its rotator thread. A file that cannot be resumed (it fails verification, its headers do not match, its keystore is missing, cannot be loaded or lacks its keys) now fails with an IOException instead of a RuntimeException, so that CsvAuditEventHandler.startup() logs it and opens the other topics, and a publish to the topic fails with a BadRequestException.
… or an unloadable keystore A resumed file with a row, a header or a final signature cut short by a crash made CsvSecureVerifier.verify() throw a RuntimeException: a SuperCsvException, a NullPointerException for a signature that no longer decodes as Base64, an ArrayIndexOutOfBoundsException for a header of one column. The constructor wrapped it, and the startup failed. It now turns it into an IOException, as CsvSecureArchiveVerifier turns it into a failed result. A keystore that cannot be opened or loaded now fails its topic with an IOException also when the file is not resumed. A topic that got no event keeps an empty file next to its keystore, and after a change of the Password key it failed the whole startup.
KeyStore.load lets a RuntimeException, such as a ClassCastException or a NullPointerException, through for a corrupted JCEKS keystore. The constructor now turns it into the IOException that names the keystore, as it does for an empty keystore or one stored under another password. The IllegalStateException of KeyStoreBuilder whose cause is a KeyStoreException or a NoSuchAlgorithmException is rethrown instead: the JVM cannot create or check a JCEKS keystore, a configuration error that still fails the startup. The two parameterised tests of SecureCsvWriterTest get a corrupted-keystore row and a 60 s timeOut.
7327f11 to
3a4b8b3
Compare
|
@maximthomas, round 2 is in 3a4b8b3, on a branch rebased onto the current 1. issue, a corrupted topic keystore. Fixed with your block: the 2. issue, an empty column name in a resumed header. Fixed in #353 ( 3. question, a JVM that cannot create a JCEKS keystore. The catch was meant for the file only. It now rethrows the 4. question, read and query of a topic whose file failed verification. Left as is, and the description now says so, as a second behaviour change. 5. question, 400 for a writer reopened at runtime. That is #364, and #347 fixes it: 6. suggestion, 7. note, the Tests section. The
|
maximthomas
left a comment
There was a problem hiding this comment.
praise: The split keystore catch separates the environment from the file, and the new fixture pins the arm it adds.
SecureCsvWriter.java:122-127rethrows theIllegalStateExceptionwhose cause is aKeyStoreExceptionorNoSuchAlgorithmException, so a JVM that cannot create a JCEKS keystore fails the startup again, as onmaster. The check is sound:KeyStore.loaddeclares noKeyStoreException, and the onlyNoSuchAlgorithmExceptioninJceKeyStore.engineLoadis theSHAdigest. Neither depends on the file (JDK 11-26 sources, jdk-27-ga).corruptKeyStore(SecureCsvWriterTest.java:416-425) is deterministic.KeyStore.loadthrows theClassCastExceptionthat drives the newRuntimeExceptionarm on JDK 11, 17, 21, 24, 25 and 26, run for this review.
…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.
…#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.
…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.
…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.
…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.
#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()`.
…8 on every path (#348) Fixes #336. ## Charset `RotatableWriter` writes in UTF-8, and `CsvSecureUtils.dataToSign()` computes each HMAC over the UTF-8 bytes of the values. `TextWriter.Stream`, which writes when rotation is disabled, and `CsvSecureVerifier` used the platform default charset. With a default charset other than UTF-8 (JDK 11–17 on Windows, or `-Dfile.encoding`), an untampered file with a non-ASCII value failed verification with "The HMac at row N is not correct", the live file too, so the writer could not resume it. With rotation disabled, a character that the platform charset cannot encode, such as a Cyrillic letter in windows-1252, was written as `?`. Every reader and writer of the audit files now uses UTF-8: - `TextWriter.Stream` writes in UTF-8, as `RotatableWriter` does. In this repository only the two CSV writers use it. - `CsvSecureVerifier` reads in UTF-8. - `CsvAuditEventHandler` reads the audit file in UTF-8 for `readEvent` and `queryEvents`, which returned non-ASCII values garbled. - `StandardCsvWriter` reads the header of the file it resumes in UTF-8. A non-ASCII column name failed with "Resuming an existing CSV file but the headers do not match." ## Malformed input `CsvSecureVerifier` decodes with `UTF_8.newDecoder()`, which reports malformed input instead of replacing it with U+FFFD. A file that is not UTF-8 fails with "The file is not valid UTF-8" instead of an HMAC failure, and a byte sequence that is not UTF-8 can no longer pass for a U+FFFD that the writer logged. ## Upgrade On a host whose default charset is not UTF-8 (Windows, JDK 11–17, or `-Dfile.encoding`), the files that the previous version wrote with rotation disabled are in that charset: - A tamper-evident file with a non-ASCII value that this charset encodes (`ü` or `é` in windows-1252) passed verification before and now fails with "The file is not valid UTF-8". When its bytes happen to be valid UTF-8, as some sequences of a multi-byte charset such as MS932 or GBK are, it fails with "The HMac at row N is not correct." instead. This includes the live file, which the writer verifies before it resumes it. Until #341, this failure stops the startup of the whole audit service, not only of the topic: `SecureCsvWriter` wraps it in a `RuntimeException`, which neither `CsvAuditEventHandler.startup()` nor `AuditServiceImpl.startup()` catches. It also leaves the live file open (#340). - A plain CSV file is resumed as it is, so the rows appended after the upgrade are in UTF-8. `readEvent` and `queryEvents` read the rows written before with U+FFFD in place of the bytes that are not UTF-8, and a query no longer matches such a value. A file whose header holds a non-ASCII column name, which only a custom topic schema has, is not resumed: the topic fails with "Resuming an existing CSV file but the headers do not match." On such a host, before the upgrade, stop the service and move aside the files of each topic written with rotation disabled. For a tamper-evident topic, rename `tamper-evident-<topic>.csv` and `tamper-evident-<topic>.csv.keystore` to `tamper-evident-<topic>.csv<timestamp>` and `tamper-evident-<topic>.csv<timestamp>.keystore`, with `<timestamp>` in the format of the CLI's `--suffix` without `.gz` (`-yyyy.MM.dd-HH.mm.ss` by default, as in `tamper-evident-access.csv-2026.10.19-12.00.00`): the file is not compressed. Verify them on that host with the CLI of the previous version, which reads in the platform charset. Do not use the `rotate` action of a version up to 3.2.1 for such a topic: with rotation disabled, it renames only the CSV file, under a `.gz` name although it does not compress it, and the writer of the new file overwrites the keys of the archive in the keystore that it leaves; #332 fixes this in this version. For a plain CSV topic, the `rotate` action is enough. Files written with rotation enabled were in UTF-8 already: they failed verification on such a host, and now pass. On such a host, the files written with rotation disabled are now in UTF-8 too: a tool that reads them must decode them as UTF-8. Rolling back on such a host: the previous version reads in the platform charset, so it fails the tamper-evident files that this version wrote with rotation disabled and a non-ASCII value, the live file included. It reads the non-ASCII values of a plain CSV file that this version wrote with rotation disabled garbled, and does not resume such a file whose header holds a non-ASCII column name. Run the `rotate` action of this version before the rollback, and verify the archives written after the upgrade with the CLI of this version. `TextWriter.Stream` is public: audit-core exports `org.forgerock.audit.events.handlers.writers`. With a default charset other than UTF-8, a caller of `new TextWriter.Stream(out)` outside this repository now gets the UTF-8 bytes of a non-ASCII character, and `getBytesWritten()` counts them; a file that such a caller appends to then mixes two encodings. With a UTF-8 default charset, the output is unchanged. ## Tests - `CsvWriterTest.shouldWriteAndVerifyNonAsciiValuesInUtf8`, with rotation disabled and enabled: the file is in UTF-8 and passes verification. - `CsvWriterTest.shouldNotVerifyFileNotInUtf8`: a file re-encoded in windows-1252 fails with "The file is not valid UTF-8". - `CsvWriterTest.shouldNotResumeFileNotInUtf8`: `SecureCsvWriter` does not resume such a file. - `CsvWriterTest.shouldResumeCsvFileWithNonAsciiHeader`. - `CsvAuditEventHandlerTest.testReadingAuditLogEntryWithNonAsciiValue`. - The plain CSV case of the Upgrade section: `CsvAuditEventHandlerTest.testReadingAuditLogEntryNotInUtf8` resumes a file re-encoded in windows-1252, reads its old row back with U+FFFD and the row appended after the resume as written; `CsvWriterTest.shouldNotResumeCsvFileWithNonAsciiHeaderNotInUtf8` does not resume a file whose header, with a non-ASCII column name, it writes in windows-1252. The bug shows only with a default charset other than UTF-8, so surefire runs the tests of `handler-csv` with `JAVA_TOOL_OPTIONS=-Dfile.encoding=windows-1252`, on every platform and JDK. This replaces a `JAVA_TOOL_OPTIONS` of the environment in these test JVMs. `CsvWriterTest.shouldRunWithDefaultCharsetOtherThanUtf8` fails when the tests run with a UTF-8 default charset, as in a run that does not apply this setting: there, six of the new cases pass against the unfixed code. With windows-1252, every new case but that check fails against the unfixed code, and each of the five changes is caught when reverted alone: the writer, the verifier, the strict decoder, the reader of the handler and the header check. `audit/core` and `audit/handler-csv` pass locally on JDK 11 and 27. ## Not in this PR Found by reading the code in the review of this change, older than it, and not reproduced; filed separately: - #344: the row HMAC does not cover the column boundaries, so an edit that moves characters between adjacent columns keeps it. - #345: `StandardCsvWriter` throws `ArrayIndexOutOfBoundsException` when it resumes a file with more columns than the topic schema. - #346: reading or querying a tamper-evident topic with no event yet throws `NullPointerException`. Fixed since by #354. `TextWriter.Stream` still swallows write failures through `PrintWriter`; that is #349.
Fixes #340.
Failed construction
The
SecureCsvWriterconstructor opened the audit file, and with rotation aRotatableWriterwith 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 itscatchblock; aRuntimeExceptionfrom that close is added to the original one as suppressed (TextWriterAdapter.close()logs anIOExceptionof the close instead of throwing it).new HmacCalculator(...)moves into thetryblock, since it can fail after the file is opened too.Exception type
An
IOExceptionraised during the construction is now thrown as is instead of being wrapped inRuntimeException: 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: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 anIOExceptionthat keeps the cause, asCsvSecureArchiveVerifierturns any exception of the verification into a failed result;JcaKeyStoreHandlerreads a missing keystore file as an empty keystore, andCsvSecureVerifierfailed on it with anIllegalStateException. The constructor now checks the initial key before it verifies the file, and fails with anIOExceptionthat names the keystore;FileNotFoundException), an empty keystore, as a crash while it was stored leaves it, or a keystore stored under another password (KeyStoreBuilderthrows anIllegalStateExceptionfor both), or a corrupted keystore, on whichKeyStore.loadcan throw aRuntimeException, such as aClassCastExceptionor aNullPointerException, before it checks the digest of the keystore. The constructor turns it into anIOExceptionthat 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;IOExceptiontoo, instead of anIllegalStateException.CsvAuditEventHandlercatches only anIOExceptionthere:startup()logs the failure for the topic and opens the other topics. Before, the exception left the loop over the topics andAuditServiceImpl.startup(), which catches only aResourceException, and the audit service stayed in theSTARTINGstate.BadRequestExceptionthroughresetAndReopenWriter(), andpublishEvent()returns it as a failed promise. [#334] CSV audit: the rotate action waits for the events being written #347 turns it into anInternalServerErrorException(CSV audit: a failure to write, open or read the audit file is reported as BadRequestException (400) #364).Behaviour change: the password of a topic's keystore is derived from the
Passwordkey 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 anIOException, whichstartup()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
STARTINGstate, 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 throughCsvSecureMapReader, 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 byCsvSecureArchiveVerifierand when a writer resumes it.Other failures, such as a handler keystore without the
PasswordorSignaturekey, or a JVM that cannot create a JCEKS keystore (KeyStoreBuilderthrows anIllegalStateExceptionwhose cause is aKeyStoreException, or aNoSuchAlgorithmExceptionfor the digest that checks the keystore), are still wrapped in aRuntimeException, 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 ownThreadGroup, 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 anIOExceptionthat 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.KeyStore.loadthrows aClassCastExceptionon it, checked on JDK 11, 17, 21 and 27.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. TheAuditServicereaches the running state, the other topic accepts an event, and a publish to the failing topic returns aBadRequestException.CsvWriterTest: a header mismatch on resume is now anIOException.Measured on JDK 27:
SecureCsvWriterofmaster, every case of both writer tests fails, and so do the handler test andCsvWriterTest.shouldResumeExistingCsvSecureFile.[pool-N-thread-1 alive]).SuperCsvExceptionfrom the verifier fails the signature-cut-short and header-cut-short cases.IllegalStateExceptionof an unloadable keystore when the file is not resumed fails the empty-file case with the keystore stored under another password.IOExceptionand theIllegalStateExceptionof the keystore fails the corrupted-keystore case of both writer tests.audit/handler-csvpasses locally;SecureCsvWriterTestalso 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
RotatableWriterconstructor leaks its file whenscheduleRotationAndRetentionChecks()rejects the check interval: [#343] Tamper-evident CSV audit: construct the rotatable writer once the resumed file is verified #355.NullPointerException: [#345] CSV audit: compare the header lengths when resuming a CSV file #353.