class Fluent::Log

Constants

CachedLog
IGNORE_SAME_LOG_MAX_CACHE_SIZE
LEVEL_DEBUG
LEVEL_ERROR
LEVEL_FATAL
LEVEL_INFO
LEVEL_TEXT
LEVEL_TRACE
LEVEL_WARN
LOG_EVENT_LABEL
LOG_EVENT_TAG_PREFIX
LOG_ROTATE_AGE
LOG_TYPES
LOG_TYPE_DEFAULT
LOG_TYPE_SUPERVISOR
LOG_TYPE_WORKER0

Attributes

format[R]
ignore_repeated_log_interval[RW]
ignore_same_log_interval[RW]
level[RW]

Strictly speaking, we should also change @logger.level when the setter of @level is called. Currently, we don’t need to do it, since Fluentd::Log doesn’t use ServerEngine::DaemonLogger.level. Since We overwrites logger.level= so that @logger.level is applied to @level, we need to find a good way to do this, otherwise we will end up in an endless loop.

log_event_enabled[RW]
optional_attrs[RW]
optional_header[RW]
out[RW]
suppress_repeated_stacktrace[RW]
time_format[R]

Public Class Methods

event_tags() click to toggle source
# File lib/fluent/log.rb, line 68
def self.event_tags
  LEVEL_TEXT.map{|t| "#{LOG_EVENT_TAG_PREFIX}.#{t}" }
end
new(logger, opts={}) click to toggle source
# File lib/fluent/log.rb, line 90
def initialize(logger, opts={})
  # When ServerEngine changes the logger.level, the Fluentd logger level should also change.
  # So overwrites logger.level= below.
  # However, currently Fluentd doesn't use the ServerEngine's reloading feature,
  # so maybe we don't need this overwriting anymore.
  orig_logger_level_setter = logger.class.public_instance_method(:level=).bind(logger)
  me = self
  # The original ruby logger sets the number as each log level like below.
  # DEBUG = 0
  # INFO  = 1
  # WARN  = 2
  # ERROR = 3
  # FATAL = 4
  # Serverengine use this original log number. In addition to this, serverengine sets -1 as TRACE level.
  # TRACE = -1
  #
  # On the other hand, in fluentd side, it sets the number like below.
  # TRACE = 0
  # DEBUG = 1
  # INFO  = 2
  # WARN  = 3
  # ERROR = 4
  # FATAL = 5
  #
  # Then fluentd's level is set as serverengine's level + 1.
  # So if serverengine's logger level is changed, fluentd's log level will be changed to that + 1.
  logger.define_singleton_method(:level=) {|level| orig_logger_level_setter.call(level); me.level = self.level + 1 }

  @path = opts[:path]
  @logger = logger
  @out = logger.instance_variable_get(:@logdev)
  @level = logger.level + 1
  @debug_mode = false
  @log_event_enabled = false
  @depth_offset = 1
  @format = nil
  @time_format = nil
  @formatter = nil

  self.format = opts.fetch(:format, :text)
  self.time_format = opts[:time_format] if opts.key?(:time_format)
  enable_color out.tty?
  # TODO: This variable name is unclear so we should change to better name.
  @threads_exclude_events = []

  # Fluent::Engine requires Fluent::Log, so we must take that object lazily
  @engine = Fluent.const_get('Engine')
  @optional_header = nil
  @optional_attrs = nil

  @suppress_repeated_stacktrace = opts[:suppress_repeated_stacktrace]
  @ignore_repeated_log_interval = opts[:ignore_repeated_log_interval]
  @ignore_same_log_interval = opts[:ignore_same_log_interval]

  @process_type = opts[:process_type] # :supervisor, :worker0, :workers Or :standalone
  @process_type ||= :standalone # to keep behavior of existing code
  case @process_type
  when :supervisor
    @show_supervisor_log = true
    @show_worker0_log = false
  when :worker0
    @show_supervisor_log = false
    @show_worker0_log = true
  when :workers
    @show_supervisor_log = false
    @show_worker0_log = false
  when :standalone
    @show_supervisor_log = true
    @show_worker0_log = true
  else
    raise "BUG: unknown process type for logger:#{@process_type}"
  end
  @worker_id = opts[:worker_id]
  @worker_id_part = "##{@worker_id} " # used only for :default log type in workers
end
per_process_path(path, process_type, worker_id) click to toggle source

Create a unique path for each process.

