#ActiveRecord::SessionStore::Session Silent No More
Have you ever wondered why SQL statements for sessions aren’t logged when you are using :active_recored_store? Me too. This morning, with a hot cup of coffe by my side, I decided to dig in and find out. It turns out to be straight forward and you can easily turn it off.
Take a look at activerecord/lib/active_record/session_store.rb in Rails and you’ll find the key methods: get_session, set_session, and destroy_session. Notice that the methods that make database calls are in a block within Base.silence. The silence method (found in ActiveSupport::Benchmarkable, which ActiveRecord::Base extends) temporarily changes the log level to ::Logger::ERROR so that the SQL is not logged and then changes it back to whatever it was previously.
If you’d like to see what’s going on in there, you can override this functionality in an initializer. Put the following code in config/initializers/unsilence_session_log.rb and restart your application.
module ActiveSupport module Benchmarkable def silence yield end end end
Now you should see some extra info in your logs. Something like this:
Started GET "/" for 127.0.0.1 at 2013-01-19 13:28:11 -0800 ActiveRecord::SessionStore::Session Load (0.3ms) SELECT `sessions`.* FROM `sessions` WHERE `sessions`.`session_id` = 'fabc7c4db04d13d59a6966e0ab0ef37d' LIMIT 1 Processing by FooController#index as HTML Rendered foo/index.html.erb within layouts/application (0.3ms) Completed 200 OK in 19ms (Views: 18.3ms | ActiveRecord: 0.0ms) (0.1ms) BEGIN (0.3ms) UPDATE `sessions` SET `data` = 'BAh7CEkiEnJldHVybl90b191cmwGOgZFRkkiIWh0dHA6Ly9sb2NhbGhvc3Q6\nM ... Qx\nRmc9BjsARg==\n', `updated_at` = '2013-01-19 21:28:11' WHERE `sessions`.`id` = 285 (0.6ms) COMMIT
The session data is trimmed for slightly better readability. I had fun digging around the Rails source code, I hope you enjoyed reading!