How to resolve: Received unexpected EOS on empty DATA frame from server #866
Description
We stumbled on this issue #822, as this is exactly what we are seeing on our backend while listening to the document updates.
Seeing that the above issue is fixed, we upgraded our client to the latest version.
But we are still continuing to see the EOS on empty DATA frame from server, and our listeners stops listening any further updates.
So trying to understand what is the best way to work around these errors, so our listeners are continuously listening and we dont drop and updates from firestore.
We did try a to implement retry but after the first retry, all subsequent retries just fail and the listeners dont get connected back, which ultimately forces us to restart our application completely.
Relevant code
// entry method which gets called on application start up to start listening to document updates.
Flux<QueryDocumentSnapshot> listenToPaymentRecords() {
return queryStream()
.onErrorResume(
throwable -> {
logger.atSevere().withCause(throwable).log(
"Error connecting firebase stream: %s", throwable.getMessage());
// retrying on EOS exceptions, but doent seem to work the second time.
return Mono.delay(Duration.ofMillis(500)).thenMany(queryStream());
});
}
private Flux<QueryDocumentSnapshot> queryStream() {
return ReactiveFutures.listenToDocuments(queryForTransactions(), executor);
}
private Query queryForTransactions() {
return getCollectionReference().whereEqualTo("state", State.NEW);
}
CollectionReference getCollectionReference() {
return firestore.collection(config.getRefs().getTransactions());
}
public static Flux<QueryDocumentSnapshot> listenToDocuments(Query query, ExecutorService es) {
return Flux.create(
sink -> {
try {
final var listener =
query.addSnapshotListener(
es,
(snapshots, error) -> {
if (error != null) {
logger.atSevere().withCause(error).log("Failed to listen to snapshot change");
sink.error(error);
}
... do stuff here
}
}
Environment details
- Java version: OpenJDK 17.0.2+0
- Firestore version: 3.0.12
Steps to reproduce
- Create a snapshot listener on a document
- Wait for 1 hour
- EventListener::onEvent callback is called with non-null error parameter that is FirestoreException wrapping an EOS situation
Stack trace
2022-02-08T06:12:24-08:00 14:12:24.015 [io-executor-thread-38] ERROR c.t.h.s.p.async.ReactiveFutures - Failed to listen to snapshot change
2022-02-08T06:12:24-08:00 com.google.cloud.firestore.FirestoreException: com.google.api.gax.rpc.InternalException: io.grpc.StatusRuntimeException: INTERNAL: Received unexpected EOS on empty DATA frame from server
2022-02-08T06:12:24-08:00 at com.google.cloud.firestore.FirestoreException.forApiException(FirestoreException.java:104)
2022-02-08T06:12:24-08:00 at com.google.cloud.firestore.Watch.lambda$closeStream$2(Watch.java:344)
2022-02-08T06:12:24-08:00 at io.micronaut.scheduling.instrument.InvocationInstrumenterWrappedRunnable.run(InvocationInstrumenterWrappedRunnable.java:47)
2022-02-08T06:12:24-08:00 at io.micrometer.core.instrument.composite.CompositeTimer.record(CompositeTimer.java:79)
2022-02-08T06:12:24-08:00 at io.micrometer.core.instrument.Timer.lambda$wrap$0(Timer.java:160)
2022-02-08T06:12:24-08:00 at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
2022-02-08T06:12:24-08:00 at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
2022-02-08T06:12:24-08:00 at java.base/java.lang.Thread.run(Thread.java:833)
2022-02-08T06:12:24-08:00 Caused by: com.google.api.gax.rpc.ApiException: com.google.api.gax.rpc.InternalException: io.grpc.StatusRuntimeException: INTERNAL: Received unexpected EOS on empty DATA frame from server
2022-02-08T06:12:24-08:00 at com.google.cloud.firestore.Watch.lambda$closeStream$2(Watch.java:347)
2022-02-08T06:12:24-08:00 ... 6 common frames omitted
2022-02-08T06:12:24-08:00 Caused by: com.google.api.gax.rpc.InternalException: io.grpc.StatusRuntimeException: INTERNAL: Received unexpected EOS on empty DATA frame from server
2022-02-08T06:12:24-08:00 at com.google.api.gax.rpc.ApiExceptionFactory.createException(ApiExceptionFactory.java:65)
2022-02-08T06:12:24-08:00 at com.google.api.gax.grpc.GrpcApiExceptionFactory.create(GrpcApiExceptionFactory.java:72)
2022-02-08T06:12:24-08:00 at com.google.api.gax.grpc.GrpcApiExceptionFactory.create(GrpcApiExceptionFactory.java:60)
2022-02-08T06:12:24-08:00 at com.google.api.gax.grpc.ExceptionResponseObserver.onErrorImpl(ExceptionResponseObserver.java:82)
2022-02-08T06:12:24-08:00 at com.google.api.gax.rpc.StateCheckingResponseObserver.onError(StateCheckingResponseObserver.java:86)
2022-02-08T06:12:24-08:00 at com.google.api.gax.grpc.GrpcDirectStreamController$ResponseObserverAdapter.onClose(GrpcDirectStreamController.java:149)
2022-02-08T06:12:24-08:00 at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39)
2022-02-08T06:12:24-08:00 at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23)
2022-02-08T06:12:24-08:00 at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40)
2022-02-08T06:12:24-08:00 at com.google.api.gax.grpc.ChannelPool$ReleasingClientCall$1.onClose(ChannelPool.java:455)
2022-02-08T06:12:24-08:00 at io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:562)
2022-02-08T06:12:24-08:00 at io.grpc.internal.ClientCallImpl.access$300(ClientCallImpl.java:70)
2022-02-08T06:12:24-08:00 14:12:24.017 [io-executor-thread-38] ERROR reactor.Flux.OnErrorResume.1 - onError(com.google.cloud.firestore.FirestoreException: com.google.api.gax.rpc.InternalException: io.grpc.StatusRuntimeException: INTERNAL: Received unexpected EOS on empty DATA frame from server)
2022-02-08T06:12:24-08:00 14:12:24.017 [io-executor-thread-38] ERROR reactor.Flux.OnErrorResume.1 -
2022-02-08T06:12:24-08:00 com.google.cloud.firestore.FirestoreException: com.google.api.gax.rpc.InternalException: io.grpc.StatusRuntimeException: INTERNAL: Received unexpected EOS on empty DATA frame from server
2022-02-08T06:12:24-08:00 at com.google.cloud.firestore.FirestoreException.forApiException(FirestoreException.java:104)
2022-02-08T06:12:24-08:00 at com.google.cloud.firestore.Watch.lambda$closeStream$2(Watch.java:344)
2022-02-08T06:12:24-08:00 at io.micronaut.scheduling.instrument.InvocationInstrumenterWrappedRunnable.run(InvocationInstrumenterWrappedRunnable.java:47)
2022-02-08T06:12:24-08:00 at io.micrometer.core.instrument.composite.CompositeTimer.record(CompositeTimer.java:79)
2022-02-08T06:12:24-08:00 at io.micrometer.core.instrument.Timer.lambda$wrap$0(Timer.java:160)