Google-cloud-ruby: bigquery: branch 5552: execution expired (Google::Cloud::Error) in list_tabledata

[seamusabshere]

Environment details

• OS: ubuntu 20.04
• Ruby version: 2.7
• Gem name and version: branch at https://github.com/googleapis/google-cloud-ruby/pull/5552 (which is branched from 0.20.0 I believe)

Steps to reproduce

Run list tabledata on a big table (a million rows or so).

Code example

table.data.all do |row|
  row.fetch(:column1)
end

Full backtrace

Note that this is a single backtrace - not pulled from multiple backtraces.

/var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/service.rb:538:in `rescue in execute': execution expired (Google::Cloud::Error)
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/service.rb:531:in `execute'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/service.rb:201:in `list_tabledata'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/data.rb:413:in `next'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/data.rb:486:in `block in all'
  from /usr/lib/ruby/2.7.0/delegate.rb:85:in `loop'
  from /usr/lib/ruby/2.7.0/delegate.rb:85:in `bind_call'
  from /usr/lib/ruby/2.7.0/delegate.rb:85:in `method_missing'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/data.rb:479:in `all'
  [... app ...]
/usr/lib/ruby/2.7.0/openssl/buffering.rb:57:in `sysread': execution expired (Google::Apis::TransmissionError)
  from /usr/lib/ruby/2.7.0/openssl/buffering.rb:57:in `fill_rbuff'
  from /usr/lib/ruby/2.7.0/openssl/buffering.rb:207:in `gets'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient/ssl_socket.rb:62:in `gets'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient/session.rb:805:in `block in parse_header'
  from /usr/lib/ruby/2.7.0/timeout.rb:105:in `timeout'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient/session.rb:801:in `parse_header'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient/session.rb:784:in `read_header'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient/session.rb:561:in `get_header'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient.rb:1299:in `do_get_header'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient.rb:1245:in `do_get_block'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient.rb:1019:in `block in do_request'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient.rb:1133:in `protect_keep_alive_disconnected'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient.rb:1014:in `do_request'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient.rb:1104:in `follow_redirect'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient.rb:854:in `request'
  from /var/lib/gems/2.7.0/gems/google-api-client-0.38.0/lib/google/apis/core/http_command.rb:301:in `execute_once'
  from /var/lib/gems/2.7.0/gems/google-api-client-0.38.0/lib/google/apis/core/http_command.rb:113:in `block (2 levels) in execute'
  from /var/lib/gems/2.7.0/gems/retriable-3.1.2/lib/retriable.rb:61:in `block in retriable'
  from /var/lib/gems/2.7.0/gems/retriable-3.1.2/lib/retriable.rb:56:in `times'
  from /var/lib/gems/2.7.0/gems/retriable-3.1.2/lib/retriable.rb:56:in `retriable'
  from /var/lib/gems/2.7.0/gems/google-api-client-0.38.0/lib/google/apis/core/http_command.rb:110:in `block in execute'
  from /var/lib/gems/2.7.0/gems/retriable-3.1.2/lib/retriable.rb:61:in `block in retriable'
  from /var/lib/gems/2.7.0/gems/retriable-3.1.2/lib/retriable.rb:56:in `times'
  from /var/lib/gems/2.7.0/gems/retriable-3.1.2/lib/retriable.rb:56:in `retriable'
  from /var/lib/gems/2.7.0/gems/google-api-client-0.38.0/lib/google/apis/core/http_command.rb:102:in `execute'
  from /var/lib/gems/2.7.0/gems/google-api-client-0.38.0/lib/google/apis/core/base_service.rb:360:in `execute_or_queue_command'
  from /var/lib/gems/2.7.0/gems/google-api-client-0.38.0/generated/google/apis/bigquery_v2/service.rb:1130:in `list_table_data'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/service.rb:202:in `block in list_tabledata'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/service.rb:533:in `block in execute'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/service.rb:570:in `block in execute'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/service.rb:568:in `loop'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/service.rb:568:in `execute'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/service.rb:533:in `execute'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/service.rb:201:in `list_tabledata'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/data.rb:413:in `next'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/data.rb:486:in `block in all'
  from /usr/lib/ruby/2.7.0/delegate.rb:85:in `loop'
  from /usr/lib/ruby/2.7.0/delegate.rb:85:in `bind_call'
  from /usr/lib/ruby/2.7.0/delegate.rb:85:in `method_missing'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/data.rb:479:in `all'
  [... app ...]
