Show user id/name in Rails log with Clearance gem

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).

Solution

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.

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.