How to add a session id to each log message (Rails 3)?

Question

My thinking is to grab session_id and store it in a local thread store, for example.

Thread.current[:session_id] = session[:session_id] 

But some rails are logged in before my filter is called.

I thought I could capture session_id by writing a middleware plugin. But then again, it doesn't seem to me that this is early enough for all protocols.

What is the earliest that I can capture session_id?

Thanks!

Answer 1

Since Rails 3.2 supports tagged logging using the log_tags configuration array, the log_tags array accepts a Proc object, and the proc object is called with the request object, I could configure log_tags as follows:

 config.log_tags = [ :uuid, :remote_ip, lambda {|req| "#{req.cookie_jar["_session_id"]}" } ] 

Works with Rails 3.2.3 using ActiveRecord session storage.

Answer 2

Well, I finally figured it out.

• I moved ActionDispatch::Cookies and ActionDispatch::Session::CookieStore earlier on the stack stack. This seems safe and necessary, because otherwise some logging occurs before the session is initialized.

• I added my own rack middleware component, which sets session_id to the local thread store.

• I redefine the rails logger and add session_id to each log message.

This is very useful for being able to split and analyze all the logs for a specific user session.

I would be interested to know how someone else would do this.

Answer 3

For Rails 3.2 with ActiveSupport::TaggedLogging if you use :cookie_store :

 config.log_tags = [ :uuid, :remote_ip, lambda { |r| "#{r.cookie_jar.signed["_session_id"]["session_id"]}" } ] 

Note. Change "_session_id" to :key value config/initializers/session_store.rb

Related: fooobar.com/questions/1387846 / ...

Answer 4

Based on @Felix answer. I did it on rails 4:

 # config/application.rb config.middleware.delete "ActionDispatch::Cookies" config.middleware.delete "ActionDispatch::Session::CookieStore" config.middleware.insert_before Rails::Rack::Logger, ActionDispatch::Cookies config.middleware.insert_before Rails::Rack::Logger, ActionDispatch::Session::CookieStore # config/environment/development.rb and production.rb config.log_tags = [ lambda {|req| "#{req.subdomain}/#{req.session["user_id"]}" }, :uuid ] config.log_formatter = Logger::Formatter.new 

The following logs are created here:

 I, [2015-11-05T15:45:42.617759 #22056] INFO -- : [verimor/2] [77e593dc-c852-4102-a999-5c90ea0c9d66] Started GET "/home/dashboard" for 192.168.1.37 at 2015-11-05 15:45:42 +0200 

[verimor/2] - subdomain/user_id (this is a multi-user application).

[77e593dc-c852-4102-a999-5c90ea0c9d66] is a unique identifier for this request. Useful for tracking query life cycle.

NTN.