Google-cloud-python: Pub/sub: '504 Deadline Exceeded' response from 'SubscriberClient.pull'

[TetsutaroWatanabe]

google-cloud-pubsub 1.0.0 return 504 Deadline Exceeded.

When I downgrade version to 0.45.0, then the error does not appear.

Environment details

Python 3.7.2

google-cloud-pubsub version 1.0.0

pubsub subscription

 $ gcloud pubsub subscriptions describe projects/xxx/subscriptions/yyy
ackDeadlineSeconds: 20
expirationPolicy:
  ttl: 26784000s
messageRetentionDuration: 604800s
name: projects/xxx/subscriptions/yyy
pushConfig: {}
retainAckedMessages: true
topic: projects/xxx/topics/zzz

follow packages are installed together.

$ pip list | grep google-cloud
google-cloud-bigquery     1.17.0     
google-cloud-container    0.3.0      
google-cloud-core         1.0.2      
google-cloud-logging      1.11.0     
google-cloud-pubsub       1.0.0      
google-cloud-storage      1.17.0     

Steps to reproduce

Run follow script.

from google.cloud import pubsub

subscriber_client = pubsub.SubscriberClient()
subscription_path = subscriber_client.subscription_path("xxx","yyy")
pull_response = subscriber_client.pull(subscription=subscription_path, max_messages=1)

Stack trace

Traceback (most recent call last):
  File "/Users/bbbb/venv/aaaa/lib/python3.7/site-packages/google/api_core/grpc_helpers.py", line 57, in error_remapped_callable
    return callable_(*args, **kwargs)
  File "/Users/bbbb/venv/aaaa/lib/python3.7/site-packages/grpc/_channel.py", line 565, in __call__
    return _end_unary_response_blocking(state, call, False, None)
  File "/Users/bbbb/venv/aaaa/lib/python3.7/site-packages/grpc/_channel.py", line 467, in _end_unary_response_blocking
    raise _Rendezvous(state, None, None, deadline)
grpc._channel._Rendezvous: <_Rendezvous of RPC that terminated with:
    status = StatusCode.DEADLINE_EXCEEDED
    details = "Deadline Exceeded"
    debug_error_string = "{"created":"@1570074717.534613000","description":"Error received from peer ipv4:172.217.31.138:443","file":"src/core/lib/surface/call.cc","file_line":1052,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "pubsub_bug.py", line 5, in <module>
    pull_response = subscriber_client.pull(subscription=subscription_path, max_messages=1)
  File "/Users/bbbb/venv/aaaa/lib/python3.7/site-packages/google/cloud/pubsub_v1/_gapic.py", line 40, in <lambda>
    fx = lambda self, *a, **kw: wrapped_fx(self.api, *a, **kw)  # noqa
  File "/Users/bbbb/venv/aaaa/lib/python3.7/site-packages/google/cloud/pubsub_v1/gapic/subscriber_client.py", line 1005, in pull
    request, retry=retry, timeout=timeout, metadata=metadata
  File "/Users/bbbb/venv/aaaa/lib/python3.7/site-packages/google/api_core/gapic_v1/method.py", line 143, in __call__
    return wrapped_func(*args, **kwargs)
  File "/Users/bbbb/venv/aaaa/lib/python3.7/site-packages/google/api_core/retry.py", line 273, in retry_wrapped_func
    on_error=on_error,
  File "/Users/bbbb/venv/aaaa/lib/python3.7/site-packages/google/api_core/retry.py", line 182, in retry_target
    return target()
  File "/Users/bbbb/venv/aaaa/lib/python3.7/site-packages/google/api_core/timeout.py", line 214, in func_with_timeout
    return func(*args, **kwargs)
  File "/Users/bbbb/venv/aaaa/lib/python3.7/site-packages/google/api_core/grpc_helpers.py", line 59, in error_remapped_callable
    six.raise_from(exceptions.from_grpc_error(exc), exc)
  File "<string>", line 3, in raise_from
google.api_core.exceptions.DeadlineExceeded: 504 Deadline Exceeded

[tseaver]

@TetsutaroWatanabe Thanks for the report. Your example doesn't show actually publishing any messages to the topic, which means that the pull_response should be returned with received_messages empty. I can reproduce the 504 error in this case, although not if there are actual messages to be pulled.

