2

设置场景

为了使默认的 Rails 日志记录在生产环境中更有帮助，我一直在利用 Log4r 及其诊断上下文，特别是MDC。除了来自 Rails 应用程序本身的日志之外，我还插入了一些我自己的中间件，以便我可以获得一致的日志记录，即使在 Rack 中间件中也是如此。

例如，一旦我通过 Warden 访问登录用户，我就会添加该部分所需的 MDC 条目。

def call(env)
  user = env['warden'].user
  user_context = user ? user.to_log_format : 'indetermined'
  MDC.put :user, user_context

  @app.call(env)
end

Rack 中间件中记录的其他内容是父 PID、请求 ID 等。

问题

问题是我的日志条目明显不正确。在负载下，我一直看到一个用户的身份与一个完全不同的用户对 API 发出的请求混合在一起，如果请求足够接近的话。

有人告诉我Log4r MDC 是线程安全的，Rails 4 默认是线程安全的，但显然有些不对劲。我也想知道 Rack 是否是问题所在，但是 Rails 中的线程安全性——完全是一个词，对吗？——似乎有足够的信心删除 Rack::Lock，那么这似乎也不对。

我错过了什么？所有信息似乎都说它是线程安全的，但我不相信它是。

引擎盖下

  • 导轨 4.1.10
  • Log4r 1.1.10
  • 乘客 4.0.59

参考

4

1 回答 1

0

经过一些研究和实验，这根本不是线程安全的问题。这是一个来自另一个请求的陈旧数据的问题。要了解问题，您必须了解 Log4r MDC 的内容是如何存储的，才能知道问题所在：

MDC 片段与线程一起存储，以便在整个请求期间可以访问它们以进行日志记录。

def self.put( a_key, a_value )
  self.check_thread_instance()
  Thread.current[MDCNAME][a_key] = a_value
end

所以当一个线程完全处理完一个请求时，它会接收另一个请求。不幸的是，它似乎仍然带有先前请求的详细信息 - 没有任何内容被清除。因此，所有这些旧的、不相关的细节最终都可能成为无关请求的诊断上下文。

然后，解决方案是确保在开始向新请求添加新上下文之前清除 MDC 片段：

MDC.get_context.keys.each { |k| MDC.remove(k) }

哎呀。

于 2016-05-02T17:04:41.193 回答