Google-cloud-ruby: Google Cloud PubSub async pull returns GRPC::DeadlineExceeded error

[bbulpett]

Hi, not sure if this is a bug or an error on my part. I have a subscription set up in Google PubSub and I am trying to pull messages asynchronously using the google-cloud-ruby library. Here is my code which will be executed from a rake task which passes in subscription_name:

def pull!
  creds = Google::Cloud::PubSub::Credentials.new(
    GCP_CREDENTIALS_KEYFILE_PATH,
    scope: "https://www.googleapis.com/auth/pubsub"
  )
  messages = []
  pubsub = Google::Cloud::PubSub.new(
    project_id: GOOGLE_PROJECT_ID,
    credentials: creds
  )

  subscription = pubsub.subscription(subscription_name)

  subscription.pull(immediate: true).each do |received_message|
    puts "Received message: #{received_message.data}"
    received_message.acknowledge!
    messages.push(received_message)
  end

  # Return the collected messages
  messages

rescue => error
  Rails.logger error

  messages.presence
end

The Google::Cloud::PubSub::Credentials part references a working keyfile. I know the JSON keyfile is good since I can use it to generate a working Bearer token using oauth2l and pull from the PubSub using cURL, postman, Net::HTTP, etc. Using an identical JSON credentials object for a separate Google::Cloud::Storage service and that works fine also.

But for some reason using Google::Cloud::PubSub it just hangs and won't respond. After about 60 seconds I get the following error:

