我有一个简单的商业 Rails 3.2.13 应用程序,只有一个用户,Postgres 数据库表非常小,Active Record 数据库查询非常简单。我在 Unicorn Web 服务器上的两个 dyno 上运行它,零工人。应用程序的根页面通常在开发中加载大约 150 毫秒,在 Heroku 的生产中加载不到 1 秒。
除非它随机超时。我在日志中看到超时,但不是典型的 R12 请求超时。超时如下所示:
2013-05-28T16:04:28.004290+00:00 app[web.2]: Started GET "/" for 72.28.209.197 at 2013-05-28 16:04:28 +0000
2013-05-28T16:04:44.225643+00:00 app[web.2]: E, [2013-05-28T16:04:44.225444 #2] ERROR -- : worker=2 PID:87 timeout (16s > 15s), killing
2013-05-28T16:04:44.238422+00:00 heroku[router]: at=error code=H13 desc="Connection closed without response" method=GET path=/ host=[REDACTED].herokuapp.com fwd="72.28.209.197" dyno=web.2 connect=7ms service=16240ms status=503 bytes=0
2013-05-28T16:04:44.255813+00:00 app[web.2]: E, [2013-05-28T16:04:44.255554 #2] ERROR -- : reaped #<Process::Status: pid 87 SIGKILL (signal 9)> worker=2
2013-05-28T16:04:44.298023+00:00 app[web.2]: I, [2013-05-28T16:04:44.297643 #103] INFO -- : worker=2 ready
当该请求有效时,它看起来像这样:
2013-05-28T16:03:36.965507+00:00 app[web.1]: sequenceId="102642"] Started GET "/" for 72.28.209.197 at 2013-05-28 16:03:36 +0000
2013-05-28T16:03:37.388261+00:00 app[web.1]: sequenceId="102690"] Processing by OverviewController#index as HTML
2013-05-28T16:03:38.238877+00:00 app[web.1]: sequenceId="102707"] Rendered overview/index.html.erb within layouts/application (315.8ms)
2013-05-28T16:03:38.311974+00:00 app[web.1]: sequenceId="102710"] Completed 200 OK in 924ms (Views: 432.4ms | ActiveRecord: 92.1ms)
2013-05-28T16:03:38.322786+00:00 heroku[router]: at=info method=GET path=/ host=[REDACTED].herokuapp.com fwd="72.28.209.197" dyno=web.1 connect=2ms service=1375ms status=200 bytes=136795
2013-05-28T16:03:42.625787+00:00 app[web.1]: sequenceId="102940"] Started GET "/assets/favicon.ico" for 72.28.209.197 at 2013-05-28 16:03:42 +0000
2013-05-28T16:03:58.753408+00:00 app[web.1]: sequenceId="104359"] E, [2013-05-28T16:03:58.753173 #2] ERROR -- : worker=2 PID:66 timeout (16s > 15s), killing
2013-05-28T16:03:58.801152+00:00 app[web.1]: sequenceId="104362"] E, [2013-05-28T16:03:58.800993 #2] ERROR -- : reaped #<Process::Status: pid 66 SIGKILL (signal 9)> worker=2
2013-05-28T16:03:58.798722+00:00 heroku[router]: at=error code=H13 desc="Connection closed without response" method=GET path=/assets/favicon.ico host=[REDACTED].herokuapp.com fwd="72.28.209.197" dyno=web.1 connect=3ms service=16175ms status=503 bytes=0
2013-05-28T16:03:59.127150+00:00 app[web.1]: sequenceId="104397"] I, [2013-05-28T16:03:59.126795 #84] INFO -- : worker=2 ready
注意事项:请求响应时间为 924 毫秒。但是在那之后发生了某种奇怪的错误。
这就是该请求在DB 查询方面的样子。那里没有什么令人兴奋的事情发生,那些数据库表只包含几百行数据。没有理由为什么有时响应需要 1 秒,而其他时间需要 15 秒以上。这是极其简单的控制器操作的代码:
class OverviewController < ApplicationController
def index
@current_event = Event.recent
@areas = Area.order(:position)
@reservations = Reservation.find(:all,
:conditions => { :event_id => @current_event.id },
:order => 'created_at DESC',
:limit => 5)
end
end
这是 Event#recent 方法,只是为了让您可以看到它没有做任何可能需要 15 秒以上的事情:
def self.recent
Event.last || Event.create
end
我不知道如何让这个应用程序稳定,除了把它从 Heroku 移走。我不知道有什么方法可以解决这个问题,我猜 Heroku 也帮不上忙。我只是卡住了吗?除了将应用程序移至 Engine Yard 之外,我还有其他解决问题的方法吗?