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
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.
Public Class Methods
# 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
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
# 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
We need ‘#<<` method to use this logger class with other libraries such as aws-sdk
# 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
# 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
# File lib/fluent/log.rb, line 346 def debug_backtrace(backtrace=$!.backtrace, type: :default) dump_stacktrace(type, backtrace, LEVEL_DEBUG) end
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
# 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
# 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
# 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
# File lib/fluent/log.rb, line 260 def enable_color? !@color_reset.empty? end
# File lib/fluent/log.rb, line 243 def enable_debug(b=true) @debug_mode = b self end
# File lib/fluent/log.rb, line 248 def enable_event(b=true) @log_event_enabled = b self end
# 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
# File lib/fluent/log.rb, line 409 def error_backtrace(backtrace=$!.backtrace, type: :default) dump_stacktrace(type, backtrace, LEVEL_ERROR) end
# 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
# 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
# File lib/fluent/log.rb, line 430 def fatal_backtrace(backtrace=$!.backtrace, type: :default) dump_stacktrace(type, backtrace, LEVEL_FATAL) end
# File lib/fluent/log.rb, line 450 def flush @out.flush end
# 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
# File lib/fluent/log.rb, line 616 def format_time(time) @time_formatter ? @time_formatter.exec(time) : time.strftime(@time_format) end
# 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
# 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
# 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
# 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
# File lib/fluent/log.rb, line 367 def info_backtrace(backtrace=$!.backtrace, type: :default) dump_stacktrace(type, backtrace, LEVEL_INFO) end
# 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
# File lib/fluent/log.rb, line 191 def logdev=(logdev) @out = logdev @logger.instance_variable_set(:@logdev, logdev) nil end
# File lib/fluent/log.rb, line 329 def on_debug return if @level > LEVEL_DEBUG yield end
# File lib/fluent/log.rb, line 392 def on_error return if @level > LEVEL_ERROR yield end
# File lib/fluent/log.rb, line 413 def on_fatal return if @level > LEVEL_FATAL yield end
# File lib/fluent/log.rb, line 350 def on_info return if @level > LEVEL_INFO yield end
# File lib/fluent/log.rb, line 307 def on_trace return if @level > LEVEL_TRACE yield end
# File lib/fluent/log.rb, line 371 def on_warn return if @level > LEVEL_WARN yield end
# File lib/fluent/log.rb, line 434 def puts(msg) @logger << msg + "\n" @out.flush msg rescue # FIXME nil end
# File lib/fluent/log.rb, line 238 def reopen! @out.reopen(@path, "a") if @path && @path != "-" nil end
# File lib/fluent/log.rb, line 454 def reset @out.reset if @out.respond_to?(:reset) end
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
# File lib/fluent/log.rb, line 234 def stdout? @out == $stdout end
# 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
# 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
# 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
# File lib/fluent/log.rb, line 325 def trace_backtrace(backtrace=$!.backtrace, type: :default) dump_stacktrace(type, backtrace, LEVEL_TRACE) end
# 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
# File lib/fluent/log.rb, line 388 def warn_backtrace(backtrace=$!.backtrace, type: :default) dump_stacktrace(type, backtrace, LEVEL_WARN) end
# File lib/fluent/log.rb, line 443 def write(data) @out.write(data) end