[TetsutaroWatanabe]

@tseaver Thank you for reply.
Do you mean that in case of empty 504 error is occurred according to specification ?

If yes, 504 error is misunderstanding because the expression of 504 in document is follows

The request did not complete in the time allocated. This can be caused by network issues from the client to the server, and it can also occur rarely on the server. On this error, the server may or may not execute the operation requested.

https://cloud.google.com/pubsub/docs/reference/error-codes

I misunderstood that 504 error was caused by the network issue.

[tseaver]

@TetsutaroWatanabe I believe that the 504 is reproducible, although its semantics should be transient.

[0xmax]

@tseaver I have just experienced the same issue. Trying to pull one message. If there is no new messages 504 is thrown instead of the expected empty result.

[tseaver]

Per the docs for the Pull API method, there is a return_immediately flag in the PullRequest message: if set, it avoids blocking, even in the case that no messages are available. We should likely be setting that flag for synchronous pulls.

[tseaver]

The docs for the return_immediately field of the PullRequest message state:

If this field set to true, the system will respond immediately even if it there are no messages available to return in the Pull response. Otherwise, the system may wait (for a bounded amount of time) until at least one message is available, rather than returning no messages.

Our generated SubscriberClient.pull already exposes the return_immediately parameter, and copies it into the message. So, the workaround for this issue is to pass that flag from the application.

In the (default) case that return_immediately is False, the Subscriber client GAPIC config for Pull has a timeout of 60 seconds. If the backend is likely to wait longer, then we need to update the source for that configuration.

@anguillanneuf can you find out from the backend team what that expected time should be?

[TetsutaroWatanabe]

Strangely, this issue no longer occurs. It cannot be reproduced any more.
So I think this problem is caused by a combination of a temporary network problem and an empty queue.

I close this issue. thank you.

[pmarks-net]

I suspect this is related to https://github.com/googleapis/google-cloud-python/commit/31e96ae9411b79c21260518a379a593657efe5b3 decreasing the value of initial_rpc_timeout_millis from 25000 to 5000. If I change it back to 25000, I no longer see 504 Deadline Exceeded.

Here's the code snippet that was triggering 504 errors:

client = pubsub_v1.SubscriberClient()
sub_path = client.subscription_path(project_name, sub_name)
while True:
  response = client.pull(subscription=sub_path, max_messages=1, return_immediately=False)
  for message in response.received_messages:
    ProcessMessage(message.message)
  client.acknowledge(sub_path, [m.ack_id for m in response.received_messages])

Adding client.pull(..., timeout=30.0) also seems to fix the problem.

[HenleyKuang]

I suspect this is related to 31e96ae decreasing the value of initial_rpc_timeout_millis from 25000 to 5000. If I change it back to 25000, I no longer see 504 Deadline Exceeded.

Here's the code snippet that was triggering 504 errors:

client = pubsub_v1.SubscriberClient()
sub_path = client.subscription_path(project_name, sub_name)
while True:
  response = client.pull(subscription=sub_path, max_messages=1, return_immediately=False)
  for message in response.received_messages:
    ProcessMessage(message.message)
  client.acknowledge(sub_path, [m.ack_id for m in response.received_messages])

Adding client.pull(..., timeout=30.0) also seems to fix the problem.

Yeah, I'm still getting this error when my sub has no messages. Anything under 20 seconds would raise DeadlineExceeded

[carnesen]

We've started encountering "504 Deadline Exceeded" failures intermittently after switching to synchronous pulls at the suggestion of GCP support. Since I saw this in production today using the latest releases of this library and also judging by the number of 👍 on the above comment, this issue should be re-opened. It's the #1 search result for "504 deadline exceeded" (for me at least).

$ pip list | grep google
google-api-core          1.22.0
google-auth              1.20.1
google-cloud-pubsub      1.7.0
googleapis-common-protos 1.51.0
grpc-google-iam-v1       0.12.3

[tseaver]

@carnesen google-cloud-pubsub is now maintained in its own repository. I believe the default initial RPC timeout was restored in https://github.com/googleapis/python-pubsub/pull/43. If you can reproduce this against the current release, please report there.