1

这是我的 production.log 的片段：

Started GET "/product/514034/754240" for XX.XX.202.138 at 2012-06-21 11:52:28 -0700


Started GET "/product/614409/666897" for XX.XX.228.38 at 2012-06-21 11:52:28 -0700
Processing by ProductsController#show as HTML
  Parameters: {"category_id"=>"514034", "product_id"=>"754240"}
Processing by ProductsController#show as HTML
  Parameters: {"category_id"=>"614409", "product_id"=>"666897"}
Logged in 2940659 via auth cookie
Logged in 585210 via auth cookie
[e3e3fc56bb6bd137741b269ee397683c] [2940659] Read fragment views/global-caches/header (0.7ms)
[e3e3fc56bb6bd137741b269ee397683c] [2940659]   Rendered shared/_email_form.html.haml (0.7ms)
[d81bb986be5acc0277c0c9e11b414249] [585210] Read fragment views/global-caches/sharebar-message (0.7ms)
[d81bb986be5acc0277c0c9e11b414249] [585210]   Rendered shared/_email_form.html.haml (0.7ms)
...

如您所见，它将两个不同用户的两个并发会话同时记录到同一个日志文件中。这使得无法解析我的日志并确定例如生成每种页面所花费的时间，因为这些条目的顺序不是预期的：

Started GET "/URL/BLAH" for IP at DATE
... stuff...
Completed 200 OK in XXms (ActiveRecord: YY.Yms)

相反，我得到一个不可预测的交错日志，如下所示：

Started GET "/URL/BLAH" for IP at DATE

Started GET "/URL/BLAH" for IP at DATE
... stuff...
Completed 200 OK in XXms (ActiveRecord: YY.Yms)
...stuff...
Completed 200 OK in XXms (ActiveRecord: YY.Yms)

所以不可能将“完成”与“开始”相匹配。

我想要的是一种让每个子进程写入自己的日志或其他东西的方法。或者，如果有可能以原子方式编写每个浏览量的日志，但这可能是不可能的、困难的或会损害性能。

4

1 回答 1

3

Rails 3.2 提供了不错的选项 config.log_tag

您可以添加到您的 production.rb：

config.log_tags = [ lambda { Time.now.to_i }]

因此，日志中的每一行都会以数字开头。例子：

[1351867173] 在 2012-11-02 16:39:33 +0200 开始 GET "/" for 127.0.0.1
[1351867173] RecipesController#main 处理为 HTML

日志仍然被打乱，但现在我们可以对它们进行规范化、排序。

排序-f -s -k1.1,1.11 production.log | sed 's/^............./' > sorted_production.log

（按第一个符号排序（按时间戳）并通过 sed 删除时间戳）

现在日志很容易分析。

此外，在 rails 3.2.9 中还修复了相关问题https://github.com/rails/rails/pull/7317
所以请记住这一点。
对不起英语不好...）

于 2012-11-02T17:46:33.393 回答