Repository navigation
[java-firestore] BulkWriter never sends the first batch when maxOpsPerSecond is below 20, and spins its executor #14632
Description
Issue Details
With BulkWriterOptions.setMaxOpsPerSecond(n) below 20, a first batch holding more than n writes is never sent; with only setInitialOpsPerSecond(n) below 20, it waits for the throttle's ramp-up. Either way, sendBatchLocked reschedules itself with no delay in a busy loop meanwhile.
The constructor creates the first BulkCommitBatch with maxBatchSize 20 before it lowers this.maxBatchSize to the starting rate:
Line 259 in 9de611f
| this.bulkCommitBatch = new BulkCommitBatch(firestore, bulkWriterExecutor, maxBatchSize); |
Lines 285 to 289 in 9de611f
| // Ensure that the batch size is not larger than the number of allowed | |
| // operations per second. | |
| if (startingRate < maxBatchSize) { | |
| this.maxBatchSize = (int) startingRate; | |
| } |
So the first batch can grow to 20 writes while the RateLimiter's capacity is n. tryMakeRequest(size) never succeeds when size exceeds the capacity, and getNextRequestDelayMs returns -1 for that case ("the request is not possible with the current capacity"). sendBatchLocked passes the -1 straight to bulkWriterExecutor.schedule(...), which runs it immediately:
Lines 967 to 977 in 9de611f
| } else { | |
| long delayMs = rateLimiter.getNextRequestDelayMs(batch.getMutationsSize()); | |
| logger.log(Level.FINE, () -> String.format("Backing off for %d seconds", delayMs / 1000)); | |
| bulkWriterExecutor.schedule( | |
| () -> { | |
| synchronized (lock) { | |
| sendBatchLocked(batch); | |
| } | |
| }, | |
| delayMs, | |
| TimeUnit.MILLISECONDS); |
With setMaxOpsPerSecond the capacity never grows, so the batch is never sent. With only setInitialOpsPerSecond, the capacity ramps by 1.5x every 5 minutes, so the batch would go out once the capacity reaches its size, after up to 10 minutes of a spinning executor thread. Batches after the first use the lowered size and are not affected.
Reading the same code, a retried write raises the current batch's limit to RETRY_MAX_BATCH_SIZE (10) in sendOperationLocked regardless of maxBatchSize, which would expose a rate below 10 in the same way. I have not reproduced that path, because it needs a retryable failure.
Creating the first batch after maxBatchSize is computed, capping the retry limit at min(RETRY_MAX_BATCH_SIZE, maxBatchSize), and not rescheduling on -1 would each address part of this.
Found while building an Apache Flink sink on BulkWriter (flink-gcp/flink-connector-gcp), which currently works around it.
Environment
- OS Type and Version: macOS 26 (arm64)
- Java Version and JDK Vendor: Eclipse Temurin 17.0.20
The reproducer runs against the Firestore emulator (gcr.io/google.com/cloudsdktool/google-cloud-cli:587.0.0-emulators). The defect is in client-side logic, so no GCP project is involved.
Dependencies
- Libraries-Bom: 26.90.0
- google-cloud-firestore 3.49.0
- Gax: 2.87.0
- Auth: 1.54.0
The affected code is identical in 3.49.0 and on main.
Reproducer
Run with FIRESTORE_EMULATOR_HOST pointing at the emulator, e.g. docker run -p 8080:8080 gcr.io/google.com/cloudsdktool/google-cloud-cli:587.0.0-emulators gcloud emulators firestore start --host-port=0.0.0.0:8080. Arguments: maxOpsPerSecond and the number of writes. The executor counts scheduled tasks to make the loop visible.
package repro;
import com.google.api.core.ApiFuture;
import com.google.cloud.firestore.BulkWriter;
import com.google.cloud.firestore.BulkWriterOptions;
import com.google.cloud.firestore.Firestore;
import com.google.cloud.firestore.FirestoreOptions;
import com.google.cloud.firestore.WriteResult;
import java.util.ArrayList;
import java.util.List;
import java.util.Map;
import java.util.concurrent.Callable;
import java.util.concurrent.ScheduledFuture;
import java.util.concurrent.ScheduledThreadPoolExecutor;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.TimeoutException;
import java.util.concurrent.atomic.AtomicLong;
/**
* Run with FIRESTORE_EMULATOR_HOST set. Arguments: maxOpsPerSecond (default 10) and the number of
* writes (default 20).
*/
public class RateBelowBatchSizeNeverSends {
public static void main(String[] args) throws Exception {
int maxOpsPerSecond = args.length > 0 ? Integer.parseInt(args[0]) : 10;
int writes = args.length > 1 ? Integer.parseInt(args[1]) : 20;
Firestore db = FirestoreOptions.newBuilder().setProjectId("demo").build().getService();
String collection = "rate-" + System.nanoTime();
CountingExecutor executor = new CountingExecutor();
BulkWriter bulkWriter =
db.bulkWriter(
BulkWriterOptions.builder()
.setMaxOpsPerSecond(maxOpsPerSecond)
.setExecutor(executor)
.build());
List<ApiFuture<WriteResult>> futures = new ArrayList<>();
for (int i = 0; i < writes; i++) {
futures.add(bulkWriter.set(db.document(collection + "/d" + i), Map.of("v", 1)));
}
bulkWriter.flush();
try {
futures.get(0).get(10, TimeUnit.SECONDS);
System.out.println("first write completed");
} catch (TimeoutException e) {
System.out.println("first write did not complete within 10 s");
}
System.out.println("tasks scheduled on the BulkWriter executor: " + executor.scheduled.get());
System.out.println(
"documents written: " + db.collection(collection).get().get().size() + " of " + writes);
System.exit(0);
}
/** Counts every task scheduled on it, to show the retry loop. */
static final class CountingExecutor extends ScheduledThreadPoolExecutor {
final AtomicLong scheduled = new AtomicLong();
CountingExecutor() {
super(1);
}
@Override
public ScheduledFuture<?> schedule(Runnable command, long delay, TimeUnit unit) {
scheduled.incrementAndGet();
return super.schedule(command, delay, unit);
}
@Override
public <V> ScheduledFuture<V> schedule(Callable<V> callable, long delay, TimeUnit unit) {
scheduled.incrementAndGet();
return super.schedule(callable, delay, unit);
}
}
}Logs and Stack Trace
$ java ... repro.RateBelowBatchSizeNeverSends 10 20
first write did not complete within 10 s
tasks scheduled on the BulkWriter executor: 68032582
documents written: 0 of 20
$ java ... repro.RateBelowBatchSizeNeverSends 10 11
first write did not complete within 10 s
tasks scheduled on the BulkWriter executor: 68306384
documents written: 0 of 11
$ java ... repro.RateBelowBatchSizeNeverSends 19 20
first write did not complete within 10 s
tasks scheduled on the BulkWriter executor: 68350467
documents written: 0 of 20
$ java ... repro.RateBelowBatchSizeNeverSends 10 10
first write completed
tasks scheduled on the BulkWriter executor: 2
documents written: 10 of 10
$ java ... repro.RateBelowBatchSizeNeverSends 20 20
first write completed
tasks scheduled on the BulkWriter executor: 2
documents written: 20 of 20
Behavior
Deterministic: any rate below 20 combined with more writes than the rate before the first batch is sent. One executor thread stays at 100% CPU for the duration.
Activity