Rails Rails 在生产环境中 log 的产生问题

tualatrix · 2012年02月16日 · 最后由 gazeldx 回复于 2015年06月05日 · 8633 次阅读

我在生产环境中用 nginx+unicorn 测试我的 Rails 站点,发现一个问题。

那就是我在访问时,遇到 500 问题,production.log 不会马上记录的,要等到我频繁了试了很多次 500 以后,production.log 才记录起来。相当于 buffer 满了,再写入文件。

不知道是不是我猜测的这样的行为?

如果默认是这样,那有没有办法可以改变这个行为的?

3.2 吧,log 写入是有延迟的。

#1 楼 @huacnlee 是的,最新的 3.2.1

有什么关于这个延迟设计的文档吗?干吗要这样呢。

毫无疑问 Rails 引入 bufferlog 是为了性能,我直觉既然引入了这个 feature,那么 rails core-team 定会提供一个可以 disabled buffer log 的方法,刚刚找了一下,这里提供一个方法你试试看 http://stackoverflow.com/questions/5947551/how-to-write-flush-the-rails-log-when-the-process-dies

config.logger.auto_flushing = false

好奇,以前没这个功能的时候 log 写入应该会成为瓶颈啊。

#4 楼 @huacnlee 也许是因为 rails 网站还没有普遍遇到中等以上规模的请求压力,毕竟日志文件是 append 写入的,所以这块的问题在之前并不算太大

#2 楼 @tualatrix #3 楼 @lgn21st #1 楼 @huacnlee

这是在 3.2.1 引入的,不管是 500 还是其他 log,都要等到 buffer 大小是 8K 的位数时才 flush。 config.logger.auto_flushing 在 3.2.1 中是无效的,好在 rails master 中已经有人实现了这个。

bufferlog 在 rails2.3 就有的。

~/mine/rails -> (no branch) $ git co v2.3.4
HEAD is now at a43ef24... Prepare for 2.3.4 release
~/mine/rails -> (no branch) $ git grep auto_flushing
actionpack/test/template/benchmark_helper_test.rb:    logger.auto_flushing = false
activesupport/CHANGELOG:* BufferedLogger#auto_flushing = N flushes the log every N messages. Buffers with an array instead of string. Disa

#6 楼 @ashchan

所以暂时无法在 3.2.1 里把这个 bufferlog 给关闭掉吧?

#8 楼 @tualatrix

ActiveSupport::BufferedLogger#auto_flushing is deprecated. Either set the sync level on the underlying file handle like this:

f = File.open('foo.log', 'w')
f.sync = true
ActiveSupport::BufferedLogger.new f

Or tune your filesystem. The FS cache is now what controls flushing. ActiveSupport::BufferedLogger#flush is deprecated. Set sync on your filehandle, or tune your filesystem.

上面是 3.2 的 changlog 大概的意思是,auto flushing 方法已经取消了。 现在想调节写 log 的 buffer 可以有两种方案: 1.设置文件打开方式:sync or async 2.调节操作系统的的 cache 来控制 fushing。。。这个我也不知道怎么调。。。:-)

#7 楼 @hooopo 上面讨论的问题并不是 BufferredLogger 引入的。

#11 楼 @ashchan 那是什么引入的?

#13 楼 @hooopo 就是你在 9 楼说的内容,buffered logger 是应用层的 cache,现在讨论的问题和它关系不大,是由于文件系统的异步写入能力导致的

#14 楼 @fsword 好吧 其实关闭不了延迟写日志不是 BuggeredLogger 职责调整导致的吗

#15 楼 @hooopo 这么说也不算错,以前的 BufferedLogger 设计的比较复杂,现在这么做似乎是想把责任全部交给 file system 了,但是 fs 的机制大家都不熟悉,所以才存在这个问题

#8 楼 @tualatrix #13 楼 @hooopo

3.2.2 中已经改为默认 flush 了。每次部署后看着滚滚的 log 才放心。

解决写日志办法很多,这种方式真蛋疼,为了实时看到日志还得专门升级到 3.2.2

f = File.open('foo.log', 'w') f.sync = true

#9 楼 @hooooopo 正解!

tualatrix Rails route 匹配的问题 提及了此话题。 04月03日 10:56
需要 登录 后方可回复, 如果你还没有账号请 注册新账号