Panos Matsinopoulos

Senior Software Engineer: Love Writing and Reading Software, Taking Entrepreneurial Risks, Teaching Computer Programming & Blogging here or in many other places. I also Love Music and I can call myself a small pianist!

Making Rails Logger Use One Log File Per Process With Phusion Passenger

| Comments

Introduction

Today, I had to find a way to make my production Rails application log into different log files per process. I have the application deployed using Phusion Passenger as an Apache 2 module. The reason I decided to do that was the fact that I wanted to analyze the logs with Request Log Analyzer tool. This tool requires the log files to be separate so that they do not interleave the log entries of different requests.

Blog Sponsor

This post is sponsored by Fraudpointer.

References

In order to solve that I was helped by what I found about the similar problem solved for Unicorn processes here:

A blog about how one can have different log file per Unicorn worker

Then, I had to google about how I could hook to after fork events on Phusion Passenger. There was a very good question here and its answer here. The answer directed me also on Phusion Passenger documentation for hooking on spawning events.

Implementation

I have created an initializer with the following content:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36

begin
  if Rails.env.production? && defined?(PhusionPassenger)
    PhusionPassenger.on_event(:starting_worker_process) do |forked|
      # get access to log device
      if Rails::VERSION::STRING.start_with?('4.')
        logdev = Rails.logger.instance_variable_get(:@logdev)
      elsif Rails::VERSION::STRING.start_with?('3.2')
        logdev = Rails.logger.instance_variable_get(:@logger).instance_variable_get(:@log).instance_variable_get(:@logdev)
      end

      # logdev.dev is a File instance that is the open file to log file.
      # Get the extension and prepend the process id.
      ext = File.extname(logdev.dev.path)
      pid = Process.pid
      path = logdev.dev.path.gsub /#{Regexp.escape(ext)}$/, ".#{pid}#{ext}"

      # open the new file
      file = File.open(path, 'a')
      file.binmode
      file.sync = true

      # We flush and close the current file handle, the one that writes to the single file.
      logdev.dev.flush
      logdev.dev.close

      # We replace the file handle with the new one +file+ that refers to process specific file.
      logdev.instance_variable_set(:@dev, file)
    end
  end
rescue Exception => ex
  begin
    Rails.logger.error(ex.message)
    Rails.logger.error(ex.backtrace)
  rescue
  end
end

Closing

This has been implemented for a Rails 3.2 and a Rails 4.2 application.

Any feedback from you would be much appreciated.

Comments