ruby-on-rails-3 - Heroku 上缓慢的 postgres 查询不会被 Rack 超时中断

Question

我没能通过谷歌找到信息，也许这里有人遇到过类似的问题。

我们有一个使用 Postgres 数据库在 Heroku 上运行的 Rails 应用程序。我们有一个特别慢的查询(是的，我们正在修复查询)，但在调试这个问题的过程中，我观察到我们的 rack-timeout gem 没有在 15 秒时终止请求。我通过插入 sleep(50) 进行了侧面测试，果然， Rack 超时在这种情况下工作正常。

这是我们日志的编辑副本，显示 rack-time(时间到!)在几分钟后发生，我们仍然在 30 秒后看到 H12 请求超时。

    2011-12-14T21:15:16+00:00 app[web.2]: Started GET "/search?utf8=%E2%9C%93&terms=foo" for 173.164.186.205 at Wed Dec 14 13:15:16 -0800 2011
    2011-12-14T21:15:16+00:00 app[web.2]: search query elapsed time => [0.000365018844604492]
    2011-12-14T21:15:46+00:00 heroku[router]: Error H12 (Request timeout) -> GET /search dyno=web.2 queue= wait= service=30000ms status=503 bytes=0
    2011-12-14T21:18:47+00:00 app[postgres]: [6-1] [removed] [COBALT] LOG:  duration: 211241.725 ms  statement: SELECT  [truncated]
    2011-12-14T21:18:47+00:00 app[web.2]: 
    2011-12-14T21:18:47+00:00 app[web.2]: ActionView::Template::Error (Timeout::Error: time's up!: SELECT  [truncated]):

是否了解为什么以及如何强制执行 Rack 超时？

Answer 1

是的，这里发生的就是我所说的僵尸测功机。 30 秒超时发生在位于 Dyno 上方的路由网格中。理论上，您的测功机可以运行数小时，但用户会在 30 秒后直接从路由网格中看到错误。

所以。这是怎么回事:

1. 您的请求是在 21:15:16
提出的
2. 在 21:15:46 路由网格返回错误，但您的 dyno 仍在处理
3. 在 21:18:47 您的请求完成。

至于 Rack::Timeout 和您长时间运行的查询发生了什么，它可能取决于您使用的 pg gem，因为 Rack::Timeout 依赖于线程才能正常运行。这解释了为什么在数据库返回时会出现超时。

关于僵尸测功机的更多信息:http://neilmiddleton.com/avoiding-zombie-dynos-with-heroku/