Socket errors and nginx 502 gateway errors

Pico Aeterna flippedootninja at gmail.com
Sat Apr 28 21:33:49 UTC 2012


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:

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
7366  epoll_wait(16, {{EPOLLOUT, {u32=2473356496,
u64=46963645770960}}, {EPOLLOUT, {u32=2473355152,
u64=46963645769616}}}, 512, 4316) = 2
7366  recvfrom(88, 0x7fff856374b7, 1, 2, 0, 0) = -1 EAGAIN (Resource
temporarily unavailable)
7366  epoll_wait(16, {{EPOLLIN|EPOLLOUT|EPOLLHUP, {u32=2473356496,
u64=46963645770960}}}, 512, 4315) = 1
7366  recvfrom(89, "", 4096, 0, NULL, NULL) = 0
7366  write(3, "2012/04/28 17:14:45 [error] 7366#0: *21826315 upstream
prematurely closed connec"..., 319) = 319
7366  close(89)                         = 0
7366  stat("/var/www/domain/current/public/system/maintenance.html",
0x7fff85637210) = -1 ENOENT (No such file or directory)
7366  stat("/var/www/domain/current/public/500.html/index.html",
0x7fff85637190) = -1 ENOENT (No such file or directory)
7366  stat("/var/www/domain/current/public/500.html.html",
0x7fff85637190) = -1 ENOENT (No such file or directory)
7366  stat("/var/www/domain/current/public/500.html", 0x7fff85637190)
= -1 ENOENT (No such file or directory)
7366  socket(PF_FILE, SOCK_STREAM, 0)   = 89
7366  ioctl(89, FIONBIO, [1])           = 0
7366  epoll_ctl(16, EPOLL_CTL_ADD, 89, {EPOLLIN|EPOLLOUT|EPOLLET,
{u32=2473356497, u64=46963645770961}}) = 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, [1422495985933746176], [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
7366  epoll_wait(16, {{EPOLLOUT, {u32=2473356497,
u64=46963645770961}}}, 512, 4285) = 1
7366  epoll_wait(16, {{EPOLLIN|EPOLLOUT|EPOLLHUP, {u32=2473356497,
u64=46963645770961}}}, 512, 4284) = 1
7366  recvfrom(89, "", 4096, 0, NULL, NULL) = 0
7366  write(3, "2012/04/28 17:14:45 [error] 7366#0: *21826315 upstream
prematurely closed connec"..., 319) = 319
7366  close(89)                         = 0
7366  writev(88, [{"HTTP/1.1 502 Bad Gateway\r\nServer: nginx\r\nDate:
Sat, 28 Apr 2012 21:14:45 GMT\r\nCo"..., 145},
{"<html>\r\n<head><title>502 Bad Gateway</title></head>\r\n<body
bgcolor=\"white\">\r\n<ce"..., 120},
{"<hr><center>nginx</center>\r\n</body>\r\n</html>\r\n", 46}], 3) =
311
7366  shutdown(88, 1 /* send */)        = 0


2012/04/28 17:14:45 [error] 7366#0: *21826315 upstream prematurely
closed connection while reading response header from upstream,
client:94.224.228.239, server: *.domain.nu, request: "GET /natalieliao
HTTP/1.1", upstream:
"http://unix:/var/www/domain/shared/sockets/unicorn.sock:/natalieliao",
host: "domain.nu"
2012/04/28 17:14:45 [error] 7366#0: *21826315 upstream prematurely
closed connection while reading response header from upstream, client:
94.224.228.239, server: *.domain.nu, request: "GET /natalieliao
HTTP/1.1", upstream:
"http://unix:/var/www/domain/shared/sockets/unicorn.sock:/natalieliao",
host: "domain.nu"

Nginx information:
nginx version: nginx/1.0.15
built by gcc 4.1.2 20080704 (Red Hat 4.1.2-52)
TLS SNI support disabled
configure arguments: --prefix=/etc/nginx --with-http_ssl_module
--sbin-path=/usr/sbin --http-log-path=/var/log/nginx/access.log
--error-log-path=/var/log/nginx/error.log --with-http_realip_module
--with-http_stub_status_module --pid-path=/var/run/nginx.pid

Unicorn information:
$ bundle show unicorn
/var/www/lookbook/shared/bundle/ruby/1.8/gems/unicorn-4.2.1

Ruby:
ruby:
    interpreter:  "ruby"
    version:      "1.8.7"
    date:         "2011-02-18"
    platform:     "x86_64-linux"
    patchlevel:   "2011-02-18 patchlevel 334"
    full_version: "ruby 1.8.7 (2011-02-18 patchlevel 334)
[x86_64-linux], MBARI 0x6770, Ruby Enterprise Edition 2011.03"

Setup:
Load balancer (HaProxy) => nginx => unicorn

Relevant sysctl.conf changes

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
net.core.netdev_max_backlog = 4096
net.core.somaxconn = 4096

Just curious to know if there's a socket bug that I missed with the
current version of unicorn that's installed?


More information about the mongrel-unicorn mailing list