firestore: BulkWriter.close() never resolves when a write retried after close() belongs to a batch cut for a same-document write · Issue #9444 · googleapis/google-cloud-node · GitHub
You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
{{ message }}
Repository navigation
firestore: BulkWriter.close() never resolves when a write retried after close() belongs to a batch cut for a same-document write #9444
Backend: Firestore emulator v1.21.0 and v1.22.0 (both reproduce it deterministically)
Summary
BulkWriter.close() (and flush()) never resolves when a write gets a retryable error and it sits in a batch that _sendFn scheduled with flush=false, i.e. the batch that was cut because the next write targets a document already in it.
_sendFn does this when two writes target the same document:
Once that batch commits, _sendBatch calls if (flush) this._scheduleCurrentBatch(flush), which is skipped here. The failing op's onError calls sendFn again, which puts the retry into the new current _bulkCommitBatch. Nothing ever schedules that batch:
close() already ran,
the op is not flushed (only buffered ops get markFlushed()),
and its batch was not a flush batch.
_lastOp therefore never settles, and close() hangs forever. The docs for close() promise the opposite: "Any retries scheduled as part of an onWriteError() handler will be run before the close() promise resolves."
With the default error handler the same thing happens for any retryable code. We hit it through ABORTED, where two writes to one document in one BulkWriter raced each other. The repro below uses a custom onWriteError so it is deterministic.
Steps to reproduce
// npm i @google-cloud/firestore// FIRESTORE_EMULATOR_HOST=127.0.0.1:8080 node bulkwriter-lost-retry.jsconst{ Firestore }=require('@google-cloud/firestore');constdb=newFirestore({projectId: `bw-lost-retry-${Date.now()}`});constt0=Date.now();constlog=(...a)=>console.log(`+${Date.now()-t0}ms`, ...a);(async()=>{constbw=db.bulkWriter();// Retry every error up to 3 attempts, NOT_FOUND included.bw.onWriteError(err=>{log(`write error code=${err.code} attempt=${err.failedAttempts}`);returnerr.failedAttempts<3;});constmissing=db.doc('c/missing');constother=db.doc('c/other');bw.update(missing,{a: 1}).catch(e=>log('update rejected',e.code));bw.set(other,{a: 1});// Second write to `other`: _sendFn schedules the current batch (update +// first set) with flush=false and starts a new batch for this write.bw.set(other,{a: 2});awaitbw.close();log('close() resolved');process.exit(0);})();setTimeout(()=>{log('BUG: close() still pending after 15s; the retried update was never sent');process.exit(1);},15000);
Actual:
+64ms write error code=5 attempt=1
+15001ms BUG: close() still pending after 15s; the retried update was never sent
Control: remove the second bw.set(other, …), so no batch gets cut. The retries then run and close() resolves:
With setLogFunction the last line is BulkWriter.errorFn ... shouldRetry: true, and no further request is sent.
Expected
A retry should be sent even when it belongs to a batch scheduled with flush=false, and close() should resolve once it has run, as documented.
A possible fix: have _sendBatch also reschedule the current batch after a commit when close()/flush() has already been called, for example by tracking a "flush requested" flag on the writer instead of relying on each batch's flush argument. Alternatively, _sendFn could schedule immediately when it re-enqueues a retry after a flush was requested.
Real-world impact
A service that writes one document twice in one BulkWriter (set-merge plus a follow-up update) hung forever in close(). Firestore emulator v1.22.0 started returning ABORTED Transaction lock timeout. for one of the two concurrent batchWrite calls (firebase/firebase-tools#11160), and the retry of that ABORTED write was lost as described above. Real Firestore can also return ABORTED on contention, so production code is exposed too.
Activity