>>> per_process_path(“C:/tmp/test.log”, :worker, 1) C:/tmp/test-1.log >>> per_process_path(“C:/tmp/test.log”, :supervisor, 0) C:/tmp/test-supervisor-0.log

# File lib/fluent/log.rb, line 78
def self.per_process_path(path, process_type, worker_id)
  path = Pathname(path)
  ext = path.extname

  if process_type == :supervisor
    suffix = "-#{process_type}-0#{ext}"  # "-0" for backword compatibility.
  else
    suffix = "-#{worker_id}#{ext}"
  end
  return path.sub_ext(suffix).to_s
end
str_to_level(log_level_str) click to toggle source
# File lib/fluent/log.rb, line 56
def self.str_to_level(log_level_str)
  case log_level_str.downcase
  when "trace" then LEVEL_TRACE
  when "debug" then LEVEL_DEBUG
  when "info"  then LEVEL_INFO
  when "warn"  then LEVEL_WARN
  when "error" then LEVEL_ERROR
  when "fatal" then LEVEL_FATAL
  else raise "Unknown log level: level = #{log_level_str}"
  end
end

Public Instance Methods

<<(data)

We need ‘#<<` method to use this logger class with other libraries such as aws-sdk

Alias for: write
DEBUG(*args, &block)
Alias for: debug
ERROR(*args, &block)
Alias for: error
FATAL(*args, &block)
Alias for: fatal
INFO(*args, &block)
Alias for: info
TRACE(*args, &block)
Alias for: trace
WARN(*args, &block)
Alias for: warn
caller_line(type, time, depth, level) click to toggle source
# File lib/fluent/log.rb, line 597
def caller_line(type, time, depth, level)
  worker_id_part = if type == :default && (@process_type == :worker0 || @process_type == :workers)
                     @worker_id_part
                   else
                     "".freeze
                   end
  log_msg = "#{format_time(time)} [#{LEVEL_TEXT[level]}]: #{worker_id_part}"
  if @debug_mode
    line = caller(depth+1)[0]
    if match = /^(.+?):(\d+)(?::in `(.*)')?/.match(line)
      file = match[1].split('/')[-2,2].join('/')
      line = match[2]
      method = match[3]
      return "#{log_msg}#{file}:#{line}:#{method}: "
    end
  end
  return log_msg
end
debug(*args, &block) click to toggle source
# File lib/fluent/log.rb, line 334
def debug(*args, &block)
  return if @level > LEVEL_DEBUG
  type = log_type(args)
  return if skipped_type?(type)
  args << block.call if block
  time, msg = event(:debug, args)
  return if time.nil?
  puts [@color_debug, @formatter.call(type, time, LEVEL_DEBUG, msg), @color_reset].join
rescue
end
Also aliased as: DEBUG
debug_backtrace(backtrace=$!.backtrace, type: :default) click to toggle source
# File lib/fluent/log.rb, line 346
def debug_backtrace(backtrace=$!.backtrace, type: :default)
  dump_stacktrace(type, backtrace, LEVEL_DEBUG)
end
disable_events(thread) click to toggle source

If you want to suppress event emitting in specific thread, please use this method. Events in passed thread are never emitted.

# File lib/fluent/log.rb, line 255
def disable_events(thread)
  # this method is not symmetric with #enable_event.
  @threads_exclude_events.push(thread) unless @threads_exclude_events.include?(thread)
end
dump_stacktrace(type, backtrace, level) click to toggle source
# File lib/fluent/log.rb, line 500
def dump_stacktrace(type, backtrace, level)
  return if @level > level

  time = Time.now

  if @format == :text
    line = caller_line(type, time, 5, level)
    if @ignore_repeated_log_interval && ignore_repeated_log?(:last_repeated_stacktrace, time, backtrace)
      return
    elsif @suppress_repeated_stacktrace && suppress_stacktrace?(backtrace)
      puts ["  ", line, 'suppressed same stacktrace'].join
      Thread.current[:last_repeated_stacktrace] = CachedLog.new(backtrace, time) if @ignore_repeated_log_interval
    else
      backtrace.each { |msg|
        puts ["  ", line, msg].join
      }
      Thread.current[:last_repeated_stacktrace] = CachedLog.new(backtrace, time) if @suppress_repeated_stacktrace
    end
  else
    r = {
      'time' => format_time(time),
      'level' => LEVEL_TEXT[level],
    }
    if wid = get_worker_id(type)
      r['worker_id'] = wid
    end

    if @ignore_repeated_log_interval && ignore_repeated_log?(:last_repeated_stacktrace, time, backtrace)
      return
    elsif @suppress_repeated_stacktrace && suppress_stacktrace?(backtrace)
      r['message'] = 'suppressed same stacktrace'
      Thread.current[:last_repeated_stacktrace] = CachedLog.new(backtrace, time) if @ignore_repeated_log_interval
    else
      r['message'] = backtrace.join("\n")
      Thread.current[:last_repeated_stacktrace] = CachedLog.new(backtrace, time) if @suppress_repeated_stacktrace
    end

    puts Yajl.dump(r)
  end

  nil
end
dup() click to toggle source
# File lib/fluent/log.rb, line 166
def dup
  dl_opts = {}
  dl_opts[:log_level] = @level - 1
  logger = ServerEngine::DaemonLogger.new(@out, dl_opts)
  clone = self.class.new(logger, suppress_repeated_stacktrace: @suppress_repeated_stacktrace, process_type: @process_type,
                         worker_id: @worker_id, ignore_repeated_log_interval: @ignore_repeated_log_interval,
                         ignore_same_log_interval: @ignore_same_log_interval)
  clone.format = @format
  clone.time_format = @time_format
  clone.log_event_enabled = @log_event_enabled
  # optional headers/attrs are not copied, because new PluginLogger should have another one of it
  clone
end
enable_color(b=true) click to toggle source
# File lib/fluent/log.rb, line 264
def enable_color(b=true)
  if b
    @color_trace = TTYColor::BLUE
    @color_debug = TTYColor::WHITE
    @color_info  = TTYColor::GREEN
    @color_warn  = TTYColor::YELLOW
    @color_error = TTYColor::MAGENTA
    @color_fatal = TTYColor::RED
    @color_reset = TTYColor::NORMAL
  else
    @color_trace = ''
    @color_debug = ''
    @color_info  = ''
    @color_warn  = ''
    @color_error = ''
    @color_fatal = ''
    @color_reset = ''
  end
  self
end
enable_color?() click to toggle source
# File lib/fluent/log.rb, line 260
def enable_color?
  !@color_reset.empty?
end
enable_debug(b=true) click to toggle source
# File lib/fluent/log.rb, line 243
def enable_debug(b=true)
  @debug_mode = b
  self
end
enable_event(b=true) click to toggle source
# File lib/fluent/log.rb, line 248
def enable_event(b=true)
  @log_event_enabled = b
  self
end
error(*args, &block) click to toggle source
# File lib/fluent/log.rb, line 397
def error(*args, &block)
  return if @level > LEVEL_ERROR
  type = log_type(args)
  return if skipped_type?(type)
  args << block.call if block
  time, msg = event(:error, args)
  return if time.nil?
  puts [@color_error, @formatter.call(type, time, LEVEL_ERROR, msg), @color_reset].join
rescue
end
Also aliased as: ERROR
error_backtrace(backtrace=$!.backtrace, type: :default) click to toggle source
# File lib/fluent/log.rb, line 409
def error_backtrace(backtrace=$!.backtrace, type: :default)
  dump_stacktrace(type, backtrace, LEVEL_ERROR)
end
event(level, args) click to toggle source
# File lib/fluent/log.rb, line 551
def event(level, args)
  time = Time.now
  message = @optional_header ? @optional_header.dup : ''
  map = @optional_attrs ? @optional_attrs.dup : {}
  args.each {|a|
    if a.is_a?(Hash)
      a.each_pair {|k,v|
        map[k.to_s] = v
      }
    else
      message << a.to_s
    end
  }

  map.each_pair {|k,v|
    if k == "error".freeze && v.is_a?(Exception) && !map.has_key?("error_class")
      message << " error_class=#{v.class.to_s} error=#{v.to_s.inspect}"
    else
      message << " #{k}=#{v.inspect}"
    end
  }

  if @ignore_same_log_interval
    if ignore_same_log?(time, message)
      return nil, nil
    end
  elsif @ignore_repeated_log_interval
    if ignore_repeated_log?(:last_repeated_log, time, message)
      return nil, nil
    else
      Thread.current[:last_repeated_log] = CachedLog.new(message, time)
    end
  end

  if @log_event_enabled && !@threads_exclude_events.include?(Thread.current)
    record = map.dup
    record.keys.each {|key|
      record[key] = record[key].inspect unless record[key].respond_to?(:to_msgpack)
    }
    record['message'] = message.dup
    @engine.push_log_event("#{LOG_EVENT_TAG_PREFIX}.#{level}", Fluent::EventTime.from_time(time), record)
  end

  return time, message
end
fatal(*args, &block) click to toggle source
# File lib/fluent/log.rb, line 418
def fatal(*args, &block)
  return if @level > LEVEL_FATAL
  type = log_type(args)
  return if skipped_type?(type)
  args << block.call if block
  time, msg = event(:fatal, args)
  return if time.nil?
  puts [@color_fatal, @formatter.call(type, time, LEVEL_FATAL, msg), @color_reset].join
rescue
end
Also aliased as: FATAL
fatal_backtrace(backtrace=$!.backtrace, type: :default) click to toggle source
# File lib/fluent/log.rb, line 430
def fatal_backtrace(backtrace=$!.backtrace, type: :default)
  dump_stacktrace(type, backtrace, LEVEL_FATAL)
end
flush() click to toggle source
# File lib/fluent/log.rb, line 450
def flush
  @out.flush
end
format=(fmt) click to toggle source
# File lib/fluent/log.rb, line 197
def format=(fmt)
  return if @format == fmt

  @time_format = '%Y-%m-%d %H:%M:%S %z'
  @time_formatter = Strftime.new(@time_format) rescue nil

  case fmt
  when :text
    @format = :text
    @formatter = Proc.new { |type, time, level, msg|
      r = caller_line(type, time, @depth_offset, level)
      r << msg
      r
    }
  when :json
    @format = :json
    @formatter = Proc.new { |type, time, level, msg|
      r = {
        'time' => format_time(time),
        'level' => LEVEL_TEXT[level],
        'message' => msg
      }
      if wid = get_worker_id(type)
        r['worker_id'] = wid
      end
      Yajl.dump(r)
    }
  end

  nil
end
format_time(time) click to toggle source
# File lib/fluent/log.rb, line 616
def format_time(time)
  @time_formatter ? @time_formatter.exec(time) : time.strftime(@time_format)
end
get_worker_id(type) click to toggle source
# File lib/fluent/log.rb, line 543
def get_worker_id(type)
  if type == :default && (@process_type == :worker0 || @process_type == :workers)
    @worker_id
  else
    nil
  end
end
ignore_repeated_log?(key, time, message) click to toggle source
# File lib/fluent/log.rb, line 460
def ignore_repeated_log?(key, time, message)
  cached_log = Thread.current[key]
  return false if cached_log.nil?
  (cached_log.msg == message) && (time - cached_log.time <= @ignore_repeated_log_interval)
end
ignore_same_log?(time, message) click to toggle source
# File lib/fluent/log.rb, line 466
def ignore_same_log?(time, message)
  cached_log = Thread.current[:last_same_log]
  if cached_log.nil?
    Thread.current[:last_same_log] = {message => time}
    return false
  end

  prev_time = cached_log[message]
  if prev_time
    if (time - prev_time) <= @ignore_same_log_interval
      true
    else
      cached_log[message] = time
      false
    end
  else
    if cached_log.size >= IGNORE_SAME_LOG_MAX_CACHE_SIZE
      cached_log.reject! do |_, cached_time|
        (time - cached_time) > @ignore_same_log_interval
      end
    end
    # If the size is still over, we have no choice but to clear it.
    cached_log.clear if cached_log.size >= IGNORE_SAME_LOG_MAX_CACHE_SIZE
    cached_log[message] = time
    false
  end
end
info(*args, &block) click to toggle source
# File lib/fluent/log.rb, line 355
def info(*args, &block)
  return if @level > LEVEL_INFO
  type = log_type(args)
  return if skipped_type?(type)
  args << block.call if block
  time, msg = event(:info, args)
  return if time.nil?
  puts [@color_info, @formatter.call(type, time, LEVEL_INFO, msg), @color_reset].join
rescue
end
Also aliased as: INFO
info_backtrace(backtrace=$!.backtrace, type: :default) click to toggle source
# File lib/fluent/log.rb, line 367
def info_backtrace(backtrace=$!.backtrace, type: :default)
  dump_stacktrace(type, backtrace, LEVEL_INFO)
end
log_type(args) click to toggle source
# File lib/fluent/log.rb, line 285
def log_type(args)
  if LOG_TYPES.include?(args.first)
    args.shift
  else
    LOG_TYPE_DEFAULT
  end
end
logdev=(logdev) click to toggle source
# File lib/fluent/log.rb, line 191
def logdev=(logdev)
  @out = logdev
  @logger.instance_variable_set(:@logdev, logdev)
  nil
end
on_debug() { || ... } click to toggle source
# File lib/fluent/log.rb, line 329
def on_debug
  return if @level > LEVEL_DEBUG
  yield
end
on_error() { || ... } click to toggle source
# File lib/fluent/log.rb, line 392
def on_error
  return if @level > LEVEL_ERROR
  yield
end
on_fatal() { || ... } click to toggle source
# File lib/fluent/log.rb, line 413
def on_fatal
  return if @level > LEVEL_FATAL
  yield
end
on_info() { || ... } click to toggle source
# File lib/fluent/log.rb, line 350
def on_info
  return if @level > LEVEL_INFO
  yield
end
on_trace() { || ... } click to toggle source
# File lib/fluent/log.rb, line 307
def on_trace
  return if @level > LEVEL_TRACE
  yield
end
on_warn() { || ... } click to toggle source
# File lib/fluent/log.rb, line 371
def on_warn
  return if @level > LEVEL_WARN
  yield
end
puts(msg) click to toggle source
# File lib/fluent/log.rb, line 434
def puts(msg)
  @logger << msg + "\n"
  @out.flush
  msg
rescue
  # FIXME
  nil
end
reopen!() click to toggle source
# File lib/fluent/log.rb, line 238
def reopen!
  @out.reopen(@path, "a") if @path && @path != "-"
  nil
end
reset() click to toggle source
# File lib/fluent/log.rb, line 454
def reset
  @out.reset if @out.respond_to?(:reset)
end
skipped_type?(type) click to toggle source

TODO: skip :worker0 logs when Fluentd gracefully restarted

# File lib/fluent/log.rb, line 294
def skipped_type?(type)
  case type
  when LOG_TYPE_DEFAULT
    false
  when LOG_TYPE_WORKER0
    !@show_worker0_log
  when LOG_TYPE_SUPERVISOR
    !@show_supervisor_log
  else
    raise "BUG: unknown log type:#{type}"
  end
end
stdout?() click to toggle source
# File lib/fluent/log.rb, line 234
def stdout?
  @out == $stdout
end
suppress_stacktrace?(backtrace) click to toggle source
# File lib/fluent/log.rb, line 494
def suppress_stacktrace?(backtrace)
  cached_log = Thread.current[:last_repeated_stacktrace]
  return false if cached_log.nil?
  cached_log.msg == backtrace
end
time_format=(time_fmt) click to toggle source
# File lib/fluent/log.rb, line 229
def time_format=(time_fmt)
  @time_format = time_fmt
  @time_formatter = Strftime.new(@time_format) rescue nil
end
trace(*args, &block) click to toggle source
# File lib/fluent/log.rb, line 312
def trace(*args, &block)
  return if @level > LEVEL_TRACE
  type = log_type(args)
  return if skipped_type?(type)
  args << block.call if block
  time, msg = event(:trace, args)
  return if time.nil?
  puts [@color_trace, @formatter.call(type, time, LEVEL_TRACE, msg), @color_reset].join
rescue
  # logger should not raise an exception. This rescue prevents unexpected behaviour.
end
Also aliased as: TRACE
trace_backtrace(backtrace=$!.backtrace, type: :default) click to toggle source
# File lib/fluent/log.rb, line 325
def trace_backtrace(backtrace=$!.backtrace, type: :default)
  dump_stacktrace(type, backtrace, LEVEL_TRACE)
end
warn(*args, &block) click to toggle source
# File lib/fluent/log.rb, line 376
def warn(*args, &block)
  return if @level > LEVEL_WARN
  type = log_type(args)
  return if skipped_type?(type)
  args << block.call if block
  time, msg = event(:warn, args)
  return if time.nil?
  puts [@color_warn, @formatter.call(type, time, LEVEL_WARN, msg), @color_reset].join
rescue
end
Also aliased as: WARN
warn_backtrace(backtrace=$!.backtrace, type: :default) click to toggle source
# File lib/fluent/log.rb, line 388
def warn_backtrace(backtrace=$!.backtrace, type: :default)
  dump_stacktrace(type, backtrace, LEVEL_WARN)
end
write(data) click to toggle source
# File lib/fluent/log.rb, line 443
def write(data)
  @out.write(data)
end
Also aliased as: <<