fix(logger): do not synthesize error stack on console.error in logger… - #1948
Conversation
There was a problem hiding this comment.
Code Review
This pull request removes the synthetic Error stack trace generation for string messages in console.error to prevent standard logs and runtime warnings from being misclassified as unhandled exceptions in Cloud Error Reporting. It also introduces a test suite to verify the console patching behavior. The review feedback points out a critical test isolation issue where Node's require cache and pre-existing patches could cause tests to interfere with each other, and provides a robust solution to clear the cache and restore the console using guaranteed unpatched references.
1886d07 to
7297c96
Compare
|
/gemini review |
There was a problem hiding this comment.
Code Review
This pull request updates the console compatibility layer in src/logger/compat.ts to stop synthesizing Error stacks for console.error string logs, ensuring standard Node.js console behavior and preventing misclassification in Cloud Error Reporting. It also adds a comprehensive test suite in spec/logger.spec.ts. The review feedback highlights a bug where calling console methods with no arguments outputs the string "undefined" instead of an empty string, suggesting a fix using rest parameters. Additionally, the feedback recommends adding a test case for empty arguments and resetting global test variables in a beforeEach hook to prevent test pollution.
7297c96 to
a8246b2
Compare
| function patchedConsole(severity: string): (data: any, ...args: any[]) => void { | ||
| return function (data: any, ...args: any[]): void { | ||
| let message = format(data, ...args); | ||
| if (severity === "ERROR") { |
There was a problem hiding this comment.
Are there any cases where we still want this behavior if the message was from an actual stack trace or something? I'm not sure if in addition to fixing a real problem we're regressing in some cases where we actually wanted this behavior. Someone wrote it this way for a reason the first time but I don't know why. I'd be curious if you did any research into this and what you found.
There was a problem hiding this comment.
I looked into the git history to see why it was written this way. logger/compat was originally added in v3 (PR #701) purely as a drop-in shim to output structured JSON without any stack synthesis. In v4 (PR #1161), when the main SDK logger (functions.logger.error) was updated to synthesize stacks for Cloud Error Reporting, that line was copied over to compat.ts as well (and without the instanceof Error check).
While synthesizing a stack makes sense when someone explicitly calls functions.logger.error("..."), doing it in console.error causes Node runtime warnings (like MaxListenersExceededWarning from connection pools) to get decorated with a fake stack trace and misclassified as application crashes in Cloud Error Reporting. It also double-wrapped actual Error objects passed to console.error(err).
Taking this out doesn't regress intended behavior: console.error(err) with real Error objects still outputs the genuine stack trace through util.format, string logs will still be categorized as severity: "ERROR", and the main SDK logger (src/logger/index.ts) remains untouched. This just restores logger/compat to its original intended behavior.
There was a problem hiding this comment.
OK. Thanks for digging a bit more. I'm convinced.
| function patchedConsole(severity: string): (data: any, ...args: any[]) => void { | ||
| return function (data: any, ...args: any[]): void { | ||
| let message = format(data, ...args); | ||
| if (severity === "ERROR") { |
There was a problem hiding this comment.
OK. Thanks for digging a bit more. I'm convinced.
Description
Fixes #1945
Background:
When users import
firebase-functions/logger/compat, it monkeypatches globalconsole.*methods to format logs into structured Cloud Logging JSON lines.Previously,
patchedConsole("ERROR")unconditionally created a syntheticErrorstack for allconsole.errorcalls viamessage = new Error(message).stack || message.This caused two problems:
MaxListenersExceededWarningtriggered when connection pooling with libraries likeaxios) print warnings viaconsole.error.logger/compatintercepted these string warnings and attached a fake stack trace pointing topatchedConsoleinsidecompat.js. Google Cloud Error Reporting then interpreted these harmless warnings as active application crashes in the function runtime.Errorobjects were passed toconsole.error(err),util.format(err)already rendered the callsite stack trace. Wrapping it again innew Error(message).stackresulted in a distortedError: Error: ...double-wrapped stack trace.Changes:
src/logger/compat.ts: Removednew Error(message).stackwrapper frompatchedConsole. String logs and Node runtime warnings toconsole.errorare now output directly withERRORseverity without synthetic stack traces, while actualErrorobjects retain their authentic callsite stack.spec/logger.spec.ts: Added adescribe("compat", ...)test block coveringconsole.log,console.info,console.debug,console.warn, andconsole.error(handling strings, formatted templates, andErrorobjects).Code sample
Release notes
relnote: Fixed an issue where
firebase-functions/logger/compatadded synthetic Error stack traces to stringconsole.errorcalls and Node.js runtime warnings.