Formatting Rails Logs Using ActiveRecord

So, I have an application that previously did not need ActiveRecord - this way we removed ActiveRecord from the application and formatted our log as such:

In application.rb:

class DreamLogFormatter < Logger::Formatter SEVERITY_TO_COLOR_MAP = {'DEBUG'=>'32', 'INFO'=>'0;37', 'WARN'=>'35', 'ERROR'=>'31', 'FATAL'=>'31', 'UNKNOWN'=>'37'} def call(severity, time, progname, msg) color = SEVERITY_TO_COLOR_MAP[severity] "\033[0;37m[%s] \033[#{color}m%5s - %s\033[0m\n" % [time.to_s(:short), severity, msg2str(msg)] end end class ActiveSupport::BufferedLogger def formatter=(formatter) @log.formatter = formatter end end 

In development.rb

 config.logger = Logger.new("log/#{Rails.env}.log") config.logger.formatter = DreamLogFormatter.new ActiveResource::Base.logger = Logger.new("log/#{Rails.env}.log") ActiveResource::Base.logger.formatter = DreamLogFormatter.new 

Note. An ActiveResource registrar configuration has been added because we want the URL of our ActiveResource calls as follows:

 GET http://localhost:2524/users/ --> 200 OK 239 (13.0ms) 

Recording with this configuration gave us a nice combination of ActiveResource calls and our own logging using Rails.logger .

However, we need to add ActiveRecord back to our application, since we needed to change the session store from the cookie store to the ActiveRecord store. And since adding ActiveRecord back, registration no longer works beautifully.

Previous log output:

 Started GET "/audit/?key1=value1&key2=value2" for 0:0:0:0:0:0:0:1%0 at 2012-08-15 15:39:58 -0400 [15 Aug 15:39] INFO - Processing by AuditController#index as HTML [15 Aug 15:39] INFO - Parameters: {"utf8"=>"✓", "key1"=>"value1", "key2"=>"value2"} [15 Aug 15:39] INFO - GET http://localhost:2524/api/users/jeff/prefs/?label=language [15 Aug 15:39] INFO - --> 200 OK 151 (55.0ms) [15 Aug 15:39] WARN - There is no user currently logged in - retrieving default theme. [15 Aug 15:39] INFO - GET http://localhost:2524/api/users/jeff/prefs/?label=theme [15 Aug 15:39] INFO - --> 200 OK 151 (35.0ms) 

Note. . What I really like about this format is that every request is logged, starting with Started GET <URL> or POST or PUT, etc., followed by which controller and function performs the processing, and what parameters are sent. This is very useful for debugging. In addition, this format allowed us to print our own Rails.logger login information.

Current log output (with ActiveRecord) :

 [20 Aug 11:40] INFO - GET http://localhost:2524/api/users/jeff [20 Aug 11:40] INFO - --> 200 OK 199 (144.0ms) [20 Aug 11:40] INFO - GET http://localhost:2524/api/users/jeff/prefs/?label=language [20 Aug 11:40] INFO - --> 200 OK 148 (12.0ms) [20 Aug 11:40] INFO - GET http://localhost:2524/api/users/jeff/prefs/?label=theme [20 Aug 11:40] INFO - --> 200 OK 155 (15.0ms) 

Essentially, all we get is a constant stream of URL requests - it does not register anything from Rails.logger , and there is no separation between different requests - it is literally just one constant stream of URLs and responses.


I tried setting ActiveResource::Base.logger = ActiveRecord::Base.logger , as many recommend blogs, but it just made things worse - he registered a couple of URLs and then just stopped logging, unless it was on ERROR level (and nowhere have I set the registration level, so it should still be the default)

Any help or suggestions would be greatly appreciated! Thanks

+4
source share
1 answer

All Articles