diff --git a/CHANGELOG.md b/CHANGELOG.md index c79a6c643f6..e497319306f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,3 +1,4 @@ - Added `appcheck:providers:list`, `appcheck:providers:get` and `appcheck:providers:set` to configure App Check attestation providers for an app. - Added `appcheck:apps:list` to show every app with its configured App Check providers. -- Added web app support for Crashlytics MCP tools and prompts.>>>>>>> main +- Added web app support for Crashlytics MCP tools and prompts. +- Fixed `firebase deploy` leaving the Python discovery admin server (`serving.py`) running after a killed or wedged deploy, which caused later deploys to hang indefinitely on `connect ETIMEDOUT` (#10847). diff --git a/src/deploy/functions/runtimes/python/index.spec.ts b/src/deploy/functions/runtimes/python/index.spec.ts index 81e1d9a31fc..81426a14cc2 100644 --- a/src/deploy/functions/runtimes/python/index.spec.ts +++ b/src/deploy/functions/runtimes/python/index.spec.ts @@ -1,7 +1,12 @@ +import { ChildProcess } from "child_process"; +import { EventEmitter } from "events"; + import { expect } from "chai"; import * as sinon from "sinon"; import * as python from "."; +import * as pythonUtils from "../../../../functions/python"; +import { IS_WINDOWS } from "../../../../utils"; const PROJECT_ID = "test-project"; const SOURCE_DIR = "/some/path/fns"; @@ -34,4 +39,167 @@ describe("PythonDelegate", () => { expect(delegate.getPythonBinary()).to.equal("python.exe"); }); }); + + describe("serveAdmin", () => { + const ADMIN_PORT = 8081; + // Mirrors the constants in ./index.ts. + const FORCE_KILL_DELAY_MS = 10_000; + const SHUTDOWN_TIMEOUT_MS = 15_000; + + let sandbox: sinon.SinonSandbox; + let clock: sinon.SinonFakeTimers; + let child: ChildProcess; + let runWithVirtualEnvStub: sinon.SinonStub; + let killProcessTreeStub: sinon.SinonStub; + let fetchStub: sinon.SinonStub; + let destroyStdoutStub: sinon.SinonStub; + let destroyStderrStub: sinon.SinonStub; + let unrefStub: sinon.SinonStub; + let delegate: python.Delegate; + + beforeEach(() => { + sandbox = sinon.createSandbox(); + child = new EventEmitter() as ChildProcess; + destroyStdoutStub = sandbox.stub(); + destroyStderrStub = sandbox.stub(); + unrefStub = sandbox.stub(); + Object.assign(child, { + pid: 4242, + exitCode: null, + signalCode: null, + stdout: Object.assign(new EventEmitter(), { destroy: destroyStdoutStub }), + stderr: Object.assign(new EventEmitter(), { destroy: destroyStderrStub }), + unref: unrefStub, + }); + runWithVirtualEnvStub = sandbox.stub(pythonUtils, "runWithVirtualEnv").returns(child); + killProcessTreeStub = sandbox.stub(pythonUtils, "killProcessTree"); + // Tracking installs real process-level signal handlers; not under test here. + sandbox.stub(pythonUtils, "trackVirtualEnvChild"); + sandbox.stub(pythonUtils, "untrackVirtualEnvChild"); + fetchStub = sandbox.stub(global, "fetch" as never); + delegate = new python.Delegate(PROJECT_ID, SOURCE_DIR, "python312"); + sandbox.stub(delegate, "modulesDir").resolves("/some/site-packages/firebase_functions"); + clock = sandbox.useFakeTimers(); + }); + + afterEach(() => { + sandbox.restore(); + }); + + it("spawns detached so the kill can reach Python under the venv shell wrapper", async () => { + await delegate.serveAdmin(ADMIN_PORT, {}); + + const spawnOpts = runWithVirtualEnvStub.firstCall.args[3] as { detached: boolean }; + expect(spawnOpts.detached).to.equal(!IS_WINDOWS); + }); + + it("asks the server to quit and resolves once it exits", async () => { + fetchStub.resolves(new Response("", { status: 200 })); + const killProcess = await delegate.serveAdmin(ADMIN_PORT, {}); + + const shutdown = killProcess(); + child.emit("exit", 0); + await shutdown; + + expect(fetchStub.firstCall.args[0]).to.equal( + `http://127.0.0.1:${ADMIN_PORT}/__/quitquitquit`, + ); + expect(killProcessTreeStub).to.not.have.been.called; + }); + + it("force-kills the process group when the server never answers quitquitquit", async () => { + // A wedged server: bound to the port but not accepting connections. + fetchStub.rejects(Object.assign(new Error("connect ETIMEDOUT"), { code: "ETIMEDOUT" })); + const killProcess = await delegate.serveAdmin(ADMIN_PORT, {}); + + const shutdown = killProcess(); + await clock.tickAsync(FORCE_KILL_DELAY_MS); + + expect(killProcessTreeStub).to.have.been.calledOnceWithExactly(4242); + + child.emit("exit", null, "SIGKILL"); + await shutdown; + }); + + it("gives up instead of hanging the deploy when the process refuses to die", async () => { + fetchStub.rejects(Object.assign(new Error("connect ETIMEDOUT"), { code: "ETIMEDOUT" })); + const killProcess = await delegate.serveAdmin(ADMIN_PORT, {}); + + // The child never emits "exit". Before the fix this awaited forever, which + // is what left CI deploys hanging until the job timeout. + const shutdown = killProcess(); + let settled = false; + void shutdown.then(() => (settled = true)); + + await clock.tickAsync(SHUTDOWN_TIMEOUT_MS); + await shutdown; + + expect(settled).to.be.true; + }); + + it("releases the surviving child's handles so it cannot hold the CLI open", async () => { + fetchStub.rejects(Object.assign(new Error("connect ETIMEDOUT"), { code: "ETIMEDOUT" })); + const killProcess = await delegate.serveAdmin(ADMIN_PORT, {}); + + const shutdown = killProcess(); + await clock.tickAsync(SHUTDOWN_TIMEOUT_MS); + await shutdown; + + // A detached child and its pipes each keep the event loop alive, which + // would move the hang from the deploy to process exit rather than fix it. + expect(destroyStdoutStub).to.have.been.called; + expect(destroyStderrStub).to.have.been.called; + expect(unrefStub).to.have.been.called; + }); + + it("does not reject when the child errors, so the real discovery error survives", async () => { + fetchStub.rejects(new Error("connect ECONNREFUSED")); + const killProcess = await delegate.serveAdmin(ADMIN_PORT, {}); + + const shutdown = killProcess(); + child.emit("error", new Error("spawn failed")); + + await shutdown; + }); + + it("returns immediately when the server died before shutdown was called", async () => { + fetchStub.rejects(new Error("connect ECONNREFUSED")); + const killProcess = await delegate.serveAdmin(ADMIN_PORT, {}); + + // A server that failed to start, e.g. a venv that could not be activated. + // "exit" does not replay, so a listener attached at shutdown time would + // never fire and the deploy would stall for SHUTDOWN_TIMEOUT_MS. + child.emit("exit", 1); + + const shutdown = killProcess(); + let settled = false; + void shutdown.then(() => (settled = true)); + + await clock.tickAsync(0); + expect(settled).to.be.true; + await shutdown; + + // Nothing left alive, so we must not signal a pid that has been reaped + // and possibly recycled. + await clock.tickAsync(FORCE_KILL_DELAY_MS); + expect(killProcessTreeStub).to.not.have.been.called; + }); + + it("returns immediately when the child failed to spawn before shutdown was called", async () => { + fetchStub.rejects(new Error("connect ECONNREFUSED")); + const killProcess = await delegate.serveAdmin(ADMIN_PORT, {}); + + // A spawn failure leaves exitCode and signalCode null, so checking those + // is not enough on its own to notice the process is gone. + child.emit("error", new Error("spawn ENOENT")); + + const shutdown = killProcess(); + let settled = false; + void shutdown.then(() => (settled = true)); + + await clock.tickAsync(0); + expect(settled).to.be.true; + await shutdown; + }); + }); }); diff --git a/src/deploy/functions/runtimes/python/index.ts b/src/deploy/functions/runtimes/python/index.ts index 0bd3d343a8e..0c63324bd38 100644 --- a/src/deploy/functions/runtimes/python/index.ts +++ b/src/deploy/functions/runtimes/python/index.ts @@ -1,6 +1,7 @@ import * as fs from "fs"; import * as path from "path"; import { promisify } from "util"; +import { ChildProcess } from "child_process"; import * as portfinder from "portfinder"; @@ -9,10 +10,29 @@ import * as backend from "../../backend"; import * as discovery from "../discovery"; import * as supported from "../supported"; import { logger } from "../../../../logger"; -import { DEFAULT_VENV_DIR, runWithVirtualEnv, virtualEnvCmd } from "../../../../functions/python"; +import { + DEFAULT_VENV_DIR, + killProcessTree, + runWithVirtualEnv, + trackVirtualEnvChild, + untrackVirtualEnvChild, + virtualEnvCmd, +} from "../../../../functions/python"; import { FirebaseError } from "../../../../error"; import { Build } from "../../build"; import { assertExhaustive } from "../../../../functional"; +import { IS_WINDOWS } from "../../../../utils"; + +// How long to wait for the admin server to shut down in response to +// /__/quitquitquit before force-killing it. +const FORCE_KILL_DELAY_MS = 10_000; +// Cap on how long to keep waiting for the child once the shutdown request has +// settled. A wedged server that survives even SIGKILL of its process group must +// not be able to hang the deploy. +const SHUTDOWN_TIMEOUT_MS = 15_000; +// A server that is bound but not accepting connections will never answer, so the +// shutdown request needs its own timeout rather than relying on the socket layer. +const QUITQUITQUIT_TIMEOUT_MS = 5_000; /** * Create a runtime delegate for the Python runtime, if applicable. @@ -149,7 +169,7 @@ export class Delegate implements runtimes.RuntimeDelegate { return Promise.resolve(); } - async serveAdmin(port: number, envs: backend.EnvironmentVariables) { + async serveAdmin(port: number, envs: backend.EnvironmentVariables): Promise<() => Promise> { const modulesDir = await this.modulesDir(); const envWithAdminPort = { ...envs, @@ -161,30 +181,85 @@ export class Delegate implements runtimes.RuntimeDelegate { envWithAdminPort, )} in ${this.sourceDir}`, ); - const childProcess = runWithVirtualEnv(args, this.sourceDir, envWithAdminPort); + // detached so the shell runWithVirtualEnv spawns becomes the leader of its + // own process group: that lets killProcessTree() force-kill the shell *and* + // the Python process underneath it, instead of just the shell. + const childProcess = runWithVirtualEnv(args, this.sourceDir, envWithAdminPort, { + detached: !IS_WINDOWS, + }); childProcess.stdout?.on("data", (chunk: Buffer) => { logger.info(chunk.toString("utf8")); }); childProcess.stderr?.on("data", (chunk: Buffer) => { logger.error(chunk.toString("utf8")); }); - return Promise.resolve(async () => { - try { - await fetch(`http://127.0.0.1:${port}/__/quitquitquit`); - } catch (e) { - logger.debug("Failed to call quitquitquit. This often means the server failed to start", e); - } - const quitTimeout = setTimeout(() => { - if (!childProcess.killed) { - childProcess.kill("SIGKILL"); - } - }, 10_000); - clearTimeout(quitTimeout); - return new Promise((resolve, reject) => { - childProcess.once("exit", resolve); - childProcess.once("error", reject); + // Attached here rather than in shutdownAdmin() because 'exit' and 'error' do + // not replay: a server that dies before shutdown is called (a venv that fails + // to activate, a missing interpreter) would otherwise leave a listener that + // never fires and stall the whole shutdown until SHUTDOWN_TIMEOUT_MS. + const exited = new Promise((resolve) => { + childProcess.once("exit", () => resolve()); + childProcess.once("error", () => resolve()); + }); + trackVirtualEnvChild(childProcess); + return Promise.resolve(() => this.shutdownAdmin(childProcess, port, exited)); + } + + /** + * Shut down a discovery admin server, escalating from an HTTP request to a + * force-kill of its process group. Bounded by QUITQUITQUIT_TIMEOUT_MS followed + * by SHUTDOWN_TIMEOUT_MS, since the timers only start once the request settles. + * + * `exited` must have been attached at spawn time; see serveAdmin(). + */ + private async shutdownAdmin( + childProcess: ChildProcess, + port: number, + exited: Promise, + ): Promise { + try { + await fetch(`http://127.0.0.1:${port}/__/quitquitquit`, { + signal: AbortSignal.timeout(QUITQUITQUIT_TIMEOUT_MS), }); + } catch (e) { + logger.debug("Failed to call quitquitquit. This often means the server failed to start", e); + } + const forceKill = setTimeout(() => { + // No childProcess.killed check: that flag only reflects calls to .kill() + // on this object, and killProcessTree() is already a no-op for a process + // group that has gone away. + if (childProcess.pid) { + logger.debug( + `Discovery admin server on port ${port} did not shut down when asked. Force-killing it.`, + ); + killProcessTree(childProcess.pid); + } + }, FORCE_KILL_DELAY_MS); + let giveUp: NodeJS.Timeout | undefined; + const timedOut = new Promise((resolve) => { + giveUp = setTimeout(() => resolve(false), SHUTDOWN_TIMEOUT_MS); }); + try { + const exitedCleanly = await Promise.race([exited.then(() => true), timedOut]); + if (exitedCleanly) { + untrackVirtualEnvChild(childProcess); + } else { + // A detached child and its pipes both hold the CLI's event loop open, so + // leaving it alive would hang the deploy at process exit instead of here. + // Releasing them is also what lets the 'exit' handler run at all, and the + // child stays tracked so that handler gets one last attempt at it. + childProcess.stdout?.destroy(); + childProcess.stderr?.destroy(); + childProcess.unref(); + logger.debug( + `Discovery admin server on port ${port} survived being force-killed. ` + + `Continuing without it; it may need to be cleaned up manually.`, + ); + } + } finally { + clearTimeout(forceKill); + clearTimeout(giveUp); + } } async discoverBuild( diff --git a/src/functions/python.spec.ts b/src/functions/python.spec.ts new file mode 100644 index 00000000000..d836e6d2157 --- /dev/null +++ b/src/functions/python.spec.ts @@ -0,0 +1,147 @@ +import { ChildProcess } from "child_process"; +import { EventEmitter } from "events"; + +import { expect } from "chai"; +import * as sinon from "sinon"; + +import { killProcessTree, trackVirtualEnvChild, untrackVirtualEnvChild } from "./python"; +import { IS_WINDOWS } from "../utils"; + +// Process groups and POSIX signals do not exist on Windows, where killProcessTree +// shells out to taskkill instead. +const itPosix = IS_WINDOWS ? it.skip : it; + +describe("killProcessTree", () => { + let sandbox: sinon.SinonSandbox; + let killStub: sinon.SinonStub; + + beforeEach(() => { + sandbox = sinon.createSandbox(); + killStub = sandbox.stub(process, "kill"); + }); + + afterEach(() => { + sandbox.restore(); + }); + + itPosix("signals the whole process group, not just the shell pid", () => { + killProcessTree(4242); + + // A negative pid is what makes this reach the Python process underneath the + // `. venv/bin/activate && python ...` shell wrapper. + expect(killStub).to.have.been.calledOnceWithExactly(-4242, "SIGKILL"); + }); + + itPosix("does not throw when the process group has already exited", () => { + const esrch = Object.assign(new Error("kill ESRCH"), { code: "ESRCH" }); + killStub.throws(esrch); + + expect(() => killProcessTree(4242)).to.not.throw(); + }); + + for (const pid of [0, -1, NaN]) { + it(`refuses to signal anything for a pid of ${pid}`, () => { + // process.kill(-0, ...) would signal the CLI's own process group, i.e. + // kill the very process trying to do the cleanup. + killProcessTree(pid); + + expect(killStub).to.not.have.been.called; + }); + } +}); + +describe("virtual env child tracking", () => { + let sandbox: sinon.SinonSandbox; + let killStub: sinon.SinonStub; + let child: ChildProcess; + + beforeEach(() => { + sandbox = sinon.createSandbox(); + killStub = sandbox.stub(process, "kill"); + child = new EventEmitter() as ChildProcess; + // A live ChildProcess reports null for both, not undefined. + Object.assign(child, { pid: 4242, exitCode: null, signalCode: null }); + }); + + afterEach(() => { + untrackVirtualEnvChild(child); + sandbox.restore(); + }); + + itPosix("force-kills tracked children on SIGTERM, the signal CI sends on cancellation", () => { + // A co-listener keeps process.listenerCount() above zero after our handler + // removes itself, so the handler does not re-raise and end the test run. + const coListener = (): void => undefined; + process.on("SIGTERM", coListener); + try { + trackVirtualEnvChild(child); + process.emit("SIGTERM", "SIGTERM"); + + expect(killStub).to.have.been.calledOnceWithExactly(-4242, "SIGKILL"); + } finally { + process.removeListener("SIGTERM", coListener); + } + }); + + itPosix("re-raises the signal once cleanup is done so the exit code is preserved", () => { + trackVirtualEnvChild(child); + process.emit("SIGTERM", "SIGTERM"); + + // Once for the child's process group, once to re-raise on ourselves. + expect(killStub).to.have.been.calledWithExactly(-4242, "SIGKILL"); + expect(killStub).to.have.been.calledWithExactly(process.pid, "SIGTERM"); + }); + + itPosix("force-kills tracked children on SIGQUIT", () => { + // Ctrl-\ reaches the foreground process group only, and a detached child is + // in its own group, so nothing kills it unless this handler does. + const coListener = (): void => undefined; + process.on("SIGQUIT", coListener); + try { + trackVirtualEnvChild(child); + process.emit("SIGQUIT", "SIGQUIT"); + + expect(killStub).to.have.been.calledOnceWithExactly(-4242, "SIGKILL"); + } finally { + process.removeListener("SIGQUIT", coListener); + } + }); + + itPosix("does not signal a child that has already exited", () => { + const coListener = (): void => undefined; + process.on("SIGTERM", coListener); + try { + trackVirtualEnvChild(child); + // Reaped by now, so the pid may belong to an unrelated process group. + Object.assign(child, { exitCode: 0 }); + process.emit("SIGTERM", "SIGTERM"); + + expect(killStub).to.not.have.been.calledWith(-4242); + } finally { + process.removeListener("SIGTERM", coListener); + } + }); + + it("restores default signal behaviour once nothing is left to clean up", () => { + const before = process.listenerCount("SIGTERM"); + trackVirtualEnvChild(child); + expect(process.listenerCount("SIGTERM")).to.equal(before + 1); + + untrackVirtualEnvChild(child); + expect(process.listenerCount("SIGTERM")).to.equal(before); + }); + + it("keeps handlers installed while other children are still tracked", () => { + const other = new EventEmitter() as ChildProcess; + Object.assign(other, { pid: 4343 }); + const before = process.listenerCount("SIGTERM"); + + trackVirtualEnvChild(child); + trackVirtualEnvChild(other); + untrackVirtualEnvChild(child); + expect(process.listenerCount("SIGTERM")).to.equal(before + 1); + + untrackVirtualEnvChild(other); + expect(process.listenerCount("SIGTERM")).to.equal(before); + }); +}); diff --git a/src/functions/python.ts b/src/functions/python.ts index a56bac9bed6..2ab4eaf3dd1 100644 --- a/src/functions/python.ts +++ b/src/functions/python.ts @@ -45,3 +45,118 @@ export function runWithVirtualEnv( env: envs as any, }); } + +/** + * Force-kill a process spawned by runWithVirtualEnv, including its Python + * grandchild. + * + * runWithVirtualEnv always spawns through a shell (`. venv/bin/activate && `), + * so the pid it returns is the shell, not the Python process underneath it. + * Signaling that pid alone does not reliably reach Python, so callers must pass + * `detached: true` when spawning (making the shell the leader of its own process + * group) and kill the whole group here instead of a single pid. + */ +export function killProcessTree(pid: number): void { + // Callers already skip an unspawned child, but guard here too: this function is + // exported, and process.kill(-0, ...) would signal the CLI's own process group. + if (!pid || pid <= 0) { + return; + } + if (IS_WINDOWS) { + // taskkill /T walks the process tree by parent pid, so it doesn't rely on + // the process group trick used below. + cp.spawnSync("taskkill", ["/pid", pid.toString(), "/T", "/F"]); + return; + } + try { + // A negative pid signals the whole process group rather than just `pid`. + process.kill(-pid, "SIGKILL"); + } catch (e) { + // Group may already be gone (process exited on its own). + } +} + +/** + * Signals that should trigger cleanup of tracked children. SIGTERM is what CI + * runners send on job cancellation or timeout, which is the case that used to + * leave orphaned admin servers behind. SIGINT and SIGQUIT are terminal-generated + * and so only reach the foreground process group: a detached child never sees + * them on its own. + */ +const CLEANUP_SIGNALS: NodeJS.Signals[] = ["SIGINT", "SIGTERM", "SIGHUP", "SIGQUIT"]; + +const trackedChildren = new Set(); +const signalHandlers = new Map void>(); + +function killAllTrackedChildren(): void { + for (const child of trackedChildren) { + // A child that has already exited may have had its pid reaped and recycled + // as the leader of some unrelated process group by now. + if (child.pid && child.exitCode === null && child.signalCode === null) { + killProcessTree(child.pid); + } + } + trackedChildren.clear(); +} + +function removeCleanupHandlers(): void { + if (!signalHandlers.size) { + return; + } + process.removeListener("exit", killAllTrackedChildren); + for (const [signal, handler] of signalHandlers) { + process.removeListener(signal, handler); + } + signalHandlers.clear(); +} + +function addCleanupHandlers(): void { + if (signalHandlers.size) { + return; + } + // 'exit' covers normal and uncaught-exception exits. It does *not* fire for + // signal-terminated processes, hence the explicit signal handlers below. + process.on("exit", killAllTrackedChildren); + for (const signal of CLEANUP_SIGNALS) { + const handler = (): void => { + killAllTrackedChildren(); + // Attaching a signal listener suppresses Node's default "terminate on + // signal" behaviour, so restore it: drop our listeners and re-raise, but + // only if nobody else (e.g. the emulator's own shutdown handler) is still + // listening and expecting to drive the exit itself. + removeCleanupHandlers(); + if (process.listenerCount(signal) === 0) { + process.kill(process.pid, signal); + } + }; + signalHandlers.set(signal, handler); + process.on(signal, handler); + } +} + +/** + * Track a detached child spawned by runWithVirtualEnv so that it is force-killed + * if the CLI itself goes away before the caller's normal cleanup path runs. + * + * Passing `detached: true` at spawn time takes the child out of the CLI's process + * group, which means it no longer dies with the CLI on Ctrl-C. Tracking it here + * restores that, and extends it to SIGTERM (CI cancellation) and SIGHUP. + * + * Nothing can help if the CLI is SIGKILLed, since that signal cannot be caught. + */ +export function trackVirtualEnvChild(child: cp.ChildProcess): void { + trackedChildren.add(child); + addCleanupHandlers(); +} + +/** + * Stop tracking a child that has exited. Cleanup handlers are removed once + * nothing is left to clean up, so the CLI's default signal behaviour is not + * altered for the rest of the run. + */ +export function untrackVirtualEnvChild(child: cp.ChildProcess): void { + trackedChildren.delete(child); + if (!trackedChildren.size) { + removeCleanupHandlers(); + } +}