Backport 5.5: AP-25788: Dump log buffer in shutdown hook if not yet initialized#82
Conversation
AP-25788 (NodeLogger may swallow buffered log messages)
There was a problem hiding this comment.
Pull request overview
This PR backports a startup logging reliability fix (AP-25788) to ensure buffered log messages aren’t lost if the JVM shuts down before KNIME logging initialization completes.
Changes:
- Introduces a
LogBuffer.drain()API that returns drained messages plus overflow metadata. - Adds a failsafe shutdown hook in
KNIMELoggerto dump any buffered startup logs to stdout/stderr with a configurable minimum level. - Adds environment variables in
KNIMEConstantsto configure failsafe logging target and minimum level.
Reviewed changes
Copilot reviewed 3 out of 3 changed files in this pull request and generated 4 comments.
| File | Description |
|---|---|
org.knime.core/src/eclipse/org/knime/core/node/logging/LogBuffer.java |
Adds BufferContents and a drain() method; updates draining logic to use the new API. |
org.knime.core/src/eclipse/org/knime/core/node/logging/KNIMELogger.java |
Installs a shutdown hook and implements failsafe emission of buffered startup logs. |
org.knime.core/src/eclipse/org/knime/core/node/KNIMEConstants.java |
Defines env vars to configure failsafe logging output target and minimum level. |
💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
| void drainTo(final Consumer<BufferedLogMessage> consumer) { | ||
| if (!m_logBuffer.isEmpty()) { | ||
| final var contents = drain(); | ||
| if (!contents.isEmpty()) { |
There was a problem hiding this comment.
drainTo() calls drain(), but drain() explicitly documents that callers must synchronize on the LogBuffer instance. drainTo() itself neither synchronizes nor documents the same requirement, so it violates drain()'s contract and is unsafe if invoked without external locking. Consider making drain() (and/or drainTo()) synchronized, or synchronizing internally on this, and update the Javadoc accordingly.
| if (isFailsafeShutdownLoggingActive) { | ||
| emitToFailsafeLoggingTarget(m_name, level, messageSupplier.get(), cause); | ||
| return; |
There was a problem hiding this comment.
In failsafe-shutdown mode, this evaluates messageSupplier.get() unconditionally before the level filter is applied inside emitToFailsafeLoggingTarget(...). That can introduce unexpected side effects and unnecessary work for messages below FAILSAFE_LOGGING_MIN_LEVEL. Consider checking level.isGreaterOrEqual(FAILSAFE_LOGGING_MIN_LEVEL) (or adding a supplier-based overload) before invoking the supplier.
| if (isFailsafeShutdownLoggingActive) { | ||
| emitToFailsafeLoggingTarget(m_name, level, messageSupplier.get(), cause); | ||
| return; | ||
| } |
There was a problem hiding this comment.
Same issue as above: when isFailsafeShutdownLoggingActive becomes true between the outer and inner initialization checks, messageSupplier.get() is still evaluated even if the message would be filtered out by FAILSAFE_LOGGING_MIN_LEVEL. Add a level check before invoking the supplier (or route through a supplier-aware emit method) to preserve lazy-evaluation semantics.
| out.printf("KNIME startup failsafe logging dump: %s. %s buffered. Minimum level: %s.%n", | ||
| reason, countMessages, minLevel); | ||
| if (shouldEmitEvictionNotice) { | ||
| emitToFailsafeLoggingTarget(KNIMELogger.class.getName(), contents.evictionMessageLevel(), | ||
| "[*** Log incomplete: log buffer did wrap around -- %d messages were evicted from buffer in total ***]" | ||
| .formatted(contents.evictedEntries()), | ||
| null, Instant.now()); | ||
| } | ||
| for (final var message : matchingMessages) { | ||
| emitToFailsafeLoggingTarget(message.name(), message.level(), message.message(), message.cause(), | ||
| message.instant()); | ||
| } |
There was a problem hiding this comment.
drainBufferedMessagesTo(PrintStream out, ...) writes the header/footer to out, but the actual log events are emitted via emitToFailsafeLoggingTarget(...), which always prints to the global FAILSAFE_LOGGING_TARGET. This can split the dump across two streams if out is ever different, and makes the out parameter misleading. Consider either emitting everything to out (pass it into emit...) or removing/renaming the out parameter to reflect the fixed target.
AP-25788 (NodeLogger may swallow buffered log messages)