unicorn Ruby/Rack server user+dev discussion/patches/pulls/bugs/help
 help / color / mirror / code / Atom feed
* Show request details on timeout killing
@ 2014-12-04 21:15 Bráulio Bhavamitra
  2014-12-05  1:06 ` Eric Wong
  0 siblings, 1 reply; 4+ messages in thread
From: Bráulio Bhavamitra @ 2014-12-04 21:15 UTC (permalink / raw)
  To: unicorn-public

Hello all,

Currently, unicorn kills a worker that reached timeout with the
following message:
E, [2014-12-04T19:12:23.646053 #32612] ERROR -- : worker=4 PID:11911
timeout (61s > 60s), killing

How can I see which URL was being processed by that worker?

I need to identify the problematic request.

cheers,
bráulio

^ permalink raw reply	[flat|nested] 4+ messages in thread

* Re: Show request details on timeout killing
  2014-12-04 21:15 Show request details on timeout killing Bráulio Bhavamitra
@ 2014-12-05  1:06 ` Eric Wong
  2014-12-05 21:58   ` Bráulio Bhavamitra
  0 siblings, 1 reply; 4+ messages in thread
From: Eric Wong @ 2014-12-05  1:06 UTC (permalink / raw)
  To: Bráulio Bhavamitra; +Cc: unicorn-public

Bráulio Bhavamitra <braulio@eita.org.br> wrote:
> Hello all,
> 
> Currently, unicorn kills a worker that reached timeout with the
> following message:
> E, [2014-12-04T19:12:23.646053 #32612] ERROR -- : worker=4 PID:11911
> timeout (61s > 60s), killing
> 
> How can I see which URL was being processed by that worker?

I suggest adding better logging to your app, perhaps to log when
requests start.

> I need to identify the problematic request.

And to use application-level timeouts, see:

	http://unicorn.bogomips.org/Application_Timeouts.html

The SIGKILL timeout in unicorn is only a last resort when the Ruby VM
is broken beyond repair and cannot respond to any signals[1].

[1] SIGKILL and SIGSTOP are special signals which the kernel
    enforces, Ruby has no chance to block/catch/ignore them.

^ permalink raw reply	[flat|nested] 4+ messages in thread

* Re: Show request details on timeout killing
  2014-12-05  1:06 ` Eric Wong
@ 2014-12-05 21:58   ` Bráulio Bhavamitra
  2014-12-05 22:16     ` Eric Wong
  0 siblings, 1 reply; 4+ messages in thread
From: Bráulio Bhavamitra @ 2014-12-05 21:58 UTC (permalink / raw)
  To: Eric Wong; +Cc: unicorn-public

Ok Eric, the problem is that some requests are in a infinite loop,
consuming a lot of resources.

Rails/nginx already log many request on production.log/access.log, but
I can't know which of them timeouted.

cheers,
bráulio

On Thu, Dec 4, 2014 at 10:06 PM, Eric Wong <e@80x24.org> wrote:
> Bráulio Bhavamitra <braulio@eita.org.br> wrote:
>> Hello all,
>>
>> Currently, unicorn kills a worker that reached timeout with the
>> following message:
>> E, [2014-12-04T19:12:23.646053 #32612] ERROR -- : worker=4 PID:11911
>> timeout (61s > 60s), killing
>>
>> How can I see which URL was being processed by that worker?
>
> I suggest adding better logging to your app, perhaps to log when
> requests start.
>
>> I need to identify the problematic request.
>
> And to use application-level timeouts, see:
>
>         http://unicorn.bogomips.org/Application_Timeouts.html
>
> The SIGKILL timeout in unicorn is only a last resort when the Ruby VM
> is broken beyond repair and cannot respond to any signals[1].
>
> [1] SIGKILL and SIGSTOP are special signals which the kernel
>     enforces, Ruby has no chance to block/catch/ignore them.

^ permalink raw reply	[flat|nested] 4+ messages in thread

* Re: Show request details on timeout killing
  2014-12-05 21:58   ` Bráulio Bhavamitra
@ 2014-12-05 22:16     ` Eric Wong
  0 siblings, 0 replies; 4+ messages in thread
From: Eric Wong @ 2014-12-05 22:16 UTC (permalink / raw)
  To: Bráulio Bhavamitra; +Cc: unicorn-public

Bráulio Bhavamitra <braulio@eita.org.br> wrote:
> Rails/nginx already log many request on production.log/access.log, but
> I can't know which of them timeouted.

Can't Rails log when a request starts and finishes?
(I haven't touched Rails in years)

Look for starts on PIDs without finishes.

Something along the lines of the following middlware (totally untested):

    class LogBeforeAfter
      def initialize(app)
        @app = app
      end

      def call(env)
        env["rack.logger"].info("#$$ start #{env['PATH_INFO']}")
        response = @app.call(env)
        env["rack.logger"].info("#$$   end #{env['PATH_INFO']}")
        response
      end
    end

    -------------- config.ru ---------------
    use LogBeforeAfter
    # other middlewares...
    run YourApp.new

See Rack::CommonLogger source for more examples/detail.

^ permalink raw reply	[flat|nested] 4+ messages in thread

end of thread, other threads:[~2014-12-05 22:16 UTC | newest]

Thread overview: 4+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2014-12-04 21:15 Show request details on timeout killing Bráulio Bhavamitra
2014-12-05  1:06 ` Eric Wong
2014-12-05 21:58   ` Bráulio Bhavamitra
2014-12-05 22:16     ` Eric Wong

Code repositories for project(s) associated with this inbox:

	../../../unicorn.git

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).