ruby-on-rails - Nginx/Unicorn/Rails 连接超时

Question

我正在使用 Nginx/Unicorn 运行 Rails 应用程序。链接到我的nginx.conf和 unicorn.rb

我正在通过 capistrano 进行部署，最初该应用程序运行良好。然而，一段时间后(即 ~ 10-20 分钟)没有请求，传入请求将遇到问题。 (返回错误 500 出错页面)。

Rails production.log 显示它收到了请求，但我没有做任何其他事情:

I, [2015-01-29T13:12:03.725959 #24176]  INFO -- : Started GET "/" for xxx.18.170.101 at 2015-01-29 13:12:03 +0000

nginx 的 access.log

xxx.18.170.101 - - [29/Jan/2015:13:14:33 +0000] "GET / HTTP/1.1" 504 1477 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/40.0.2214.91 Safari/537.36"

nginx 的错误日志

2015/01/29 13:14:33 [error] 23786#0: *20 upstream timed out (110: Connection timed out) while reading response header from upstream, client: xxx.18.170.101, server: , request: "GET / HTTP/1.1", upstream: "http://unix:/tmp/unicorn.my_app.sock/", host: "my_server"

unicorn 的error.log 显示超时并kill worker

D, [2015-01-29T13:01:45.386741 #22987] DEBUG -- : waiting 121.0s after suspend/hibernation
E, [2015-01-29T13:16:04.784404 #22987] ERROR -- : worker=0 PID:24176 timeout (241s > 240s), killing
E, [2015-01-29T13:16:04.794715 #22987] ERROR -- : reaped #<Process::Status: pid 24176 SIGKILL (signal 9)> worker=0
I, [2015-01-29T13:16:05.797775 #24377]  INFO -- : worker=0 spawned pid=24377
I, [2015-01-29T13:16:05.827508 #24377]  INFO -- : worker=0 ready

奇怪的是，在发出几个请求后，它会再次起作用:正常生产.log

I, [2015-01-29T13:34:39.054539 #24666]  INFO -- : Started GET "/" for xx.18.170.101 at 2015-01-29 13:34:39 +0000
I, [2015-01-29T13:34:39.122488 #24666]  INFO -- : Processing by ProductsController#index as HTML
....

然后如果一段时间没有请求，错误又会发生。

看时间戳和成功请求和错误请求的production.log的区别，我认为nginx，unicorn设置没有任何问题。但是，通常当一个请求到达 Rails 应用程序时，它将被处理 processing by ...Controller 但是一段时间后没有请求，下一个请求被卡在某个地方。

关于如何修复或调试此问题的任何建议？我试过 strace 但结果很难弄清楚。最耗时的是:

[pid 12649] 06:34:02 select(8, [7], NULL, NULL, {44, 88867}) = 0 (Timeout) <44.105805>

Answer 1

我不是 100% 确定这个答案，但我还不能发表评论。所以我不能告诉你为什么你的请求花了这么长时间，但重要的错误消息是你的 unicorn worker 被杀的地方。

来自你的 unicorn.rb:timeout 240

来自您的 unicorn_error.log:

ERROR -- : worker=0 PID:24176 timeout (241s > 240s), killing

因此该请求花费的时间超过 240 秒。尝试增加您的 unicorn 超时，以便请求可以通过，然后查看您的日志文件以了解花费了这么长时间的内容。你说 unicorn 不是问题是对的，因为除非你正在做你和用户期望花费很长时间的事情，否则你不应该花费 +240s。