From 6d8551b31a48a73001aac90334bdc54c2413ac7c Mon Sep 17 00:00:00 2001 From: Chris Thompson <106194718+christhompsongoogle@users.noreply.github.com> Date: Mon, 12 Oct 2026 20:47:10 +0000 Subject: [PATCH] fix: stream downloadable emulator logs to Emulator UI ### Description Fixes an issue where output from downloadable emulators (such as Cloud Firestore and Realtime Database) was written to local disk debug logs but never streamed to the Emulator Suite UI (`/logs`): 1. Parse child process output severity (`INFO`, `WARN`, `ERROR`, `DEBUG`) in `downloadableEmulators.ts` instead of hardcoding `DEBUG`. 2. Configure `WebSocketTransport` in `loggingEmulator.ts` with `level: process.env.DEBUG ? "debug" : "info"`. 3. Set `logger.level = "debug"` in `useConsoleLoggers()` when `process.env.DEBUG` is enabled. ### Scenarios Tested - Unit tests in `src/emulator/downloadableEmulators.spec.ts`, `src/emulator/loggingEmulator.spec.ts`, and `src/logger.spec.ts`. ### Sample Commands ```bash firebase emulators:start firebase emulators:start --debug ``` --- CHANGELOG.md | 1 + src/emulator/downloadableEmulators.spec.ts | 29 ++++++ src/emulator/downloadableEmulators.ts | 24 +++-- src/emulator/loggingEmulator.spec.ts | 103 +++++++++++++++++++++ src/emulator/loggingEmulator.ts | 6 +- src/logger.spec.ts | 37 +++++++- src/logger.ts | 2 + 7 files changed, 193 insertions(+), 9 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index e171e217116..9e3af2394c9 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,3 +4,4 @@ - Fixed a race condition in `SourceTokenScraper` that could cause concurrent function deployments to hang when refreshing an expired source token (#6989). - Fixed an issue where a Function Kit and a functions codebase sharing the same source directory failed `firebase.json` validation. (#11253) - Fixed an issue where Cloud Functions creation did not retry on HTTP 403 service account propagation errors. (#11251) +- Fixed an issue where logs from downloadable emulators (such as Cloud Firestore and Realtime Database) were not streamed to the Emulator Suite UI. diff --git a/src/emulator/downloadableEmulators.spec.ts b/src/emulator/downloadableEmulators.spec.ts index f4dc93448b0..eefd7c74f73 100644 --- a/src/emulator/downloadableEmulators.spec.ts +++ b/src/emulator/downloadableEmulators.spec.ts @@ -102,3 +102,32 @@ describe("downloadDetails", () => { expect(downloadableEmulators.emulatorVersionOverride(Emulators.PUBSUB)).to.equal(fakeVersion); }); }); + +describe("parseLogLevel", () => { + it("should parse SEVERE and ERROR logs as ERROR", () => { + expect(downloadableEmulators.parseLogLevel("SEVERE: Unhandled exception")).to.equal("ERROR"); + expect(downloadableEmulators.parseLogLevel("ERROR: Rules evaluation failed")).to.equal("ERROR"); + expect(downloadableEmulators.parseLogLevel("[error] something failed")).to.equal("ERROR"); + }); + + it("should parse WARNING and WARN logs as WARN", () => { + expect(downloadableEmulators.parseLogLevel("WARNING: Permission denied")).to.equal("WARN"); + expect(downloadableEmulators.parseLogLevel("WARN: Deprecated syntax")).to.equal("WARN"); + expect(downloadableEmulators.parseLogLevel("[warning] check rules")).to.equal("WARN"); + }); + + it("should parse INFO logs as INFO", () => { + expect(downloadableEmulators.parseLogLevel("INFO: Cloud Firestore Emulator running")).to.equal( + "INFO", + ); + expect(downloadableEmulators.parseLogLevel("[info] Listening on port 8080")).to.equal("INFO"); + }); + + it("should default to DEBUG when no higher severity keyword matches", () => { + expect(downloadableEmulators.parseLogLevel("FINE: Detailed trace message")).to.equal("DEBUG"); + expect(downloadableEmulators.parseLogLevel("API endpoint: http://localhost:8080")).to.equal( + "DEBUG", + ); + expect(downloadableEmulators.parseLogLevel("Some informational text")).to.equal("DEBUG"); + }); +}); diff --git a/src/emulator/downloadableEmulators.ts b/src/emulator/downloadableEmulators.ts index 5fc9ae5db41..c50f1aebb93 100755 --- a/src/emulator/downloadableEmulators.ts +++ b/src/emulator/downloadableEmulators.ts @@ -433,6 +433,16 @@ export function requiresJava(emulator: Emulators): boolean { return false; } +/** + * Parses the severity level from a downloadable emulator output line. + */ +export function parseLogLevel(text: string): "INFO" | "WARN" | "ERROR" | "DEBUG" { + if (/\b(SEVERE|ERROR)\b/i.test(text)) return "ERROR"; + if (/\b(WARNING|WARN)\b/i.test(text)) return "WARN"; + if (/\bINFO\b/i.test(text)) return "INFO"; + return "DEBUG"; +} + async function _runBinary( emulator: DownloadableEmulatorDetails, command: DownloadableEmulatorCommand, @@ -492,15 +502,17 @@ async function _runBinary( `${description} logging to ${clc.bold(getLogFileName(emulator.name))}`, ); - emulator.instance.stdout?.on("data", (data) => { - logger.log("DEBUG", data.toString()); + emulator.instance.stdout?.on("data", (data: Buffer) => { + const text = data.toString(); + logger.log(parseLogLevel(text), text); emulator.stdout.write(data); }); - emulator.instance.stderr?.on("data", (data) => { - logger.log("DEBUG", data.toString()); + emulator.instance.stderr?.on("data", (data: Buffer) => { + const text = data.toString(); + logger.log(parseLogLevel(text), text); emulator.stdout.write(data); - if (data.toString().includes("java.lang.UnsupportedClassVersionError")) { + if (text.includes("java.lang.UnsupportedClassVersionError")) { logger.logLabeled( "WARN", emulator.name, @@ -508,7 +520,7 @@ async function _runBinary( ); } - if (data.toString().includes("address already in use")) { + if (text.includes("address already in use")) { const message = `${description} has exited because its configured port ${command.port} is already in use. Are you running another copy of the emulator suite?`; logger.logLabeled("ERROR", emulator.name, message); } diff --git a/src/emulator/loggingEmulator.spec.ts b/src/emulator/loggingEmulator.spec.ts index 94c0dbb8054..ec9ce95e8aa 100644 --- a/src/emulator/loggingEmulator.spec.ts +++ b/src/emulator/loggingEmulator.spec.ts @@ -50,4 +50,107 @@ describe("LoggingEmulator", () => { const receivedMessage = await messagePromise; expect(receivedMessage.message).to.contain("Hello world from unit test!"); }); + + it("should discard debug messages when DEBUG env is not set", async () => { + const originalDebug = process.env.DEBUG; + const originalLevel = logger.level; + delete process.env.DEBUG; + logger.level = "info"; + + try { + emulator = new LoggingEmulator({ port, host: "127.0.0.1" }); + await emulator.start(); + + const ws = new WebSocket(`ws://127.0.0.1:${port}`); + client = ws; + + const received: LogEntry[] = []; + const infoPromise = new Promise((resolve, reject) => { + const timeout = setTimeout(() => { + reject(new Error("Timeout waiting for info message")); + }, 5000); + + ws.on("message", (data) => { + try { + const entry = JSON.parse(data.toString()) as LogEntry; + received.push(entry); + if (entry.message.includes("Info message after debug")) { + clearTimeout(timeout); + resolve(); + } + } catch (e) { + clearTimeout(timeout); + reject(e); + } + }); + }); + + await new Promise((resolve, reject) => { + ws.on("open", () => resolve()); + ws.on("error", (err) => reject(err)); + }); + + logger.debug("Should be ignored"); + logger.info("Info message after debug"); + + await infoPromise; + expect(received.some((m) => m.message.includes("Should be ignored"))).to.be.false; + expect(received.some((m) => m.message.includes("Info message after debug"))).to.be.true; + } finally { + if (originalDebug !== undefined) { + process.env.DEBUG = originalDebug; + } else { + delete process.env.DEBUG; + } + logger.level = originalLevel; + } + }); + + it("should broadcast debug messages when DEBUG env is set", async () => { + const originalDebug = process.env.DEBUG; + const originalLevel = logger.level; + process.env.DEBUG = "true"; + logger.level = "debug"; + + try { + emulator = new LoggingEmulator({ port, host: "127.0.0.1" }); + await emulator.start(); + + const ws = new WebSocket(`ws://127.0.0.1:${port}`); + client = ws; + + const messagePromise = new Promise((resolve, reject) => { + const timeout = setTimeout(() => { + reject(new Error("Timeout waiting for debug message")); + }, 5000); + + ws.on("message", (data) => { + clearTimeout(timeout); + try { + resolve(JSON.parse(data.toString()) as LogEntry); + } catch (e) { + reject(e); + } + }); + }); + + await new Promise((resolve, reject) => { + ws.on("open", () => resolve()); + ws.on("error", (err) => reject(err)); + }); + + logger.debug("Debug message from unit test!"); + + const receivedMessage = await messagePromise; + expect(receivedMessage.level).to.equal("debug"); + expect(receivedMessage.message).to.contain("Debug message from unit test!"); + } finally { + if (originalDebug !== undefined) { + process.env.DEBUG = originalDebug; + } else { + delete process.env.DEBUG; + } + logger.level = originalLevel; + } + }); }); diff --git a/src/emulator/loggingEmulator.ts b/src/emulator/loggingEmulator.ts index 45f90e1bca1..658290729c0 100644 --- a/src/emulator/loggingEmulator.ts +++ b/src/emulator/loggingEmulator.ts @@ -40,7 +40,9 @@ export class LoggingEmulator implements EmulatorInstance { constructor(private args: LoggingEmulatorArgs) {} start(): Promise { - this.transport = new WebSocketTransport(); + this.transport = new WebSocketTransport({ + level: process.env.DEBUG ? "debug" : "info", + }); this.transport.start(this.getInfo()); logger.add(this.transport); return Promise.resolve(); @@ -78,7 +80,7 @@ class WebSocketTransport extends TransportStream { connections = new Set(); history: LogEntry[] = []; - constructor(options = {}) { + constructor(options: TransportStream.TransportStreamOptions = {}) { super(options); this.setMaxListeners(30); } diff --git a/src/logger.spec.ts b/src/logger.spec.ts index ec5bfb1124e..22d46b11200 100644 --- a/src/logger.spec.ts +++ b/src/logger.spec.ts @@ -6,7 +6,13 @@ import * as path from "path"; import * as Transport from "winston-transport"; -import { logger, findAvailableLogFile, resolveLogTarget, useFileLogger } from "./logger"; +import { + logger, + findAvailableLogFile, + resolveLogTarget, + useFileLogger, + useConsoleLoggers, +} from "./logger"; interface FileTransport extends Transport { dirname?: string; @@ -27,10 +33,13 @@ function getLoggerTransports(logObj: unknown): FileTransport[] { describe("logger", () => { const originalEnv = process.env.FIREBASE_DEBUG_PATH; + const originalDebug = process.env.DEBUG; + let originalLevel: string; let testTmpDir: string; beforeEach(() => { delete process.env.FIREBASE_DEBUG_PATH; + originalLevel = logger.level; testTmpDir = fs.mkdtempSync(path.join(os.tmpdir(), "firebase-debug-test-")); }); @@ -40,6 +49,12 @@ describe("logger", () => { } else { delete process.env.FIREBASE_DEBUG_PATH; } + if (originalDebug !== undefined) { + process.env.DEBUG = originalDebug; + } else { + delete process.env.DEBUG; + } + logger.level = originalLevel; sinon.restore(); if (fs.existsSync(testTmpDir)) { fs.rmSync(testTmpDir, { recursive: true, force: true, maxRetries: 5, retryDelay: 50 }); @@ -311,4 +326,24 @@ describe("logger", () => { } }); }); + + describe("useConsoleLoggers", () => { + it("should set root logger level to debug when DEBUG env var is set", () => { + process.env.DEBUG = "true"; + const beforeTransports = [...getLoggerTransports(logger)]; + + useConsoleLoggers(); + + expect(logger.level).to.equal("debug"); + + const afterTransports = getLoggerTransports(logger); + const addedTransports = afterTransports.filter((t) => !beforeTransports.includes(t)); + expect(addedTransports).to.have.lengthOf(1); + expect(addedTransports[0].level).to.equal("debug"); + + for (const t of addedTransports) { + logger.remove(t); + } + }); + }); }); diff --git a/src/logger.ts b/src/logger.ts index ff8dbb5fcc9..8a4d6d2245d 100644 --- a/src/logger.ts +++ b/src/logger.ts @@ -67,6 +67,7 @@ export interface Logger { remove(transport: Transport): Logger; silent: boolean; + level: string; } function expandErrors(logger: winston.Logger): winston.Logger { @@ -297,6 +298,7 @@ export function useFileLogger(logFile?: string): string { */ export function useConsoleLoggers(): void { if (process.env.DEBUG) { + logger.level = "debug"; logger.add( new winston.transports.Console({ level: "debug",