GRPC::DeadlineExceeded: 4:Deadline Exceeded. debug_error_string:{"created":"@1602610740.445195000","description":"Deadline Exceeded","file":"src/core/ext/filters/deadline/deadline_filter.cc","file_line":69,"grpc_status":4}
/Users/bbulpet/.rbenv/versions/2.6.5/lib/ruby/gems/2.6.0/gems/grpc-1.32.0-universal-darwin/src/ruby/lib/grpc/generic/active_call.rb:29:in `check_status'
/Users/bbulpet/.rbenv/versions/2.6.5/lib/ruby/gems/2.6.0/gems/grpc-1.32.0-universal-darwin/src/ruby/lib/grpc/generic/active_call.rb:180:in `attach_status_results_and_complete_call'
/Users/bbulpet/.rbenv/versions/2.6.5/lib/ruby/gems/2.6.0/gems/grpc-1.32.0-universal-darwin/src/ruby/lib/grpc/generic/active_call.rb:376:in `request_response'
/Users/bbulpet/.rbenv/versions/2.6.5/lib/ruby/gems/2.6.0/gems/grpc-1.32.0-universal-darwin/src/ruby/lib/grpc/generic/client_stub.rb:172:in `block (2 levels) in request_response'
/Users/bbulpet/.rbenv/versions/2.6.5/lib/ruby/gems/2.6.0/gems/grpc-1.32.0-universal-darwin/src/ruby/lib/grpc/generic/interceptors.rb:170:in `intercept!'
/Users/bbulpet/.rbenv/versions/2.6.5/lib/ruby/gems/2.6.0/gems/grpc-1.32.0-universal-darwin/src/ruby/lib/grpc/generic/client_stub.rb:171:in `block in request_response'
/Users/bbulpet/.rbenv/versions/2.6.5/lib/ruby/gems/2.6.0/gems/gapic-common-0.3.4/lib/gapic/grpc/service_stub/rpc_call.rb:121:in `call'
/Users/bbulpet/.rbenv/versions/2.6.5/lib/ruby/gems/2.6.0/gems/gapic-common-0.3.4/lib/gapic/grpc/service_stub.rb:156:in `call_rpc'
/Users/bbulpet/.rbenv/versions/2.6.5/lib/ruby/gems/2.6.0/gems/google-cloud-pubsub-v1-0.1.2/lib/google/cloud/pubsub/v1/subscriber/client.rb:503:in `get_subscription'
/Users/bbulpet/.rbenv/versions/2.6.5/lib/ruby/gems/2.6.0/gems/google-cloud-pubsub-2.1.0/lib/google/cloud/pubsub/service.rb:154:in `get_subscription'
/Users/bbulpet/.rbenv/versions/2.6.5/lib/ruby/gems/2.6.0/gems/google-cloud-pubsub-2.1.0/lib/google/cloud/pubsub/project.rb:286:in `subscription'

I've tried everything I can think of based on the documentation. Updated all related gems and even tried using deprecated syntax out of desperation. When a debugger is added it appears that this occurs when the following call is executed:

pubsub.subscription(subscription_name)

Also I know the above code does work to produce a Google::Cloud::PubSub::Project object (which I've assigned to pubsub variable), but calling any method of pubsub hangs for a minute and throws the above error response.

If anyone has at least an idea of where to start troubleshooting that would be most appreciated. Curious to know if there are known issues or potential conflicts with other Google::Cloud gems/dependencies (this project does use google-cloud-storage as well).

Thanks

[quartzmo]

See discussion on associated Stack Overflow question.

[quartzmo]

Also I know the above code does work to produce a Google::Cloud::PubSub::Project object

Creating the Google::Cloud::PubSub::Project client object does not make any RPCs or test the credentials in any way until an RPC-backed method is called.

[quartzmo]

Curious to know if there are known issues or potential conflicts with other Google::Cloud gems/dependencies (this project does use google-cloud-storage as well).

Not that are known, and google-cloud-storage and google-cloud-pubsub are very frequently used together, including in the automated integration tests for google-cloud-storage.

[quartzmo]

I can easily and quickly retrieve messages from this subscription using both cURL and Net:HTTP with the same credentials and the https://pubsub.googleapis.com/v1/projects/project-name/subscriptions/subscription-name:pull endpoint. So this account does have the requisite permission to pull.

The gcloud client offers another way to test, although I do not believe it is based on gRPC. Are you able to use gcloud pubsub subscriptions pull in that environment with the same service account? (See Authorizing [gcloud] with a service account.)

[bbulpett]

@quartzmo Thank you for your help. After ensuring that gcloud auth had the correct service account, I was the able to use gcloud pubsub subscriptions pull <subscription-name> using the same service account associated with these credentials. It returned the expected results printed in table format.

[quartzmo]

Great, I think that successful gcloud call (along with your Net::HTTP usage) eliminates the possibility of an auth/permissions issue with your service account.

Do you have another way to test gRPC in that environment? Possibly with another client library from google-cloud-ruby? (like gcloud, google-cloud-storage does not use gRPC)

[quartzmo]

I'm trying to find a simple way to test gRPC without Google auth, in case your service account only has permissions for pubsub.

[bbulpett]

Do you have another way to test gRPC in that environment? Possibly with another client library from google-cloud-ruby?

No currently but I'm trying to find something temporary to stub in. Prior to this pubsub attempt we were only using cloud storage.

[quartzmo]

I don't want to ask for exhaustive details about your deployment, but can you think of anything that would prevent gRPC from working correctly over HTTP/2 in that environment? Also, do you have any way to test your application in a different environment? (We're currently wondering if something is blocking outgoing gRPC calls in the current environment.)

[bbulpett]

Nothing I'm aware of that would prevent this but I'll reach out to the team. Our application does have an environment that I can use to try it out, which I'll begin preparing for now.

[quartzmo]

calling any method of pubsub hangs for a minute and throws the above error response

I believe that the timeout you're seeing could originate in the Ruby grpc client when outgoing requests are blocked by something. (See this grpc issue for a description of this as correct behavior: "Adding the iptables rule results in lots of DEADLINE_EXCEEDED (timeout) exceptions as expected... I expected to see the greeter_client.py continue iterating over the while loop, timing out in exactly 300ms on every call")

The 60 second timeout for get_subscription is configured here in v1/subscriber/client.rb

[quartzmo]

The gRPC Ruby Quickstart tutorial provides a simple "hello world" gRPC service that you might be able to deploy to test gRPC from within the environment in question, although I think for the best test, you would want to deploy the service outside of that environment. I'm not sure what your constraints are for doing something like this.

[bbulpett]

Thanks, the gPRC hello world test appeared to work fine in this environment, based on the instructions in your link. I'll give a try deploying to the different environment once it is freed up. In the meantime we're going to try rolling back to an older version of google-cloud-pubsub (i.e. 0.x.x) since we have several other applications running on old versions.

[quartzmo]

If you have success with an older version, please let us know the version number as well as any higher versions you tested that didn't work.

[bbulpett]

So I didn't have any luck with older versions either. However I was able to ship this to a deployed environment. Executed the code with debugging in place and it connected to pubsub and ran my async message pulls flawlessly. Not sure what could cause this, but now returning to my local environment I am now able to connect. Perhaps the initial connection needs to be made from a GCP hosted application?

In any event it appears to be running now and since I've confirmed our connectivity I can continue my local testing using the emulator. This issue can probably be closed I think. Thank you very much for your help and insight @quartzmo and if you know of some reason it works now that I made that initial connection in the deployed env please advise so I can document.

[quartzmo]

Wow, that sounds like an unusual experience, I have no idea why successful execution in one environment would resolve an issue in another. (If anyone knows, please comment.) In any case, if the trouble was indeed with gRPC; hopefully it will prove its worth with its higher performance. I'll close this issue now. Please do not hesitate to re-open, or to open a new one, if you experience any more difficulty.