Heroku 上奇怪的 TTFB（第一个字节的时间）问题

我们正在改进 Heroku 上托管的 Rails 应用程序（rails 3.2.8 和 ruby​​ 1.9.3）的性能。在此期间，我们遇到了一个令人震惊的问题，其来源似乎极难追踪。让我快速解释一下我们如何遇到这个问题以及我们如何尝试隔离它。

--

自六月左右以来，我们在整个网站的“首字节时间”方面都经历了奇怪的滞后行为。使用该网站时问题很明显（有时应用程序在 10-20 秒内没有响应），并且它也存在于通过pagetest.org 进行的瀑布分析中。 我们的总部位于丹麦，但可以从任何主机处获得此结果。

为了确认该问题，我们执行了基准测试，向一个简单页面发送 300 个相同的请求并测量响应时间。 如果我们向首页发送 300 个请求，中位响应时间低于 1 秒，这相当不错。让我们害怕的是，60 个请求花费的时间是两倍多，其中 40 个请求花费的时间超过 4 秒。有些请求需要长达 16 秒的时间。

这些缓慢的请求都不会出现在我们用于性能监控的 New Relic 中。不会出现任何请求排队，无论我们将 Web 流程扩展至多高，结果都是相同的。 尽管如此，我们不能否认问题是由应用程序代码引起的，因此我们尝试了另一个实验，通过机架中间件响应请求。

通过将此中间件 (TestMiddleware) 放置在机架堆栈的开头，我们在请求到达应用程序之前就返回了请求，确保以下中间件或 Rails 应用程序都不会导致延迟。

Middleware setup:
$ heroku run rake middleware
use Rack::Cache
use ActionDispatch::Static
use TestMiddleware
use Rack::Rewrite
use Rack::Lock
use Rack::Runtime
use Rack::MethodOverride
use ActionDispatch::RequestId
use Rails::Rack::Logger
use ActionDispatch::ShowExceptions
use ActionDispatch::DebugExceptions
use ActionDispatch::RemoteIp
use Rack::Sendfile
use ActionDispatch::Callbacks
use ActiveRecord::ConnectionAdapters::ConnectionManagement
use ActiveRecord::QueryCache
use ActionDispatch::Cookies
use ActionDispatch::Session::DalliStore
use ActionDispatch::Flash
use ActionDispatch::ParamsParser
use ActionDispatch::Head
use Rack::ConditionalGet
use Rack::ETag
use ActionDispatch::BestStandardsSupport
use NewRelic::Rack::BrowserMonitoring
use Rack::RailsExceptional
use OmniAuth::Builder
run AU::Application.routes

然后，我们运行相同的脚本来记录响应时间，并得到几乎相同的结果。中值响应时间约为 130 毫秒（显然更快，因为它不会影响应用程序。但仍有 60 个请求花费了超过 400 毫秒，25 个请求花费了超过 1 秒。同样，有些请求慢至 16 秒。

一种解释可能与网络上的缓慢跳跃或 DNS 设置有关，但跟踪路由的结果看起来完全正常。

这个结果通过在 Heroku 上托管的另一个 Rails 3.2 和 ruby​​ 1.9.3 应用程序上运行响应脚本得到了证实 - 根本没有奇怪的行为。

DNS 设置遵循 Heroku 的建议。

--

至少可以说我们很困惑。 Heroku 的路由网络是否存在可疑之处？ 为什么我们会看到这种奇怪的行为？我们如何摆脱它？为什么我们在 New Relic 中看不到它？

原来这是一种请求排队。有时，该网络服务器很忙，并且由于heroku只是将随机传入的请求随机路由到任何dyno，那么我可能最终会排在dyno后面的队列中，该队列由于例如以下原因而完全卡住了。数据库问题。奇怪的是，这在 new relic 中很难注意到（在查看图表中的资源时取消选中所有其他资源是个好主意，然后队列突然出现）

2013 年 2 月 21 日编辑：事实证明，它在 Newrelic 中不那么引人注目的原因是，它没有被测量！http://rapgenius.com/Lemon-money-trees-rap-genius-response-to-heroku-lyrics http://rapgenius.com/Lemon-money-trees-rap-genius-response-to-heroku-lyrics

我们发现这非常令人沮丧，最终我们放弃了 Heroku，转而使用专用服务器。这使我们以 1/10 的成本获得了 20 倍的性能提升。此外，我必须说，我们对 Heroku 感到失望，Heroku 在发生这种情况时否认缓慢是由于他们的基础设施造成的，尽管我们对此表示怀疑并多次强调了这一点。我们甚至得到了这样的答案：

Heroku 2012 年 8 月 28 日：“如果您没有在 New Relic 中看到请求排队或其他缓慢的报告，那么这可能不是服务器端问题。Heroku 的内部路由应该花费

此外，我们采访了 Newrelic，他们似乎也没有意识到这个问题，尽管他们自称与 Heroku 有着非常密切的工作关系。

新遗迹 2012 年 8 月 29 日：“看来导致这种情况的原因是在 Ruby 代理的可见性开始之前发生的。代理记录的队列时间是从请求进入测功机的时间开始的，因此速度减慢是在那之前发生的。”

最重要的是，我们最终花了很多时间来优化代码，而这并不是真正的瓶颈。另外，为了提高我们的性能，我们还使用了太高的测功机规模，但我们真正从中得到的唯一好处是从 Heroku 和 Newrelic 获得了更大的收益 - 不酷。我很高兴我们改变了。

附言。当时甚至存在一个错误，导致 newrelic pro 在所有 dynos 上收费，即使我们（根据 Newrelic 自己的建议）禁用了对后台工作进程的监控。双方花了很长时间和很多电子邮件才承认错误。

聚苯硫醚。如果您不知道当前正在进行的讨论，那么这里是链接http://rapgenius.com/James-somers-herokus-ugly-secret-lyrics http://rapgenius.com/James-somers-herokus-ugly-secret-lyrics

2013 年 2 月 26 日编辑Heroku 刚刚宣布 https://blog.heroku.com/archives/2013/2/21/better_queuing_metrics_with_updated_new_relic_add_on在他们的时事通讯中，Newrelic 发布了update http://blog.newrelic.com/2013/02/21/using-new-relic-on-heroku-read-how-our-new-ruby-agent-measures-queue-time/这显然可以让我们了解 Heroku 的情况。

2013 年 8 月 4 日编辑Heroku 刚刚发布了FAQ https://blog.heroku.com/archives/2013/4/3/routing_and_web_performance_on_heroku_a_faq超出主题