pubsub DEADLINE_EXCEEDED (after period of inactivity)

[fondberg]

We see a strange behaviour in when there is low traffic on a topic where stackdriver shows a spike in undelivered messages as well as oldest unacknowledged message.

We do get some io.grpc.StatusRuntimeExceptions during these low traffic times but not when there is high traffic during the day.

Could comeone have an explaination about this? We are using
-netty-all 4.1.5.Final

• com.google.cloud 0.5.1

io.grpc.StatusRuntimeException: DEADLINE_EXCEEDED: The service was unable to fulfill your request. Please try again. [code=8a75]
    at io.grpc.Status.asRuntimeException
    at io.grpc.stub.ClientCalls$UnaryStreamToFuture.onClose
    at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.close
    at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.access$600
    at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInContext
    at io.grpc.internal.ContextRunnable.run
    at io.grpc.internal.SerializingExecutor$TaskRunner.run
    at java.util.concurrent.Executors$RunnableAdapter.call
    at java.util.concurrent.FutureTask.run
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run
    at java.util.concurrent.ThreadPoolExecutor.runWorker
    at java.util.concurrent.ThreadPoolExecutor$Worker.run
    at java.lang.Thread.run
com.google.api.gax.grpc.ApiException: io.grpc.StatusRuntimeException: DEADLINE_EXCEEDED: The service was unable to fulfill your request. Please try again. [code=8a75]
    at com.google.api.gax.grpc.ExceptionTransformingCallable$ExceptionTransformingFuture.onFailure
    at com.google.common.util.concurrent.Futures$6.run
    at com.google.common.util.concurrent.MoreExecutors$DirectExecutor.execute
    at com.google.common.util.concurrent.AbstractFuture.executeListener
    at com.google.common.util.concurrent.AbstractFuture.complete
    at com.google.common.util.concurrent.AbstractFuture.setException
    at io.grpc.stub.ClientCalls$GrpcFuture.setException
    at io.grpc.stub.ClientCalls$UnaryStreamToFuture.onClose
    at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.close
    at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.access$600
    at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInContext
    at io.grpc.internal.ContextRunnable.run
    at io.grpc.internal.SerializingExecutor$TaskRunner.run
    at java.util.concurrent.Executors$RunnableAdapter.call
    at java.util.concurrent.FutureTask.run
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run
    at java.util.concurrent.ThreadPoolExecutor.runWorker
    at java.util.concurrent.ThreadPoolExecutor$Worker.run
    at java.lang.Thread.run
com.google.cloud.pubsub.PubSubException: io.grpc.StatusRuntimeException: DEADLINE_EXCEEDED: The service was unable to fulfill your request. Please try again. [code=8a75]
    at com.google.cloud.pubsub.spi.DefaultPubSubRpc$1.apply
    at com.google.cloud.pubsub.spi.DefaultPubSubRpc$1.apply
    at com.google.common.util.concurrent.Futures$CatchingFuture.doFallback
    at com.google.common.util.concurrent.Futures$CatchingFuture.doFallback
    at com.google.common.util.concurrent.Futures$AbstractCatchingFuture.run
    at com.google.common.util.concurrent.MoreExecutors$DirectExecutor.execute
    at com.google.common.util.concurrent.AbstractFuture.executeListener
    at com.google.common.util.concurrent.AbstractFuture.complete
    at com.google.common.util.concurrent.AbstractFuture.setException
    at com.google.common.util.concurrent.SettableFuture.setException
    at com.google.api.gax.grpc.BundlingFuture.setException
    at com.google.api.gax.grpc.BundlingContext.sendResult
    at com.google.api.gax.grpc.BundleExecutor.processBundle
    at com.google.api.gax.bundling.ThresholdBundlingForwarder$BundleForwardingRunnable.processBundle
    at com.google.api.gax.bundling.ThresholdBundlingForwarder$BundleForwardingRunnable.run
    at java.lang.Thread.run

[garrettjonesgoogle]

This sounds suspiciously like issues that have been seen with grpc in other languages.

[fondberg]

Yes I saw them when I googled. It is super weird as it happens when there is low traffic

[fondberg]

Here is a picture from stackdriver showing a month worth of data.
The spikes in undelivered messages happen on weekends and in the nights.
If anyone have any idea on how to debug this I would be happy to help.

[garrettjonesgoogle]

We will be upgrading to grpc 1.2 soon: #1691 ; If the issue is fixed by that, then there would be no work to be done.

[fondberg]

ok thanks, but will that be with the new pubsub api only or also for 0.5.1?

[garrettjonesgoogle]

It would be put into master, so it would only be available in the release it was added to, or later releases. Since this library is not GA, we are not patching previous releases yet.

[garrettjonesgoogle]

Marking as blocked (grpc 1.2 upgrade)

[garrettjonesgoogle]

After we upgrade to 1.2, in order to see if this is fixed, we need to make sure that calls are successful after long periods of inactivity (at least an hour).

[fondberg]

It will be hard for us to help testing as we require thread limitations for our pubsub implementation (see #1827) and we haven't migrated to the new API.

[garrettjonesgoogle]

The latest release of google-cloud-pubsub now depends on grpc 1.2.

[garrettjonesgoogle]

Removing the release-blocking label because we don't have a repro case.

[garrettjonesgoogle]

Since we don't have a repro case, I'm going to close this out. If the issue is still happening on the latest google-cloud-java (note: we are on grpc 1.4 now), please re-open.