Userstamp trying to set stamper when connecting to dB if not called

[noctivityinc]

This is a weird one. We have a simple monitoring routine in a controller called HealthController

Here is the method:

 def db
    sql = "SELECT true;"
    ActiveRecord::Base.establish_connection
    result = ActiveRecord::Base.connection.execute(sql)
    resp = result.first["bool"] == 't'

    respond_to do |wants|
      wants.json do
        if resp
          render json: {status: :ok}
        else
          render json: {status: :unprocessable_entity}
        end
      end
    end
end

In our controller spec when we try to do a simple GET from the health controller, we get an error. Here is the spec:

RSpec.describe HealthController, :type => :controller do

  describe "GET db" do
    it "returns http success" do
      get :db, format: 'json'
      expect(response).to have_http_status(:success)
    end
  end

end

And here is what we see:

1) HealthController GET db returns http success
     Failure/Error: get :db, format: 'json'

     NameError:
       undefined local variable or method `current_user' for #<HealthController:0x007fb202cae480>
       Did you mean?  current_ability
     # /Users/jlippiner/.rvm/gems/ruby-2.4.1@dmvcs/gems/activerecord-userstamp-3.0.4/lib/active_record/userstamp/controller_additions.rb:34:in `set_stamper'
     # /Users/jlippiner/.rvm/gems/ruby-2.4.1@dmvcs/gems/activerecord-userstamp-3.0.4/lib/active_record/userstamp/controller_additions.rb:21:in `with_stamper'
     # /Users/jlippiner/.rvm/gems/ruby-2.4.1@dmvcs/gems/activesupport-4.2.9/lib/active_support/callbacks.rb:432:in `block in make_lambda'
     # /Users/jlippiner/.rvm/gems/ruby-2.4.1@dmvcs/gems/activesupport-4.2.9/lib/active_support/callbacks.rb:312:in `block in halting'
     # /Users/jlippiner/.rvm/gems/ruby-2.4.1@dmvcs/gems/activesupport-4.2.9/lib/active_support/callbacks.rb:497:in `block in around'
     # /Users/jlippiner/.rvm/gems/ruby-2.4.1@dmvcs/gems/activesupport-4.2.9/lib/active_support/callbacks.rb:505:in `call'
     # /Users/jlippiner/.rvm/gems/ruby-2.4.1@dmvcs/gems/activesupport-4.2.9/lib/active_support/callbacks.rb:92:in `__run_callbacks__'
     # /Users/jlippiner/.rvm/gems/ruby-2.4.1@dmvcs/gems/activesupport-4.2.9/lib/active_support/callbacks.rb:778:in `_run_process_action_callbacks'
     # /Users/jlippiner/.rvm/gems/ruby-2.4.1@dmvcs/gems/activesupport-4.2.9/lib/active_support/callbacks.rb:81:in `run_callbacks'
     # /Users/jlippiner/.rvm/gems/ruby-2.4.1@dmvcs/gems/actionpack-4.2.9/lib/abstract_controller/callbacks.rb:19:in `process_action'
     # /Users/jlippiner/.rvm/gems/ruby-2.4.1@dmvcs/gems/actionpack-4.2.9/lib/action_controller/metal/rescue.rb:29:in `process_action'
     # /Users/jlippiner/.rvm/gems/ruby-2.4.1@dmvcs/gems/actionpack-4.2.9/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action'
     # /Users/jlippiner/.rvm/gems/ruby-2.4.1@dmvcs/gems/activesupport-4.2.9/lib/active_support/notifications.rb:164:in `block in instrument'
     # /Users/jlippiner/.rvm/gems/ruby-2.4.1@dmvcs/gems/activesupport-4.2.9/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
     # /Users/jlippiner/.rvm/gems/ruby-2.4.1@dmvcs/gems/activesupport-4.2.9/lib/active_support/notifications.rb:164:in `instrument'
     # /Users/jlippiner/.rvm/gems/ruby-2.4.1@dmvcs/gems/actionpack-4.2.9/lib/action_controller/metal/instrumentation.rb:30:in `process_action'
     # /Users/jlippiner/.rvm/gems/ruby-2.4.1@dmvcs/gems/actionpack-4.2.9/lib/action_controller/metal/params_wrapper.rb:250:in `process_action'
     # /Users/jlippiner/.rvm/gems/ruby-2.4.1@dmvcs/gems/activerecord-4.2.9/lib/active_record/railties/controller_runtime.rb:18:in `process_action'
     # /Users/jlippiner/.rvm/gems/ruby-2.4.1@dmvcs/gems/actionpack-4.2.9/lib/abstract_controller/base.rb:137:in `process'
     # /Users/jlippiner/.rvm/gems/ruby-2.4.1@dmvcs/gems/actionview-4.2.9/lib/action_view/rendering.rb:30:in `process'
     # /Users/jlippiner/.rvm/gems/ruby-2.4.1@dmvcs/gems/actionpack-4.2.9/lib/action_controller/test_case.rb:639:in `process'
     # /Users/jlippiner/.rvm/gems/ruby-2.4.1@dmvcs/gems/actionpack-4.2.9/lib/action_controller/test_case.rb:67:in `process'
     # /Users/jlippiner/.rvm/gems/ruby-2.4.1@dmvcs/gems/actionpack-4.2.9/lib/action_controller/test_case.rb:514:in `get'
     # ./spec/controllers/health_controller_spec.rb:7:in `block (3 levels) in <top (required)>'

Finished in 0.7188 seconds (files took 7.26 seconds to load)
1 example, 1 failure

Why would userstamp be involved at all in this?

[noctivityinc]

Update - apparently it has NOTHING to do with the method being called as it crashes well before:

Here are the routes:

Rails.application.routes.draw do

  get "health/db"
  get "health/app"

And we can have an empty method in the health controller:

def app
end

and it will still crash with the same error.

[noctivityinc]

Another update:

Adding a current user method to the HealthController fixed the issue:

  def current_user
    nil
  end

BUT this still doesnt explain why it was called in the first place.

[lowjoel]

This is because ActiveRecord Userstamp sets the stamper for the lifetime of the request when flow of control is given to the controller. This is so that users do not have to explicitly set the stamper at the entry of every request.

I would imagine most controllers would have the current_user method; AFAIK Devise would just return nil for controllers which do not require authentication. Is that not the case for you?

[lowjoel]

The behaviour is included in controller_additions.rb