Nodejs-pubsub: Random DEADLINE_EXCEEDED errors emitted for modifyAckDeadline and acknowledge

[mkls]

Environment details

• OS: Ubuntu 18.04
• Node.js version: 10.11.0
• npm version: 6.5.0
• @google-cloud/pubsub version: 0.28.1

We are processing about 300 messages per second from a subscription, and about once or twice a day we randomly get DEADLINE_EXCEEDED errors emitted like these:

Failed to "acknowledge" for 55 message(s). Reason: 4 DEADLINE_EXCEEDED: Deadline Exceeded
and
Failed to "modifyAckDeadline" for 63 message(s). Reason: 4 DEADLINE_EXCEEDED: Deadline Exceeded

Steps to reproduce

A minimal setup is something like this:

const subscription = new PubSub({...}).subscription(subscriptionName);
subscription.on(`message`, message => processMessage());
subscription.on(`error`, error => console.log(error));

Our processMessage function usually takes around 150ms to run, with highest peaks of 1500ms.

The acknowledgement deadline for the subscription in cloud console is set to 600 seconds.

We've looked through similar issues and tried experimenting with setting

      batching: {
        callOptions: {
          timeout: 600000
        }
      }

as a subscription option as described in #240.

Also tried setting the ackDeadline subscription option, but neither of them seemed to help.

We've also looked through the source code of this repo, but couldn't figure out much, other than these errors come from MessageQueues for ack and nack messages, and seem to be coming through google-gax from somewhere in grpc.

Locally I can make the client emit these errors, if I set { batching: { callOptions: { timeout: 1 }}}, but in production this value is set to a much higher value.

We could just ignore these errors, but it would feel better if someone could give some tips on how to find the root cause or what could be going wrong .

[kir-titievsky]

These are safe to ignore as these are retry-able errors. Ideally we should hide these behind a higher level logging flag.

[pjm17971]

@jkwlui I'm not sure this should be closed as this should ideally be handled internally. For us these errors cause the subscription on close() handler to be called after the on error() handler is called with the DEADLINE_EXCEEDED message. This puts the application in a state of not receiving messages at all. This was actually somewhat hard to detect on our end and cost a non-trivial amount of time to identify the problem (the unhandled exception was in the log messages, but it was a needle in a haystack).

In the mean time, can you advise on how to retry something after the close() unexpected exit handler is called? (or to do something in the error() handler to prevent the exit?) Currently we just exit the process and let Kubernetes recreate the pod. If there's a cleaner way to handle this it would be helpful to know. Also, if this is known behavior, then perhaps the example code for handling subscriptions should include these cases and how to correctly respond, since I'm assume most pubsub use is long running.

[filipsuk]

We are still facing the same issue, have you found any workarounds @mkls @pjm17971 ?

[kir-titievsky]

That a failed ack / modAck request would hang the client seems like a bug
or red herring. Those failures should generally be harmless as they are
best effort anyway. Peter, how frequently do you see these errors, per
time and per message?

On Fri, Sep 27, 2019 at 11:12 AM Filip Suk [e-mail] wrote:

We are still facing the same issue, have you found any workarounds @mkls
https://github.com/mkls @pjm17971 https://github.com/pjm17971 ?

—
You are receiving this because you commented.
Reply to this email directly, view it on GitHub
https://github.com/googleapis/nodejs-pubsub/issues/568?email_source=notifications&email_token=AENMYFQJCQ4WOJQNCEQAFQTQLYPFPA5CNFSM4HEH4JW2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOD7ZG2FQ#issuecomment-535981334,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AENMYFRHZZXCOQPW3HFEI23QLYPFPANCNFSM4HEH4JWQ
.

--
Kir Titievsky | Product Manager | Google Cloud Pub/Sub
https://cloud.google.com/pubsub/overview

[mahaben]

We are facing the same issue, this error puts the app in a state of not receiving messages at all. Any workaround?

Thanks,

[callmehiphop]

@mahaben while this error can be frustrating, I am pretty concerned to hear that it puts your application into that kind of state. Might I trouble you for some additional details?

Are you seeing an uncaught exception/unhandled rejection when this error occurs?
How many subscription objects do you have open in your application?
Are you setting any custom flow control settings on the subscription?
Roughly how many pending messages do you have on your topic?

[filipsuk]

This happened to us mainly when doing CPU intensive work while processing task queue from pubsub.

However I found a suitable workaround, using the general library fixed the issue for me https://github.com/googleapis/google-api-nodejs-client

[callmehiphop]

I think this is probably a duplicate of #770 so I'm going to close this out. If anyone feels that this is an error, let us know and we'll be happy to re-open.