Repository navigation
fix(functions): suppress premature failure warnings on SA propagation and quota retries - #11325
shettyvarun268 wants to merge 8 commits into
Conversation
There was a problem hiding this comment.
Code Review
This pull request addresses an issue where Cloud Functions deployments logged premature failure warnings when retrying transient service account propagation or quota errors. It updates the error logging logic in both v1 and v2 Cloud Functions modules to log service account propagation errors at the debug level, and adds corresponding unit tests. The review feedback suggests a more robust extraction of error messages when the error is a string, and recommends refactoring the unit tests to clean up stubs and intercepts in afterEach hooks instead of inline try..finally blocks, adhering to the repository style guide.
… and quota retries
When creating, updating, or deleting Cloud Functions hits a newly provisioned
managed service account (firebase-fn-*) propagation delay (HTTP 404/400/403)
or HTTP 429 Quota Exceeded error, functionsOpLogReject previously logged
warning banners ("had HTTP Error..." and "failed to create function...")
before QueueExecutor retried the operation.
This change:
- Logs service account propagation errors at debug level in functionsOpLogReject
instead of emitting premature warning banners on intermediate attempts.
- Suppresses the immediate "failed to <type> function" warning during
HTTP 429 Quota Exceeded retries in GCFv2 (matching GCFv1).
6c3dd91 to
71f929f
Compare
…p-sa-propagation-retry-logs
…ed SA 404, and updateFunction
wandamora
left a comment
There was a problem hiding this comment.
I left comments to fix the current direction of this PR, but Andy's review tool had an interesting proposal:
🟡 [Architecture & Layering] Decouple src/gcp/ REST clients from src/deploy/functions/release/executor
Rationale: src/gcp/cloudfunctions.ts (line 14) and src/gcp/cloudfunctionsv2.ts (line 21) are single-attempt REST clients, whereas retry orchestration is decided per call site in Fabricator + QueueExecutor (src/deploy/functions/release/executor.ts:108). Importing isServiceAccountPropagationError upward from ../deploy/functions/release/executor leaves other QueueExecutor-retried errors (409 Conflict and 503 Service Unavailable in isTransientError, and code === 8 in isCloudRunResourceExhausted) still emitting premature failure warnings before succeeding on retry, while non-queued callers (src/functions/secrets.ts:363,376 in firebase functions:secrets:set, and deleteV1Function in fabricator.ts:908) log "Waiting to retry..." / "Waiting for service account propagation..." when no retry will occur.
Consider keeping src/gcp/cloudfunctions*.ts side-effect-free (matching src/gcp/runv2.ts:229-307) and logging retry notices (Waiting to retry... on isQuotaExhaustion, logger.debug on other matched retryPredicates) directly inside QueueExecutor's handler (executor.ts:108-110). If keeping warning logic in functionsOpLogReject for this PR, consider also suppressing isTransientError (409/503) warnings and moving shared error predicates to a lower-level module.
This comment is interesting in offering a different architectural approach to solve this retry logging problem and centralizing this in QueueExecutor. This approach may be "cleaner" so that the HTTP cloudfunctions clients do not need to guess if a retry occurred because the QueueExecutor has that information. After talking a bit with Jetski, this direction would be more complex for a few reasons:
-
QueueExecutordoesn't know what it is running:Executor.run onlyreceives an anonymous() => Promise<T>—it has no funcName or"create" | "update" | "delete"verb. Worse,FabricatorusesQueueExecutorat ~35 call sites (Pub/Sub topics, Eventarc channels, Cloud Scheduler, Cloud Tasks, Cloud Run IAM, plus pollOperation inside the same lambda). TeachingQueueExecutorto print"Waiting to retry..."with the function name requires threading operation metadata throughRunOptionsacrossFabricator(or sniffingerr.context?.function) while avoiding new log noise on the other ~30 tasks. -
Higher UX blast radius: Removing
logWarning/logLabeledWarningfromfunctionsOpLogRejectrequires reworking how multi-line remediation messages (maxScale may not exceed,Runtime validation errors,first-time Eventarc setup) render across v1, v2, and direct callers likesecrets.ts. -
No circular dependency today: executor.ts only imports
src/throttler/*, so importing predicates fromexecutor.tsintosrc/gcp/—while slightly awkward layering—is acyclic and safe at runtime.
Would love to hear @ajperel's thoughts about what to do. Varun's change does work at minimally fixing this, but this appraoch may be better for the "long-term architecture".
| context: { function: func.name }, | ||
| }); | ||
| throw new FirebaseError( | ||
| `Failed to ${type} function ${func.name}${errMessage ? `: ${errMessage}` : ""}`, |
There was a problem hiding this comment.
🔴 [CLI UX & Error Surfacing] Duplicate raw HTTP error output on non-retryable 2nd Gen failures
Rationale: On any non-SA, non-429, non-maxScale failure (e.g., 400 invalid config, 403 permission denied, or 404 custom service account typo), line 260 logs utils.logLabeledWarning(\"functions\", errMessage) and line 271 logs utils.logLabeledWarning(\"functions\", \"failed to ...\"). Because line 274 now appends : ${errMessage} unconditionally to the thrown FirebaseError, Fabricator (src/deploy/functions/release/fabricator.ts:82,699,860) immediately catches the unretried error and calls logger.error((err as Error).message) (which prints at default CLI info level per src/logger.ts:310-319), dumping both Failed to <type> function ... and the entire Request to https://... had HTTP Error: ... payload a second time back-to-back. Additionally, maxScale may not exceed (lines 235-249), which previously suppressed the raw HTTP error in favor of a friendly quota remediation message, now also dumps the raw HTTP error via Fabricator.
Suggested Fix: Only include : ${errMessage} on the thrown FirebaseError for the branches where the raw error warning was suppressed (isServiceAccountPropagationError and 429, so RetriesExhaustedError still surfaces the root cause if retries exhaust), or drop the redundant utils.logLabeledWarning(\"functions\", errMessage) at line 260 while keeping maxScale without the : ${errMessage} suffix:
const suppressed = isServiceAccountPropagationError(err) || err?.context?.response?.statusCode === 429;
throw new FirebaseError(
`Failed to ${type} function ${func.name}${suppressed && errMessage ? `: ${errMessage}` : \"\"}`,
{
original: err,
status: err?.context?.response?.statusCode,
context: { function: func.name },
},
);(Note: if gating : ${errMessage} on suppressed, update the non-managed SA 404 test in cloudfunctionsv2.spec.ts:1030 to assert rejectedWith(\"Failed to create function ...\") while verifying warnSpy.firstCall received the raw 404 message.)
There was a problem hiding this comment.
Good catch! Updated this so we only append errMessage to the thrown error when the warning was suppressed (for SA propagation and 429 retries), and updated the test accordingly.
| }, | ||
| }); | ||
|
|
||
| await expect(cloudfunctions.createFunction(CLOUD_FUNCTION)).to.eventually.be.rejectedWith( |
There was a problem hiding this comment.
🔴 [Test Isolation & Mock Verification] Clone shared CLOUD_FUNCTION fixture and assert scope.isDone() per test
Rationale:
cloudfunctions.createFunctionmutates its argument in-place by assigningcloudFunction.buildEnvironmentVariables = { ..., GOOGLE_NODE_RUN_SCRIPTS: \"\" }(src/gcp/cloudfunctions.ts:242), andcloudfunctionsv2.createFunction/updateFunctionlikewise mutatebuildConfig.environmentVariablesandserviceConfig.environmentVariablesin-place (src/gcp/cloudfunctionsv2.ts:309,316,392,398). Passing the suite-levelCLOUD_FUNCTION(here and line802) andCLOUD_FUNCTION_V2(src/gcp/cloudfunctionsv2.spec.ts:966,995,1000,1028,1048,1099) constants directly mutates shared fixtures, causingfunctionFromEndpoint.to.deep.equaltests (cloudfunctions.spec.ts:67-71,cloudfunctionsv2.spec.ts:82) to fail if test order changes or suites are filtered (note howcloudfunctionsv2.spec.ts:916-927clonesCLOUD_FUNCTION_V2for this reason).- Because
afterEachcallsnock.cleanAll()(andsrc/test/helpers/mocha-bootstrap.jsalso clearsnockafter each test), the legacy suite-levelafter(() => expect(nock.isDone()).to.be.true)at line49cannot detect unconsumed mocks (GEMINI.md). Capture thenockscope(or checkexpect(nock.isDone()).to.be.true) inside each test in both spec files.
Suggested Fix:
const scope = nock(functionsOrigin())
.post(\"/v1/projects/project/locations/region/functions\")
.reply(404, {
error: {
message:
\"Service account projects/-/serviceAccounts/firebase-fn-201@project.iam.gserviceaccount.com does not exist.\",
},
});
await expect(
cloudfunctions.createFunction({ ...CLOUD_FUNCTION }),
).to.eventually.be.rejectedWith(
\"Service account projects/-/serviceAccounts/firebase-fn-201@project.iam.gserviceaccount.com does not exist.\",
);
expect(warnSpy.called).to.be.false;
expect(debugSpy.calledWith(sinon.match(\"Waiting for service account propagation\"))).to.be
.true;
expect(scope.isDone()).to.be.true;There was a problem hiding this comment.
Done! cloned the fixtures and added expect(scope.isDone()).to.be.true across the tests in both spec files.
| } from "../functions/constants"; | ||
| import { RequireKeys } from "../metaprogramming"; | ||
| import { captureRuntimeValidationError } from "./cloudfunctions"; | ||
| import { isServiceAccountPropagationError } from "../deploy/functions/release/executor"; |
There was a problem hiding this comment.
🟡 [Architecture & Layering] Decouple src/gcp/ REST clients from src/deploy/functions/release/executor
Rationale: src/gcp/cloudfunctions.ts (line 14) and src/gcp/cloudfunctionsv2.ts (line 21) are single-attempt REST clients, whereas retry orchestration is decided per call site in Fabricator + QueueExecutor (src/deploy/functions/release/executor.ts:108). Importing isServiceAccountPropagationError upward from ../deploy/functions/release/executor leaves other QueueExecutor-retried errors (409 Conflict and 503 Service Unavailable in isTransientError, and code === 8 in isCloudRunResourceExhausted) still emitting premature failure warnings before succeeding on retry, while non-queued callers (src/functions/secrets.ts:363,376 in firebase functions:secrets:set, and deleteV1Function in fabricator.ts:908) log \"Waiting to retry...\" / \"Waiting for service account propagation...\" when no retry will occur.
Consider keeping src/gcp/cloudfunctions*.ts side-effect-free (matching src/gcp/runv2.ts:229-307) and logging retry notices (Waiting to retry... on isQuotaExhaustion, logger.debug on other matched retryPredicates) directly inside QueueExecutor's handler (executor.ts:108-110). If keeping warning logic in functionsOpLogReject for this PR, consider also suppressing isTransientError (409/503) warnings and moving shared error predicates to a lower-level module.
Description
When deploying Cloud Functions with declarative security, newly provisioned managed service accounts (
firebase-fn-[0-9]+@<project>.iam.gserviceaccount.com) take time to propagate across Google Cloud IAM and downstream services (Cloud Functions, Eventarc, Cloud Run). WhileQueueExecutorretries these transient404/400/403errors,functionsOpLogRejectinsrc/gcp/cloudfunctionsv2.tsandsrc/gcp/cloudfunctions.tspreviously logged immediate failure warnings (⚠ functions: Request to ... had HTTP Error: 404...and⚠ functions: failed to create function ...) before each retry attempt—alarming users even when a subsequent retry succeeded. Similarly, 2nd Gen429Quota Exceeded errors loggedfailed to <type> functionimmediately afterWaiting to retry....This change:
isServiceAccountPropagationError) atdebuglevel infunctionsOpLogRejectinstead of printing warning banners during retries.failed to <type> functionwarning during429Quota Exceeded retries incloudfunctionsv2.ts(matchingcloudfunctions.ts).FirebaseError(Failed to ${type} function ${funcName}: ${errMessage}) so the root cause is still surfaced if all retries are exhausted.Scenarios Tested
requiresRolenewly provisionedfirebase-fn-*service accounts (verified404and403propagation retries log only at--debuglevel with zero premature warning banners and succeed on retry).src/gcp/cloudfunctionsv2.spec.tsandsrc/gcp/cloudfunctions.spec.tsverifying:404,400(Eventarc), and403(Cloud RunactAs) service account propagation errors log atdebuglevel without emitting warning banners acrosscreateFunctionandupdateFunction.404errors still log warning banners immediately.429Quota Exceeded errors incloudfunctionsv2only log theWaiting to retry...warning.Sample Commands
firebase deploy --only functions