Unicorn freezes, requests got stuck in the queue most likely

Unicorn freezes, requests got stuck in the queue most likely

[Alexander Dymo]

Hi,

I'd appreciate an advice on how to debug the following problem: unicorn sometimes freezes for 6-7 seconds and stops taking new requests, then resumes as if nothing happened. Details below.

My setup:
- nginx 0.7.67 proxying requests to unicorn
- unicorn 4.4.0
- rails 2.3.x application

Unicorn is set up as I've described in this list earlier:
http://rubyforge.org/pipermail/mongrel-unicorn/2010-November/000770.html

In short:
- we have two groups of workers:
   - one serving long-running requests that take more than 10 sec, listening to a '/tmp/long_requests_unicorn.sock' socket
   - another serving normal requests, listening to '/tmp/unicorn.sock' socket
- nginx determines which request goes to which sockets.

This worked perfectly for 2 years. Looks like after we upgraded to unicorn 4.4, the normal requests started to get stuck in the queue. That happens randomly, several times per day. When that happens, requests wait for up to 7 seconds to be served. At that time most or all of the workers are available and not doing anything. Unicorn restart fixes the problem.

Has anyone seen something freezes like that? I'd appreciate any help with debugging and understanding this problem.
_______________________________________________
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

Re: Unicorn freezes, requests got stuck in the queue most likely

[Eric Wong]

Alexander Dymo <adymo@pluron.com> wrote:
> In short:
> - we have two groups of workers:
>   - one serving long-running requests that take more than 10 sec, listening to a '/tmp/long_requests_unicorn.sock' socket
>   - another serving normal requests, listening to '/tmp/unicorn.sock' socket
> - nginx determines which request goes to which sockets.
> 
> This worked perfectly for 2 years. Looks like after we upgraded to
> unicorn 4.4, the normal requests started to get stuck in the queue.
> That happens randomly, several times per day. When that happens,
> requests wait for up to 7 seconds to be served. At that time most or
> all of the workers are available and not doing anything. Unicorn
> restart fixes the problem.

How are you determining requests get stuck for up to 7 seconds?
Just hitting the app?

How is the system (CPU/RAM/swap usage) around this time?

Are you using Raindrops::LastDataRecv or Raindrops::Watcher?
(If not and you're on Linux, please give them a try[1]).

Anything in the stderr logs?  Dying/restarted workers might cause
this.  Otherwise, I'd look for unexpected long-running requests
in your Rails logs.

> Has anyone seen something freezes like that? I'd appreciate any help
> with debugging and understanding this problem.

I certainly have not.  Did you perform any other upgrades around this
point?

Can you try reverting to 4.3.1 (or earlier, and not changing anything else)
and see if the problem presents itself there?

Also, which OS/version is this?


[1] http://raindrops.bogomips.org/
_______________________________________________
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

Re: Unicorn freezes, requests got stuck in the queue most likely

[Alexander Dymo]

> How are you determining requests get stuck for up to 7 seconds?
By measuring time between nginx gets the request and worker starts processing it.

> How is the system (CPU/RAM/swap usage) around this time?
No load at all. 14G free ram, no swap usage.

> Are you using Raindrops::LastDataRecv or Raindrops::Watcher?
> (If not and you're on Linux, please give them a try[1]).
Not yet. I'll take a look.

> Anything in the stderr logs?  Dying/restarted workers might cause this.
We are logging worker restarts, so no, no restarts/dying workers.

> I certainly have not.  Did you perform any other upgrades around this point?
Yes, we upgraded other ruby gems as well.

> Can you try reverting to 4.3.1 (or earlier, and not changing anything else)
> and see if the problem presents itself there?
Thanks, will do.

> Also, which OS/version is this?
Debian 6.0
_______________________________________________
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

Re: Unicorn freezes, requests got stuck in the queue most likely

[Eric Wong]

Btw, I (and I'm sure other readers) would be interested in what your
diagnosis/resolution is, regardless of whether it's a problem with
unicorn or anything else.
_______________________________________________
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

Re: Unicorn freezes, requests got stuck in the queue most likely

[Troex Nevelin]

> This worked perfectly for 2 years. Looks like after we upgraded to unicorn 4.4, the normal requests started to get stuck in the queue. That happens randomly, several times per day. When that happens, requests wait for up to 7 seconds to be served. At that time most or all of the workers are available and not doing anything. Unicorn restart fixes the problem.

Monitoring the queue is important and raindrops is all about it,
I have a small nice munin script to keep track on it:
https://github.com/troex/raindrops-watcher-munin
Live example with 8 workers:
http://mon.melkov.net/PeterHost-RU/spb1.melkov.net/raindrops_watcher.html

If your unicorn queue gets higher than something is probably blocking
the app, in my example you can notice on daily graph that at the each
hour beginning it gets a small spike - that's rake task rushing DB, as
a result app becoming slower and the queue grows which can lead to that
clients wait 3-4 seconds while rails log resulting only with 50-100ms
higher average response times.


>From my experience I never had problems between nginx and unicorn,
if it gets stuck than 99% it's some blocker in the app.

As Eric said the harder to trace issues are when worker dies and you
don't get logging from rails app, for that case take a look at previous
post about that problem that helped me to find out the problem in my app:
http://article.gmane.org/gmane.comp.lang.ruby.unicorn.general/1269


Also request-log-analytics and new_relic is good way to start tracing
blocks and slowdowns in the app. And raindrops if great for monitoring
the queue before requests get processed by the app.
_______________________________________________
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