Help debugging Google OAuth 2 callback

[cenon-delrosario]

Hi,

Not really an issue but I was wondering if someone can help us diagnose an issue with Google OAuth2.

The problem we are seeing is that after the user consents to sharing their details the callback GET request gets logged by Puma but we are not seeing additional log entries while the request is being processed. The only log entry we see is when it fails the GET request.

Environment setup:

• Ubuntu running in EC2 with NGINX proxy
• Rails version: 7.0.3.1 with Puma rack server
• Devise gem version: 4.8.1

Devise initializer:
config.omniauth :google_oauth2, ENV['GOOGLE_CLIENT_ID'], ENV['GOOGLE_CLIENT_SECRET'], { name: 'google' }

Rails routes:

user_google_omniauth_authorize GET|POST /users/auth/google(.:format)                                users/omniauth_callbacks#passthru
user_google_omniauth_callback GET|POST /users/auth/google/callback(.:format)                    users/omniauth_callbacks#google

The log as follows:

I, [2025-07-07T06:40:50.320640 #22788]  INFO -- : [a80446b3-12ea-4dca-ae47-a1dff1dbd0f2] Started GET "/users/auth/google/callback?state=d3c639663aa13c205e9883d1a9f1f0e74ba5d4c46849a9d5&code=4%2F0AVMBsJhX12S8-FDacujrbmeZb0QSwDwLO98WztMUfhZeRcCv2MdLKOw4JFNt-dG1OgrNlQ&scope=email+profile+https%3A%2F%2Fwww.googleapis.com%2Fauth%2Fuserinfo.profile+https%3A%2F%2Fwww.googleapis.com%2Fauth%2Fuserinfo.email+openid&authuser=0&prompt=consent" for 52.62.9.255 at 2025-07-07 06:40:50 +0000
I, [2025-07-07T06:40:50.321955 #22788]  INFO -- : [a80446b3-12ea-4dca-ae47-a1dff1dbd0f2] Processing by Users::OmniauthCallbacksController#failure as */*
I, [2025-07-07T06:40:50.322033 #22788]  INFO -- : [a80446b3-12ea-4dca-ae47-a1dff1dbd0f2]   Parameters: {"state"=>"d3c639663aa13c205e9883d1a9f1f0e74ba5d4c46849a9d5", "code"=>"4/0AVMBsJhX12S8-FDacujrbmeZb0QSwDwLO98WztMUfhZeRcCv2MdLKOw4JFNt-dG1OgrNlQ", "scope"=>"email profile https://www.googleapis.com/auth/userinfo.profile https://www.googleapis.com/auth/userinfo.email openid", "authuser"=>"0", "prompt"=>"consent"}
I, [2025-07-07T06:40:50.323814 #22788]  INFO -- : [a80446b3-12ea-4dca-ae47-a1dff1dbd0f2] Devise Failure
I, [2025-07-07T06:40:50.324127 #22788]  INFO -- : [a80446b3-12ea-4dca-ae47-a1dff1dbd0f2] Redirected to https://staging.hackerspace.govhack.org/
I, [2025-07-07T06:40:50.324255 #22788]  INFO -- : [a80446b3-12ea-4dca-ae47-a1dff1dbd0f2] Completed 302 Found in 2ms (ActiveRecord: 0.3ms | Allocations: 569)

Code in the Controller:

class Users::OmniauthCallbacksController < Devise::OmniauthCallbacksController
  def google
    Rails.logger.debug "Devise Google: Started getting user details"
    @user = google_sign_in request.env['omniauth.auth']
    if @user.persisted?
      Rails.logger.debug "Devise Google: Persisting user"
      flash[:notice] = I18n.t 'devise.omniauth_callbacks.success', kind: 'Google'
      sign_in_and_redirect @user, event: :authentication
    else
      Rails.logger.debug "Devise Google: before handle_auth_error"
      handle_auth_error
    end
  end

  ...

  def failure
    Rails.logger.debug "Devise Failure"
    redirect_to root_path, alert: 'Something went wrong ☹️'
  end

As you can see from the logs it shows the failure message: Devise Failure but is does not even show Devise Google: Started getting user details

This makes us think that there is a layer processing the GET request before it gets to the google method in the controller.
Somewhere before that it fails but there is nothing in the logs.

Are there additional diagnostics we can do to help show what the actual problem is?