Re: Is it possible to log better info in timeouts?

2014-01-01 Thread Eric Wong
Carlos Peñas  wrote:
> Recently we had an issue with an external service for an app served with
> unicorn. And some of our requests died with unicorn's timeout because a
> not properly secured call to this external service. We had 20s
> timeout but in production with ten worker and a big percent of urls
> hitting external services 20 secons of timeout sooner or later brings
> down the entire site.
> 
> in the logs when this hapens this line is left for debugging:
> 
> E, [2013-12-25T23:56:49.363426 #26324] ERROR -- : worker=2 PID:27956 timeout 
> (21s > 20s), killing
> E, [2014-12-25T23:56:49.396005 #26324] ERROR -- : reaped # pid 27956 SIGKILL (signal 9)> worker=2
> 
> 
> Is it possible to opt to print to the error log some other info perhaps
> the bactrace of the process or the offending request?

The SIGKILL sent by the master isn't avoidable/trapable in userspace,
the KILL-ed process has no chance to dump a backtrace.

> Even better whould be possible to hack a watchdog that could log "slow
> requests" like mysql slow_queries?

You need to do this in your application.  The timeout in unicorn is a
last resort: http://unicorn.bogomips.org/Application_Timeouts.html
I don't encourage relying on the unicorn timeout, it's a hack for broken
libraries or fatal bugs in Ruby (which are rarer nowadays).
___
Unicorn mailing list - mongrel-unicorn@rubyforge.org
http://rubyforge.org/mailman/listinfo/mongrel-unicorn
Do not quote signatures (like this one) or top post when replying


Is it possible to log better info in timeouts?

2014-01-01 Thread Carlos Peñas
Hi!

Recently we had an issue with an external service for an app served with
unicorn. And some of our requests died with unicorn's timeout because a
not properly secured call to this external service. We had 20s
timeout but in production with ten worker and a big percent of urls
hitting external services 20 secons of timeout sooner or later brings
down the entire site.

in the logs when this hapens this line is left for debugging:

E, [2013-12-25T23:56:49.363426 #26324] ERROR -- : worker=2 PID:27956 timeout 
(21s > 20s), killing
E, [2014-12-25T23:56:49.396005 #26324] ERROR -- : reaped # worker=2


Is it possible to opt to print to the error log some other info perhaps
the bactrace of the process or the offending request?

Even better whould be possible to hack a watchdog that could log "slow
requests" like mysql slow_queries?

I'm asking after look a bit the code but it's a bit far away for my
skills right now.

Thanks.

-- 
Carlos Peñas San José
car...@adoptales.es

___
Unicorn mailing list - mongrel-unicorn@rubyforge.org
http://rubyforge.org/mailman/listinfo/mongrel-unicorn
Do not quote signatures (like this one) or top post when replying