运维 Ruby 原生日志分割已经解决多进程问题？

lgcjwt · June 01, 2018 · Last by pathbox replied at June 04, 2018 · 8872 hits

Topic has been selected as the excellent topic by the admin.

Ruby 原生日志分割存在多进程问题？

今天星期一，你刚到公司，Bill 就来到你的办公桌旁说：“有个本地部署的客户，希望日志分割不用 logrotata，没办法，甲方有进程洁癖。”，经过商量，我决定先调研三种主流的日志分割方案（logrotata、ruby 原生、log4r），然后再开始工作。

而 Bill 更希望我用 ruby 原生的日志分割，经过一番搜索，发现@huacnlee的这篇帖子

https://ruby-china.org/topics/3704

本着初生牛犊不怕虎，进一步查阅 ruby 的源码：logger.rb，发现问题可能在这里：

def shift_log_age
  (@shift_age-3).downto(0) do |i|
    if FileTest.exist?("#{@filename}..#{i}")
      File.rename("#{@filename}.#{i}", "#{@filename}.#{i+1}")
    end
  end
  @dev.close rescue nil
  File.rename("#{@filename}", "#{@filename}.0")
  @dev = create_logfile(@filename)
  return true
end

这里只粘出来按照日期分割的部分，多线程情况下显然会有问题。如果能改善这段代码，显然能很 ruby 哲学地运用 ruby 原生的日志分割

又本着不怕虎，我试图打开类重写这个方法来解决这个问题

 def shift_log_age
  @dev = open_logfile(@filename)
  date = Time.now.strftime("%Y%m%d")
  return true if @dev.stat.size < @shift_size
  ......
  return true
end

完成这个动作之后，我迫不及待的将代码布上服务器

设置分割大小为 1M，开始用脚本开两个 worker 不停的写日志，发现完全没有问题。我将这个结果兴奋的告诉 Bill，Bill 却很淡定，甚至有些疑惑，指出了这里面几个明显的问题：

1. 存在临界域问题

2. 每次都要重新 open，费力又不能解决问题

Bill 的疑惑在于，这样的代码不可能解决临界域的问题，但是测试的结果却是没有问题的。Bill 决定拒接我的 PR，让我继续研究

至此，我已经决定放弃 ruby 原生日志分割，转而去研究 log4r，直到我在丧气中刷完 Facebook，偶然发现了这个：

https://www.slideshare.net/sonots/rubylogger-rubyconf-20131109

这个需要翻墙，为了省事，直接截图粘贴过来。感受一下作者 Naotoshi Seo 的兴奋之情。

再去 ruby 源码的 github 发现

https://github.com/ruby/ruby/pull/428

至此看来，ruby 原生日志分割，可以完美使用了，而我的方法之所以能成功，看来完全是因为 ruby 日志分割原本就支持多进程了

在 Bill 的帮助下，发现解决这一问题的关键在于

File.open(@filename, File::WRONLY | File::APPEND) do |lock|
  lock.flock(File::LOCK_EX) # inter-process locking. will be unlocked at closing file
  if File.identical?(@filename, lock) and File.identical?(lock, @dev)
    yield # log shifting
  else
  # log shifted by another process (i-node before locking and i-node after locking are different)
    @dev.close rescue nil
    @dev = open_logfile(@filename)
    @dev.sync = true
  end
end