Use of Timecop breaks GRPC requests

qnm commented 3 years ago

Thanks for stopping by to let us know something could be better!

PLEASE READ: If you have a support contract with Google, please create an issue in the support console instead of filing on GitHub. This will ensure a timely response.

Please run down the following list and make sure you've tried the usual "quick fixes":

Search the issues already opened: https://github.com/googleapis/google-cloud-ruby/issues
Search StackOverflow: http://stackoverflow.com/questions/tagged/google-cloud-platform+ruby

If you are still having issues, please be sure to include as much information as possible:

Environment details

OS: Linux, POP! OS 21.04
Ruby version: 2.6.6
Gem name and version: 'google-analytics-data'

Steps to reproduce

Install timecop in addition to 'google-analytics-data'
Use Timecop to set a date in the past e.g. Timecop.freeze(DateTime.parse('2021-04-23 10:00:00 +1100'))
Execute a ga4 analytics report using the gem
See the request fail with the error Google::Cloud::DeadlineExceededError

timecop is a gem commonly used to simulate time in the past. In my case I'm using it to ensure that relative time report parameters are fixed in my specs.

Code example

require 'google/analytics/data'
require 'timecop'

Timecop.freeze(DateTime.parse('2021-04-23 10:00:00 +1100'))

token = {
  'uid' => '',
  'consumer_key' => '',
  'consumer_secret' => '',
  'refresh_token' => ''
}

client = ::Google::Analytics::Data.analytics_data do |config|
  config.credentials = Signet::OAuth2::Client.new(
    :authorization_uri => 'https://accounts.google.com/o/oauth2/auth',
    :token_credential_uri => 'https://www.googleapis.com/oauth2/v3/token',
    :client_id => token['consumer_key'],
    :client_secret => token['consumer_secret'],
    :scope => 'https://www.googleapis.com/auth/analytics.readonly',
    :refresh_token => token['refresh_token']
  )
end

request = {
  'property' => token['uid'],
  'dimensions' => [
    {'name' => 'date'},
  ],
  'metrics' => [
    {
      'name' => 'newUsers'
    },
  ],
  'date_ranges' => [
    {
      'start_date' => '30daysAgo',
      'end_date' => 'yesterday'
    }
  ]
}

response = client.run_report request

puts response

Full backtrace

qnm@pop-os ~/D/G/ga4-analytics-test (master) [1]> bundle exec ruby test.rb
Traceback (most recent call last):
    9: from test.rb:42:in `<main>'
    8: from /home/qnm/.asdf/installs/ruby/2.6.6/lib/ruby/gems/2.6.0/gems/google-analytics-data-v1beta-0.3.0/lib/google/analytics/data/v1beta/analytics_data/client.rb:294:in `run_report'
    7: from /home/qnm/.asdf/installs/ruby/2.6.6/lib/ruby/gems/2.6.0/gems/gapic-common-0.7.0/lib/gapic/grpc/service_stub.rb:156:in `call_rpc'
    6: from /home/qnm/.asdf/installs/ruby/2.6.6/lib/ruby/gems/2.6.0/gems/gapic-common-0.7.0/lib/gapic/grpc/service_stub/rpc_call.rb:121:in `call'
    5: from /home/qnm/.asdf/installs/ruby/2.6.6/lib/ruby/gems/2.6.0/gems/grpc-1.41.0-x86_64-linux/src/ruby/lib/grpc/generic/client_stub.rb:173:in `block in request_response'
    4: from /home/qnm/.asdf/installs/ruby/2.6.6/lib/ruby/gems/2.6.0/gems/grpc-1.41.0-x86_64-linux/src/ruby/lib/grpc/generic/interceptors.rb:170:in `intercept!'
    3: from /home/qnm/.asdf/installs/ruby/2.6.6/lib/ruby/gems/2.6.0/gems/grpc-1.41.0-x86_64-linux/src/ruby/lib/grpc/generic/client_stub.rb:174:in `block (2 levels) in request_response'
    2: from /home/qnm/.asdf/installs/ruby/2.6.6/lib/ruby/gems/2.6.0/gems/grpc-1.41.0-x86_64-linux/src/ruby/lib/grpc/generic/active_call.rb:376:in `request_response'
    1: from /home/qnm/.asdf/installs/ruby/2.6.6/lib/ruby/gems/2.6.0/gems/grpc-1.41.0-x86_64-linux/src/ruby/lib/grpc/generic/active_call.rb:180:in `attach_status_results_and_complete_call'
/home/qnm/.asdf/installs/ruby/2.6.6/lib/ruby/gems/2.6.0/gems/grpc-1.41.0-x86_64-linux/src/ruby/lib/grpc/generic/active_call.rb:29:in `check_status': 4:Deadline Exceeded. debug_error_string:{"created":"@1635469730.030594601","description":"Deadline Exceeded","file":"src/core/ext/filters/deadline/deadline_filter.cc","file_line":81,"grpc_status":4} (GRPC::DeadlineExceeded)
    2: from test.rb:42:in `<main>'
    1: from /home/qnm/.asdf/installs/ruby/2.6.6/lib/ruby/gems/2.6.0/gems/google-analytics-data-v1beta-0.3.0/lib/google/analytics/data/v1beta/analytics_data/client.rb:263:in `run_report'
/home/qnm/.asdf/installs/ruby/2.6.6/lib/ruby/gems/2.6.0/gems/google-analytics-data-v1beta-0.3.0/lib/google/analytics/data/v1beta/analytics_data/client.rb:299:in `rescue in run_report': 4:Deadline Exceeded. debug_error_string:{"created":"@1635469730.030594601","description":"Deadline Exceeded","file":"src/core/ext/filters/deadline/deadline_filter.cc","file_line":81,"grpc_status":4} (Google::Cloud::DeadlineExceededError)

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

Thanks!

dazuma commented 1 year ago

Transferred this issue to this repo because the deadline logic for client libraries lives in the gapic-common gem. I think it is possible to make the gem compatible with timecop by using Process.clock_gettime rather than Time.now. It may, however, make testing the gem more difficult because... we can no longer mock Time.now from our tests. 🤷🏻

abachman commented 1 year ago

For anyone else who runs into this problem, I just ran into this trying to start work on a move to Cloud Spanner (using the local emulator, btw) in a Rails app and ended up with a similar solution in my test suite.

I wasn't able to get the precise fix in #942 working as a runtime patch, but this has the same effect.

In a file named spec/support/spanner/ext/gapic_rpc_call.rb, I redefined Time with just the Time.now method overridden:

# frozen_string_literal: true

# Fix for the "Timecop breaks spanner transactions" issue
#
# https://github.com/googleapis/gapic-generator-ruby/pull/942
# https://github.com/googleapis/gapic-generator-ruby/issues/941
module Gapic
  class ServiceStub
    class RpcCall
      # redefine Time in the scope of this class to prevent the Time.now override bug
      class Time < ::Time
        def self.now
          at Process.clock_gettime Process::CLOCK_REALTIME
        end
      end
    end
  end
end

I then required the file from spec/spec_helper.rb.

The same problem occurs with Timecop.freeze and Rails' built-in travel_to, etc time methods.

OS: ruby:3.0.5-slim-bullseye docker image
Ruby version: 3.0.5
Gem name and version: gapic-common (0.20.0)

googleapis / gapic-generator-ruby