Using omniauth-oauth2
alongside omniauth-facebook
and omniauth-google-oauth2
for social authentication with Devise, we saw this obscure error cropping up in our Cucumber suite. We couldn't figure out what was going wrong. Google led us on some goose hunts. Any ideas?
@selenium
Scenario: I can login with Google+ # features/authentication.feature:114
A refresh_token is not available (RuntimeError)
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/oauth2-0.8.1/lib/oauth2/access_token.rb:81:in `refresh!'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/omniauth-oauth2-1.0.3/lib/omniauth/strategies/oauth2.rb:63:in `callback_phase'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/omniauth-1.1.1/lib/omniauth/strategy.rb:219:in `callback_call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/omniauth-1.1.1/lib/omniauth/strategy.rb:175:in `call!'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/omniauth-1.1.1/lib/omniauth/strategy.rb:157:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/omniauth-1.1.1/lib/omniauth/strategy.rb:177:in `call!'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/omniauth-1.1.1/lib/omniauth/strategy.rb:157:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/meta_request-0.2.1/lib/meta_request/middlewares/app_request_handler.rb:11:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/rack-contrib-1.1.0/lib/rack/contrib/response_headers.rb:17:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/meta_request-0.2.1/lib/meta_request/middlewares/headers.rb:16:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/meta_request-0.2.1/lib/meta_request/middlewares/meta_request_handler.rb:13:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/request_store-1.0.5/lib/request_store/middleware.rb:9:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/sass-3.2.1/lib/sass/plugin/rack.rb:54:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/warden-1.2.1/lib/warden/manager.rb:35:in `block in call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/warden-1.2.1/lib/warden/manager.rb:34:in `catch'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/warden-1.2.1/lib/warden/manager.rb:34:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/actionpack-3.2.13/lib/action_dispatch/middleware/best_standards_support.rb:17:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/rack-1.4.5/lib/rack/etag.rb:23:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/rack-1.4.5/lib/rack/conditionalget.rb:25:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/actionpack-3.2.13/lib/action_dispatch/middleware/head.rb:14:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/actionpack-3.2.13/lib/action_dispatch/middleware/params_parser.rb:21:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/actionpack-3.2.13/lib/action_dispatch/middleware/flash.rb:242:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/rack-1.4.5/lib/rack/session/abstract/id.rb:210:in `context'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/rack-1.4.5/lib/rack/session/abstract/id.rb:205:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/actionpack-3.2.13/lib/action_dispatch/middleware/cookies.rb:341:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/activerecord-3.2.13/lib/active_record/query_cache.rb:64:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/activerecord-3.2.13/lib/active_record/connection_adapters/abstract/connection_pool.rb:479:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/actionpack-3.2.13/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/activesupport-3.2.13/lib/active_support/callbacks.rb:405:in `_run__3252172032061673430__call__1496937490684777386__callbacks'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/activesupport-3.2.13/lib/active_support/callbacks.rb:405:in `__run_callback'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/activesupport-3.2.13/lib/active_support/callbacks.rb:385:in `_run_call_callbacks'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/activesupport-3.2.13/lib/active_support/callbacks.rb:81:in `run_callbacks'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/actionpack-3.2.13/lib/action_dispatch/middleware/callbacks.rb:27:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/actionpack-3.2.13/lib/action_dispatch/middleware/remote_ip.rb:31:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/bugsnag-1.2.12/lib/bugsnag/rack.rb:36:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/actionpack-3.2.13/lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/actionpack-3.2.13/lib/action_dispatch/middleware/show_exceptions.rb:56:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/cucumber-rails-1.4.0/lib/cucumber/rails/action_controller.rb:10:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/railties-3.2.13/lib/rails/rack/logger.rb:32:in `call_app'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/railties-3.2.13/lib/rails/rack/logger.rb:16:in `block in call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/activesupport-3.2.13/lib/active_support/tagged_logging.rb:22:in `tagged'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/railties-3.2.13/lib/rails/rack/logger.rb:16:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/actionpack-3.2.13/lib/action_dispatch/middleware/request_id.rb:22:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/rack-1.4.5/lib/rack/methodoverride.rb:21:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/rack-1.4.5/lib/rack/runtime.rb:17:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/activesupport-3.2.13/lib/active_support/cache/strategy/local_cache.rb:72:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/rack-1.4.5/lib/rack/lock.rb:15:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/actionpack-3.2.13/lib/action_dispatch/middleware/static.rb:63:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/railties-3.2.13/lib/rails/engine.rb:479:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/railties-3.2.13/lib/rails/application.rb:223:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/rack-1.4.5/lib/rack/builder.rb:134:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/rack-1.4.5/lib/rack/urlmap.rb:64:in `block in call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/rack-1.4.5/lib/rack/urlmap.rb:49:in `each'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/rack-1.4.5/lib/rack/urlmap.rb:49:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/capybara-2.0.3/lib/capybara/server.rb:19:in `call'
/Users/dev/.rvm/gems/ruby-1.9.3-p194@geostellar/gems/rack-1.4.5/lib/rack/handler/webrick.rb:59:in `service'
/Users/dev/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/webrick/httpserver.rb:138:in `service'
/Users/dev/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/webrick/httpserver.rb:94:in `run'
/Users/dev/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/webrick/server.rb:191:in `block in start_thread'
Given I am a visitor # features/step_definitions/authentication_steps.rb:6
When I visit the login or register page # features/step_definitions/authentication_steps.rb:52
And I login with Google+ # features/step_definitions/authentication_steps.rb:29
Then I see the text "Signed in successfully." # features/step_definitions/web_steps.rb:159
We discovered that the error only occurred when a previous test ran that used Timecop
to travel forward in time by 1 day. As it turns out, Google tokens only last for 3600 seconds, so travelling an hour ahead invalidated the original token. Refreshing was then made impossible.
Moral of the story: don't forget to Timecop.return
after travelling in time.