Show user id/name in Rails log with Clearance gem

Question

I'm looking for a way to show the current user on each line in the Rails logs. E.g. [johndoe] Started GET "/" for 127.0.0.1 at 2020-06-07 01:10:33 +0000

Some research suggested using the rails config.log_tags setting

(I came up with a solution, but I have absolutely no idea if there are security ramifications with this).

Answer 1

I found a few ideas which involed finding the user id through their session and cookies. This didn't work for Clearance req.env didn't contain the same data.

• http://blog.simontaranto.com/post/2018-05-18-better-rails-logs-current-user-request-context.html/
• How to log user_name in Rails?

Final code

req is an instance of ActionDispatch::Request, which is created when you load the webpage. You can use a Proc within config.log_tags (which is typically set in config/application.rb or in config/environments/.rb) like this:

config.log_tags = [
    ->(req) { User.current_user_from_request(req) }
]

User.current_user_from_request(request) is a method i've created to handle grabbing the user. This is the current, working implementation:

def self.current_user_from_request(req)
  user = req.env.fetch('rack.request.form_hash', nil)&.fetch('session', nil)&.fetch('email', nil)
  if user.blank?
    Clearance::RackSession.new(Rails.application).call(req.env) unless req.env.key?(:clearance)
    user = req.env[:clearance]&.current_user&.email
    # This line is specific to my implementation. I identify users by their email, and dont need to know the domain  
  end
  user.split("@").first if user.present? 
end

Notes

Read on if you'd like to know how I reached this conclusion.

I found that clearance has Clearance::RackSession and the method call(env) Reads previously existing sessions from a cookie and maintains the cookie on each response.

This code added a :clearance key to req.env

Clearance::RackSession.new(Rails.application).call(req.env)

From here, finding the current user is simply:

req.env[:clearance]&.current_user

Which returns an instance of User (which inherits from ApplicationRecord)

A few issues were raised

Doing this on each request was causing stack too deep errors:

Clearance::RackSession.new(Rails.application).call(req.env) unless req.env.key?(:clearance)

This worked until I logged out and back in, where it raised a ActionController::InvalidAuthenticityToken error. Looks like i was running afoul of forgery protection.

Checking req.env when this error was raised, I found that the form hash submitted on /sessions/sign_in included the user's email, accessed here:

req.env['rack.request.form_hash']

So if I try to access this first (this works for sign_in and sign_out requests) and fallback to the above solution (which works for all other actions), we have a working solution:

user = req.env.fetch('rack.request.form_hash', nil)&.fetch('session', nil)&.fetch('email', nil)

See the Final Code section above for the whole thing. I also want to repeat that I do not know the security implications of this, or if there are any.