Rubyist のための python 標準 logging モジュールの擬似コード

Published: 2019/5/27

python には標準 logging モジュールがついてくる。しかしこの logging モジュール、ドキュメントを３回ぐらい読み直さないと、挙動がよくわからず、わからないどころか若干ドツボにハマる。

ドキュメントを３回ぐらい読み直す過程で、どうして擬似コードになっていないのか、という疑問が湧いてきたので、普段自分がよく使う ruby でその挙動をざっくりと再現してみた。

ポイント

Logger は階層構造をなす
Logger は effective level の概念を持つ
Logger の handler は handle するかしないかの判定ロジックを内部に持つ
Logging.debug 系は、ルートロガーが存在しない場合には、勝手にそれを生成しにいく
Logging には LastResort なるものが実は存在する。どこでも handle されないとそれが呼ばれる。

動く擬似コード

module Logging
  DEBUG = 10
  INFO = 20
  WARNING = 30
  ERROR = 40
  CRITICAL = 50

  module LoggableConcern
    %i[debug info warning error critical].each do |lvl_sym|
      define_method(lvl_sym) do |msg|
        lvl = Logging.const_get(lvl_sym.to_s.upcase)
        log(lvl, msg)
      end
    end
  end

  class Handler
    attr_accessor :level, :filters

    def initialize
      @filters = []
    end

    def handle(log_record)
      return if log_record.level < level
      return if filters.any? { |filter| filter.reject?(log_record) }

      do_handle(log_record)
    end
  end

  class StreamHandler < Handler
    def initialize(io)
      super()
      @io = io
    end
    attr_reader :io

    def do_handle(log_record)
      io.puts log_record
    end
  end

  LogRecord = Struct.new(:level, :message)

  class Logger
    include LoggableConcern

    attr_accessor :propagate, :level, :filters, :handlers

    class << self
      def loggers
        @loggers ||= {}
      end

      def get(name)
        loggers[name] ||= Logger.new(name)
      end
    end

    def initialize(name)
      @name = name
      @handlers = []
      @filters = []
    end
    attr_reader :name

    def parent
      return if name == ''

      separated = name.split('.')
      loop do
        separated.pop
        break if Logger.get(separated.join('.'))
      end
    end

    def effective_level
      level || parent&.effective_level
    end

    def log(lvl, msg)
      return if effective_level && lvl < effective_level

      log_record = LogRecord.new(lvl, msg)
      return if filters.any? { filter.reject?(log_record) }

      current = self
      handled = false
      while current
        handlers.each do |handler|
          handled = true
          handler.handle(log_record)
        end
        current = current.propagate && current&.parent
      end

      Logging.last_resort.handle(log_record) unless handled
    end
  end

  class DefaultLastResort
    def handle(log_record)
      STDERR.puts log_record
    end
  end


  @root_logger = Logger.get('')
  @last_resort = DefaultLastResort.new

  class << self
    include LoggableConcern

    attr_accessor :root_logger, :last_resort

    def log(level, msg)
      basic_config if root_logger.handlers.empty?
      root_logger.log(level, msg)
    end

    def basic_config(level: WARNING)
      handler = StreamHandler.new(STDERR)
      handler.level = level
      root_logger.handlers << handler
    end
  end
end


piyo_logger = Logging::Logger.get('piyo')
piyo_logger.debug('hoge')
piyo_logger.warning('fuga')

Logging.warning('foo')
Logging.debug('bar')