Fix the message in the console log and add the stack trace#354
Conversation
Enhances the console logger to better handle and format errors, including stack traces and error message extraction. It also adds global handlers for uncaught exceptions, unhandled rejections, and process warnings to ensure comprehensive error logging.
Normalizes error handling within the logger, ensuring errors are properly formatted, and their stacks are available. Adds logic to convert non-string messages to JSON strings in the console logger preventing errors when logging objects. Removes debug tap logic that is no longer needed.
Enhances the console logger to handle various message types and formats more effectively. It now correctly processes errors, including those embedded within other objects, and ensures messages are properly stringified, especially when dealing with non-string or symbolic message types. Adds stack trace duplication for debug level logging.
Guarantees that warnings are always converted to Error objects before being passed to the logger. This ensures consistent handling of warning messages, including their stack traces, in the logging system.
|
Important Review skippedAuto reviews are disabled on base/target branches other than the default branch. Please check the settings in the CodeRabbit UI or the You can disable this status message by setting the Note Other AI code review bot(s) detectedCodeRabbit has detected other AI code review bot(s) in this pull request and will avoid duplicating their findings in the review comments. This may lead to a less comprehensive review. WalkthroughThe logger module is refactored to support configurable initialization via an optional options object with defaults, introducing level-wrapping for Error handling, process-wide handlers for uncaught exceptions and unhandled rejections, and enhanced console logger formatting with a modular pipeline for improved message extraction and error detail propagation. Changes
Sequence DiagramssequenceDiagram
participant App as Application
participant Logger as Logger Factory
participant LevelWrapper as Level Wrapper
participant Handler as Log Handler
participant Console as Console Logger
rect rgb(100, 180, 220)
Note over App,Console: Logger Initialization
App->>Logger: makeLogger({loggers, level, meta})
Logger->>Logger: Apply wrapLevel to each level
Logger-->>App: Return wrapped logger instance
end
rect rgb(220, 150, 100)
Note over LevelWrapper,Console: Error Capture Flow
App->>LevelWrapper: logger.error(new Error("msg"))
LevelWrapper->>Handler: Convert to structured event<br/>{level, message, error, stack}
Handler->>Console: Pass structured log
Console-->>App: Formatted output
end
rect rgb(150, 200, 100)
Note over App,Handler: Non-Error Flow
App->>LevelWrapper: logger.info("message")
LevelWrapper->>Handler: Pass through unchanged
Handler->>Console: Format normally
Console-->>App: Formatted output
end
sequenceDiagram
participant Process as Node.js Process
participant Logger as Logger Factory
participant GlobalHandler as Global Handler
participant Console as Console Logger
rect rgb(200, 100, 100)
Note over Process,Console: Uncaught Exception Handler
Process->>Logger: process.on('uncaughtException', ...)
Logger->>GlobalHandler: Attach one-time handler
Note over GlobalHandler: Exception occurs
Process->>GlobalHandler: Emit uncaughtException event
GlobalHandler->>Console: logger.error(exception)
Console-->>Process: Formatted error logged
end
rect rgb(200, 100, 150)
Note over Process,Console: Unhandled Rejection Handler
Process->>Logger: process.on('unhandledRejection', ...)
Logger->>GlobalHandler: Attach one-time handler
Note over GlobalHandler: Promise rejection occurs
Process->>GlobalHandler: Emit unhandledRejection event
GlobalHandler->>Console: logger.error(normalized Error)
Console-->>Process: Formatted rejection logged
end
Estimated code review effort🎯 4 (Complex) | ⏱️ ~45 minutes
Poem
✨ Finishing touches🧪 Generate unit tests (beta)
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
There was a problem hiding this comment.
Pull Request Overview
This PR refactors the console logger to improve message extraction and stack trace handling, and adds global process event handlers for uncaught exceptions and unhandled rejections.
- Refactored message normalization logic into discrete helper functions for better maintainability
- Added support for extracting messages from Symbol.for('message'), embedded errors, and stack traces
- Integrated global process event handlers to automatically log uncaught exceptions, unhandled rejections, and warnings
Reviewed Changes
Copilot reviewed 3 out of 3 changed files in this pull request and generated 11 comments.
| File | Description |
|---|---|
| src/loggers/console.js | Refactored formatter with new helper functions to normalize messages and extract them from various sources (symbols, embedded errors, stacks); changed stack trace capture to always be enabled |
| src/logger.test.js | Added basic tests for error message extraction and stack trace derivation in both JSON and simple formatters |
| src/logger.js | Added level wrapping to handle Error instances, integrated global process event handlers for uncaught exceptions/rejections/warnings, removed JSDoc documentation |
💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
| if (!process.__trojsLoggerHandlersAttached) { | ||
| process.__trojsLoggerHandlersAttached = true | ||
|
|
||
| process.on('uncaughtException', (err) => { | ||
| try { | ||
| logger.error(err instanceof Error ? err : new Error(String(err))) | ||
| } catch { | ||
| // eslint-disable-next-line no-console | ||
| console.error('UNCAUGHT_EXCEPTION', err) | ||
| } | ||
| }) | ||
|
|
||
| process.on('unhandledRejection', (reason) => { | ||
| let err | ||
| if (reason instanceof Error) { | ||
| err = reason | ||
| } else if (typeof reason === 'string') { | ||
| err = new Error(reason) | ||
| } else { | ||
| try { | ||
| err = new Error(JSON.stringify(reason)) | ||
| } catch { | ||
| err = new Error(String(reason)) | ||
| } | ||
| } | ||
| try { | ||
| logger.error(err) | ||
| } catch { | ||
| // eslint-disable-next-line no-console | ||
| console.error('UNHANDLED_REJECTION', err) | ||
| } | ||
| }) | ||
|
|
||
| process.on('warning', (warning) => { | ||
| try { | ||
| logger.warn( | ||
| warning instanceof Error | ||
| ? warning | ||
| : ( | ||
| new Error( | ||
| `${warning.name}: ${warning.message}\n${warning.stack || ''}` | ||
| ) | ||
| ) | ||
| ) | ||
| } catch { | ||
| // eslint-disable-next-line no-console | ||
| console.warn('PROCESS_WARNING', warning) | ||
| } | ||
| }) | ||
| } |
There was a problem hiding this comment.
The check-then-set pattern on process.__trojsLoggerHandlersAttached is not atomic. If multiple loggers are created concurrently, there's a potential race condition where multiple handlers could be attached before any of them sets the flag. Consider using a module-level boolean that's set before any async operations, or ensure logger creation is serialized.
| process.on('uncaughtException', (err) => { | ||
| try { | ||
| logger.error(err instanceof Error ? err : new Error(String(err))) | ||
| } catch { | ||
| // eslint-disable-next-line no-console | ||
| console.error('UNCAUGHT_EXCEPTION', err) | ||
| } | ||
| }) | ||
|
|
||
| process.on('unhandledRejection', (reason) => { | ||
| let err | ||
| if (reason instanceof Error) { | ||
| err = reason | ||
| } else if (typeof reason === 'string') { | ||
| err = new Error(reason) | ||
| } else { | ||
| try { | ||
| err = new Error(JSON.stringify(reason)) | ||
| } catch { | ||
| err = new Error(String(reason)) | ||
| } | ||
| } | ||
| try { | ||
| logger.error(err) | ||
| } catch { | ||
| // eslint-disable-next-line no-console | ||
| console.error('UNHANDLED_REJECTION', err) | ||
| } | ||
| }) | ||
|
|
||
| process.on('warning', (warning) => { | ||
| try { | ||
| logger.warn( | ||
| warning instanceof Error | ||
| ? warning | ||
| : ( | ||
| new Error( | ||
| `${warning.name}: ${warning.message}\n${warning.stack || ''}` | ||
| ) | ||
| ) | ||
| ) | ||
| } catch { | ||
| // eslint-disable-next-line no-console | ||
| console.warn('PROCESS_WARNING', warning) | ||
| } | ||
| }) | ||
| } |
There was a problem hiding this comment.
The global process event handlers (uncaughtException, unhandledRejection, warning) are registered on every logger creation (when the flag isn't set). This creates a tight coupling between logger instances and process-level error handling. If multiple parts of an application create loggers with different configurations, only the first logger's configuration will be used for these global handlers. Consider documenting this behavior or making it opt-in via configuration.
| } | ||
|
|
||
| if (embedded) { | ||
| info.message = embedded.message || embedded.toString() |
There was a problem hiding this comment.
When an embedded error is found, the function unconditionally overwrites info.message even if a valid message already exists. This means that if both info.message and info.error are present, the original message will be lost. The condition should check if info.message is empty or missing before overwriting it, similar to the logic in lines 20-21 of extractSymbolMessage.
| info.message = embedded.message || embedded.toString() | |
| if (!info.message || info.message === '') { | |
| info.message = embedded.message || embedded.toString() | |
| } |
| const embedded | ||
| = (info.error instanceof Error && info.error) |
There was a problem hiding this comment.
Syntax error: Missing assignment operator. The line should be:
const embedded =This will cause a parse error.
| const embedded | |
| = (info.error instanceof Error && info.error) | |
| const embedded = | |
| (info.error instanceof Error && info.error) |
| delete clone.stack | ||
| delete clone.error | ||
| delete clone.exception | ||
| delete clone[SYMBOL_MESSAGE] |
There was a problem hiding this comment.
When finalizing an empty message, several properties are deleted from the clone including level, stack, error, exception, and the symbol. However, there's no deletion of stacktrace which is added by duplicateStackTraceIfDebug. If stacktrace is present in the info object, it might be included in the JSON stringification, which may not be intended.
| delete clone[SYMBOL_MESSAGE] | |
| delete clone[SYMBOL_MESSAGE] | |
| delete clone.stacktrace |
src/loggers/console.js
Outdated
|
|
||
| const simpleFormatter = winston.format.combine( | ||
| ensureErrorProps(), | ||
| winston.format.errors({ stack: true }), |
There was a problem hiding this comment.
The winston.format.errors({ stack: true }) now always captures stack traces regardless of the logger?.debug setting. Previously, stack trace capture was conditional on logger?.debug ?? false. This means stack traces will now be captured even when debug mode is off, which could have performance implications and may expose sensitive information in production logs. The display of stack traces in the output is still controlled by the debug flag at line 119, but the capture happens unconditionally.
| const stringifyNonStringMessage = (info) => { | ||
| if (info.message && typeof info.message !== 'string') { | ||
| try { | ||
| info.message = JSON.stringify(info.message) | ||
| } catch { | ||
| info.message = String(info.message) | ||
| } | ||
| return info | ||
| })(), | ||
| simpleLoggerWithStack | ||
| } | ||
| } | ||
|
|
||
| const deriveMessageFromStack = (info) => { | ||
| if (info.stack && (!info.message || info.message === '')) { | ||
| info.message = stackHead(info.stack) | ||
| } | ||
| } | ||
|
|
||
| const finalizeEmptyMessage = (info) => { | ||
| if (!info.message || info.message === '') { | ||
| const clone = { ...info } | ||
| delete clone.level | ||
| delete clone.stack | ||
| delete clone.error | ||
| delete clone.exception | ||
| delete clone[SYMBOL_MESSAGE] | ||
| const keys = Object.keys(clone) | ||
| info.message = keys.length > 0 ? JSON.stringify(clone) : '' | ||
| } | ||
| } | ||
|
|
||
| const duplicateStackTraceIfDebug = (info) => { | ||
| if ((logger?.debug ?? false) && info.stack) { | ||
| info.stacktrace = info.stack | ||
| } | ||
| } |
There was a problem hiding this comment.
The helper functions extractSymbolMessage, attachEmbeddedError, stringifyNonStringMessage, deriveMessageFromStack, finalizeEmptyMessage, and duplicateStackTraceIfDebug do not return values but modify the info object in-place. For consistency with Winston format functions (which return the info object), these should return info or be clearly documented as side-effect functions.
| if (!process.__trojsLoggerHandlersAttached) { | ||
| process.__trojsLoggerHandlersAttached = true |
There was a problem hiding this comment.
Using process.__trojsLoggerHandlersAttached pollutes the process object with a custom property. This is not a recommended practice as it could conflict with other code or future Node.js features. Consider using a module-level variable or WeakMap to track whether handlers have been attached.
src/loggers/console.js
Outdated
|
|
||
| const jsonFormatter = winston.format.combine( | ||
| ensureErrorProps(), | ||
| winston.format.errors({ stack: true }), |
There was a problem hiding this comment.
The winston.format.errors({ stack: true }) now always captures stack traces regardless of the logger?.debug setting. Previously, stack trace capture was conditional on logger?.debug ?? false. This means stack traces will now be captured even when debug mode is off, which could have performance implications and may expose sensitive information in production logs. The duplicateStackTraceIfDebug function only controls whether stacktrace property is added, not whether the stack is captured initially.
Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com>
Configures the visibility of stack traces in the console logger based on the debug level. It disables stack traces unless the logger's debug level is enabled, reducing verbosity in production environments.
|
@coderabbitai review |
✅ Actions performedReview triggered.
|
|
@coderabbitai summary |
✅ Actions performedSummary regeneration triggered. |
Refines JSDoc comments to improve clarity and accuracy regarding the logger configuration options. The changes clarify the types of the `options` and `options.loggers` parameters, replacing generic `Object` types with more specific descriptions.
There was a problem hiding this comment.
Pull Request Overview
Copilot reviewed 3 out of 3 changed files in this pull request and generated 6 comments.
💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
| * @param {Array<{[key: string]: string}>} [options.loggers=defaultLoggers] - Array of logger transport configurations. | ||
| * @param {string} [options.level='info'] - Minimum log level for the logger. | ||
| * @param {object} [options.meta={}] - Default metadata to include in all log messages. | ||
| * @returns {LoggerType} Winston logger instance with custom level wrappers. |
There was a problem hiding this comment.
The @returns type annotation is incorrect. The function returns a Winston logger instance (winston.Logger), not LoggerType which is the configuration schema type imported from './models/schemas/logger.js'.
Change to: @returns {winston.Logger} Winston logger instance with custom level wrappers.
| * @returns {LoggerType} Winston logger instance with custom level wrappers. | |
| * @returns {winston.Logger} Winston logger instance with custom level wrappers. |
| try { | ||
| logger.error(err instanceof Error ? err : new Error(String(err))) |
There was a problem hiding this comment.
Using process.__trojsLoggerHandlersAttached as a flag to prevent duplicate event handlers has a race condition. If multiple logger instances are created concurrently (e.g., during module initialization), they could both check the flag before either sets it, leading to duplicate event handlers being attached.
Consider using a more robust approach like checking if handlers are already attached by inspecting process.listenerCount() or using a proper synchronization mechanism.
| process.__trojsLoggerHandlersAttached = true | ||
|
|
||
| process.on('uncaughtException', (err) => { | ||
| try { |
There was a problem hiding this comment.
Modifying the process object with custom properties like __trojsLoggerHandlersAttached is not a recommended practice as it pollutes the global namespace and could conflict with other libraries or code using the same pattern.
Consider using a module-level variable instead:
let handlersAttached = false
// Later in code:
if (!handlersAttached) {
handlersAttached = true
// attach handlers...
}| return stack ? `${text}\n${stack}` : text | ||
| }) | ||
| if (info.message instanceof Error) { | ||
| info.message = info.message.message || info.message.toString() |
There was a problem hiding this comment.
The function returns early when info.message instanceof Error, but this happens after checking if (info instanceof Error). However, if info instanceof Error is true and info.message is also an Error, the code on line 49 will execute (extracting the message), but then the function returns without setting the stack. This could lead to missing stack traces for nested errors.
Consider preserving the stack from info.message if it exists:
if (info.message instanceof Error) {
const msgError = info.message
info.message = msgError.message || msgError.toString()
if (!info.stack && msgError.stack) {
info.stack = msgError.stack
}
return
}| info.message = info.message.message || info.message.toString() | |
| const msgError = info.message | |
| info.message = msgError.message || msgError.toString() | |
| if (!info.stack && msgError.stack) { | |
| info.stack = msgError.stack | |
| } |
| * @param {object} [options={}] - Logger configuration options. | ||
| * @param {Array<{[key: string]: string}>} [options.loggers=defaultLoggers] - Array of logger transport configurations. | ||
| * @param {string} [options.level='info'] - Minimum log level for the logger. | ||
| * @param {object} [options.meta={}] - Default metadata to include in all log messages. | ||
| * @returns {LoggerType} Winston logger instance with custom level wrappers. | ||
| * These handlers will log errors and warnings using the logger, and are only attached once per process. |
There was a problem hiding this comment.
@sideeffect is not a standard JSDoc tag. Consider using @sideEffect (with capital E) or standard JSDoc conventions like documenting this behavior in the function description or using @fires for events.
| * @param {object} [options={}] - Logger configuration options. | |
| * @param {Array<{[key: string]: string}>} [options.loggers=defaultLoggers] - Array of logger transport configurations. | |
| * @param {string} [options.level='info'] - Minimum log level for the logger. | |
| * @param {object} [options.meta={}] - Default metadata to include in all log messages. | |
| * @returns {LoggerType} Winston logger instance with custom level wrappers. | |
| * These handlers will log errors and warnings using the logger, and are only attached once per process. | |
| * | |
| * Side effects: This function attaches process-level event handlers for 'uncaughtException', 'unhandledRejection', and 'warning'. | |
| * These handlers will log errors and warnings using the logger, and are only attached once per process. | |
| * | |
| * @fires process#uncaughtException | |
| * @fires process#unhandledRejection | |
| * @fires process#warning | |
| * @param {object} [options={}] - Logger configuration options. | |
| * @param {Array<{[key: string]: string}>} [options.loggers=defaultLoggers] - Array of logger transport configurations. | |
| * @param {string} [options.level='info'] - Minimum log level for the logger. | |
| * @param {object} [options.meta={}] - Default metadata to include in all log messages. | |
| * @returns {LoggerType} Winston logger instance with custom level wrappers. |
| ? warning | ||
| : ( | ||
| new Error( | ||
| `${warning.name}: ${warning.message}\n${warning.stack || ''}` | ||
| ) | ||
| ) | ||
| ) | ||
| } catch { | ||
| // eslint-disable-next-line no-console |
There was a problem hiding this comment.
The 'warning' event handler creates a custom error message by concatenating warning.name, warning.message, and warning.stack, but this assumes warning is a Node.js Warning object with these properties. However, the conditional on line 106 checks if warning instanceof Error, suggesting warnings might not always have these properties.
Consider handling cases where warning.name or warning.message might be undefined:
const message = warning.name && warning.message
? `${warning.name}: ${warning.message}\n${warning.stack || ''}`
: String(warning)
new Error(message)
2 participants
Summary by CodeRabbit
Release Notes
New Features
Improvements
✏️ Tip: You can customize this high-level summary in your review settings.