0

我将一个应用程序从竹子堆栈移动到雪松，服务器的行为很奇怪，它在第一个请求时超时，根据日志需要 40 秒，而下一个相同的请求需要 1.5 秒。你会认为测功机睡着了，但我有 2-3 个测功机（使用租火）和 3 个工人。

  • 导轨 3.2
  • 红宝石 1.9.3
  • heroku 雪松
  • heroku postgres 起重机
  • MongoDB，MongoHQ 大型
  • mongo_mapper 0.11.1
  • 薄的
  • 没有缓存

这是一个用户交互很少的应用程序，因为它主要是一个巨大的后台工作工具。使用它的客户很少，但重要的是，我显然不能让应用程序每天早上或午餐后超时。你也会讨厌的。

➜  my_app git:(master) ✗ heroku logs -t -p web --remote production

一些不活动后的第一个请求40880ms

Started GET "/my_model" for xx.160.183.xxx at 2013-10-31 15:19:34 +0000
Processing by MyModelsController#index as HTML
User Load (6.8ms)  SELECT "users".* FROM "users" WHERE "users"."id" = 110237164 LIMIT 1
MyModel Load (12.0ms)  SELECT "my_model".* FROM "my_model" ORDER BY name ASC
Rendered my_model/_my_model_statuses.html.erb (3515.6ms)
Rendered my_model/_my_model_statuses.html.erb (3514.8ms)
Rendered my_model/_my_model_statuses.html.erb (3210.6ms)
Rendered my_model/_my_model_statuses.html.erb (3968.4ms)
Rendered my_model/_my_model_statuses.html.erb (2652.0ms)
Rendered my_model/_my_model_statuses.html.erb (2253.5ms)
Rendered my_model/_my_model_statuses.html.erb (1339.7ms)
Rendered my_model/_my_model_statuses.html.erb (1333.0ms)
Rendered my_model/_my_model_statuses.html.erb (2901.9ms)
Rendered my_model/_my_model_statuses.html.erb (636.3ms)
Rendered my_model/_my_model_statuses.html.erb (1598.6ms)
Rendered my_model/_my_model_statuses.html.erb (10.1ms)
Rendered my_model/_my_model_statuses.html.erb (909.3ms)
Rendered my_model/_my_model_statuses.html.erb (911.5ms)
Rendered my_model/_my_model_statuses.html.erb (1435.4ms)
Rendered my_model/_my_model_statuses.html.erb (1043.9ms)
Rendered my_model/_my_model_statuses.html.erb (1712.3ms)
Rendered my_model/_my_model_statuses.html.erb (793.8ms)
Rendered my_model/_my_model_statuses.html.erb (290.2ms)
Rendered my_model/_my_model_statuses.html.erb (1142.0ms)
Rendered my_model/_my_model_statuses.html.erb (342.6ms)
Rendered my_model/_my_model_statuses.html.erb (376.0ms)
Rendered my_model/_my_model_statuses.html.erb (2161.8ms)
Rendered my_model/_my_model_statuses.html.erb (1194.9ms)
Rendered my_model/_my_model_statuses.html.erb (1293.4ms)
Rendered my_model/_my_model_overview.html.erb (40695.0ms)
Rendered my_model/index.html.erb within layouts/application (40721.5ms)
Rendered shared/_menu.html.erb (1.0ms)
Rendered shared/_usermenu.html.erb (2.3ms)
Rendered shared/_header.html.erb (27.1ms)
Rendered shared/_messages.html.erb (0.1ms)
Rendered feedbacks/_new.html.erb (15.8ms)
Completed 200 OK in 40880ms (Views: 40856.2ms | ActiveRecord: 18.8ms)

这是一个表格，其中每一行都是部分提取的，以便我可以看到花费了时间。

这是超时之后。1398 毫秒

