Fix CodeQL note-severity alerts: ignored error status of file and stream calls - #814
Conversation
…eam calls Handle the status of File.renameTo/mkdir/createNewFile and InputStream.skip calls that was silently dropped: * SizeLimitInputStream.skip() now accounts only for the bytes the parent stream actually skipped, and ASN1InputStreamReader skips trailing sequence bytes in a loop, failing the decode when they cannot be skipped instead of leaving the reader in the middle of the sequence. * Configuration, schema, task state, LDIF backend and backup descriptor updates are renamed into place with StaticUtils.renameFile(), which reports a failed rename instead of leaving the new data in the temporary file. * Log rotation reports a failed rename, keeps appending to the current file rather than truncating it, and no longer counts the rotation as done. * Directories are created with Files.createDirectories() so that a failure is reported rather than ignored. * LDIFExportConfig creates the export file atomically in FAIL mode and only changes permissions of files it created itself. * The referential integrity plugin reports an update log file it failed to replace, which would otherwise be replayed again on the next startup. The remaining three alerts of this rule are false positives: the queues in LDAPConnectionFactory, LDAPPassThroughAuthenticationPolicyFactory and OnDiskMergeImporter are either unbounded or sized to fit, so offer() always succeeds.
maximthomas
left a comment
There was a problem hiding this comment.
Nice sweep — the ASN.1 fixes and the renameFile() conversions are correct, and the three offer() false positives are rightly left alone. Verified locally: opendj-core + opendj-server-legacy compile clean, and org.forgerock.opendj.io passes (1582 invocations, 0 failures).
The MultifileTextWriter change, however, is reachable with the stock config.ldif and needs rework before merge.
Rotation failure recurses until StackOverflowError (blocker)
opendj-server-legacy/src/main/java/org/opends/server/loggers/MultifileTextWriter.java:611
The new logger.error(...) sits between writer.close() and constructWriter(...):
writer.flush(); writer.close(); // writer now CLOSED
final boolean renamed = currentFile.renameTo(newFile);
if (!renamed) {
logger.error(LocalizableMessage.raw("Unable to rotate log file %s to %s", ...)); // <-- here
}
constructWriter(currentFile, ..., append || !renamed, bufferSize); // writer/outputStream replacedWhen this instance backs the errors log, that call comes straight back in, on the same thread:
rotate() [writer closed, outputStream still the old over-limit MeteredStream]
-> logger.error(...) -> OpenDJLoggerAdapter.publish() -> ErrorLogger.log()
-> TextErrorLogPublisher.log() -> writer.writeRecord() // SAME instance
-> synchronized(this) [reentrant] -> written + size + 1 >= sizeLimit
-> rotate() -> renameTo fails again -> logger.error(...) -> ...
Every gate passes with the shipped opendj-server-legacy/resource/config/config.ldif:
| gate | value |
|---|---|
ds-cfg-asynchronous (cn=File-Based Error Logger) |
false — no async decoupling |
ds-cfg-default-severity |
includes error → isEnabledFor true |
cn=Size Limit Rotation Policy attached |
yes (100 MB) → sizeLimit > 0 |
outputStream.written after failed rename |
seeded file.length(), append=true keeps it ≥ sizeLimit |
The first failed rotation may or may not recurse; constructWriter(append=true) then writes the pending record, pushing the file past sizeLimit, so the next record recurses unconditionally. LogPublisherErrorHandler.handleCloseError has no latch (unlike handleWriteError), so stderr floods until the stack blows.
With sizeLimit == 0 (time-only rotation) you get the mirror image: the record goes to the closed writer and is lost, while lastRotationTime is refreshed anyway (TimeLimitRotationPolicy.java:72 reads it) — deferring the retry a full 7 days. Either way the operator never sees the message in logs/errors, which is the whole point of the fix.
Move the logger.error(...) below constructWriter(...) (where the existing logger.trace already lives).
Failed rotation triggers rotate() on every subsequent record (major)
Same method. constructWriter seeds MeteredStream with file.length(), so append || !renamed leaves the file at/over sizeLimit. writeRecord calls rotate() inline — it is not only driven by RotaterThread:
synchronized(this) {
if (sizeLimit > 0 && outputStream.written + size + 1 >= sizeLimit) {
rotate(); // MultifileTextWriter.java:552
}
...
}Under a persistent failure (read-only log dir; on Windows a target that exists or an open handle) every log record does flush + close + renameTo + reopen + an ERROR line. The old code truncated — data loss, but stable. Please latch the failure and suppress size-triggered attempts until the next RotaterThread tick or a successful rename.
Compressed-schema backup failure now fails LDAP writes (major)
opendj-server-legacy/src/main/java/org/opends/server/core/DefaultCompressedSchema.java:232
if (liveFile.exists()) {
renameFile(liveFile, new File(liveFile.getAbsolutePath() + ".save")); // now throws
}
renameFile(tempFile, liveFile);save() is called from storeAttribute / storeObjectClasses (:65-77), i.e. the entry-encoding write path, and the enclosing catch (Exception) turns this into a DirectoryException with the server error result code. Previously a failed .save rename was ignored and the update still landed on POSIX. An undeletable .save now turns a cosmetic backup problem into a failed add/modify. Suggest keeping the .save step best-effort and making only the tempFile -> liveFile swing fatal.
Wrong argument for ERR_PLUGIN_REFERENT_REPLACE_LOGFILE (minor)
opendj-server-legacy/src/main/java/org/opends/server/plugins/ReferentialIntegrityPlugin.java:869
if (!logFile.delete() || !logFile.createNewFile()) {
logger.error(ERR_PLUGIN_REFERENT_REPLACE_LOGFILE, logFileName); // %s is the *reason*
}
} catch (IOException io) {
logger.error(ERR_PLUGIN_REFERENT_REPLACE_LOGFILE, io.getMessage());The catalog entry is An error occurred replacing the ... update log file: %s, where %s is the reason — as the sibling call two lines down shows. Passing the path yields ...update log file: /path/logs/referint. Pass a reason instead, and make it say the entries will be replayed.
Adjacent infinite loop (pre-existing, major)
opendj-server-legacy/src/main/java/org/opends/server/protocols/LDIFConnectionHandler.java:476-488 — the block directly above the line this PR changes:
if (new File(renamedPath).exists()) {
int i=2;
while (true) {
if (! new File(renamedPath + "." + i).exists()) {
renamedPath = renamedPath + "." + i; // no break
}
i++;
}
}No break on any path, and renamedPath keeps growing (x.2, x.2.3, …) → thread hangs, String grows until OOM. Reachable when two failed LDIF runs land in the same GMT second. Not introduced here, but it is exactly this sweep's defect class, one line from the diff.
Nits
- Misleading rotate comment:
// Do not overwrite an already rotated file—File.renameTodoes overwrite on POSIX. WithTimeStampNaming's second-granularity names (yyyyMMddHHmmss'Z'), two rotations in the same second silently destroy the earlier file and report success.renamed == falseis in practice a Windows / read-only /EXDEVpath. - Same bug left in the same file:
MultifileTextWriter.java:426-427doesfile.delete(); totalFilesCleaned++;— structurally identical to thetotalFilesRotated++-after-failed-renameTobug fixed 180 lines below. - Redundant deletes not dropped: still present immediately before a
renameFile()that already deletes the target —types/BackupDirectory.java:336,backends/task/TaskScheduler.java:1258,config/ConfigurationHandler.java:825,backends/LDIFBackend.java:289.BackupDirectory.java:311also still ignoresdir.mkdirs()while equivalent sites were converted toFiles.createDirectories. - New failure surface for an unused directory:
quicksetup/installer/InstallerHelper.java:984—Files.createDirectories(libDir)is the last statement in the method and everything consuminglibDiris commented out, yet it can now abort an install step wheremkdir()was silent. - Startup behaviour change:
config/ConfigurationHandler.java:1612-1617—config-changes.ldifrename failures now propagate toInitializationException, so a read-only config dir or a stale non-deletableconfig.ldif.prechangesprevents startup. Intended, but worth a release note. Also consider naming.prechangesin the message: if the second rename fails,config.ldifno longer exists. - Raw message for a new ERROR:
LocalizableMessage.rawinMultifileTextWriterbypasses the catalog. There is precedent, but a new ERROR in the logging subsystem is better as aLoggerMessagesentry — as theChangelogExceptionadded in this same PR correctly does. - No tests: cheap and valuable additions —
SizeLimitInputStream.getBytesRead()after a shortskip();readEndSequence()with trailing components over aBufferedInputStream(the case that motivatedskipFully); and aMultifileTextWriterrotation-failure test (pre-create the rotated name) asserting append-not-truncate,totalFilesRotatedunchanged, and no recursion.
Not re-run locally: the opendj-server-legacy suite (needs -Pprecommit). CI was still queued at review time, including all three windows-latest jobs — the ones most relevant to the renameTo behaviour above.
* MultifileTextWriter reports a failed rotation after the writer has been re-opened, and latches the failure so that neither the report nor the size triggered rotation is repeated until a rotation succeeds. When this writer backs the error log, the report used to re-enter writeRecord() through a writer which had just been closed and was still over the size limit, and recursed until the stack blew up. lastRotationTime is only refreshed on a successful rotation, so a time based policy retries on the next interval instead of waiting for a whole new period, and the message moved from LocalizableMessage.raw() to the message catalog. * Log files a retention policy fails to delete are no longer counted as cleaned, and the failure is reported once. * DefaultCompressedSchema keeps a copy of the previous token data on a best effort basis again: save() runs on the entry encoding path, so an undeletable ".save" file turned a backup problem into a failed add or modify. Only the temporary file swing stays fatal. * The referential integrity plugin uses a dedicated message when it cannot replace the update log file, instead of passing a path where the catalog entry expects a reason, and says that the records will be processed again. * Drop the four explicit deletes left immediately before a renameFile() which already deletes and checks the target, create the backup directory with Files.createDirectories(), and remove the creation of an instance "lib" directory whose only consumer is commented out. * Add regression tests for SizeLimitInputStream.getBytesRead() after a short skip, for readEndSequence()/skipElement() over a BufferedInputStream and for the rotation failure of a writer backing the error log, which reproduces the StackOverflowError against the previous code.
|
Thanks — the analysis of the rotation path is correct, including the reachability through the shipped Rotation failure recurses until StackOverflowError (blocker) — fixedConfirmed end to end:
if (renamed)
{
logger.trace("Log file %s rotated and renamed to %s", currentFile, newFile);
totalFilesRotated++;
rotationFailed = false;
lastRotationTime = TimeThread.getCalendar();
}
else if (!rotationFailed)
{
rotationFailed = true;
logger.error(ERR_LOGGER_ERROR_ROTATING_FILE, currentFile, newFile);
}You were right about the Failed rotation triggers
|
| test | against the previous code |
|---|---|
SizeLimitInputStreamTestCase.testSkipAccountsForTheBytesActuallySkipped |
expected:<3> but was:<16> |
SizeLimitInputStreamTestCase.testSkipStopsAtTheEndOfTheParentStream |
fails |
ASN1InputStreamReaderTestCase.testDecodeSequenceIncompleteReadOverBufferedStream |
fails |
ASN1InputStreamReaderTestCase.testSkipElementOverBufferedStream |
fails |
MultifileTextWriterTestCase.testFailedRotationOfTheErrorLogDoesNotRecurse |
java.lang.StackOverflowError |
The last one wires a TextErrorLogPublisher to the writer under test and makes the rename fail portably by pre-creating the rotated name as a non-empty directory, so it reproduces exactly the path you described. The other two MultifileTextWriterTestCase cases cover the successful rotation and the append-not-truncate behaviour.
Testing
opendj-core: 676 tests (org.forgerock.opendj.ioplus the newcom.forgerock.opendj.utilcase), all passing.opendj-server-legacy(-Pprecommit):MultifileTextWriterTestCase,AbstractTextAccessLogPublisherTest,DebugLogPublisherTest,LDIFBackendTestCase,ReferentialIntegrityPluginTestCase,TestBackupAndRestore,BackupManagerTestCase,TaskBackendTestCase,SchemaBackendTestCase,TestImportAndExport— 369 tests, all passing.
org.opends.quicksetup.ConfigurationTest fails in my working copy, but for an unrelated local reason: target/package still held a stale opendj-5.1.2-SNAPSHOT-slim.zip containing an already configured instance (db/userRoot/*.jdb, locks/, config.ldif.startok), so setup exits with 3 and "Server Already Configured" before any of this code runs. It passes from a clean build; the CI Windows jobs are the ones worth watching for the renameTo behaviour.
| @@ -622,9 +644,23 @@ private synchronized void rotate() | |||
| errorHandler.handleOpenError(currentFile, e); | |||
| } | |||
|
|
|||
| logger.trace("Log file %s rotated and renamed to %s", currentFile, newFile); | |||
| totalFilesRotated++; | |||
| lastRotationTime = TimeThread.getCalendar(); | |||
| if (renamed) | |||
| { | |||
| logger.trace("Log file %s rotated and renamed to %s", currentFile, newFile); | |||
| totalFilesRotated++; | |||
| rotationFailed = false; | |||
| lastRotationTime = TimeThread.getCalendar(); | |||
| } | |||
| else if (!rotationFailed) | |||
| { | |||
| // The latch must be set before logging: when this writer backs the error log, the message | |||
| // below comes straight back into writeRecord() on this thread. It has to reach a writer which | |||
| // has been re-opened above, and it must not trigger another rotation attempt. | |||
| rotationFailed = true; | |||
| logger.error(ERR_LOGGER_ERROR_ROTATING_FILE, currentFile, newFile); | |||
| } | |||
There was a problem hiding this comment.
constructWriter()logs two permission warnings of its own (:205,:211), and by the time it
runs,outputStreamhas already been re-seeded tofile.length()— over the size limit, since the
failed rename forcesappend. When this writer backs the error log, those warnings re-enter
writeRecord()on this thread whilerotationFailedis stillfalse, so the size check fires and
rotate()is called again: unbounded recursion until the stack blows, which I reproduced against
this branch. Setting the latch before the re-open closes the window;reportkeeps the failure
logged exactly once, so report-once, latch-clear-on-success and thelastRotationTimesemantics
are all unchanged and the new test still passes.
| final boolean renamed = currentFile.renameTo(newFile); | |
| // The latch must be set before the writer is re-opened: constructWriter() logs warnings of its | |
| // own, and when this writer backs the error log they come straight back into writeRecord() on | |
| // this thread, where they must not trigger another rotation attempt. | |
| final boolean report = !renamed && !rotationFailed; | |
| rotationFailed = !renamed; | |
| try | |
| { | |
| // If the file could not be rotated then keep appending to it rather than truncating it. | |
| constructWriter(currentFile, filePermissions, encoding, append || !renamed, | |
| bufferSize); | |
| } | |
| catch (Exception e) | |
| { | |
| logger.traceException(e); | |
| errorHandler.handleOpenError(currentFile, e); | |
| } | |
| if (renamed) | |
| { | |
| logger.trace("Log file %s rotated and renamed to %s", currentFile, newFile); | |
| totalFilesRotated++; | |
| lastRotationTime = TimeThread.getCalendar(); | |
| } | |
| else if (report) | |
| { | |
| logger.error(ERR_LOGGER_ERROR_ROTATING_FILE, currentFile, newFile); | |
| } |
There was a problem hiding this comment.
Applied as-is in 00fd5fa — confirmed: the permission warnings in constructWriter() fire after the stream has been re-seeded with the over-limit file length and before the latch was set, so the window was real.
Since FilePermission.setPermissions is static and there is no portable way to make it fail, the new testWarningDuringReopenAfterFailedRotationDoesNotRecurse drives the same window through the File itself: setPermissions checks exists() exactly where the permission warnings are logged, after the writer has been re-opened, and the hooked file logs a warning through the very error logger this writer backs. Against d465627 it dies with StackOverflowError, the stack cycling through that hook; with the latch set before the re-open it passes and asserts that the warning lands in the log file, that the record which triggered the rotation is not lost, and that the rotation failure is reported exactly once. MultifileTextWriterTestCase passes as a whole (4 tests, -Pprecommit failsafe run).
constructWriter() logs permission warnings of its own, and when the writer backs the error log they re-enter writeRecord() on the same thread over the size limit, where they used to start another rotation attempt: unbounded recursion until the stack blew up. Reported-once, latch-clear-on-success and the lastRotationTime semantics are unchanged.
Addresses 37 of the 40 open
java/ignored-error-status-of-callcode scanning alerts (all alerts still open in the repository are note severity; the warning/error ones were fixed in #791 and #793).Real defects behind the alerts
SizeLimitInputStream.skip()credited the requested byte count instead of what the parent stream actually skipped, sogetBytesRead()could over-report.ASN1InputStreamReadernow skips trailing SEQUENCE bytes in a loop —InputStream.skipmay legitimately skip fewer bytes than requested without reaching EOF, which is exactly whatBufferedInputStreamdoes — and raises a fatal decode error when they cannot be skipped, instead of silently leaving the reader in the middle of the sequence. The same helper is used byskipElement(), which also removes spurious "truncated value" failures on buffered input.MultifileTextWriter.rotate()reported a successful rotation even whenrenameTofailed, and then re-opened the un-rotated file withappend=false, truncating it. The file is now kept and appended to,totalFilesRotatedis not incremented, and the failure is reported — but only after the writer has been re-opened, and behind a latch:cn=File-Based Error Loggeris synchronous, logserror, and has a size limit rotation policy attached), logging from insiderotate()comes straight back intowriteRecord()on the same thread through the reentrant monitor. Logging beforeconstructWriter(...)sent the message to a writer which had just been closed, and left it still over the size limit, so the record triggered another rotation and the pair recursed until the stack blew up. The latch is set before the writer is re-opened, becauseconstructWriter(...)logs permission warnings of its own which re-enterwriteRecord()the same way.renameTo+ re-open + an ERROR line for every single record. Retries are left to theRotaterThread, once per interval, and the latch is cleared by the first successful rename.lastRotationTimeis only refreshed on a successful rotation, so a time based policy asks for a rotation again on the next interval rather than going quiet for a whole period.totalFilesCleaned/lastCleanCount, and the failure is reported once.LDIFExportConfigcreates the export file atomically inFAILmode, closing the TOCTOU window betweenexists()and the creation, and only changes permissions of a file it created itself.Silently dropped write failures
Configuration (
.startok,config-changes.ldif), compressed schema, concatenated schema, task state, LDIF backend and backup descriptor updates are moved into place with the existingStaticUtils.renameFile(), which throws on failure so that the surrounding handlers emit their existing messages and alerts instead of leaving the new data in the temporary file. Redundant explicit deletes of the rename targets were dropped, asrenameFile()performs and checks them.One exception: in
DefaultCompressedSchema.save(), keeping the previous token data asschematokens.dat.savestays best effort and is only logged.save()runs on the entry encoding path, so making that step fatal would turn a backup problem into a failed add or modify. Only the.tmp→ live swing fails the operation.Directories are created with
Files.createDirectories(), a failed creation of the changelog last-rotation-time marker raisesChangelogException, and the remainingcreateNewFile()results are either consumed meaningfully or removed where the output stream creates the file anyway. The creation of the instancelibdirectory inInstallerHelper.writeSetOpenDSJavaHome()is removed rather than checked, since nothing reads that path any more.Upgrade note
config-changes.ldifis now applied withrenameFile(), so a failure to moveconfig.ldifaside or to put the patched file in place propagates as anInitializationExceptioninstead of being ignored. A read-onlyconfigdirectory, or a staleconfig.ldif.prechangesthat cannot be deleted, now prevents startup with an explicit error rather than silently starting from unpatched configuration.Left as false positives
LDAPConnectionFactory:1035,LDAPPassThroughAuthenticationPolicyFactory:548(unboundedConcurrentLinkedQueue) andOnDiskMergeImporter:3126(ArrayBlockingQueuefilled to exactly its capacity) —offer()cannot returnfalsethere, so no code change was made.Testing
New regression tests, each of which fails against the code it covers:
SizeLimitInputStreamTestCase—getBytesRead()after a shortskip()over a partially consumedBufferedInputStream, the cap at the size limit, and a skip that reaches the end of the parent stream.ASN1InputStreamReaderTestCase—readEndSequence()with unread trailing components andskipElement(), both over aBufferedInputStreamwhoseskip()returns short without reaching EOF.MultifileTextWriterTestCase— a successful rotation, a failed rotation (rotated name pre-created as a non-empty directory, whichrenameTorefuses on every platform) asserting append-not-truncate and an unchangedtotalFilesRotated, a failed rotation of a writer wired to aTextErrorLogPublisher, which reproduced theStackOverflowError, and a warning logged while the writer is re-opened after a failed rotation — hooked through theexists()check thatFilePermission.setPermissionsperforms exactly where the permission warnings are logged — which recursed the same way.Suites run:
opendj-core:org.forgerock.opendj.ioandcom.forgerock.opendj.util— 676 tests, all passing.opendj-server-legacy(-Pprecommit):MultifileTextWriterTestCase,AbstractTextAccessLogPublisherTest,DebugLogPublisherTest,LDIFBackendTestCase,ReferentialIntegrityPluginTestCase,TestBackupAndRestore,BackupManagerTestCase,TaskBackendTestCase,SchemaBackendTestCase,TestImportAndExport— 369 tests, all passing. Earlier runs also coveredFileReplicaDBTest,LogFileTest,LogTest,ReplicationEnvironmentTest,TestImportAndExportandAddSchemaFileTaskTestCase.Not in scope
LDIFConnectionHandler.processLDIFFile()contains a pre-existingwhile (true)with nobreak, one line above code this PR touches. It is tracked as #828 rather than fixed here.