Log a timeout warning before it times out and unicorn kills the worker.

README.md

Log Before Timeout

Logs a timeout warning before unicorn kills the worker.

If something is running long enough for unicorn to want to kill it then its worth spending the time fixing. If the process is killed you will never know why it failed.

This will add a warning after 30 seconds and another one 1second before unicorn kills it.

How it works:

It adds a middleware that sits on the Rack layer between Unicorn and Rails. It creates a timer Thread that sleeps for a set amount of time and if the current thread is still running then log a warning.

So if the world ends at least you will have a log message for it.

log_before_timeout.rb

# config/initializers/log_before_timeout.rb

# Log a timeout warning before it times out and unicorn kills the worker.
#  1st warning at 30 seconds
#  2nd warning just before unicorn timeout

class LogBeforeTimeout
  attr_accessor :timeout, :first_warning_timeout, :second_warning_timeout

  def initialize(app)
    @app = app
    @timeout = 300 # get this form unicorn!
    @first_warning_timeout = 30
    @second_warning_timeout = timeout - first_warning_timeout - 1
  end

  def call(env)

    timer = Thread.new do
      sleep(first_warning_timeout)
      unless Thread.current[:done]
        ApplicationErrorRecord::TimeoutWarning.log(env, "[Timeout Warning] Unicorn worker has been working for 30 seconds")
        sleep(second_warning_timeout)
        unless Thread.current[:done]
          ApplicationErrorRecord::TimeoutWarning.log(env, "[Timeout Warning] Unicorn worker is about to timeout.")
        end
      end
    end

    @app.call(env)
  ensure
    timer[:done] = true # main thread completed mark the done flags 
    timer.run if timer.alive? # we need the run so that the thread builds the TimeoutWarning.
  end

end

production.rb

# config/environments/xxxxxx.rb

Rails.application.configure do
 config.middleware.use("LogBeforeTimeout")
end