Rails 3.2.2 日志文件无序，请求交织答案

【问题标题】：Rails 3.2.2 log files unordered, requests intertwinedRails 3.2.2 日志文件无序，请求交织
【发布时间】：2012-07-19 13:24:13
【问题描述】：

我记得获得了有序的日志文件，这样您就可以遵循一个请求，然后是下一个请求，依此类推。

现在，正如我 4 岁的孩子所说的那样，日志文件是“全部乱码”，这意味着它们不再是单独的、不同的文本块。来自两个请求的日志会交织/混淆。

例如：

Started GET /foobar
...
Completed 200 OK in 2ms (Views: 0.4ms | ActiveRecord: 0.8ms)
Patient Load (wait, that's from another request that has nothing to do with foobar!)
[ blank space ]
Something else

这太让人抓狂了，因为我无法在一个请求中说出发生了什么。

这是在乘客上运行的。

【问题讨论】：

我认为是相关的news.ycombinator.com/item?id=4483390

标签： ruby-on-rails-3 logging

【解决方案1】：

我试图搜索相同的答案，但找不到任何好的信息。我不确定你是否应该修复服务器或 Rails 代码。

如果您想了解有关此问题的更多信息，请参阅删除旧记录方式的提交 https://github.com/rails/rails/commit/04ef93dae6d9cec616973c1110a33894ad4ba6ed

【讨论】：

【解决方案2】：

如果您更看重生产日志的可读性，那么您可以使用

PassengerMaxInstancesPerApp 1

配置。它可能会导致一些缩放问题。或者，您可以在 application.rb 中添加类似的内容：

process_log_filename = Rails.root + "log/#{Rails.env}-#{Process.pid}.log"
log_file = File.open(process_log_filename, 'a')
Rails.logger = ActiveSupport::BufferedLogger.new(log_file)

【讨论】：

如果我没记错的话，如果你碰巧得到了前一个进程的 PID，那会覆盖你的旧日志文件。这可以通过频繁轮换在一定程度上得到缓解，但由于 PID 不是您可以指望的东西，因此仍然不是 100% 安全的。我认为您想在日志文件名中添加时间戳或其他内容。另外：PassengerMaxInstancesPerApp 建议毫无用处，近乎刻薄；我会从你的答案中删除它。
我对这个答案投了反对票，因为你不应该建议PassengerMaxInstancesPerApp 改变。如果有人询问如何释放硬盘空间，这类似于建议删除根目录的代码行。请修改。
PassengerMaxInstancesPerApp 部分是个笑话，但如果您在开发过程中使用它，它也是一个真正的解决方案。

【解决方案3】：

是的！他们已经在ActiveSupport::BufferedLogger 中进行了一些更改，因此不再需要等待请求结束来刷新日志：

但是他们添加了ActiveSupport::TaggedLogging，这很有趣，您可以在每条日志上标记任何您想要的标记。

在您的情况下，最好使用 request UUID 标记日志，如下所示：

# config/application.rb
config.log_tags = [:uuid]

那么即使日志被搞砸了，您仍然可以跟踪其中哪些与您正在跟进的请求相对应。

您可以使用此功能制作更多有趣的东西来帮助您进行日志研究：

【讨论】：

【解决方案4】：

好吧，对我来说，TaggedLogging 解决方案是行不通的，如果服务器严重崩溃，我可以忍受一些日志丢失，但我希望我的日志得到完美排序。因此，根据the issue comments 的建议，我将其应用于我的应用程序：

# lib/sequential_logs.rb
module ActiveSupport
  class BufferedLogger
    def flush
      @log_dest.flush
    end
    def respond_to?(method, include_private = false)
      super
    end
  end
end

# config/initializers/sequential_logs.rb
require 'sequential_logs.rb'

Rails.logger.instance_variable_get(:@logger).instance_variable_get(:@log_dest).sync = false

据我所知，这并没有影响我的应用程序，它仍在运行，现在我的日志再次有意义。

【讨论】：

【解决方案5】：

他们应该添加一些准随机 reqid 并将其写在与单个请求有关的每一行中。这样你就不会感到困惑了。

【讨论】：

【解决方案6】：

我没用过，但我相信Lumberjack's unit_of_work method 可能就是您要找的。你打电话：

Lumberjack.unit_of_work do
  yield
end

并且在该块或产生的块中完成的所有日志记录都带有唯一 ID 标记。

【讨论】：