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

我们正在改进我们在Heroku托管的rails应用程序的性能（rails 3.2.8和ruby 1.9.3）。 在此过程中，我们遇到了一个令人担忧的问题，其源头似乎非常难以追踪。 让我快速解释一下我们如何体验这个问题以及我们如何尝试隔离它。

–

从6月左右开始，我们在整个网站的Time to First Byte中经历了奇怪的滞后行为。 使用该网站时问题很明显（有时候应用程序没有响应10-20秒），并且它也通过webpagetest.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设置有关，但traceroute的结果看起来完全正常。

通过在Heroku上托管的另一个rails 3.2和ruby 1.9.3应用程序上运行响应脚本来确认此结果 – 完全没有奇怪的行为。

DNS设置遵循Heroku的建议。

–

至少我们很困惑。 Heroku的路由网络可能有些可疑吗？ 为什么我们看到这种奇怪的行为呢？ 我们如何摆脱它？ 为什么我们不能在New Relic中看到它？

Answer 1

原来它是一种请求排队。 有时候，那个Web服务器很忙，而且因为heroku只是随机地将传入的请求随机地路由到任何dyno，然后我可能会在dyno后面的队列中结束，因为例如数据库问题而完全卡住了。 奇怪的是，这在新的遗物中几乎不可察觉（在他们的图表中查看所有其他资源是个好主意，然后突然出现排队）

EDIT 21/2 2013：事实certificate，它在Newrelic中难以察觉的原因是它没有被测量过！ http://rapgenius.com/Lemon-money-trees-rap-genius-response-to-heroku-lyrics

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

Heroku 28/8 2012： “如果您没有看到New Relic中报告的请求排队或其他缓慢，那么这可能不是服务器端问题.Heroku的内部路由应该花费<1ms。我们的监控系统都没有指示任何目前路由问题。“

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

Newrelic 29/8 2012： “看起来在Ruby代理的可见性开始之前发生的任何事情都会发生。代理记录的队列时间是从请求进入 dyno 开始的时间，因此在此之前发生减速。”

最重要的是，我们最终花费了数小时和数小时来优化不是瓶颈的代码。 另外，为了提高我们的表现，还有一个过高的dyno规模，但我们真正得到的唯一一件事就是来自Heroku和Newrelic的更多收据 – 不是很酷。 我很高兴我们改变了。

PS。 当时甚至还有一个错误导致所有dynos的新手专业人员收费，即使我们（根据Newrelics自己的建议）已禁用对我们后台工作进程的监控。 在双方承认错误之前，花了很多时间和许多电子邮件。

PPS。 如果您不了解当前正在进行的讨论，那么这里是链接http://rapgenius.com/James-somers-herokus-ugly-secret-lyrics

编辑26/2 2013 Heroku刚刚在他们的时事通讯中宣布 ，Newrelic发布了一个更新 ，显然应该对Heroku的情况有所了解。

编辑2013年8月4日 Heroku刚刚发布了关于该主题的常见问题解答

Answer 2

traceroute不是衡量网络问题的一个很好的方法，它是一种可以在网络中找到故障的工具，但它不会向您显示最佳视图。

尝试只是建立一个静态网页，并使用网页测试仪的IP地址点击它。 如果它仍然很慢，责怪网络。

如果由于某种原因它很快，那么你有一个不同的问题。