diff --git a/kits/delete-user-data/CHANGELOG.md b/kits/delete-user-data/CHANGELOG.md index 0e40c6a6f..908a26689 100644 --- a/kits/delete-user-data/CHANGELOG.md +++ b/kits/delete-user-data/CHANGELOG.md @@ -1,3 +1,5 @@ +- fix: a failed run is now logged at ERROR severity. On 2nd gen, Cloud Run records a function that throws as HTTP 200, and the stack trace went to stderr with no severity, so failures that the extension reported as `status: 'error'` were easy to miss. Each function now logs the error's stack trace at ERROR before it fails, as the extension did, so log-based alerts can catch it. See "Failed runs show as HTTP 200" in the README, which also covers timeouts. + - fix: an Eventarc publish failure no longer fails the function. A channel that was deleted or is unreachable answers `PERMISSION_DENIED`, and the publish was awaited after the work, so the deletion completed but the invocation still failed. The publish failure is now logged as a warning and the invocation continues. Deploys also declare `eventarcpublishing.googleapis.com`, so the API is enabled on your project whether or not you use events. The failed invocation used to be redelivered, re-running a deletion that had already succeeded; it no longer is. - fix: `ENABLE_AUTO_DISCOVERY` accepts the extension's `yes` / `no` values again. The kit had declared it as a boolean param, which only counts the literal `true` as enabled, so a `.env` copied from an installed extension instance carried `yes` and silently left auto-discovery switched off. The param is now the extension's labeled `Yes` / `No` select and is read the same way the extension read it. diff --git a/kits/delete-user-data/README.md b/kits/delete-user-data/README.md index 465d7a7cd..08ecea318 100644 --- a/kits/delete-user-data/README.md +++ b/kits/delete-user-data/README.md @@ -202,6 +202,31 @@ Auth event `google.firebase.auth.user.v2.deleted` instead of the 1st gen This mainly matters if you have infrastructure or alerting keyed to function generation. +### Failed runs show as HTTP 200 + +On the extension's 1st gen functions, a thrown error or a timeout was logged as +`finished with status: 'error'` (or `'timeout'`). On 2nd gen, Cloud Run +records these event deliveries as HTTP 200 even when the function fails, so +request status and error-rate charts do not show failures. + +Instead, the kit logs the error's stack trace for every failed run at ERROR +severity, as the extension did, and then lets the run fail. Error Reporting +groups it with the copy of the stack that the functions framework writes to +stderr, so each failure shows up twice in the same group. To be told about +failures, create a +[log-based alert](https://cloud.google.com/logging/docs/alerting/log-based-alerts) +on ERROR severity, for example: + +``` +resource.type="cloud_run_revision" +resource.labels.service_name=~"^kit--" +(severity>=ERROR OR textPayload:"maximum request timeout") +``` + +A function can't log its own timeout. A timeout shows up only as an INFO request +log that says "The request has been terminated because it has reached the +maximum request timeout", which the second clause above matches. + ### Events need an existing channel, and their source has changed The extension created its Eventarc channel when you installed it with events diff --git a/kits/delete-user-data/src/index.ts b/kits/delete-user-data/src/index.ts index cca4a43d0..9ab314d1a 100644 --- a/kits/delete-user-data/src/index.ts +++ b/kits/delete-user-data/src/index.ts @@ -17,10 +17,13 @@ import { PubSub } from "@google-cloud/pubsub"; import * as admin from "firebase-admin"; import { getFirestore } from "firebase-admin/firestore"; -import type { Role } from "firebase-functions/v2"; +import type { CloudEvent, Role } from "firebase-functions/v2"; import { requiresAPI, requiresRole } from "firebase-functions/v2"; import { onUserDeleted } from "firebase-functions/v2/identity"; -import { onMessagePublished } from "firebase-functions/v2/pubsub"; +import { + type MessagePublishedData, + onMessagePublished, +} from "firebase-functions/v2/pubsub"; import { assertRequiredParams, CONFIG_EXPRESSIONS, @@ -29,10 +32,12 @@ import { import * as events from "./events"; import { getDatabaseUrl, resolveDeleteUserDataConfig } from "./export-config"; import { + type DeleteMessageData, type HandlerContext, handleClear, handleDeletion as runDeletion, handleSearch as runSearch, + type SearchMessageData, } from "./handlers"; import * as logs from "./logs"; @@ -109,27 +114,50 @@ function getContext(): HandlerContext { return ctx; } -export const clearData = onUserDeleted((event) => { - // The Auth event delivers no user record when the payload envelope is empty, - // so bail before getContext() rather than initialising the SDKs for nothing. - const uid = event.data?.uid; - if (!uid) { - logs.deletionEventMissingUid(event.id); - return; - } - return handleClear(uid, getContext()); -}); +// On 2nd gen, a handler that throws is still recorded as HTTP 200 in the +// request log, and the functions framework prints the stack to stderr with no +// severity. Log the error at ERROR severity so log-based alerts and Error +// Reporting see it, then rethrow so the invocation still counts as failed. +function logFailures( + handler: (event: E) => unknown +): (event: E) => Promise { + return async (event) => { + try { + return await handler(event); + } catch (err) { + logs.unhandledError(err); + throw err; + } + }; +} + +export const clearData = onUserDeleted( + logFailures((event) => { + // The Auth event delivers no user record when the payload envelope is empty, + // so bail before getContext() rather than initialising the SDKs for nothing. + const uid = event.data?.uid; + if (!uid) { + logs.deletionEventMissingUid(event.id); + return; + } + return handleClear(uid, getContext()); + }) +); export const handleSearch = onMessagePublished( { topic: CONFIG_EXPRESSIONS.discoveryTopicName, }, - (event) => runSearch(event.data.message.json, getContext()) + logFailures((event: CloudEvent>) => + runSearch(event.data.message.json, getContext()) + ) ); export const handleDeletion = onMessagePublished( { topic: CONFIG_EXPRESSIONS.deletionTopicName, }, - (event) => runDeletion(event.data.message.json, getContext()) + logFailures((event: CloudEvent>) => + runDeletion(event.data.message.json, getContext()) + ) ); diff --git a/kits/delete-user-data/src/logs.ts b/kits/delete-user-data/src/logs.ts index cbacbc8dd..14010e4ab 100644 --- a/kits/delete-user-data/src/logs.ts +++ b/kits/delete-user-data/src/logs.ts @@ -14,6 +14,7 @@ * limitations under the License. */ +import { format } from "node:util"; import { logger } from "firebase-functions"; import type { ResolvedDeleteUserDataConfig } from "./export-config"; @@ -126,6 +127,14 @@ export const deletionEventMissingUid = (eventId: string) => { ); }; +// Logged as the bare stack, like the extension's 1st gen ERROR entry. Error +// Reporting groups it with the framework's own stderr copy of the stack. +export const unhandledError = (err: unknown) => + logger.write({ + severity: "ERROR", + message: (err instanceof Error && err.stack) || format(err), + }); + export function warnInvalidPaths(invalidPathCount: number, uid: string) { logger.warn( `Attempted to delete ${invalidPathCount} invalid paths for deleted user ${uid}` diff --git a/kits/delete-user-data/tests/context.test.ts b/kits/delete-user-data/tests/context.test.ts index 59b253b33..ddf87d891 100644 --- a/kits/delete-user-data/tests/context.test.ts +++ b/kits/delete-user-data/tests/context.test.ts @@ -52,6 +52,7 @@ import * as admin from "firebase-admin"; import type { HandlerContext } from "../src/handlers"; import { handleClear } from "../src/handlers"; import { clearData } from "../src/index"; +import * as logs from "../src/logs"; function deletionEvent(uid: string) { return { @@ -118,4 +119,21 @@ describe("handler context", () => { options: { projectId: PROJECT_ID }, }); }); + + test("logs a failed deletion at ERROR severity and rethrows", async () => { + const err = new Error("boom"); + vi.mocked(handleClear).mockRejectedValueOnce(err); + + await expect(clearData(deletionEvent("uid-7"))).rejects.toBe(err); + + expect(logs.unhandledError).toHaveBeenCalledWith(err); + }); + + test("does not log an error when the deletion succeeds", async () => { + vi.mocked(handleClear).mockResolvedValueOnce(undefined); + + await clearData(deletionEvent("uid-8")); + + expect(logs.unhandledError).not.toHaveBeenCalled(); + }); }); diff --git a/kits/delete-user-data/tests/index.test.ts b/kits/delete-user-data/tests/index.test.ts index b031ab638..4f5c092ff 100644 --- a/kits/delete-user-data/tests/index.test.ts +++ b/kits/delete-user-data/tests/index.test.ts @@ -23,7 +23,7 @@ vi.mock("../src/handlers", async (importOriginal) => ({ })); import { handleClear } from "../src/handlers"; -import { clearData } from "../src/index"; +import { clearData, handleDeletion, handleSearch } from "../src/index"; import * as logs from "../src/logs"; function deletionEvent(data: unknown) { @@ -68,3 +68,39 @@ describe("clearData", () => { expect(logs.deletionEventMissingUid).toHaveBeenCalledWith("event-id"); }); }); + +function pubsubEvent(data: string) { + return { + specversion: "1.0", + id: "message-event-id", + type: "google.cloud.pubsub.topic.v1.messagePublished", + source: "//pubsub.googleapis.com/projects/test-project/topics/t", + time: "2026-01-01T00:00:00.000Z", + data: { + message: { + messageId: "1", + data: Buffer.from(data).toString("base64"), + }, + subscription: "s", + }, + } as any; +} + +// 2nd gen records a failed invocation as HTTP 200, so the ERROR log is the +// only signal. The rethrow keeps the invocation marked as failed. +describe.each([ + ["handleSearch", handleSearch], + ["handleDeletion", handleDeletion], +] as const)("%s", (name, fn) => { + beforeEach(() => { + vi.clearAllMocks(); + }); + + test("logs a malformed message at ERROR severity and rethrows", async () => { + await expect(fn(pubsubEvent("not json"))).rejects.toThrow( + /Unable to parse Pub\/Sub message data as JSON/ + ); + + expect(logs.unhandledError).toHaveBeenCalledWith(expect.any(Error)); + }); +}); diff --git a/kits/delete-user-data/tests/logs.test.ts b/kits/delete-user-data/tests/logs.test.ts new file mode 100644 index 000000000..270484423 --- /dev/null +++ b/kits/delete-user-data/tests/logs.test.ts @@ -0,0 +1,48 @@ +/** + * Copyright 2026 Google LLC + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * https://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +import { logger } from "firebase-functions"; +import { afterEach, describe, expect, test, vi } from "vitest"; +import * as logs from "../src/logs"; + +afterEach(() => { + vi.restoreAllMocks(); +}); + +describe("unhandledError", () => { + test("writes the error's stack as an ERROR entry", () => { + const write = vi.spyOn(logger, "write").mockImplementation(() => {}); + const err = new Error("boom"); + + logs.unhandledError(err); + + expect(write).toHaveBeenCalledWith({ + severity: "ERROR", + message: err.stack, + }); + }); + + test("handles a thrown value that is not an Error", () => { + const write = vi.spyOn(logger, "write").mockImplementation(() => {}); + + logs.unhandledError("plain string"); + + expect(write).toHaveBeenCalledWith({ + severity: "ERROR", + message: "plain string", + }); + }); +});