Skip to content

Commit

Permalink
Merge pull request #3119 from fluent/add-ignore_same_log_interval
Browse files Browse the repository at this point in the history 
Add ignore_same_log _interval parameter
  • Loading branch information
@repeatedly
repeatedly authored Sep 4, 2020
2 parents b5f4a6d + 4638886 commit adca029
Show file tree
Hide file tree
Showing 4 changed files with 89 additions and 8 deletions.
36 changes: 33 additions & 3 deletions lib/fluent/log.rb
View file
Original file line number Diff line number Diff line change
Expand Up @@ -113,6 +113,7 @@ def initialize(logger, opts={})

@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
Expand Down Expand Up @@ -141,7 +142,8 @@ def dup
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)
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
Expand All @@ -151,7 +153,7 @@ def dup

attr_reader :format
attr_reader :time_format
attr_accessor :log_event_enabled, :ignore_repeated_log_interval
attr_accessor :log_event_enabled, :ignore_repeated_log_interval, :ignore_same_log_interval
attr_accessor :out
attr_accessor :level
attr_accessor :optional_header, :optional_attrs
Expand Down Expand Up @@ -428,6 +430,27 @@ def ignore_repeated_log?(key, time, message)
(cached_log.msg == message) && (time - cached_log.time <= @ignore_repeated_log_interval)
end

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

def suppress_stacktrace?(backtrace)
cached_log = Thread.current[:last_repeated_stacktrace]
return false if cached_log.nil?
Expand Down Expand Up @@ -507,7 +530,11 @@ def event(level, args)
end
}

if @ignore_repeated_log_interval
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
Expand Down Expand Up @@ -569,6 +596,9 @@ def initialize(logger)
if logger.instance_variable_defined?(:@ignore_repeated_log_interval)
@ignore_repeated_log_interval = logger.instance_variable_get(:@ignore_repeated_log_interval)
end
if logger.instance_variable_defined?(:@ignore_same_log_interval)
@ignore_same_log_interval = logger.instance_variable_get(:@ignore_same_log_interval)
end

self.format = @logger.format
self.time_format = @logger.time_format
Expand Down
14 changes: 10 additions & 4 deletions lib/fluent/supervisor.rb
View file
Original file line number Diff line number Diff line change
Expand Up @@ -302,14 +302,16 @@ def self.load_config(path, params = {})
log_level = params['log_level']
suppress_repeated_stacktrace = params['suppress_repeated_stacktrace']
ignore_repeated_log_interval = params['ignore_repeated_log_interval']
ignore_same_log_interval = params['ignore_same_log_interval']

log_path = params['log_path']
chuser = params['chuser']
chgroup = params['chgroup']
log_rotate_age = params['log_rotate_age']
log_rotate_size = params['log_rotate_size']