/usr/lib/ruby/2.7.0/openssl/buffering.rb:57:in `sysread': execution expired (HTTPClient::ReceiveTimeoutError)
  from /usr/lib/ruby/2.7.0/openssl/buffering.rb:57:in `fill_rbuff'
  from /usr/lib/ruby/2.7.0/openssl/buffering.rb:207:in `gets'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient/ssl_socket.rb:62:in `gets'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient/session.rb:805:in `block in parse_header'
  from /usr/lib/ruby/2.7.0/timeout.rb:105:in `timeout'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient/session.rb:801:in `parse_header'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient/session.rb:784:in `read_header'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient/session.rb:561:in `get_header'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient.rb:1299:in `do_get_header'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient.rb:1245:in `do_get_block'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient.rb:1019:in `block in do_request'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient.rb:1133:in `protect_keep_alive_disconnected'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient.rb:1014:in `do_request'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient.rb:1104:in `follow_redirect'
  from /var/lib/gems/2.7.0/gems/httpclient-2.8.3/lib/httpclient.rb:854:in `request'
  from /var/lib/gems/2.7.0/gems/google-api-client-0.38.0/lib/google/apis/core/http_command.rb:301:in `execute_once'
  from /var/lib/gems/2.7.0/gems/google-api-client-0.38.0/lib/google/apis/core/http_command.rb:113:in `block (2 levels) in execute'
  from /var/lib/gems/2.7.0/gems/retriable-3.1.2/lib/retriable.rb:61:in `block in retriable'
  from /var/lib/gems/2.7.0/gems/retriable-3.1.2/lib/retriable.rb:56:in `times'
  from /var/lib/gems/2.7.0/gems/retriable-3.1.2/lib/retriable.rb:56:in `retriable'
  from /var/lib/gems/2.7.0/gems/google-api-client-0.38.0/lib/google/apis/core/http_command.rb:110:in `block in execute'
  from /var/lib/gems/2.7.0/gems/retriable-3.1.2/lib/retriable.rb:61:in `block in retriable'
  from /var/lib/gems/2.7.0/gems/retriable-3.1.2/lib/retriable.rb:56:in `times'
  from /var/lib/gems/2.7.0/gems/retriable-3.1.2/lib/retriable.rb:56:in `retriable'
  from /var/lib/gems/2.7.0/gems/google-api-client-0.38.0/lib/google/apis/core/http_command.rb:102:in `execute'
  from /var/lib/gems/2.7.0/gems/google-api-client-0.38.0/lib/google/apis/core/base_service.rb:360:in `execute_or_queue_command'
  from /var/lib/gems/2.7.0/gems/google-api-client-0.38.0/generated/google/apis/bigquery_v2/service.rb:1130:in `list_table_data'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/service.rb:202:in `block in list_tabledata'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/service.rb:533:in `block in execute'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/service.rb:570:in `block in execute'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/service.rb:568:in `loop'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/service.rb:568:in `execute'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/service.rb:533:in `execute'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/service.rb:201:in `list_tabledata'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/data.rb:413:in `next'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/data.rb:486:in `block in all'
  from /usr/lib/ruby/2.7.0/delegate.rb:85:in `loop'
  from /usr/lib/ruby/2.7.0/delegate.rb:85:in `bind_call'
  from /usr/lib/ruby/2.7.0/delegate.rb:85:in `method_missing'
  from /var/lib/gems/2.7.0/bundler/gems/google-cloud-ruby-8b6a7f9bcaef/google-cloud-bigquery/lib/google/cloud/bigquery/data.rb:479:in `all' 
  [... app ...]

Making sure to follow these steps will guarantee the quickest resolution possible.

Thanks!

[quartzmo]

@seamusabshere Thank you for reporting this issue. Can you try configuring a longer timeout when you initialize the client?

[seamusabshere]

@quartzmo

my error is a HTTPClient::ReceiveTimeoutError

that is controlled by https://github.com/nahi/httpclient/blob/4d60d8bdba79719b7729fca4e4a91b8959b0c1d0/lib/httpclient/session.rb#L801

however you do not set receive_timeout here https://github.com/googleapis/google-api-ruby-client/blob/334a41b6f9063318b4301665a0501c06c1e5d25f/lib/google/apis/core/base_service.rb#L409-L419

so I don't think I can affect this timeout with Google::Cloud::Bigquery.new(retries: 10, timeout: 120)

please advise

[seamusabshere]

@quartzmo any insight?

[quartzmo]

I believe that receive_timeout is set with the value of the client timeout argument here in service.rb.

[quartzmo]

Sorry, no, I was mistaken, that is read_timeout, not receive_timeout.

[quartzmo]

Actually, it does look correct:

service.client_options.read_timeout_sec = timeout

and

if client_options.read_timeout_sec
  client.receive_timeout = client_options.read_timeout_sec
end

[seamusabshere]

@quartzmo i apologize, you're totally correct, it's right there

trying this out

[quartzmo]

@seamusabshere Any new information?

[seamusabshere]

@quartzmo

• we have not seen JSON::ParserError since we started using your branch from at #5552
• we have not seen ReceiveTimeoutError since we increased timeout per your instructions

[quartzmo]

@seamusabshere Since #5552 is not merged, and we do not want to merge that change unless strictly necessary to resolve #5180, can you try reverting back to v1.21.0 but with the increased timeout?

[seamusabshere]

@quartzmo ok, rolling that out now

[quartzmo]

@seamusabshere How is it going with the released version 1.21.0 and the increased timeout? Any more list_tabledata JSON parse errors?

[quartzmo]

@seamusabshere Any update?

[seamusabshere]

JSON::ParserError and ReceiveTimeoutError haven't appeared. I guess that's good?

[quartzmo]

Yes, it's great! Can we close this issue?

[seamusabshere]

yes thank you very much for your attention!