Started GET "/my_models" for xxx.160.183.xxx at 2013-10-31 15:21:18 +0000
Processing by MyModelsController#index as HTML
User Load (2.4ms)  SELECT "users".* FROM "users" WHERE "users"."id" = 110237164 LIMIT 1
MyModel Load (3.2ms)  SELECT "my_models".* FROM "my_models" ORDER BY name ASC
Rendered my_models/_my_model_statuses.html.erb (87.7ms)
Rendered my_models/_my_model_statuses.html.erb (25.5ms)
Rendered my_models/_my_model_statuses.html.erb (35.7ms)
Rendered my_models/_my_model_statuses.html.erb (107.8ms)
Rendered my_models/_my_model_statuses.html.erb (163.9ms)
Rendered my_models/_my_model_statuses.html.erb (26.2ms)
Rendered my_models/_my_model_statuses.html.erb (26.3ms)
Rendered my_models/_my_model_statuses.html.erb (19.3ms)
Rendered my_models/_my_model_statuses.html.erb (121.4ms)
Rendered my_models/_my_model_statuses.html.erb (62.6ms)
Rendered my_models/_my_model_statuses.html.erb (94.9ms)
Rendered my_models/_my_model_statuses.html.erb (8.2ms)
Rendered my_models/_my_model_statuses.html.erb (19.1ms)
Rendered my_models/_my_model_statuses.html.erb (15.8ms)
Rendered my_models/_my_model_statuses.html.erb (59.9ms)
Rendered my_models/_my_model_statuses.html.erb (20.6ms)
Rendered my_models/_my_model_statuses.html.erb (78.8ms)
Rendered my_models/_my_model_statuses.html.erb (25.3ms)
Rendered my_models/_my_model_statuses.html.erb (13.3ms)
Rendered my_models/_my_model_statuses.html.erb (130.1ms)
Rendered my_models/_my_model_statuses.html.erb (9.7ms)
Rendered my_models/_my_model_statuses.html.erb (11.1ms)
Rendered my_models/_my_model_statuses.html.erb (92.0ms)
Rendered my_models/_my_model_statuses.html.erb (51.6ms)
Rendered my_models/_my_model_statuses.html.erb (23.1ms)
Rendered my_models/_my_models_overview.html.erb (1385.7ms)
Rendered my_models/index.html.erb within layouts/application (1386.3ms)
Rendered shared/_menu.html.erb (0.3ms)
Rendered shared/_usermenu.html.erb (0.6ms)
Rendered shared/_header.html.erb (1.5ms)
Rendered shared/_messages.html.erb (0.0ms)
Rendered feedbacks/_new.html.erb (1.5ms)
Completed 200 OK in 1398ms (Views: 1388.8ms | ActiveRecord: 5.5ms)

我没有使用任何显式缓存，只是使用普通的 Rails ActiveRecord 来填充表。在当地根本不是这样的。Heroku 支持推荐并发和缓存，这适用于高流量的应用程序。这是一个低流量的应用程序，一个工具。他们没有评论竹子与雪松的话题，所以我在这里联系，以防有人知道我不知道的事情。

在这两种情况下DB < 20 ms，这都是 CPU 的东西，渲染模板。

4

2 回答 2

0

是的...我会分享而不是删除问题。希望我的错误能帮助某人更快地了解这一点。

问题出在 mongodb 查询上。不是睡觉的测功机或服务。只是我自己的代码。

MongoHQ 有一个“慢查询”页面报告“没有慢查询”，这非常令人困惑。我想为 Matt McCay 的出色支持和尊重的方法鼓掌，尽管这是一个（又一个？）“用户错误”。他向我展示了显示这一点的 mongodb 日志记录：

Tue Nov 5 22:59:46.722 [conn2335303] query myapp-production.day_reports query: { $query: { my_model_id: 2147259060, some_unindexed_field: { $gt: 0 } }, $orderby: { some_index_timestamp: -1 } } ntoreturn:1 ntoskip:0 nscanned:775 scanAndOrder:1 keyUpdates:0 locks(micros) r:7474265 nreturned:0 reslen:20 7474ms
Tue Nov 5 22:59:49.439 [conn2335303] query myapp-production.day_reports query: { $query: { my_model_id: 2147259071, some_unindexed_field: { $gt: 0 } }, $orderby: { some_index_timestamp: -1 } } ntoreturn:1 ntoskip:0 nscanned:502 scanAndOrder:1 keyUpdates:0 locks(micros) r:2570470 nreturned:0 reslen:20 2570ms

在同一个查询中只显示两个（30 个）。注意7474ms和2570ms

我想知道为什么这些不会在 MongoHQ 中被列为“慢查询”......让这成为一个警告，不要让自己被愚弄或蒙蔽。

解决方案：就我而言，我通过非规范化解决了这个问题，我在每次写入时将计算值保存在我的模型中。我也可以使用索引，它会非常快，但在这种情况下，我读取的模型在 PostgreSQL 中，并且通过非规范化，我根本不需要连接到 MongoDB - 在这个特定的请求上。

为什么以下查询的速度如此之快？

答案可以在这里找到：http: //docs.mongodb.org/manual/faq/fundamentals/#does-mongodb-handle-caching

MongoDB 在 RAM 中保存/缓存最后获取的数据。

理想情况下，我应该如何解决这个问题？

  1. 隔离并消除。我应该同时插入和拔出 heroku postgresql 和 mongohq 以排除它们。“第一次慢，之后很快”让我专注于服务器问题，我应该知道更好。
  2. 更彻底地研究日志。
于 2013-11-12T19:31:58.773 回答
0

这就是 heroku 处理资源的方式。它被称为 dyno-idling，他们去年发布了这个：https ://devcenter.heroku.com/articles/dynos#dyno-idling 。

修复它的 heorku 方法是支付额外的测功机，然后它将一直运行。但是您也可以使用 ping 服务来 ping 您的站点。有些人每小时一次，有些人每十五分钟一次，有些人每分钟一次。这将使您的测功机保持活跃，并且您的瘦服务器始终“清醒”

于 2013-11-04T15:21:59.303 回答