unicorn Ruby/Rack server user+dev discussion/patches/pulls/bugs/help
 help / color / mirror / code / Atom feed
* 502 bad gateway on nginx with recv() failed
@ 2010-10-22 19:50 Naresh V
  2010-10-22 21:14 ` Eric Wong
  0 siblings, 1 reply; 5+ messages in thread
From: Naresh V @ 2010-10-22 19:50 UTC (permalink / raw)
  To: mongrel-unicorn

Hi,

I'm serving the puppetmaster application with its config.ru through
unicorn - proxied by nginx.
I'm using unix sockets, 4 workers, and 2048 backlog.

The clients - after their typical "puppet run" - send back a report to
the master in YAML.
Some clients whose reports tend to be large (close to 2mb) get a 502
bad gateway error and error out.

nginx log:

2010/10/22 14:20:27 [error] 19461#0: *17115 recv() failed (104:
Connection reset by peer) while reading response header from upstream,
client: 1x.yy.zz.x4, server: , request: "PUT /production/report/nagios
HTTP/1.1", upstream:
"http://unix:/tmp/.sock:/production/report/nagios", host:
"puppet:8140"

I was getting the same thing earlier when I had unicorn listening on
TCP sockets instead of UNIX sockets. And I had a lot of connections in
TIME_WAIT:

tcp        0      0 127.0.0.1:8141              127.0.0.1:54507
     TIME_WAIT   -
tcp        0      0 127.0.0.1:8141              127.0.0.1:57322
     TIME_WAIT   -

Fluctuating all the way from 20 to 800. A quick restart of nginx
tended to bring the number down.


-Naresh V.
_______________________________________________
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


^ permalink raw reply	[flat|nested] 5+ messages in thread
* Re: 502 bad gateway on nginx with recv() failed
  2010-10-22 19:50 502 bad gateway on nginx with recv() failed Naresh V
@ 2010-10-22 21:14 ` Eric Wong
  2010-10-23  4:48   ` Naresh V
  0 siblings, 1 reply; 5+ messages in thread
From: Eric Wong @ 2010-10-22 21:14 UTC (permalink / raw)
  To: unicorn list

Naresh V <nareshov@gmail.com> wrote:
> Hi,
> 
> I'm serving the puppetmaster application with its config.ru through
> unicorn - proxied by nginx.
> I'm using unix sockets, 4 workers, and 2048 backlog.
> 
> The clients - after their typical "puppet run" - send back a report to
> the master in YAML.
> Some clients whose reports tend to be large (close to 2mb) get a 502
> bad gateway error and error out.
> 
> nginx log:
> 
> 2010/10/22 14:20:27 [error] 19461#0: *17115 recv() failed (104:
> Connection reset by peer) while reading response header from upstream,
> client: 1x.yy.zz.x4, server: , request: "PUT /production/report/nagios
> HTTP/1.1", upstream:
> "http://unix:/tmp/.sock:/production/report/nagios", host:
> "puppet:8140"

Hi Naresh, do you see anything in the Unicorn stderr log file?

Is the 2mb report part of the response or request?  Unicorn should
have no problems accepting large requests (Rainbows! defaults the
client_max_body_size to 1mb, just like nginx).

It could be Unicorn's internal (default 60s) timeout kicking
in because puppet is slowly reading/generating the 2mb body.

Also, which version of Unicorn and nginx is this?

> I was getting the same thing earlier when I had unicorn listening on
> TCP sockets instead of UNIX sockets. And I had a lot of connections in
> TIME_WAIT:
> 
> tcp        0      0 127.0.0.1:8141              127.0.0.1:54507
>      TIME_WAIT   -
> tcp        0      0 127.0.0.1:8141              127.0.0.1:57322
>      TIME_WAIT   -
> 
> Fluctuating all the way from 20 to 800. A quick restart of nginx
> tended to bring the number down.

Having many TIME_WAIT sockets is normal and expected when you're
starting/stopping lots of TCP connections.  It's nothing to worry about
unless you get several thousands of requests/second, and then you should
apply tcp_tw_reuse/tcp_tw_recycle as mentioned in
http://unicorn.bogomips.org/TUNING.html (or switch to UNIX domain
sockets and use nginx for keepalive).

-- 
Eric Wong
_______________________________________________
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


^ permalink raw reply	[flat|nested] 5+ messages in thread
* Re: 502 bad gateway on nginx with recv() failed
  2010-10-22 21:14 ` Eric Wong
@ 2010-10-23  4:48   ` Naresh V
  2010-10-23 23:22     ` Eric Wong
  0 siblings, 1 reply; 5+ messages in thread
