Add process information to Rails logger

Question

I currently have a Rails application that has multiple processes: the web serving processes and the background workers, that are triggered by Redis.

Problem is sometimes is hard to check the log files and determine where a given behavior happened - was it on the Web portion or on the Resque workers?

Is there a way to include the process name or even process id or something that allows me to differentiate each log entry by process?

score 4 · Accepted Answer · edited May 23 '17 at 12:32

It looks like there are a few options out there for this:

Subclass Buffered logger and use that instead: https://gist.github.com/krutten/1091611 (from http://help.papertrailapp.com/discussions/suggestions/18-include-pids-in-rails-productionlog)
Create your own middleware that makes the pid available and use it with config.log_tags: http://www.peterboling.com/2012/4/5/rails-3-2-custom-logging
Do this: config.log_tags = [:subdomain, :uuid, :remote_ip, Proc.new { "PID-%.5d" % $$ }] (which the previous link says is slow)
Or this: config.log_tags = [Proc.new { "PID: %.5d" % Process.pid }]
Log the request uuid instead

Here is a related SO article: - Rails 3.2.2 log files unordered, requests intertwined

The best bet to me seems to be to use :uuid instead. It conveys the same information to let you distinguish between requests when you have multiple processes logging to the same file.

This looks very cool, thanks for your answer. I will accept it since it's been a while and nobody else replied. — kolrie, Mar 20 '13 at 19:22

score 2 · Answer 2 · edited Mar 29 '19 at 20:10

If you need process ID outside of a controller context (e.g. delayed job) you can put this in an initializer:

class ActiveSupport::BufferedLogger
  def formatter=(formatter)
    @log.formatter = formatter
  end
end

class Formatter
  SEVERITY_TO_COLOR_MAP   = {'DEBUG'=>'0;37', 'INFO'=>'32', 'WARN'=>'33', 'ERROR'=>'31', 'FATAL'=>'31', 'UNKNOWN'=>'37'}

  def call(severity, time, progname, msg)
    formatted_severity = sprintf("%-5s","#{severity}")

    formatted_time = time.strftime("%Y-%m-%d %H:%M:%S.") << time.usec.to_s[0..6].ljust(6)
    color = SEVERITY_TO_COLOR_MAP[severity]

    "\033[0;37m#{formatted_time} (pid:#{$$})\033[0m [\033[#{color}m#{formatted_severity}\033[0m] #{msg.strip}\n"
  end

end

Rails.logger.formatter = Formatter.new

More here: http://www.software-thoughts.com/2013/08/adding-process-id-and-timestamps-to.html

Original post here: http://cbpowell.wordpress.com/2012/04/05/beautiful-logging-for-ruby-on-rails-3-2/

Add process information to Rails logger

2 Answers2