Master repeatedly killing workers due to timeouts

Eric Wong normalperson at yhbt.net
Sun Dec 11 15:13:41 EST 2011


Troex Nevelin <list at mrtech.ru> wrote:
> Hello,
> 
> I have a simillar problem that started after update, 3 days ago we
> moved from REE 1.8 / Rails 2 to Ruby 1.9.3 and Rails 3.1, also we
> replaced memcached with redis so this is huge update and there are
> many places where we can have an issue.
> 
> I also have checked my MySQL slow log and there are no requests which
> take more than 5 seconds to complete.
> 
> My question is it possible to log the last request (URI) made to the
> worker before killing it on timeout?

There's no way to trap/handle SIGKILL in the worker, and telling the
master every URI the worker makes is too expensive.

This is horrible middleware, but _may_ work if you just forgot a timeout
and Ruby itself isn't blocked (due to a bad C extension):

    class LogBeforeTimeout < Struct.new(:app)
      def call(env)
        thr = Thread.new do
          sleep(59) # set this to Unicorn timeout - 1
          unless Thread.current[:done]
            path = env["PATH_INFO"]
            qs = env["QUERY_STRING"] and path = "#{path}?#{qs}"
            env["rack.logger"].warn("#{path} about to die from SIGKILL")
          end
        end
        app.call(env)
      ensure
        thr[:done] = true
        thr.run
      end
    end

Or you can just log the nev before app.call:

  def call(env)
    path = env["PATH_INFO"]
    qs = env["QUERY_STRING"] and path = "#{path}?#{qs}"
    env["rack.logger"].debug "START #{path}"
    app.call(env)
  ensure
    env["rack.logger"].debug "FINISH #{path}"
  end

And look for START lines without corresponding FINISH lines.

All code in this post is totally untested, so may contain syntax errors


More information about the mongrel-unicorn mailing list