class Fluent::Log

Constants

CachedLog
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]
log_event_enabled[RW]
optional_attrs[RW]
optional_header[RW]
out[RW]
time_format[R]

Public Class Methods

event_tags() click to toggle source
# File lib/fluent/log.rb, line 66
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 70
def initialize(logger, opts={})
  # overwrites logger.level= so that config reloading resets level of Fluentd::Log
  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 }

  @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 = :text
  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
str_to_level(log_level_str) click to toggle source
# File lib/fluent/log.rb, line 54
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 558
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 302
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 314
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 223
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 461
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 141
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 232
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 228
def enable_color?
  !@color_reset.empty?
end
enable_debug(b=true) click to toggle source
# File lib/fluent/log.rb, line 211
def enable_debug(b=true)
  @debug_mode = b
  self
end
enable_event(b=true) click to toggle source
# File lib/fluent/log.rb, line 216
def enable_event(b=true)
  @log_event_enabled = b
  self
end
error(*args, &block) click to toggle source
# File lib/fluent/log.rb, line 365
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 377
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 512
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 386
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 398
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 418
def flush
  @out.flush
end
format=(fmt) click to toggle source
# File lib/fluent/log.rb, line 168
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 577
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 504
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 428
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 434
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
    cached_log[message] = time
    false
  end
end
info(*args, &block) click to toggle source
# File lib/fluent/log.rb, line 323
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 335
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 253
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 162
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 297
def on_debug
  return if @level > LEVEL_DEBUG
  yield
end
on_error() { || ... } click to toggle source
# File lib/fluent/log.rb, line 360
def on_error
  return if @level > LEVEL_ERROR
  yield
end
on_fatal() { || ... } click to toggle source
# File lib/fluent/log.rb, line 381
def on_fatal
  return if @level > LEVEL_FATAL
  yield
end
on_info() { || ... } click to toggle source
# File lib/fluent/log.rb, line 318
def on_info
  return if @level > LEVEL_INFO
  yield
end
on_trace() { || ... } click to toggle source
# File lib/fluent/log.rb, line 275
def on_trace
  return if @level > LEVEL_TRACE
  yield
end
on_warn() { || ... } click to toggle source
# File lib/fluent/log.rb, line 339
def on_warn
  return if @level > LEVEL_WARN
  yield
end
puts(msg) click to toggle source
# File lib/fluent/log.rb, line 402
def puts(msg)
  @logger << msg + "\n"
  @out.flush
  msg
rescue
  # FIXME
  nil
end
reopen!() click to toggle source
# File lib/fluent/log.rb, line 205
def reopen!
  # do nothing in @logger.reopen! because it's already reopened in Supervisor.load_config
  @logger.reopen! if @logger
  nil
end
reset() click to toggle source
# File lib/fluent/log.rb, line 422
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 262
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
suppress_stacktrace?(backtrace) click to toggle source
# File lib/fluent/log.rb, line 455
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 200
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 280
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 293
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 344
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 356
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 411
def write(data)
  @out.write(data)
end
Also aliased as: <<