Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add ignore_same_log _interval parameter #3119

Merged
merged 2 commits into from
Sep 4, 2020
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
36 changes: 33 additions & 3 deletions lib/fluent/log.rb
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
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
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
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
cosmo0920 marked this conversation as resolved.
Show resolved Hide resolved

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