Repository navigation
Conversation
On 2nd gen, Cloud Run records a function that throws as HTTP 200 and the stack goes to stderr with no severity. Wrap the three triggers so a failure is logged at ERROR with the function name and event id, then rethrown. Document the HTTP 200 behaviour and a log-based alert in the README.
There was a problem hiding this comment.
Code Review
This pull request introduces explicit error logging at ERROR severity for failed function runs in the delete-user-data kit, addressing an issue where 2nd gen Cloud Run functions record failures as HTTP 200. It adds a logFailures wrapper to catch, log, and rethrow errors, along with corresponding tests and documentation. The feedback suggests improving the robustness of logFailures by using optional chaining to prevent secondary crashes when accessing event.id on potentially null or undefined events, and enhancing unhandledError to support plain objects that contain message or stack properties instead of only checking for instances of the standard Error class.
…he extension message.json wraps a parse error as "Unable to parse Pub/Sub message data as JSON", which Error Reporting groups apart from the extension's plain SyntaxError.
… runs execution_count still reports error, timeout and out of memory on 2nd gen; only Cloud Run's request log and request_count show HTTP 200.
…data-error-logging # Conflicts: # kits/delete-user-data/CHANGELOG.md # kits/delete-user-data/README.md # kits/delete-user-data/src/index.ts # kits/delete-user-data/tests/index.test.ts
…data-error-logging
… of rethrowing it
cabljac
left a comment
There was a problem hiding this comment.
A few comments/questions
| if (Date.now() - started >= timeoutMs()) { | ||
| return; |
There was a problem hiding this comment.
I think this can drop a real failure. timeoutMs() only sees setGlobalOptions, not the timeout the service actually has. The two differ if someone raises the timeout in the console or with gcloud, and with preserveExternalChanges: true the CLI keeps that value on later deploys. The kit then still assumes 60s. If auto-discovery throws at 90s on a service with a 300s timeout, the wrapper returns normally: no ERROR, no stderr stack, and execution_count would record ok. For a deletion kit that looks like a clean delete when it wasn't.
Could we drop the timeout check and always log and rethrow? That also removes timeoutMs() and the param unwrapping. The cost is that a failure after a real timeout shows up in Error Reporting again (the stderr stack), which I think is better than hiding a failure. If we keep the check, logging the late error at WARNING instead of dropping it would at least leave a trace.
| // 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. |
There was a problem hiding this comment.
Error Reporting already picks up the framework's stderr stack, so this entry adds a second occurrence in the same group rather than making it visible there (the README says as much). Maybe:
| // 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. | |
| // severity. Log the error at ERROR severity so log-based alerts see it, then | |
| // rethrow so the invocation still counts as failed. |
| logs, such as `Successfully removed data for user`, minutes later. If it then | ||
| fails, the kit drops the error without logging it, as the extension recorded | ||
| nothing after a timeout, so it doesn't reach your alerts or Error Reporting. |
There was a problem hiding this comment.
Worth saying that per-path failures inside handleClear (firestorePathError, rtdbPathError, storagePathError) still log at ERROR after a timeout. Only an error that escapes the handler is dropped. As written, a reader could take this as "late failures are invisible". If the timeout check goes (see the comment on logFailures), this can just say a late failure is still logged.
Logs every failed kit run at ERROR severity, as the extension did. On 2nd gen a failed run is still logged as HTTP 200, so before this a failure was only a stderr stack with no severity, and ERROR alerts never fired. Fixes #3251 (part of #3249).
Changes
clearData,handleSearchandhandleDeletionlog a thrown error withlogs.unhandledError(one ERROR entry with the bare stack, as the extension did), then rethrow it so the run still fails.timeoutSeconds, default 60s), the error is dropped, neither logged nor rethrown, since the extension recorded nothing after a timeout and Cloud Run has already logged and counted it.JSON.parse(Buffer.from(data, "base64").toString("utf8")), so a malformed message throws the extension's plainSyntaxErrorinstead of firebase-functions' wrapper.cloudfunctions.googleapis.com/function/execution_countwithstatus!="ok", or a log-based alert. CHANGELOG updated.clearData.Testing
On a test project, I deployed
firebase/delete-user-data@0.1.30and the kit from this branch with the same config: a missing Firestore database, and aSEARCH_FUNCTIONhelper that returnsnot json, sleeps 75s, or returns a 400 MB body. A second kit instance had a 120s global timeout param. I published malformed and valid messages, deleted test users, and checked logs, Error Reporting andexecution_count. "Kit before" is the kit onkits; rows this PR doesn't change come from the code.handleSearch,handleDeletion)SyntaxErrorstack;status: 'error'(DEBUG)SyntaxErrorstack as the extension, plus the framework's stderr copy; request log INFO 200Error: 5 NOT_FOUND)SEARCH_FUNCTIONreturnsnot json(clearData)status: 'timeout'(DEBUG) onlySuccessfully removed data for useronce it finishesMemory limit of 256 MiB exceeded…;status: 'crash'(DEBUG)execution_countstatuseserror,timeout,crashSyntaxError, whose top frame is the kit's code innode_modulesseverity>=ERROR OR textPayload:"maximum request timeout")An earlier version that only skipped logging after a timeout still let the framework's stderr stack reach Error Reporting; dropping the error fixed that.
vitest runpasses (179 tests) and Prettier passes.tscpasses with@types/nodetemporarily installed; without itpnpm buildfails onkits, which this change doesn't cause.