Skip to content

Commit 7b4d2d5

Browse files
authored
log: add system_config option to force stacktrace level (#5008)
**Which issue(s) this PR fixes**: None. **What this PR does / why we need it**: **What this PR does** Add a new system_config option: `forced_stacktrace_level`. * Option: `system/log/forced_stacktrace_level` * Type: `enum` * `none`, `trace`, `debug`, `info`, `warn`, `error`, `fatal` * Default: `none` By default, the behavior of Fluentd does not change. So, this does not affect existing users. If you set this option and change the value, the log levels of stacktraces are forced to that value. Stacktraces that do not meet the log level are discarded in advance. After the log level is changed, it is judged again for logging or discarded finally. For example, by default (`log_level info`), ... * All `trace`/`debug` stacktraces are not logged regardless of this option. * If you set `forced_stacktrace_level debug`, then all stacktraces are not logged. This is because we should avoid logging logs that contradict `log_level`, and to avoid unexpectedly logging logs that are initially `trace`/`debug` level. Setting example: ```xml <system> <log> forced_stacktrace_level info </log> </system> ``` **why we need it** To make it easier to exclude stacktraces from monitoring Fluentd's own logs. (You don't need this feature if using [@FLUENT_LOG](https://docs.fluentd.org/deployment/logging#capture-fluentd-logs) to transfer. For some reason, there are users who need to monitor Fluentd's log files directly. This feature is for those uses.) For example, there could be a system that raises an alert when an error-level log is detected. You may want to exclude some error-level logs from the detection. However, if stacktraces are logged at error level, you need to exclude those stacktraces as well. With the current specification, that is troublesome. Ideally, it would be preferable to exclude all stacktraces from the detection. It is sufficient to have access to stacktraces when investigating the details. An easy way to improve the current situation is this feature. If you are detecting error logs as in the previous example, you can easily exclude all stacktraces from the detection by forcing the stacktrace level to `info` with this feature. **Docs Changes**: * fluent/fluentd-docs-gitbook#589 **Release Note**: System configuration: Add `forced_stacktrace_level` to force the log level of stacktraces. **Sample**: ```xml <system> <log> forced_stacktrace_level info </log> </system> <source> @type sample @id test tag test.fail </source> <match test.fail> @type null never_flush </match> ``` Without `forced_stacktrace_level info`: ``` 2025-06-23 18:16:45 +0900 [info]: #0 fluent/log.rb:371:info: fluentd worker is now running worker=0 2025-06-23 18:16:46 +0900 [warn]: #0 fluent/log.rb:392:warn: emit transaction failed: error_class=RuntimeError error="failed to flush" location="/home/daipom/work/fluentd/fluentd/lib/fluent/plugin/out_null.rb:54:in `process'" tag="test.fail" 2025-06-23 18:16:46 +0900 [warn]: #0 fluent/event_router.rb:114:emit_stream: /home/daipom/work/fluentd/fluentd/lib/fluent/plugin/out_null.rb:54:in `process' 2025-06-23 18:16:46 +0900 [warn]: #0 fluent/event_router.rb:114:emit_stream: /home/daipom/work/fluentd/fluentd/lib/fluent/plugin/output.rb:865:in `emit_sync' 2025-06-23 18:16:46 +0900 [warn]: #0 fluent/event_router.rb:114:emit_stream: /home/daipom/work/fluentd/fluentd/lib/fluent/event_router.rb:115:in `emit_stream' 2025-06-23 18:16:46 +0900 [warn]: #0 fluent/event_router.rb:114:emit_stream: /home/daipom/work/fluentd/fluentd/lib/fluent/event_router.rb:106:in `emit' 2025-06-23 18:16:46 +0900 [warn]: #0 fluent/event_router.rb:114:emit_stream: /home/daipom/work/fluentd/fluentd/lib/fluent/plugin/in_sample.rb:115:in `block in emit' 2025-06-23 18:16:46 +0900 [warn]: #0 fluent/event_router.rb:114:emit_stream: /home/daipom/work/fluentd/fluentd/lib/fluent/plugin/in_sample.rb:115:in `times' 2025-06-23 18:16:46 +0900 [warn]: #0 fluent/event_router.rb:114:emit_stream: /home/daipom/work/fluentd/fluentd/lib/fluent/plugin/in_sample.rb:115:in `emit' 2025-06-23 18:16:46 +0900 [warn]: #0 fluent/event_router.rb:114:emit_stream: /home/daipom/work/fluentd/fluentd/lib/fluent/plugin/in_sample.rb:100:in `run' 2025-06-23 18:16:46 +0900 [warn]: #0 fluent/event_router.rb:114:emit_stream: /home/daipom/work/fluentd/fluentd/lib/fluent/plugin_helper/thread.rb:78:in `block in thread_create' ``` With `forced_stacktrace_level info`: ``` 2025-06-23 18:13:59 +0900 [warn]: #0 fluent/log.rb:392:warn: emit transaction failed: error_class=RuntimeError error="failed to flush" location="/home/daipom/work/fluentd/fluentd/lib/fluent/plugin/out_null.rb:54:in `process'" tag="test.fail" 2025-06-23 18:13:59 +0900 [info]: #0 fluent/event_router.rb:114:emit_stream: /home/daipom/work/fluentd/fluentd/lib/fluent/plugin/out_null.rb:54:in `process' 2025-06-23 18:13:59 +0900 [info]: #0 fluent/event_router.rb:114:emit_stream: /home/daipom/work/fluentd/fluentd/lib/fluent/plugin/output.rb:865:in `emit_sync' 2025-06-23 18:13:59 +0900 [info]: #0 fluent/event_router.rb:114:emit_stream: /home/daipom/work/fluentd/fluentd/lib/fluent/event_router.rb:115:in `emit_stream' 2025-06-23 18:13:59 +0900 [info]: #0 fluent/event_router.rb:114:emit_stream: /home/daipom/work/fluentd/fluentd/lib/fluent/event_router.rb:106:in `emit' 2025-06-23 18:13:59 +0900 [info]: #0 fluent/event_router.rb:114:emit_stream: /home/daipom/work/fluentd/fluentd/lib/fluent/plugin/in_sample.rb:115:in `block in emit' 2025-06-23 18:13:59 +0900 [info]: #0 fluent/event_router.rb:114:emit_stream: /home/daipom/work/fluentd/fluentd/lib/fluent/plugin/in_sample.rb:115:in `times' 2025-06-23 18:13:59 +0900 [info]: #0 fluent/event_router.rb:114:emit_stream: /home/daipom/work/fluentd/fluentd/lib/fluent/plugin/in_sample.rb:115:in `emit' 2025-06-23 18:13:59 +0900 [info]: #0 fluent/event_router.rb:114:emit_stream: /home/daipom/work/fluentd/fluentd/lib/fluent/plugin/in_sample.rb:100:in `run' 2025-06-23 18:13:59 +0900 [info]: #0 fluent/event_router.rb:114:emit_stream: /home/daipom/work/fluentd/fluentd/lib/fluent/plugin_helper/thread.rb:78:in `block in thread_create' ``` Signed-off-by: Daijiro Fukuda <[email protected]>
1 parent 6821e4b commit 7b4d2d5

File tree

6 files changed

+111
-0
lines changed

6 files changed

+111
-0
lines changed

lib/fluent/log.rb

Lines changed: 19 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -138,6 +138,7 @@ def initialize(logger, opts={})
138138
@optional_attrs = nil
139139

140140
@suppress_repeated_stacktrace = opts[:suppress_repeated_stacktrace]
141+
@forced_stacktrace_level = nil
141142
@ignore_repeated_log_interval = opts[:ignore_repeated_log_interval]
142143
@ignore_same_log_interval = opts[:ignore_same_log_interval]
143144

@@ -240,6 +241,14 @@ def reopen!
240241
nil
241242
end
242243

244+
def force_stacktrace_level?
245+
not @forced_stacktrace_level.nil?
246+
end
247+
248+
def force_stacktrace_level(level)
249+
@forced_stacktrace_level = level
250+
end
251+
243252
def enable_debug(b=true)
244253
@debug_mode = b
245254
self
@@ -500,6 +509,16 @@ def suppress_stacktrace?(backtrace)
500509
def dump_stacktrace(type, backtrace, level)
501510
return if @level > level
502511

512+
dump_stacktrace_internal(
513+
type,
514+
backtrace,
515+
force_stacktrace_level? ? @forced_stacktrace_level : level,
516+
)
517+
end
518+
519+
def dump_stacktrace_internal(type, backtrace, level)
520+
return if @level > level
521+
503522
time = Time.now
504523

505524
if @format == :text

lib/fluent/supervisor.rb

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -908,6 +908,7 @@ def setup_global_logger(supervisor: false)
908908
ignore_repeated_log_interval: system_config.ignore_repeated_log_interval,
909909
ignore_same_log_interval: system_config.ignore_same_log_interval,
910910
)
911+
$log.force_stacktrace_level(system_config.log.forced_stacktrace_level) if system_config.force_stacktrace_level?
911912
$log.enable_color(false) if actual_log_path
912913
$log.enable_debug if system_config.log_level <= Fluent::Log::LEVEL_DEBUG
913914

lib/fluent/system_config.rb

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -79,6 +79,7 @@ class SystemConfig
7979
end
8080
end
8181
config_param :rotate_size, :size, default: nil
82+
config_param :forced_stacktrace_level, :enum, list: [:none, :trace, :debug, :info, :warn, :error, :fatal], default: :none
8283
end
8384

8485
config_section :counter_server, multi: false do
@@ -118,6 +119,10 @@ class SystemConfig
118119
config_param :compress, :enum, list: [:text, :gzip], default: nil
119120
end
120121

122+
def force_stacktrace_level?
123+
@log.forced_stacktrace_level != :none
124+
end
125+
121126
def self.create(conf, strict_config_value=false)
122127
systems = conf.elements(name: 'system')
123128
return SystemConfig.new if systems.empty?
@@ -162,6 +167,7 @@ def configure(conf, strict_config_value=false)
162167
end
163168

164169
@log_level = Log.str_to_level(@log_level.to_s) if @log_level
170+
@log[:forced_stacktrace_level] = Log.str_to_level(@log.forced_stacktrace_level.to_s) if force_stacktrace_level?
165171
end
166172

167173
def dup

test/config/test_system_config.rb

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -82,6 +82,7 @@ def parse_text(text)
8282
assert_nil(sc.log.path)
8383
assert_equal(:text, sc.log.format)
8484
assert_equal('%Y-%m-%d %H:%M:%S %z', sc.log.time_format)
85+
assert_equal(:none, sc.log.forced_stacktrace_level)
8586
end
8687

8788
data(
@@ -124,6 +125,7 @@ def parse_text(text)
124125
path /tmp/fluentd.log
125126
format json
126127
time_format %Y
128+
forced_stacktrace_level info
127129
</log>
128130
</system>
129131
EOS
@@ -133,6 +135,7 @@ def parse_text(text)
133135
assert_equal('/tmp/fluentd.log', sc.log.path)
134136
assert_equal(:json, sc.log.format)
135137
assert_equal('%Y', sc.log.time_format)
138+
assert_equal(Fluent::Log::LEVEL_INFO, sc.log.forced_stacktrace_level)
136139
end
137140

138141
# info is removed because info level can't be specified via command line

test/test_log.rb

Lines changed: 79 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -386,6 +386,85 @@ def test_different_log_level
386386
end
387387
end
388388

389+
sub_test_case "force_stacktrace_level" do
390+
data(
391+
none: [ nil, ["trace", "debug", "info", "warn", "error", "fatal"] ],
392+
trace: [ Fluent::Log::LEVEL_TRACE, ["trace", "trace", "trace", "trace", "trace", "trace"] ],
393+
debug: [ Fluent::Log::LEVEL_DEBUG, ["debug", "debug", "debug", "debug", "debug", "debug"] ],
394+
info: [ Fluent::Log::LEVEL_INFO, ["info", "info", "info", "info", "info", "info"] ],
395+
warn: [ Fluent::Log::LEVEL_WARN, ["warn", "warn", "warn", "warn", "warn", "warn"] ],
396+
error: [ Fluent::Log::LEVEL_ERROR, ["error", "error", "error", "error", "error", "error"] ],
397+
fatal: [ Fluent::Log::LEVEL_FATAL, ["fatal", "fatal", "fatal", "fatal", "fatal", "fatal"] ],
398+
)
399+
test "level should be forced" do |(level, expected)|
400+
backtrace = ["backtrace"]
401+
logger = Fluent::Log.new(
402+
ServerEngine::DaemonLogger.new(
403+
@log_device,
404+
log_level: ServerEngine::DaemonLogger::TRACE,
405+
)
406+
)
407+
logger.force_stacktrace_level(level) unless level.nil?
408+
409+
logger.trace_backtrace(backtrace)
410+
logger.debug_backtrace(backtrace)
411+
logger.info_backtrace(backtrace)
412+
logger.warn_backtrace(backtrace)
413+
logger.error_backtrace(backtrace)
414+
logger.fatal_backtrace(backtrace)
415+
416+
assert do
417+
expected == logger.out.logs.map { |log| log.match(/ \[([a-z]+)\]: backtrace$/)[1] }
418+
end
419+
end
420+
421+
test "stacktraces that do not meet log_level initially should be discarded" do
422+
logger = Fluent::Log.new(
423+
ServerEngine::DaemonLogger.new(
424+
@log_device,
425+
log_level: ServerEngine::DaemonLogger::INFO,
426+
)
427+
)
428+
logger.force_stacktrace_level(Fluent::Log::LEVEL_INFO)
429+
430+
logger.trace_backtrace(["trace"])
431+
logger.debug_backtrace(["debug"])
432+
logger.info_backtrace(["info"])
433+
logger.warn_backtrace(["warn"])
434+
logger.error_backtrace(["error"])
435+
logger.fatal_backtrace(["fatal"])
436+
437+
assert_equal(
438+
[
439+
" #{@timestamp_str} [info]: info\n",
440+
" #{@timestamp_str} [info]: warn\n",
441+
" #{@timestamp_str} [info]: error\n",
442+
" #{@timestamp_str} [info]: fatal\n",
443+
],
444+
logger.out.logs,
445+
)
446+
end
447+
448+
test "stacktraces that do not meet log_level finally should be discarded" do
449+
logger = Fluent::Log.new(
450+
ServerEngine::DaemonLogger.new(
451+
@log_device,
452+
log_level: ServerEngine::DaemonLogger::INFO,
453+
)
454+
)
455+
logger.force_stacktrace_level(Fluent::Log::LEVEL_DEBUG)
456+
457+
logger.trace_backtrace(["trace"])
458+
logger.debug_backtrace(["debug"])
459+
logger.info_backtrace(["info"])
460+
logger.warn_backtrace(["warn"])
461+
logger.error_backtrace(["error"])
462+
logger.fatal_backtrace(["fatal"])
463+
464+
assert_equal([], logger.out.logs)
465+
end
466+
end
467+
389468
sub_test_case "ignore_repeated_log_interval" do
390469
def test_same_message
391470
message = "This is test"

test/test_supervisor.rb

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -715,6 +715,7 @@ def test_init_for_logger(supervisor)
715715
<log>
716716
format json
717717
time_format %FT%T.%L%z
718+
forced_stacktrace_level info
718719
</log>
719720
</system>
720721
EOC
@@ -728,6 +729,8 @@ def test_init_for_logger(supervisor)
728729
assert_equal false, $log.suppress_repeated_stacktrace
729730
assert_equal 10, $log.ignore_repeated_log_interval
730731
assert_equal 20, $log.ignore_same_log_interval
732+
assert_equal Fluent::Log::LEVEL_INFO, $log.instance_variable_get(:@forced_stacktrace_level)
733+
assert_true $log.force_stacktrace_level?
731734
end
732735

733736
data(

0 commit comments

Comments
 (0)