Re: Socket errors and nginx 502 gateway errors

[Pico Aeterna <flippedootninja@gmail.com>]

Eric,

Thanks for the response.

Unicorn Stderr Errorlog:

reaped #<Process::Status: pid=9103,signaled(SIGIOT=6)> worker=9
/var/www/domain/releases/20120427011507/app/controllers/application_controller.rb:172:
[BUG] Segmentation fault
ruby 1.8.7 (2011-02-18 patchlevel 334) [x86_64-linux], MBARI 0x6770,
Ruby Enterprise Edition 2011.03

Exception `Errno::EAGAIN' at
/var/www/domain/shared/bundle/ruby/1.8/gems/net-http-persistent-2.6/lib/net/http/faster.rb:15
- Resource temporarily unavailable
Exception `EOFError' at
/var/www/domain/shared/bundle/ruby/1.8/gems/net-http-persistent-2.6/lib/net/http/faster.rb:15
- end of file reached
Exception `Errno::EAGAIN' at
/var/www/domain/shared/bundle/ruby/1.8/gems/net-http-persistent-2.6/lib/net/http/faster.rb:15
- Resource temporarily unavailable
Exception `EOFError' at
/var/www/domain/shared/bundle/ruby/1.8/gems/net-http-persistent-2.6/lib/net/http/faster.rb:15
- end of file reached
Exception `TypeError' at
/var/www/domain/releases/20120427011507/app/views/search/_facet.html.erb:5
- can't convert String into Integer
Exception `ActionView::MissingTemplate' at
/var/www/domain/shared/bundle/ruby/1.8/gems/actionpack-2.3.11/lib/action_view/paths.rb:74
- Missing template widget/.erb in view path app/views
Exception `EOFError' at
/var/www/domain/shared/bundle/ruby/1.8/gems/newrelic_rpm-3.3.3/lib/new_relic/data_serialization.rb:111
- end of file reached
Exception `ActionView::MissingTemplate' at
/var/www/domain/shared/bundle/ruby/1.8/gems/actionpack-2.3.11/lib/action_view/paths.rb:74
- Missing template look/.erb in view path app/views
Exception `Memcached::NotFound' at
/var/www/domain/shared/bundle/ruby/1.8/gems/memcached-1.0.6/lib/memcached/memcached.rb:597
- Memcached::NotFound
Exception `Memcached::NotFound' at
/var/www/domain/shared/bundle/ruby/1.8/gems/memcached-1.0.6/lib/memcached/memcached.rb:525
- Memcached::NotFound
Exception `EOFError' at
/var/www/domain/shared/bundle/ruby/1.8/gems/newrelic_rpm-3.3.3/lib/new_relic/data_serialization.rb:111
- end of file reached
Exception `ActionView::MissingTemplate' at
/var/www/domain/shared/bundle/ruby/1.8/gems/actionpack-2.3.11/lib/action_view/paths.rb:74
- Missing template widget/.erb in view path app/views
Exception `ActionView::MissingTemplate' at
/var/www/domain/shared/bundle/ruby/1.8/gems/actionpack-2.3.11/lib/action_view/paths.rb:74
- Missing template widget/.erb in view path app/views
Exception `ActionView::MissingTemplate' at
/var/www/domain/shared/bundle/ruby/1.8/gems/actionpack-2.3.11/lib/action_view/paths.rb:74
- Missing template look/.erb in view path app/views
Exception `NoMethodError' at
/var/www/domain/releases/20120427011507/app/controllers/application_controller.rb:255
- undefined method `include?' for nil:NilClass
Exception `ActionView::MissingTemplate' at
/var/www/domain/shared/bundle/ruby/1.8/gems/actionpack-2.3.11/lib/action_view/paths.rb:74
- Missing template user/.erb in view path app/views
Exception `Memcached::NotFound' at
/var/www/domain/shared/bundle/ruby/1.8/gems/memcached-1.0.6/lib/memcached/memcached.rb:597
- Memcached::NotFound
Exception `Memcached::NotFound' at
/var/www/domain/shared/bundle/ruby/1.8/gems/memcached-1.0.6/lib/memcached/memcached.rb:597
- Memcached::NotFound


Strace with 2048 on nginx

7369  connect(31, {sa_family=AF_FILE,
path="/var/www/domain/shared/sockets/unicorn.sock"...}, 110) = 0
7369  getsockopt(31, SOL_SOCKET, SO_ERROR, [1424310214479314944], [4]) = 0
7369  writev(31, [{"GET
/widget/looks.js?id=1172821&thumbs=3&source=my_looks&gender=both&align=center&r=1320622693&hash=36189f21135680efbe2d076d0b56bb06
HTTP/1.0\r\nX-Forwarded
-For: 83.9.20.243, 83.9.20.243\r\nHost: domain.nu\r\nConnection:
close\r\nUser-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64)
AppleWebKit/534.55.3 (KHTML, like Gecko) Version/5.1.5
Safari/534.55.3\r\nAccept: */*\r\nReferer:
http://www.xxxxx.com/\r\nAccept-Language: pl-PL\r\nAccept-Encoding:
gzip, deflate\r\nCookie:
__utma=78941577.1641012066.1319789648.1325094074.1325949868.3;
__utmz=78941577.1325949868.3.3.utmcsr=xxxx.com|utmccn=(referral)|utmcmd=referral|utmcct=/l.php;
__gads=ID=269c5cea8f09aea0:T=1319789648:S=ALNI_MaqwdMaIFS5I3FeqLnv86oivdVDuA;
__qca=P0-1390452860-1319789648200\r\n\r\n", 745}], 1) = 7457369
epoll_wait(22, {{EPOLLOUT, {u32=2473377616, u64=46963645792080}}},
512, 17146) = 17369  epoll_wait(22, {{EPOLLIN|EPOLLOUT|EPOLLHUP,
{u32=2473377616, u64=46963645792080}}}, 512, 17146) = 17369
recvfrom(31, "", 4096, 0, NULL, NULL) = 0
7369  write(3, "2012/04/28 19:10:30 [error] 7369#0: *21954594 upstream
prematurely closed connection while reading response header from
upstream, client: 83.9.20.243, server: *.domain.nu, request: \"GET
/widget/looks.js?id=1172821&thumbs=3&source=my_looks&gender=both&align=center&r=1320622693&hash=36189f21135680efbe2d076d0b56bb06
HTTP/1.1\", upstream:
\"http://unix:/var/www/domain/shared/sockets/unicorn.sock:/widget/looks.js?id=1172821&thumbs=3&source=my_looks&nder=both&align=center&r=1320622693&hash=36189f21135680ef
be2d076d0b56bb06\", host: \"domain.nu\", referrer:
\"http://www.xxx.com/\"\n", 597) = 597
7369  close(31)                         = 0
7369  writev(20, [{"HTTP/1.1 502 Bad Gateway\r\nServer: nginx\r\nDate:
Sat, 28 Apr 2012 23:10:30 GMT\r\nContent-Type:
text/html\r\nContent-Length: 166\r\nConnection: close\r\n\r\n", 145},
{"<html>\r\n<head><title>502 Bad Gateway</title></head>\r\n<body
bgcolor=\"white\">\r\n<center><h1>502 Bad Gateway</h1></center>\r\n",
120}, {"<hr><center>nginx</center>\r\n</body>\r\n</html>\r\n", 46}],
3) = 311


Using the following I was able to get a 200 response

req='GET / HTTP/1.1\r\nHost: domain.com\r\n\r\n'
printf "$req" | socat - UNIX:/var/www/domain/shared/sockets/unicorn.sock

HTTP/1.1 200 OK
Date: Sun, 29 Apr 2012 16:29:08 GMT
Status: 200 OK
Connection: close
ETag: "cc3c683b35f20547c69e8155279b3ecf"
Content-Type: text/html; charset=utf-8
X-Runtime: 227
Content-Length: 144433
Set-Cookie: _domain_session=BAh7CToKZ2VvaXBGOg9zZXNzaW9uX2lkIiU4NGIzYzkzZjUxNTAwYzUyZDhmYjkzOGM1YjhhNzUxNDoQbW9iaWxlX3ZpZXdGOgtsb2NhbGUiB2Vu--524e4c395bcfa87ca0ce0ab5bfb2f305d4a5f12b;
domain=.domain.com; path=/; HttpOnly
Cache-Control: private, max-age=0, must-revalidate

Sorry but i'm new to debugging Unicorn.  Hopefully some of this is helpful.

Thanks

On Sat, Apr 28, 2012 at 2:59 PM, Eric Wong <normalperson@yhbt.net> wrote:
> Pico Aeterna <flippedootninja@gmail.com> wrote:
>> Hi,
>>
>> We've been getting reports that our users have been getting random 502
>> Errors.  After investigating I noticed 'upstream prematurely closed
>> connection while reading response header from upstream' in my nginx
>> error logs.  From using strace it appears that there's numerous socket
>> SO_ERROR..  I temporarily switched out the domain sockets with TCP,
>> however am seeing the same result/issue.
>>
>> Strace and Nginx error log below:
>
> Can you show us an strace of a unicorn worker, too?  (use
> "worker_processes 1" when debugging this)
>
> Also, the unicorn stderr log can be helpful.
>
>> 7366  epoll_ctl(16, EPOLL_CTL_ADD, 89, {EPOLLIN|EPOLLOUT|EPOLLET,
>> {u32=2473356496, u64=46963645770960}}) = 0
>> 7366  connect(89, {sa_family=AF_FILE,
>> path="/var/www/domain/shared/sockets/unicorn.sock"...}, 110) = 0
>> 7366  getsockopt(89, SOL_SOCKET, SO_ERROR, [1422340301959200768], [4]) = 0
>> 7366  writev(89, [{"GET /natalieliao HTTP/1.0\r\nX-Forwarded-For:
>> 94.224.228.239, 94.224.228.239\r\nHost"..., 1084}], 1) = 1084
>
> Can you pass "-s 2048" (or larger value) when stracing?  It'll be
> helpful to know what else is in the HTTP header.
>
>> Load balancer (HaProxy) => nginx => unicorn
>
> Does hitting unicorn directly with curl (TCP) give an expected result?
> (You can use the strace output above to have curl mimic what nginx
> sends, or even use printf | socat which works with Unix sockets).
>
>> Relevant sysctl.conf changes
>
> Probably not relevant since you switched to Unix sockets, but
> consider default sysctl values while debugging (especially tcp_tw_*)
>
>> net.ipv4.ip_local_port_range = 1024 65535
>> net.ipv4.tcp_fin_timeout = 15
>> #timewait sockets
>> net.ipv4.tcp_tw_reuse = 1
>> net.ipv4.tcp_tw_recycle = 1
> _______________________________________________
> 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
_______________________________________________
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