From: Naresh V @ 2010-10-23  4:48 UTC (permalink / raw)
  To: unicorn list

On 23 October 2010 02:44, Eric Wong <normalperson@yhbt.net> wrote:
> Naresh V <nareshov@gmail.com> wrote:
>> Hi,
>>
>> I'm serving the puppetmaster application with its config.ru through
>> unicorn - proxied by nginx.
>> I'm using unix sockets, 4 workers, and 2048 backlog.
>>
>> The clients - after their typical "puppet run" - send back a report to
>> the master in YAML.
>> Some clients whose reports tend to be large (close to 2mb) get a 502
>> bad gateway error and error out.
>>
>> nginx log:
>>
>> 2010/10/22 14:20:27 [error] 19461#0: *17115 recv() failed (104:
>> Connection reset by peer) while reading response header from upstream,
>> client: 1x.yy.zz.x4, server: , request: "PUT /production/report/nagios
>> HTTP/1.1", upstream:
>> "http://unix:/tmp/.sock:/production/report/nagios", host:
>> "puppet:8140"
>
> Hi Naresh, do you see anything in the Unicorn stderr log file?

Hi Eric, I think I caught it:

E, [2010-10-22T23:03:30.207455 #10184] ERROR -- : worker=2 PID:10206
timeout (60.207392s > 60s), killing
I, [2010-10-22T23:03:31.212533 #10184]  INFO -- : reaped
#<Process::Status: pid=10206,signaled(SIGKILL=9)> worker=2
I, [2010-10-22T23:03:31.214768 #10490]  INFO -- : worker=2 spawned pid=10490
I, [2010-10-22T23:03:31.221748 #10490]  INFO -- : worker=2 ready


> Is the 2mb report part of the response or request?  Unicorn should
> have no problems accepting large requests (Rainbows! defaults the
> client_max_body_size to 1mb, just like nginx).

It's part of the PUT request, I guess.

> It could be Unicorn's internal (default 60s) timeout kicking
> in because puppet is slowly reading/generating the 2mb body.

I raised the timeout first to 120, then 180 - and I continued to get
the 502 (with the logs as above)
When I raised it upto 240, puppetd complained:

#-(1)> puppetd -t -v  --trace
notice: Ignoring --listen on onetime run
info: Caching catalog for nagios
info: Applying configuration version '1287807847'
notice: Finished catalog run in 25.86 seconds
/usr/lib/ruby/1.8/timeout.rb:54:in `rbuf_fill'
/usr/lib/ruby/1.8/timeout.rb:56:in `timeout'
/usr/lib/ruby/1.8/timeout.rb:76:in `timeout'
/usr/lib/ruby/1.8/net/protocol.rb:132:in `rbuf_fill'
/usr/lib/ruby/1.8/net/protocol.rb:116:in `readuntil'
/usr/lib/ruby/1.8/net/protocol.rb:126:in `readline'
/usr/lib/ruby/1.8/net/http.rb:2020:in `read_status_line'
/usr/lib/ruby/1.8/net/http.rb:2009:in `read_new'
/usr/lib/ruby/1.8/net/http.rb:1050:in `request'
/usr/lib/ruby/1.8/net/http.rb:1037:in `request'
/usr/lib/ruby/1.8/net/http.rb:543:in `start'
/usr/lib/ruby/1.8/net/http.rb:1035:in `request'
/usr/lib/ruby/1.8/net/http.rb:857:in `put'
/usr/lib/ruby/site_ruby/1.8/puppet/indirector/rest.rb:90:in `save'
/usr/lib/ruby/site_ruby/1.8/puppet/indirector/indirection.rb:253:in `save'
/usr/lib/ruby/site_ruby/1.8/puppet/indirector.rb:64:in `save'
/usr/lib/ruby/site_ruby/1.8/puppet/configurer.rb:178:in `send_report'
/usr/lib/ruby/site_ruby/1.8/puppet/configurer.rb:172:in `run'
/usr/lib/ruby/site_ruby/1.8/puppet/agent.rb:39:in `run'
/usr/lib/ruby/site_ruby/1.8/puppet/agent/locker.rb:21:in `lock'
/usr/lib/ruby/site_ruby/1.8/puppet/agent.rb:39:in `run'
/usr/lib/ruby/1.8/sync.rb:229:in `synchronize'
/usr/lib/ruby/site_ruby/1.8/puppet/agent.rb:39:in `run'
/usr/lib/ruby/site_ruby/1.8/puppet/agent.rb:103:in `with_client'
/usr/lib/ruby/site_ruby/1.8/puppet/agent.rb:37:in `run'
/usr/lib/ruby/site_ruby/1.8/puppet/application.rb:171:in `call'
/usr/lib/ruby/site_ruby/1.8/puppet/application.rb:171:in `controlled_run'
/usr/lib/ruby/site_ruby/1.8/puppet/agent.rb:35:in `run'
/usr/lib/ruby/site_ruby/1.8/puppet/application/agent.rb:114:in `onetime'
/usr/lib/ruby/site_ruby/1.8/puppet/application/agent.rb:88:in `run_command'
/usr/lib/ruby/site_ruby/1.8/puppet/application.rb:287:in `run'
/usr/lib/ruby/site_ruby/1.8/puppet/application.rb:393:in `exit_on_fail'
/usr/lib/ruby/site_ruby/1.8/puppet/application.rb:287:in `run'
/usr/sbin/puppetd:4
err: Could not run Puppet configuration client: execution expired


> Also, which version of Unicorn and nginx is this?

unicorn (1.1.4) and nginx-0.8.49-1.el5

>> I was getting the same thing earlier when I had unicorn listening on
>> TCP sockets instead of UNIX sockets. And I had a lot of connections in
>> TIME_WAIT:
>>
>> tcp        0      0 127.0.0.1:8141              127.0.0.1:54507
>>      TIME_WAIT   -
>> tcp        0      0 127.0.0.1:8141              127.0.0.1:57322
>>      TIME_WAIT   -
>>
>> Fluctuating all the way from 20 to 800. A quick restart of nginx
>> tended to bring the number down.
>
> Having many TIME_WAIT sockets is normal and expected when you're
> starting/stopping lots of TCP connections.  It's nothing to worry about
> unless you get several thousands of requests/second, and then you should
> apply tcp_tw_reuse/tcp_tw_recycle as mentioned in
> http://unicorn.bogomips.org/TUNING.html (or switch to UNIX domain
> sockets and use nginx for keepalive).
>
> --
> Eric Wong


-Naresh V.
_______________________________________________
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

^ permalink raw reply	[flat|nested] 5+ messages in thread
* Re: 502 bad gateway on nginx with recv() failed
  2010-10-23  4:48   ` Naresh V
@ 2010-10-23 23:22     ` Eric Wong
  2010-10-24  6:00       ` Naresh V
  0 siblings, 1 reply; 5+ messages in thread
From: Eric Wong @ 2010-10-23 23:22 UTC (permalink / raw)
  To: unicorn list

Naresh V <nareshov@gmail.com> wrote:
> On 23 October 2010 02:44, Eric Wong <normalperson@yhbt.net> wrote:
> > Naresh V <nareshov@gmail.com> wrote:
> >> I'm serving the puppetmaster application with its config.ru through
> >> unicorn - proxied by nginx.
> >> I'm using unix sockets, 4 workers, and 2048 backlog.
> >>
> >> The clients - after their typical "puppet run" - send back a report to
> >> the master in YAML.
> >> Some clients whose reports tend to be large (close to 2mb) get a 502
> >> bad gateway error and error out.
> >>
> >> nginx log:
> >>
> >> 2010/10/22 14:20:27 [error] 19461#0: *17115 recv() failed (104:
> >> Connection reset by peer) while reading response header from upstream,
> >> client: 1x.yy.zz.x4, server: , request: "PUT /production/report/nagios
> >> HTTP/1.1", upstream:
> >> "http://unix:/tmp/.sock:/production/report/nagios", host:
> >> "puppet:8140"
> >
> > Hi Naresh, do you see anything in the Unicorn stderr log file?
> 
> Hi Eric, I think I caught it:
> 
> E, [2010-10-22T23:03:30.207455 #10184] ERROR -- : worker=2 PID:10206
> timeout (60.207392s > 60s), killing
> I, [2010-10-22T23:03:31.212533 #10184]  INFO -- : reaped
> #<Process::Status: pid=10206,signaled(SIGKILL=9)> worker=2
> I, [2010-10-22T23:03:31.214768 #10490]  INFO -- : worker=2 spawned pid=10490
> I, [2010-10-22T23:03:31.221748 #10490]  INFO -- : worker=2 ready
> 
> > Is the 2mb report part of the response or request?  Unicorn should
> > have no problems accepting large requests (Rainbows! defaults the
> > client_max_body_size to 1mb, just like nginx).
> 
> It's part of the PUT request, I guess.
> 
> > It could be Unicorn's internal (default 60s) timeout kicking
> > in because puppet is slowly reading/generating the 2mb body.
> 
> I raised the timeout first to 120, then 180 - and I continued to get
> the 502 (with the logs as above)
> When I raised it upto 240, puppetd complained:

Interesting.  I'm not familiar with Puppet internals, but is there any
valid reason it would be taking this long?

Can you tell if the Unicorn worker is doing anything (using up CPU time
in top) or just blocked on some socket connection to a database or DNS?
(strace/truss will help).

You should definitely talk to Puppet developers/users about why it's
taking so long.  HTTP requests taking anywhere near 60s is an eternity,
I wonder if your Puppet is somehow misconfigured.

-- 
Eric Wong
_______________________________________________
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


^ permalink raw reply	[flat|nested] 5+ messages in thread
* Re: 502 bad gateway on nginx with recv() failed
  2010-10-23 23:22     ` Eric Wong
@ 2010-10-24  6:00       ` Naresh V
  0 siblings, 0 replies; 5+ messages in thread
From: Naresh V @ 2010-10-24  6:00 UTC (permalink / raw)
  To: unicorn list

On 24 October 2010 04:52, Eric Wong <normalperson@yhbt.net> wrote:
> Naresh V <nareshov@gmail.com> wrote:
>> On 23 October 2010 02:44, Eric Wong <normalperson@yhbt.net> wrote:
>> > Naresh V <nareshov@gmail.com> wrote:
>> >> I'm serving the puppetmaster application with its config.ru through
>> >> unicorn - proxied by nginx.
>> >> I'm using unix sockets, 4 workers, and 2048 backlog.
>> >>
>> >> The clients - after their typical "puppet run" - send back a report to
>> >> the master in YAML.
>> >> Some clients whose reports tend to be large (close to 2mb) get a 502
>> >> bad gateway error and error out.
>> >>
>> >> nginx log:
>> >>
>> >> 2010/10/22 14:20:27 [error] 19461#0: *17115 recv() failed (104:
>> >> Connection reset by peer) while reading response header from upstream,
>> >> client: 1x.yy.zz.x4, server: , request: "PUT /production/report/nagios
>> >> HTTP/1.1", upstream:
>> >> "http://unix:/tmp/.sock:/production/report/nagios", host:
>> >> "puppet:8140"
>> >
>> > Hi Naresh, do you see anything in the Unicorn stderr log file?
>>
>> Hi Eric, I think I caught it:
>>
>> E, [2010-10-22T23:03:30.207455 #10184] ERROR -- : worker=2 PID:10206
>> timeout (60.207392s > 60s), killing
>> I, [2010-10-22T23:03:31.212533 #10184]  INFO -- : reaped
>> #<Process::Status: pid=10206,signaled(SIGKILL=9)> worker=2
>> I, [2010-10-22T23:03:31.214768 #10490]  INFO -- : worker=2 spawned pid=10490
>> I, [2010-10-22T23:03:31.221748 #10490]  INFO -- : worker=2 ready
>>
>> > Is the 2mb report part of the response or request?  Unicorn should
>> > have no problems accepting large requests (Rainbows! defaults the
>> > client_max_body_size to 1mb, just like nginx).
>>
>> It's part of the PUT request, I guess.
>>
>> > It could be Unicorn's internal (default 60s) timeout kicking
>> > in because puppet is slowly reading/generating the 2mb body.
>>
>> I raised the timeout first to 120, then 180 - and I continued to get
>> the 502 (with the logs as above)
>> When I raised it upto 240, puppetd complained:
>
> Interesting.  I'm not familiar with Puppet internals, but is there any
> valid reason it would be taking this long?
>
> Can you tell if the Unicorn worker is doing anything (using up CPU time
> in top) or just blocked on some socket connection to a database or DNS?
> (strace/truss will help).
>
> You should definitely talk to Puppet developers/users about why it's
> taking so long.  HTTP requests taking anywhere near 60s is an eternity,
> I wonder if your Puppet is somehow misconfigured.
>

Yes, puppet-server was mis-configured and went unnoticed. The reports
are supposed to be accepted by another URL and that had to be
configured appropriately.

Sorry for the false alarm.

-Naresh.
_______________________________________________
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

^ permalink raw reply	[flat|nested] 5+ messages in thread
end of thread, other threads:[~2010-10-24  6:25 UTC | newest]

Thread overview: 5+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2010-10-22 19:50 502 bad gateway on nginx with recv() failed Naresh V
2010-10-22 21:14 ` Eric Wong
2010-10-23  4:48   ` Naresh V
2010-10-23 23:22     ` Eric Wong
2010-10-24  6:00       ` Naresh V

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

	https://yhbt.net/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).