-
Notifications
You must be signed in to change notification settings - Fork 1.2k
fix(emulator): Storage emulator hangs under concurrent requests #10852
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Changes from all commits
b893d8a
7e8742f
6cc1d68
3a26048
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change | ||||||||||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
|
|
@@ -62,7 +62,7 @@ | |||||||||||||||||||||
| issues: StorageRulesIssues; | ||||||||||||||||||||||
| }> { | ||||||||||||||||||||||
| if (opts.method === RulesetOperationMethod.LIST && this.rulesVersion < 2) { | ||||||||||||||||||||||
| const issues = new StorageRulesIssues(); | ||||||||||||||||||||||
| issues.warnings.push( | ||||||||||||||||||||||
| "Permission denied. List operations are only allowed for rules_version='2'.", | ||||||||||||||||||||||
| ); | ||||||||||||||||||||||
|
|
@@ -75,7 +75,7 @@ | |||||||||||||||||||||
| return this.runtime.verifyWithRuleset(this.rulesetName, opts, runtimeVariableOverrides); | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| unload() { | ||||||||||||||||||||||
| throw new Error("NOT_IMPLEMENTED"); | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
|
|
@@ -86,11 +86,11 @@ | |||||||||||||||||||||
| public warnings: string[] = [], | ||||||||||||||||||||||
| ) {} | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| static fromResponse(resp: RuntimeActionResponse) { | ||||||||||||||||||||||
| return new StorageRulesIssues(resp.errors || [], resp.warnings || []); | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| get all() { | ||||||||||||||||||||||
| return [...this.errors, ...this.warnings]; | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
|
|
@@ -109,18 +109,21 @@ | |||||||||||||||||||||
| private _requestCount = 0; | ||||||||||||||||||||||
| private _requests: { | ||||||||||||||||||||||
| [s: number]: { | ||||||||||||||||||||||
| handler: (rap: any) => void; | ||||||||||||||||||||||
| request: RuntimeActionRequest; | ||||||||||||||||||||||
| }; | ||||||||||||||||||||||
| } = {}; | ||||||||||||||||||||||
| private _childprocess?: ChildProcess; | ||||||||||||||||||||||
| private _alive = false; | ||||||||||||||||||||||
| // Holds the incomplete trailing line of the runtime's stdout between "data" | ||||||||||||||||||||||
| // events. See handleRuntimeStdout(). | ||||||||||||||||||||||
| private _stdoutBuffer = ""; | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| get alive() { | ||||||||||||||||||||||
| return this._alive; | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| async start(autoDownload = true) { | ||||||||||||||||||||||
| if (this.alive) { | ||||||||||||||||||||||
| return; | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
|
|
@@ -167,7 +170,7 @@ | |||||||||||||||||||||
| }); | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| // This catches error when spawning the java process | ||||||||||||||||||||||
| this._childprocess.on("error", (err: any) => { | ||||||||||||||||||||||
| void handleEmulatorProcessError(Emulators.STORAGE, err); | ||||||||||||||||||||||
| }); | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
|
|
@@ -188,42 +191,64 @@ | |||||||||||||||||||||
| }); | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| this._childprocess.stdout?.on("data", (buf: Buffer) => { | ||||||||||||||||||||||
| const serializedRuntimeActionResponse = buf.toString("utf-8").trim(); | ||||||||||||||||||||||
| if (serializedRuntimeActionResponse !== "") { | ||||||||||||||||||||||
| let rap; | ||||||||||||||||||||||
| try { | ||||||||||||||||||||||
| rap = JSON.parse(serializedRuntimeActionResponse) as RuntimeActionResponse; | ||||||||||||||||||||||
| } catch (err: unknown) { | ||||||||||||||||||||||
| EmulatorLogger.forEmulator(Emulators.STORAGE).log( | ||||||||||||||||||||||
| "INFO", | ||||||||||||||||||||||
| serializedRuntimeActionResponse, | ||||||||||||||||||||||
| ); | ||||||||||||||||||||||
| return; | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
| this.handleRuntimeStdout(buf.toString("utf-8")); | ||||||||||||||||||||||
| }); | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| const id = rap.id ?? rap.server_request_id; | ||||||||||||||||||||||
| if (id === undefined) { | ||||||||||||||||||||||
| console.log(`Received no ID from server response ${serializedRuntimeActionResponse}`); | ||||||||||||||||||||||
| return; | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
| return startPromise; | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| const request = this._requests[id]; | ||||||||||||||||||||||
| /** | ||||||||||||||||||||||
| * Dispatches a chunk of the rules runtime's stdout to the awaiting requests. | ||||||||||||||||||||||
| * | ||||||||||||||||||||||
| * The runtime writes one JSON response per line. Node stream "data" events do | ||||||||||||||||||||||
| * not respect message boundaries: under concurrent load several responses | ||||||||||||||||||||||
| * arrive in a single chunk, and a single response can be split across chunks. | ||||||||||||||||||||||
| * So we buffer the incomplete trailing line and only parse complete, | ||||||||||||||||||||||
| * newline-delimited lines. Parsing a raw chunk instead would throw on any | ||||||||||||||||||||||
| * batched responses and silently drop them, hanging every request in the | ||||||||||||||||||||||
| * batch — the root cause of #6194 and #6865. | ||||||||||||||||||||||
| */ | ||||||||||||||||||||||
| private handleRuntimeStdout(chunk: string): void { | ||||||||||||||||||||||
| this._stdoutBuffer += chunk; | ||||||||||||||||||||||
| const lines = this._stdoutBuffer.split("\n"); | ||||||||||||||||||||||
| // The last element is the incomplete trailing line ("" if the chunk ended | ||||||||||||||||||||||
| // on a newline); keep it buffered until its terminator arrives. | ||||||||||||||||||||||
| this._stdoutBuffer = lines.pop() ?? ""; | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| for (const rawLine of lines) { | ||||||||||||||||||||||
| const line = rawLine.trim(); | ||||||||||||||||||||||
| if (line === "") { | ||||||||||||||||||||||
| continue; | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| if (rap.status !== "ok" && !("action" in rap)) { | ||||||||||||||||||||||
| console.warn(`[RULES] ${rap.status}: ${rap.message}`); | ||||||||||||||||||||||
| rap.errors.forEach(console.warn.bind(console)); | ||||||||||||||||||||||
| return; | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
| let rap; | ||||||||||||||||||||||
| try { | ||||||||||||||||||||||
| rap = JSON.parse(line) as RuntimeActionResponse; | ||||||||||||||||||||||
| } catch (err: unknown) { | ||||||||||||||||||||||
| EmulatorLogger.forEmulator(Emulators.STORAGE).log("INFO", line); | ||||||||||||||||||||||
| continue; | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| if (request) { | ||||||||||||||||||||||
| request.handler(rap); | ||||||||||||||||||||||
| } else { | ||||||||||||||||||||||
| console.log(`No handler for event ${serializedRuntimeActionResponse}`); | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
| const id = rap.id ?? rap.server_request_id; | ||||||||||||||||||||||
| if (id === undefined) { | ||||||||||||||||||||||
| console.log(`Received no ID from server response ${line}`); | ||||||||||||||||||||||
| continue; | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
|
Comment on lines
+233
to
236
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Avoid using
Suggested change
References
|
||||||||||||||||||||||
| }); | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| return startPromise; | ||||||||||||||||||||||
| const request = this._requests[id]; | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| if (rap.status !== "ok" && !("action" in rap)) { | ||||||||||||||||||||||
| console.warn(`[RULES] ${rap.status}: ${rap.message}`); | ||||||||||||||||||||||
|
Check warning on line 241 in src/emulator/storage/rules/runtime.ts
|
||||||||||||||||||||||
| rap.errors.forEach(console.warn.bind(console)); | ||||||||||||||||||||||
| continue; | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
|
Comment on lines
+240
to
+244
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Avoid using
Suggested change
References
|
||||||||||||||||||||||
|
|
||||||||||||||||||||||
| if (request) { | ||||||||||||||||||||||
| request.handler(rap); | ||||||||||||||||||||||
| } else { | ||||||||||||||||||||||
| console.log(`No handler for event ${line}`); | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
|
Comment on lines
+246
to
+250
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Avoid using
Suggested change
References
|
||||||||||||||||||||||
| } | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| stop(): Promise<void> { | ||||||||||||||||||||||
|
|
@@ -263,22 +288,29 @@ | |||||||||||||||||||||
| } | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| return new Promise<RuntimeActionResponse>((resolve) => { | ||||||||||||||||||||||
| this._requests[runtimeActionRequest.id] = { | ||||||||||||||||||||||
| const requestId = runtimeActionRequest.id; | ||||||||||||||||||||||
| this._requests[requestId] = { | ||||||||||||||||||||||
| request: runtimeActionRequest, | ||||||||||||||||||||||
| handler: resolve, | ||||||||||||||||||||||
| handler: (rap: RuntimeActionResponse) => { | ||||||||||||||||||||||
| // Free the pending-request entry on completion. Previously entries | ||||||||||||||||||||||
| // were only deleted on the firestore cross-service override path, | ||||||||||||||||||||||
| // leaking one entry per request otherwise. | ||||||||||||||||||||||
| delete this._requests[requestId]; | ||||||||||||||||||||||
| resolve(rap); | ||||||||||||||||||||||
| }, | ||||||||||||||||||||||
| }; | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| const serializedRequest = JSON.stringify(runtimeActionRequest); | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
| // Added due to https://github.com/firebase/firebase-tools/issues/3915 | ||||||||||||||||||||||
| // Without waiting to acquire the lock and allowing the child process enough time | ||||||||||||||||||||||
| // (~15ms) to pipe the output back, the emulator will run into issues with | ||||||||||||||||||||||
| // capturing the output and resolving corresponding promises en masse. | ||||||||||||||||||||||
| // The ~15ms delay that used to sit here (added for #3915) was a workaround | ||||||||||||||||||||||
| // for the stdout framing bug: it slowed request writes so responses were | ||||||||||||||||||||||
| // less likely to batch into a single "data" event. Now that stdout is | ||||||||||||||||||||||
| // framed on newlines (see the handler in start()), the delay is | ||||||||||||||||||||||
| // unnecessary and only slows every request, so release the lock as soon | ||||||||||||||||||||||
| // as the write is queued. | ||||||||||||||||||||||
| lock.acquire(synchonizationKey, (done) => { | ||||||||||||||||||||||
| this._childprocess?.stdin?.write(serializedRequest + "\n"); | ||||||||||||||||||||||
| setTimeout(() => { | ||||||||||||||||||||||
| done(); | ||||||||||||||||||||||
| }, 15); | ||||||||||||||||||||||
| done(); | ||||||||||||||||||||||
| }); | ||||||||||||||||||||||
| }); | ||||||||||||||||||||||
| } | ||||||||||||||||||||||
|
|
||||||||||||||||||||||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
To prevent potential cross-run pollution or unexpected hangs, consider resetting
_stdoutBufferto an empty string when starting or stopping the rules runtime (e.g., instart()orstop()). If the emulator is stopped and restarted, any leftover partial data in_stdoutBufferfrom the previous run could be prepended to the first response of the new run, causing JSON parsing failures.