log_opts = {suppress_repeated_stacktrace: suppress_repeated_stacktrace, ignore_repeated_log_interval: ignore_repeated_log_interval}
log_opts = {suppress_repeated_stacktrace: suppress_repeated_stacktrace, ignore_repeated_log_interval: ignore_repeated_log_interval,
ignore_same_log_interval: ignore_same_log_interval}
logger_initializer = Supervisor::LoggerInitializer.new(
log_path, log_level, chuser, chgroup, log_opts,
log_rotate_age: log_rotate_age,
Expand Down Expand Up @@ -347,6 +349,7 @@ def self.load_config(path, params = {})
chumask: 0,
suppress_repeated_stacktrace: suppress_repeated_stacktrace,
ignore_repeated_log_interval: ignore_repeated_log_interval,
ignore_same_log_interval: ignore_same_log_interval,
daemonize: daemonize,
rpc_endpoint: params['rpc_endpoint'],
counter_server: params['counter_server'],
Expand Down Expand Up @@ -441,10 +444,11 @@ def reopen!
self
end

def apply_options(format: nil, time_format: nil, log_dir_perm: nil, ignore_repeated_log_interval: nil)
def apply_options(format: nil, time_format: nil, log_dir_perm: nil, ignore_repeated_log_interval: nil, ignore_same_log_interval: nil)
$log.format = format if format
$log.time_format = time_format if time_format
$log.ignore_repeated_log_interval = ignore_repeated_log_interval if ignore_repeated_log_interval
$log.ignore_same_log_interval = ignore_same_log_interval if ignore_same_log_interval

if @path && log_dir_perm
File.chmod(log_dir_perm || 0755, File.dirname(@path))
Expand Down Expand Up @@ -511,7 +515,8 @@ def initialize(opt)
@cl_opt = opt
@conf = nil

log_opts = {suppress_repeated_stacktrace: opt[:suppress_repeated_stacktrace], ignore_repeated_log_interval: opt[:ignore_repeated_log_interval]}
log_opts = {suppress_repeated_stacktrace: opt[:suppress_repeated_stacktrace], ignore_repeated_log_interval: opt[:ignore_repeated_log_interval],
ignore_same_log_interval: opt[:ignore_same_log_interval]}
@log = LoggerInitializer.new(
@log_path, opt[:log_level], @chuser, @chgroup, log_opts,
log_rotate_age: @log_rotate_age,
Expand Down Expand Up @@ -635,7 +640,8 @@ def configure(supervisor: false)
format: @system_config.log.format,
time_format: @system_config.log.time_format,
log_dir_perm: @system_config.dir_permission,
ignore_repeated_log_interval: @system_config.ignore_repeated_log_interval
ignore_repeated_log_interval: @system_config.ignore_repeated_log_interval,
ignore_same_log_interval: @system_config.ignore_same_log_interval
)

$log.info :supervisor, 'parsing config file is succeeded', path: @config_path
Expand Down
3 changes: 2 additions & 1 deletion lib/fluent/system_config.rb
View file
Original file line number Diff line number Diff line change
Expand Up @@ -24,7 +24,7 @@ class SystemConfig
SYSTEM_CONFIG_PARAMETERS = [
:workers, :root_dir, :log_level,
:suppress_repeated_stacktrace, :emit_error_log_interval, :suppress_config_dump,
:log_event_verbose, :ignore_repeated_log_interval,
:log_event_verbose, :ignore_repeated_log_interval, :ignore_same_log_interval,
:without_source, :rpc_endpoint, :enable_get_dump, :process_name,
:file_permission, :dir_permission, :counter_server, :counter_client,
:strict_config_value, :enable_msgpack_time_support
Expand All @@ -35,6 +35,7 @@ class SystemConfig
config_param :log_level, :enum, list: [:trace, :debug, :info, :warn, :error, :fatal], default: 'info'
config_param :suppress_repeated_stacktrace, :bool, default: nil
config_param :ignore_repeated_log_interval, :time, default: nil
config_param :ignore_same_log_interval, :time, default: nil
config_param :emit_error_log_interval, :time, default: nil
config_param :suppress_config_dump, :bool, default: nil
config_param :log_event_verbose, :bool, default: nil
Expand Down
44 changes: 44 additions & 0 deletions test/test_log.rb
View file
Original file line number Diff line number Diff line change
Expand Up @@ -411,6 +411,50 @@ def test_different_message
end
end

sub_test_case "ignore_same_log_interval" do
teardown do
Thread.current[:last_same_log] = nil
end

def test_same_message
message = "This is test"
logger = ServerEngine::DaemonLogger.new(@log_device, {log_level: ServerEngine::DaemonLogger::INFO})
log = Fluent::Log.new(logger, {ignore_same_log_interval: 5})

log.error message
10.times { |i|
Timecop.freeze(@timestamp + i + 1)
log.error message
}

expected = [
"2016-04-21 02:58:41 +0000 [error]: This is test\n",
"2016-04-21 02:58:47 +0000 [error]: This is test\n"
]
assert_equal(expected, log.out.logs)
end

def test_different_message
message = "This is test"
logger = ServerEngine::DaemonLogger.new(@log_device, {log_level: ServerEngine::DaemonLogger::INFO})
log = Fluent::Log.new(logger, {ignore_same_log_interval: 10})

log.error message
3.times { |i|
Timecop.freeze(@timestamp + i)
log.error message
log.error message
log.info "Hello! " + message
}

expected = [
"2016-04-21 02:58:41 +0000 [error]: This is test\n",
"2016-04-21 02:58:41 +0000 [info]: Hello! This is test\n",
]
assert_equal(expected, log.out.logs)
end
end

def test_dup
dl_opts = {}
dl_opts[:log_level] = ServerEngine::DaemonLogger::TRACE
Expand Down

0 comments on commit adca029

Please sign in to comment.