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?

Answer 1

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/

Answer 2

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.