Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
88 changes: 88 additions & 0 deletions spec/logger.spec.ts
Original file line number Diff line number Diff line change
Expand Up @@ -218,4 +218,92 @@ describe("logger", () => {
});
});
});

describe("compat", () => {
const originalConsole = {
debug: console.debug,
info: console.info,
log: console.log,
warn: console.warn,
error: console.error,
};

before(async () => {
// Patch global console methods
await import("../src/logger/compat");
});
Comment thread
shettyvarun268 marked this conversation as resolved.

beforeEach(() => {
lastOut = "";
lastErr = "";
});

after(() => {
// Restore original console methods so other tests remain unaffected
console.debug = originalConsole.debug;
console.info = originalConsole.info;
console.log = originalConsole.log;
console.warn = originalConsole.warn;
console.error = originalConsole.error;
});

it("should patch console.log with INFO severity", () => {
console.log("test info log");
expectStdout({
severity: "INFO",
message: "test info log",
});
});
Comment thread
shettyvarun268 marked this conversation as resolved.

it("should patch console.log with no arguments", () => {
console.log();
expectStdout({
severity: "INFO",
message: "",
});
});

it("should patch console.debug with DEBUG severity", () => {
console.debug("test debug log");
expectStdout({
severity: "DEBUG",
message: "test debug log",
});
});

it("should patch console.warn with WARNING severity", () => {
console.warn("test warning log");
expectStderr({
severity: "WARNING",
message: "test warning log",
});
});

it("should patch console.error with ERROR severity without creating synthetic stack trace for string messages", () => {
// String error messages should not have synthetic Error stacks added (Issue #1945)
console.error("test error message");
expectStderr({
severity: "ERROR",
message: "test error message",
});
});

it("should patch console.error for Error objects preserving the original stack", () => {
// Error instances should retain their original stack trace without double wrapping
const err = new Error("real error");
console.error(err);
const parsed = JSON.parse(lastErr.trim()) as logger.LogEntry;
expect(parsed.severity).to.eq("ERROR");
expect(parsed.message).to.contain("Error: real error");
expect(parsed.message).to.not.contain("Error: Error: real error");
});

it("should format multiple arguments in console.error", () => {
console.error("failed with code %d: %s", 500, "internal error");
expectStderr({
severity: "ERROR",
message: "failed with code 500: internal error",
});
});
});
});
14 changes: 8 additions & 6 deletions src/logger/compat.ts
Original file line number Diff line number Diff line change
Expand Up @@ -24,12 +24,14 @@ import { format } from "util";
import { CONSOLE_SEVERITY, UNPATCHED_CONSOLE } from "./common";

/** @hidden */
function patchedConsole(severity: string): (data: any, ...args: any[]) => void {
return function (data: any, ...args: any[]): void {
let message = format(data, ...args);
if (severity === "ERROR") {

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

OK. Thanks for digging a bit more. I'm convinced.

message = new Error(message).stack || message;
}
function patchedConsole(severity: string): (...args: unknown[]) => void {
return function (...args: unknown[]): void {
// Format arguments matching standard Node console.* behavior.
// Unlike logger.error, we intentionally do NOT synthesize an Error stack for
// console.error so that Node.js runtime warnings (e.g. MaxListenersExceededWarning)
// and standard console.error string logs are not misclassified as unhandled exceptions
// in Cloud Error Reporting.
const message = format(...args);

UNPATCHED_CONSOLE[CONSOLE_SEVERITY[severity]](JSON.stringify({ severity, message }));
};
Expand Down
Loading