Rails Ruby on Rails 项目实现日志等级实时变更

lgcjwt · June 28, 2019 · Last by killyfreedom replied at July 01, 2019 · 3202 hits

对于一个 rails 项目,一般是项目进程启动的时候会根据环境不同来设置一个日志等级。
但如果想要实现日志等级的实时变更并不容易,可能存在多个更加优雅的做法,而这里分享一种实践过的简 r 有效的办法。

起源

某天,Bill 怀着一个复杂的心情看了看你,“有个特殊的需求可能需要你调研一下,我们需要对一个 rails 项目实现实时变更日志等级。”。
你思考了一下,需求倒是很明确,可是……
“当然,你只是研究一下,不是非要实现,我的意思是,当然,能实现就最好不过了”
你一定受不了这个的,但这可能并不是一件容易的事情。

思路

其实改变日志等级很容易:

logger.level = 'INFO'

尝试通过定时任务的方式进入进程修改变量值

但其实,rake 是一个新的进程,他无法进入到 puma 或者 unicorn 或者 sidekiq 的进程中修改进程的变量。

很自然的就想到通过定时任务进入进程内部,修改相应的日志等级变量值。

我相信,这样一定是能达到目标的

按照这个思路,尝试了用rufus-scheduler去替代whenever。因为 Rufus-scheduler (out of the box) is an in-process, in-memory scheduler.

其实这个方法确实是能部分实现日志等级变更的,但是sidekiq进程的日志等级就需要别的方法来控制。

而且,这并不优雅”,当你告诉 Bill 这个未成型的方案的时候,他总结道。

“我或许可以帮你了解一下这个问题的 症结 所在”

症结与解决办法

ruby 项目的所有日志添加都要通过 Logger 类的实例方法:add,是这样定义的

def add(severity, message = nil, progname = nil)
    severity ||= UNKNOWN
    if @logdev.nil? or severity < @level
      return true
    end
    if progname.nil?
      progname = @progname
    end
    if message.nil?
      if block_given?
        message = yield
      else
        message = progname
        progname = @progname
      end
    end
    @logdev.write(
      format_message(format_severity(severity), Time.now, progname, message))
    true
  end

  #add方法的调用:比如logger.info
 def info(progname = nil, &block)
    add(INFO, nil, progname, &block)
  end

关键就在于@level的附值

# +severity+:: The Severity of the log message.
 def level=(severity)
   if severity.is_a?(Integer)
     @level = severity
   else
     case severity.to_s.downcase
     when 'debug'
       @level = DEBUG
     when 'info'
       @level = INFO
     when 'warn'
       @level = WARN
     when 'error'
       @level = ERROR
     when 'fatal'
       @level = FATAL
     when 'unknown'
       @level = UNKNOWN
     else
       raise ArgumentError, "invalid log level: #{severity}"
     end
   end
 end

一般是项目进程启动的时候会根据环境不同来设置一个日志等级,但无法在进程运行过程中实时变更。

打开类

很明显,如果有一个Monkeypatch,将 add 方法重写,logger 就可以任我们宰割了。

最终这样实现:

class ::Logger

  def add(severity, message = nil, progname = nil, &block)

    file_path = "#{Rails.root}/tmp/level.yml"
    @new_time = Time.now
    @last_effect_time = @last_effect_time || Time.now - 40 

    if @new_time - @last_effect_time >= 30 && File.exists?(file_path)
      log_level = File.open(file_path).read.strip
      case log_level
        when "INFO"
          $logger_level = 1
        when "DEBUG"
          $logger_level = 0
        when "WARN"
          $logger_level = 2
        when "ERROR"
          $logger_level = 3
        when "FATAL"
          $logger_level = 4
        when "UNKNOWN"
          $logger_level = 5
      end
      @last_effect_time = @new_time
    end

    @level = $logger_level || 0

    severity ||= UNKNOWN
    if @logdev.nil? or severity < @level
      return true
    end
    progname ||= @progname
    if message.nil?
      if block_given?
        message = yield
      else
        message = progname
        progname = @progname
      end
    end
    @logdev.write(
      format_message(format_severity(severity), Time.now, progname, message))
    true
  end

end

关键在于:

file_path = "#{Rails.root}/tmp/level.yml"
 if @new_time - @last_effect_time >= 30 && File.exists?(file_path)
   log_level = File.open(file_path).read.strip
   case log_level
   when "INFO"
       $logger_level = 1
   when "DEBUG"
       $logger_level = 0
   when "WARN"
       $logger_level = 2
   when "ERROR"
       $logger_level = 3
   when "FATAL"
       $logger_level = 4
   when "UNKNOWN"
       $logger_level = 5
   end
   @last_effect_time = @new_time
 end

 @level = $logger_level || 0

这里通过在项目的 tmp 目录下新建 level.yml 来实时控制日志等级。这样做有两个好处:

  • 1.不需要通过修改数据库的值,只需要修改一个文件就可以实现日志等级切换
  • 2.设置时间间隔,可以降低 io 频率。

实测可以完美实现日志等级实时变更。如果你发现其中可能存在的问题,欢迎拍砖
git push
end~😎

数据库来的舒服。。。

基于 zk 的 watch 机制,可能会更好,而且,也算是分布式的解决方案

实时变更是为了什么?

Reply to lidashuang

比如在生产环境我想看一眼 debug 日志,但是不想发版也不想一直输出 debug 日志。或者我只想看 error 日志,就可以实时变更日志等级,看完之后再变回来。当然,也有其他方法可以满足这类要求

Reply to pynix

嗯,也许你是对的

意思是先要有一套 zk 部署吧

log_level = File.open(file_path).read.strip

这一步 从环境变量中取是否可行? 放数据库或 redis 有好处,可以统一管理或统一开关。 有一个疑问,比如你需要查某个 debug 日志了,有 10 台机器,前面的 LVS 是负载均衡的,你需要登入这 10 台机器都改一遍文件吗?如果有 100 台就会崩溃了,用数据库来管理这个开关就不会有这个问题了

Reply to lgcjwt

基于 etcd 的 watch 机制也可以

Reply to pathbox

如果是多台服务器的话确实 redis 会更好。关于服务发现,如果用几行代码能解决问题,比特意部署一套新的东西快捷。如果是原本有服务发现 etcd 或者 zk,那就是不一样的思考方向了。

Reply to pathbox

机器多,就老老实实上分布式配置管理吧...

https://github.com/ctripcorp/apollo

机器多了,你配置生效还得走灰度...

Reply to lgcjwt

zk, etcd 都可以

You need to Sign in before reply, if you don't have an account, please Sign up first.