From 72504954bc6a212c9e54218cd7ac4913caf95a12 Mon Sep 17 00:00:00 2001 From: Takuro Ashie Date: Wed, 14 Dec 2022 09:09:19 +0900 Subject: [PATCH 01/13] Add a wapper for Console::Serialized::Logger to output Async's log Signed-off-by: Takuro Ashie --- lib/fluent/log/console_adapter.rb | 62 +++++++++++++++++++ .../plugin_helper/http_server/server.rb | 3 +- 2 files changed, 64 insertions(+), 1 deletion(-) create mode 100644 lib/fluent/log/console_adapter.rb diff --git a/lib/fluent/log/console_adapter.rb b/lib/fluent/log/console_adapter.rb new file mode 100644 index 0000000000..fa7423d7f6 --- /dev/null +++ b/lib/fluent/log/console_adapter.rb @@ -0,0 +1,62 @@ +# +# Fluentd +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + +require 'console/serialized/logger' + +module Fluent + class Log + class ConsoleAdapter < Console::Serialized::Logger + def self.wrap(logger) + Console::Logger.new(ConsoleAdapter.new(logger)) + end + + def initialize(logger) + @logger = logger + super(@logger) + end + + def call(subject = nil, *arguments, severity: 'info', **options, &block) + if LEVEL_TEXT.include?(severity.to_s) + level = severity + else + @logger.warn "Unknown severity: #{severity}" + level = 'warn' + end + + args = arguments.dup + args.unshift("#{subject}") if subject + + if block_given? + if block.arity.zero? + args << yield + else + buffer = StringIO.new + yield buffer + args << buffer.string + end + end + + exception = find_exception(args) + args.delete(exception) if exception + + @logger.send(severity, args.join(" ")) + if exception && @logger.respond_to?("#{level}_backtrace") + @logger.send("#{level}_backtrace", exception) + end + end + end + end +end diff --git a/lib/fluent/plugin_helper/http_server/server.rb b/lib/fluent/plugin_helper/http_server/server.rb index 4266bc639f..549db76cc8 100644 --- a/lib/fluent/plugin_helper/http_server/server.rb +++ b/lib/fluent/plugin_helper/http_server/server.rb @@ -21,6 +21,7 @@ require 'fluent/plugin_helper/http_server/app' require 'fluent/plugin_helper/http_server/router' require 'fluent/plugin_helper/http_server/methods' +require 'fluent/log/console_adapter' module Fluent module PluginHelper @@ -38,7 +39,7 @@ def initialize(addr:, port:, logger:, default_app: nil, tls_context: nil) scheme = tls_context ? 'https' : 'http' @uri = URI("#{scheme}://#{@addr}:#{@port}").to_s @router = Router.new(default_app) - @reactor = Async::Reactor.new(nil, logger: @logger) + @reactor = Async::Reactor.new(nil, logger: Fluent::Log::ConsoleAdapter.wrap(@logger)) opts = if tls_context { ssl_context: tls_context } From bd9b69a8c86726eda7cb288cddc016baf1fa5b73 Mon Sep 17 00:00:00 2001 From: Takuro Ashie Date: Sun, 1 Jan 2023 16:03:19 +0900 Subject: [PATCH 02/13] Add a test for Fluent::Log::ConsoleAdapter Signed-off-by: Takuro Ashie --- test/log/test_console_adapter.rb | 33 ++++++++++++++++++++++++++++++++ 1 file changed, 33 insertions(+) create mode 100644 test/log/test_console_adapter.rb diff --git a/test/log/test_console_adapter.rb b/test/log/test_console_adapter.rb new file mode 100644 index 0000000000..76349acae0 --- /dev/null +++ b/test/log/test_console_adapter.rb @@ -0,0 +1,33 @@ +require_relative '../helper' + +require 'fluent/log' +require 'fluent/log/console_adapter' + +class ConsoleAdapterTest < Test::Unit::TestCase + def setup + @timestamp = Time.parse("2023-01-01 15:32:41 +0000") + @timestamp_str = @timestamp.strftime("%Y-%m-%d %H:%M:%S %z") + Timecop.freeze(@timestamp) + + @logdev = Fluent::Test::DummyLogDevice.new + @logger = ServerEngine::DaemonLogger.new(@logdev) + @fluent_log = Fluent::Log.new(@logger) + @console_logger = Fluent::Log::ConsoleAdapter.wrap(@fluent_log) + @console_logger.level = :debug + end + + def teardown + Timecop.return + end + + data(debug: :debug, + info: :info, + warn: :warn, + error: :error, + fatal: :fatal) + def test_one_message(level) + @console_logger.send(level, "message1") + assert_equal(["#{@timestamp_str} [#{level}]: message1\n"], + @logdev.logs) + end +end From aa40037d0cf14099d4d6431a9c46895bc40dbdf9 Mon Sep 17 00:00:00 2001 From: Takuro Ashie Date: Mon, 2 Jan 2023 01:01:53 +0900 Subject: [PATCH 03/13] test_console_adapter: Add more tests Signed-off-by: Takuro Ashie --- test/log/test_console_adapter.rb | 16 ++++++++++++++++ 1 file changed, 16 insertions(+) diff --git a/test/log/test_console_adapter.rb b/test/log/test_console_adapter.rb index 76349acae0..8133dbd658 100644 --- a/test/log/test_console_adapter.rb +++ b/test/log/test_console_adapter.rb @@ -20,6 +20,11 @@ def teardown Timecop.return end + def test_expected_log_levels + assert_equal({debug: 0, info: 1, warn: 2, error: 3, fatal: 4}, + Console::Logger::LEVELS) + end + data(debug: :debug, info: :info, warn: :warn, @@ -30,4 +35,15 @@ def test_one_message(level) assert_equal(["#{@timestamp_str} [#{level}]: message1\n"], @logdev.logs) end + + data(debug: :debug, + info: :info, + warn: :warn, + error: :error, + fatal: :fatal) + def test_block(level) + @console_logger.send(level) { "block message" } + assert_equal(["#{@timestamp_str} [#{level}]: block message\n"], + @logdev.logs) + end end From 7b52a7ef2dd26e9c243d5f686a349623d35fb14e Mon Sep 17 00:00:00 2001 From: Takuro Ashie Date: Mon, 2 Jan 2023 13:24:52 +0900 Subject: [PATCH 04/13] log/console_adapter: Ensure not to modify original message Signed-off-by: Takuro Ashie --- lib/fluent/log/console_adapter.rb | 35 ++++++++----------------------- test/log/test_console_adapter.rb | 11 ++++++---- 2 files changed, 16 insertions(+), 30 deletions(-) diff --git a/lib/fluent/log/console_adapter.rb b/lib/fluent/log/console_adapter.rb index fa7423d7f6..c93bb009f7 100644 --- a/lib/fluent/log/console_adapter.rb +++ b/lib/fluent/log/console_adapter.rb @@ -18,44 +18,27 @@ module Fluent class Log - class ConsoleAdapter < Console::Serialized::Logger + class ConsoleAdapter < Console::Terminal::Logger def self.wrap(logger) - Console::Logger.new(ConsoleAdapter.new(logger)) + Console::Logger.new(ConsoleAdapter.new(StringIO.new, logger)) end - def initialize(logger) + def initialize(io, logger) @logger = logger - super(@logger) + super(io, verbose: false) end - def call(subject = nil, *arguments, severity: 'info', **options, &block) + def call(subject = nil, *arguments, name: nil, severity: 'info', **options, &block) if LEVEL_TEXT.include?(severity.to_s) level = severity else - @logger.warn "Unknown severity: #{severity}" + @logger.warn("Unknown severity: #{severity}") level = 'warn' end - args = arguments.dup - args.unshift("#{subject}") if subject - - if block_given? - if block.arity.zero? - args << yield - else - buffer = StringIO.new - yield buffer - args << buffer.string - end - end - - exception = find_exception(args) - args.delete(exception) if exception - - @logger.send(severity, args.join(" ")) - if exception && @logger.respond_to?("#{level}_backtrace") - @logger.send("#{level}_backtrace", exception) - end + @io.truncate(0) + super + @logger.send(severity, @io.string.chomp) end end end diff --git a/test/log/test_console_adapter.rb b/test/log/test_console_adapter.rb index 8133dbd658..c689821b50 100644 --- a/test/log/test_console_adapter.rb +++ b/test/log/test_console_adapter.rb @@ -31,8 +31,8 @@ def test_expected_log_levels error: :error, fatal: :fatal) def test_one_message(level) - @console_logger.send(level, "message1") - assert_equal(["#{@timestamp_str} [#{level}]: message1\n"], + @console_logger.send(level, "subject") + assert_equal(["#{@timestamp_str} [#{level}]: 0.0s: subject\n"], @logdev.logs) end @@ -42,8 +42,11 @@ def test_one_message(level) error: :error, fatal: :fatal) def test_block(level) - @console_logger.send(level) { "block message" } - assert_equal(["#{@timestamp_str} [#{level}]: block message\n"], + @console_logger.send(level, "subject") { "block message" } + assert_equal([ + "#{@timestamp_str} [#{level}]: 0.0s: subject\n" + + " | block message\n" + ], @logdev.logs) end end From 3bf86c39753e2d5fcc7c6f014fb3734417835a2e Mon Sep 17 00:00:00 2001 From: Takuro Ashie Date: Mon, 2 Jan 2023 13:34:05 +0900 Subject: [PATCH 05/13] log/console_adapter: Simplify initialization parameter Signed-off-by: Takuro Ashie --- lib/fluent/log/console_adapter.rb | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/lib/fluent/log/console_adapter.rb b/lib/fluent/log/console_adapter.rb index c93bb009f7..2a489440c2 100644 --- a/lib/fluent/log/console_adapter.rb +++ b/lib/fluent/log/console_adapter.rb @@ -20,12 +20,12 @@ module Fluent class Log class ConsoleAdapter < Console::Terminal::Logger def self.wrap(logger) - Console::Logger.new(ConsoleAdapter.new(StringIO.new, logger)) + Console::Logger.new(ConsoleAdapter.new(logger)) end - def initialize(io, logger) + def initialize(logger) @logger = logger - super(io, verbose: false) + super(StringIO.new, verbose: false) end def call(subject = nil, *arguments, name: nil, severity: 'info', **options, &block) From 1d4990ce373bd145344c4f5749229c06104cb4bb Mon Sep 17 00:00:00 2001 From: Takuro Ashie Date: Mon, 2 Jan 2023 14:52:59 +0900 Subject: [PATCH 06/13] test_console_adapter: Add more tests Signed-off-by: Takuro Ashie --- test/log/test_console_adapter.rb | 32 +++++++++++++++++++++++++++++++- 1 file changed, 31 insertions(+), 1 deletion(-) diff --git a/test/log/test_console_adapter.rb b/test/log/test_console_adapter.rb index c689821b50..7199fea57c 100644 --- a/test/log/test_console_adapter.rb +++ b/test/log/test_console_adapter.rb @@ -30,12 +30,42 @@ def test_expected_log_levels warn: :warn, error: :error, fatal: :fatal) - def test_one_message(level) + def test_string_subject(level) @console_logger.send(level, "subject") assert_equal(["#{@timestamp_str} [#{level}]: 0.0s: subject\n"], @logdev.logs) end + data(debug: :debug, + info: :info, + warn: :warn, + error: :error, + fatal: :fatal) + def test_args(level) + @console_logger.send(level, "subject", 1, 2, 3) + assert_equal([ + "#{@timestamp_str} [#{level}]: 0.0s: subject\n" + + " | 1\n" + + " | 2\n" + + " | 3\n" + ], + @logdev.logs) + end + + data(debug: :debug, + info: :info, + warn: :warn, + error: :error, + fatal: :fatal) + def test_options(level) + @console_logger.send(level, "subject", kwarg1: "opt1", kwarg2: "opt2") + assert_equal([ + "#{@timestamp_str} [#{level}]: 0.0s: subject\n" + + " | {\"kwarg1\":\"opt1\",\"kwarg2\":\"opt2\"}\n" + ], + @logdev.logs) + end + data(debug: :debug, info: :info, warn: :warn, From a64fc37ed0af1c5ce6f7681187df9f97c1ac9874 Mon Sep 17 00:00:00 2001 From: Takuro Ashie Date: Mon, 2 Jan 2023 16:13:30 +0900 Subject: [PATCH 07/13] log/console_adapter: Reflect log level of wrapped logger Signed-off-by: Takuro Ashie --- lib/fluent/log/console_adapter.rb | 9 ++++++++- test/log/test_console_adapter.rb | 15 ++++++++++++++- 2 files changed, 22 insertions(+), 2 deletions(-) diff --git a/lib/fluent/log/console_adapter.rb b/lib/fluent/log/console_adapter.rb index 2a489440c2..53de0df05d 100644 --- a/lib/fluent/log/console_adapter.rb +++ b/lib/fluent/log/console_adapter.rb @@ -20,7 +20,14 @@ module Fluent class Log class ConsoleAdapter < Console::Terminal::Logger def self.wrap(logger) - Console::Logger.new(ConsoleAdapter.new(logger)) + _, level = Console::Logger::LEVELS.find { |key, value| + if logger.level <= 0 + key == :debug + else + value == logger.level - 1 + end + } + Console::Logger.new(ConsoleAdapter.new(logger), level: level) end def initialize(logger) diff --git a/test/log/test_console_adapter.rb b/test/log/test_console_adapter.rb index 7199fea57c..0d8cbea50b 100644 --- a/test/log/test_console_adapter.rb +++ b/test/log/test_console_adapter.rb @@ -13,7 +13,6 @@ def setup @logger = ServerEngine::DaemonLogger.new(@logdev) @fluent_log = Fluent::Log.new(@logger) @console_logger = Fluent::Log::ConsoleAdapter.wrap(@fluent_log) - @console_logger.level = :debug end def teardown @@ -25,6 +24,20 @@ def test_expected_log_levels Console::Logger::LEVELS) end + data(trace: [Fluent::Log::LEVEL_TRACE, :debug], + debug: [Fluent::Log::LEVEL_DEBUG, :debug], + info: [Fluent::Log::LEVEL_INFO, :info], + warn: [Fluent::Log::LEVEL_WARN, :warn], + error: [Fluent::Log::LEVEL_ERROR, :error], + fatal: [Fluent::Log::LEVEL_FATAL, :fatal]) + def test_reflect_log_level(data) + level, expected = data + @fluent_log.level = level + console_logger = Fluent::Log::ConsoleAdapter.wrap(@fluent_log) + assert_equal(Console::Logger::LEVELS[expected], + console_logger.level) + end + data(debug: :debug, info: :info, warn: :warn, From c3dadf7a821e85ab0d22c1f9ce6e7c3bcd5d3c9c Mon Sep 17 00:00:00 2001 From: Takuro Ashie Date: Mon, 2 Jan 2023 16:25:07 +0900 Subject: [PATCH 08/13] log/console_adapter: Add missing seek Signed-off-by: Takuro Ashie --- lib/fluent/log/console_adapter.rb | 1 + test/log/test_console_adapter.rb | 15 +++++++++++++++ 2 files changed, 16 insertions(+) diff --git a/lib/fluent/log/console_adapter.rb b/lib/fluent/log/console_adapter.rb index 53de0df05d..85948018ba 100644 --- a/lib/fluent/log/console_adapter.rb +++ b/lib/fluent/log/console_adapter.rb @@ -43,6 +43,7 @@ def call(subject = nil, *arguments, name: nil, severity: 'info', **options, &blo level = 'warn' end + @io.seek(0) @io.truncate(0) super @logger.send(severity, @io.string.chomp) diff --git a/test/log/test_console_adapter.rb b/test/log/test_console_adapter.rb index 0d8cbea50b..06d9d900ad 100644 --- a/test/log/test_console_adapter.rb +++ b/test/log/test_console_adapter.rb @@ -92,4 +92,19 @@ def test_block(level) ], @logdev.logs) end + + data(debug: :debug, + info: :info, + warn: :warn, + error: :error, + fatal: :fatal) + def test_multiple_entries(level) + @console_logger.send(level, "subject1") + @console_logger.send(level, "line2") + assert_equal([ + "#{@timestamp_str} [#{level}]: 0.0s: subject1\n", + "#{@timestamp_str} [#{level}]: 0.0s: line2\n" + ], + @logdev.logs) + end end From 63fb3ae9d19b42dd5cd7fe71ccb0528c90f6f23c Mon Sep 17 00:00:00 2001 From: Takuro Ashie Date: Tue, 10 Jan 2023 17:24:22 +0900 Subject: [PATCH 09/13] Add a comment for ConsoleAdapter Signed-off-by: Takuro Ashie --- lib/fluent/log/console_adapter.rb | 3 +++ 1 file changed, 3 insertions(+) diff --git a/lib/fluent/log/console_adapter.rb b/lib/fluent/log/console_adapter.rb index 85948018ba..8c2f2e6fa8 100644 --- a/lib/fluent/log/console_adapter.rb +++ b/lib/fluent/log/console_adapter.rb @@ -18,6 +18,9 @@ module Fluent class Log + # Async gem which is used by http_server helper switched logger mechanism to + # Console gem which isn't complatible with Ruby's standard Logger (since + # v1.17). This class adapts it to Fluentd's logger mechanism. class ConsoleAdapter < Console::Terminal::Logger def self.wrap(logger) _, level = Console::Logger::LEVELS.find { |key, value| From 853398f2c2fefd309f19b713afe707787051c67a Mon Sep 17 00:00:00 2001 From: Takuro Ashie Date: Tue, 10 Jan 2023 21:56:33 +0900 Subject: [PATCH 10/13] log/console_adapter: Add a comment for `verbose` argument Signed-off-by: Takuro Ashie --- lib/fluent/log/console_adapter.rb | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/lib/fluent/log/console_adapter.rb b/lib/fluent/log/console_adapter.rb index 8c2f2e6fa8..e2d6123293 100644 --- a/lib/fluent/log/console_adapter.rb +++ b/lib/fluent/log/console_adapter.rb @@ -35,6 +35,16 @@ def self.wrap(logger) def initialize(logger) @logger = logger + # When `verbose` is `true`, following items will be added as a prefix or + # suffix of the subject: + # * Severity + # * Object ID + # * PID + # * Time + # Severity and Time are added by Fluentd::Log too so they are redundant. + # PID is the worker's PID so it's also redundant. + # Object ID will be too verbose in usual cases. + # So set it as `false` here to suppress redundant items. super(StringIO.new, verbose: false) end From bedaa89745b1fbbc76516322eb4cc7fddc87705f Mon Sep 17 00:00:00 2001 From: Takuro Ashie Date: Tue, 17 Jan 2023 18:53:29 +0900 Subject: [PATCH 11/13] test_http_server_helper: Address an incompatible logger Signed-off-by: Takuro Ashie --- test/plugin_helper/test_http_server_helper.rb | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/plugin_helper/test_http_server_helper.rb b/test/plugin_helper/test_http_server_helper.rb index 6691c9182d..4fd044bb0e 100644 --- a/test/plugin_helper/test_http_server_helper.rb +++ b/test/plugin_helper/test_http_server_helper.rb @@ -127,7 +127,7 @@ def start_https_request(addr, port, verify: true, cert_path: nil, selfsigned: tr end client = Async::HTTP::Client.new(Async::HTTP::Endpoint.parse("https://#{addr}:#{port}", ssl_context: context)) - reactor = Async::Reactor.new(nil, logger: NULL_LOGGER) + reactor = Async::Reactor.new(nil, logger: Fluent::Log::ConsoleAdapter.wrap(NULL_LOGGER)) resp = nil error = nil From ed507325b9cfb26b43f7a00bdc80c7067f08c14e Mon Sep 17 00:00:00 2001 From: Takuro Ashie Date: Thu, 19 Jan 2023 09:25:46 +0900 Subject: [PATCH 12/13] log/console_adapter: Fix a wrong require path Signed-off-by: Takuro Ashie --- lib/fluent/log/console_adapter.rb | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/fluent/log/console_adapter.rb b/lib/fluent/log/console_adapter.rb index e2d6123293..e7738c7271 100644 --- a/lib/fluent/log/console_adapter.rb +++ b/lib/fluent/log/console_adapter.rb @@ -14,7 +14,7 @@ # limitations under the License. # -require 'console/serialized/logger' +require 'console/terminal/logger' module Fluent class Log From fb97f564611b9d00172ab5f0339fad77c01a9ec9 Mon Sep 17 00:00:00 2001 From: Takuro Ashie Date: Thu, 19 Jan 2023 10:08:56 +0900 Subject: [PATCH 13/13] log/console_adapter: Fix wrong severity to use Signed-off-by: Takuro Ashie --- lib/fluent/log/console_adapter.rb | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/fluent/log/console_adapter.rb b/lib/fluent/log/console_adapter.rb index e7738c7271..9c8ecf482e 100644 --- a/lib/fluent/log/console_adapter.rb +++ b/lib/fluent/log/console_adapter.rb @@ -59,7 +59,7 @@ def call(subject = nil, *arguments, name: nil, severity: 'info', **options, &blo @io.seek(0) @io.truncate(0) super - @logger.send(severity, @io.string.chomp) + @logger.send(level, @io.string.chomp) end end end