From 7b285a06e262a2ec1334e379e94feef0c35f9c5c Mon Sep 17 00:00:00 2001 From: Daijiro Fukuda Date: Mon, 13 Feb 2023 17:40:31 +0900 Subject: [PATCH 1/9] Windows: Apply the modified log path for rotation to reopen When log rotation is enabled on Windows, the log path is separated for each process. But, the new path value is not applied to the instance variable, so it breaks the following behavior, since #2663. * `File.chown(chuid, chgid, @path)` * `@logdev.reopen(@path, "a")`. I can't assume that `File.chown` is used on Windows, but `reopen` must be fixed. Signed-off-by: Daijiro Fukuda --- lib/fluent/supervisor.rb | 10 +++------- 1 file changed, 3 insertions(+), 7 deletions(-) diff --git a/lib/fluent/supervisor.rb b/lib/fluent/supervisor.rb index a1f8b64d8f..719c557f67 100644 --- a/lib/fluent/supervisor.rb +++ b/lib/fluent/supervisor.rb @@ -563,12 +563,8 @@ def init(process_type, worker_id) if @log_rotate_age || @log_rotate_size # We need to prepare a unique path for each worker since # Windows locks files. - if Fluent.windows? - path = LoggerInitializer.per_process_path(@path, process_type, worker_id) - else - path = @path - end - @logdev = Fluent::LogDeviceIO.new(path, shift_age: @log_rotate_age, shift_size: @log_rotate_size) + @path = LoggerInitializer.per_process_path(@path, process_type, worker_id) if Fluent.windows? + @logdev = Fluent::LogDeviceIO.new(@path, shift_age: @log_rotate_age, shift_size: @log_rotate_size) else @logdev = File.open(@path, "a") end @@ -591,7 +587,7 @@ def init(process_type, worker_id) $log = Fluent::Log.new(logger, @opts) $log.enable_color(false) if @path $log.enable_debug if @level <= Fluent::Log::LEVEL_DEBUG - $log.info "init #{process_type} logger", path: path, rotate_age: @log_rotate_age, rotate_size: @log_rotate_size + $log.info "init #{process_type} logger", path: @path, rotate_age: @log_rotate_age, rotate_size: @log_rotate_size end def stdout? From 560c1bb8ab09dea2e54f2ba156933f60079dcb5e Mon Sep 17 00:00:00 2001 From: Daijiro Fukuda Date: Wed, 15 Feb 2023 08:35:10 +0900 Subject: [PATCH 2/9] Test: Make sure to close LogDevice Especially on Windows, need closing to remove log files. Signed-off-by: Daijiro Fukuda --- test/test_logger_initializer.rb | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/test/test_logger_initializer.rb b/test/test_logger_initializer.rb index d31d58d2da..392b319125 100644 --- a/test/test_logger_initializer.rb +++ b/test/test_logger_initializer.rb @@ -22,6 +22,7 @@ class LoggerInitializerTest < ::Test::Unit::TestCase assert_nothing_raised do logger.init(:supervisor, 0) end + $log.out.close assert_true File.exist?(TMP_DIR) end @@ -38,8 +39,9 @@ class LoggerInitializerTest < ::Test::Unit::TestCase assert_nothing_raised do logger.init(:supervisor, 0) end - logger.apply_options(log_dir_perm: 0o777) + $log.out.close + assert_true File.exist?(TMP_DIR) assert_equal 0o777, (File.stat(TMP_DIR).mode & 0xFFF) end From abbcc64a49e15f8c581629d6b44fa89c03f8c1e2 Mon Sep 17 00:00:00 2001 From: Daijiro Fukuda Date: Wed, 15 Feb 2023 00:45:31 +0900 Subject: [PATCH 3/9] Test: Reset tmp files at setup to allow us to confirm the data after executing a test. Signed-off-by: Daijiro Fukuda --- test/test_logger_initializer.rb | 7 ++----- 1 file changed, 2 insertions(+), 5 deletions(-) diff --git a/test/test_logger_initializer.rb b/test/test_logger_initializer.rb index 392b319125..4e66f4a0dc 100644 --- a/test/test_logger_initializer.rb +++ b/test/test_logger_initializer.rb @@ -5,11 +5,8 @@ class LoggerInitializerTest < ::Test::Unit::TestCase TMP_DIR = File.expand_path(File.dirname(__FILE__) + "/tmp/logger_initializer#{ENV['TEST_ENV_NUMBER']}") - teardown do - begin - FileUtils.rm_rf(TMP_DIR) - rescue => _ - end + setup do + FileUtils.rm_rf(TMP_DIR) rescue nil end test 'when path is given' do From 13051571610f85b410b9a6b3e00bc3faee3cdd87 Mon Sep 17 00:00:00 2001 From: Daijiro Fukuda Date: Wed, 15 Feb 2023 00:50:48 +0900 Subject: [PATCH 4/9] Test: Make sure LoggerInitializerTest doesn't change the global logger Signed-off-by: Daijiro Fukuda --- test/test_logger_initializer.rb | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/test/test_logger_initializer.rb b/test/test_logger_initializer.rb index 4e66f4a0dc..3f27e889ed 100644 --- a/test/test_logger_initializer.rb +++ b/test/test_logger_initializer.rb @@ -7,6 +7,11 @@ class LoggerInitializerTest < ::Test::Unit::TestCase setup do FileUtils.rm_rf(TMP_DIR) rescue nil + @stored_global_logger = $log + end + + teardown do + $log = @stored_global_logger end test 'when path is given' do From 83041eea89ed4752c0ec24bba5586ceece470da3 Mon Sep 17 00:00:00 2001 From: Daijiro Fukuda Date: Wed, 15 Feb 2023 09:17:21 +0900 Subject: [PATCH 5/9] Test: Add tests for rotate and reopening Signed-off-by: Daijiro Fukuda --- test/test_logger_initializer.rb | 82 +++++++++++++++++++++++++++++++++ 1 file changed, 82 insertions(+) diff --git a/test/test_logger_initializer.rb b/test/test_logger_initializer.rb index 3f27e889ed..aac27ef5d7 100644 --- a/test/test_logger_initializer.rb +++ b/test/test_logger_initializer.rb @@ -47,4 +47,86 @@ class LoggerInitializerTest < ::Test::Unit::TestCase assert_true File.exist?(TMP_DIR) assert_equal 0o777, (File.stat(TMP_DIR).mode & 0xFFF) end + + test 'rotate' do + assert { not File.exist?(TMP_DIR) } + + path = File.join(TMP_DIR, 'fluent.log') + logger = Fluent::Supervisor::LoggerInitializer.new(path, Fluent::Log::LEVEL_DEBUG, nil, nil, {}, log_rotate_age: 5, log_rotate_size: 500) + logger.init(:supervisor, 0) + begin + 10.times.each do + $log.info "This is test message. This is test message. This is test message." + end + ensure + $log.out.close + end + + assert { Dir.entries(TMP_DIR).size > 3 } # [".", "..", "logfile.log", ...] + end + + test 'rotate to max age' do + assert { not File.exist?(TMP_DIR) } + + path = File.join(TMP_DIR, 'fluent.log') + logger = Fluent::Supervisor::LoggerInitializer.new(path, Fluent::Log::LEVEL_DEBUG, nil, nil, {}, log_rotate_age: 5, log_rotate_size: 500) + logger.init(:supervisor, 0) + begin + 100.times.each do + $log.info "This is test message. This is test message. This is test message." + end + ensure + $log.out.close + end + + assert { Dir.entries(TMP_DIR).size == 7 } # [".", "..", "logfile.log", ...] + end + + test 'files for each process with rotate on Windows' do + omit "Only for Windows." unless Fluent.windows? + + assert { not File.exist?(TMP_DIR) } + + path = File.join(TMP_DIR, 'fluent.log') + logger = Fluent::Supervisor::LoggerInitializer.new(path, Fluent::Log::LEVEL_DEBUG, nil, nil, {}, log_rotate_age: 5) + logger.init(:supervisor, 0) + $log.out.close + + logger = Fluent::Supervisor::LoggerInitializer.new(path, Fluent::Log::LEVEL_DEBUG, nil, nil, {}, log_rotate_age: 5) + logger.init(:worker0, 0) + $log.out.close + + logger = Fluent::Supervisor::LoggerInitializer.new(path, Fluent::Log::LEVEL_DEBUG, nil, nil, {}, log_rotate_age: 5) + logger.init(:workers, 1) + $log.out.close + + assert { Dir.entries(TMP_DIR).size == 5 } # [".", "..", "logfile.log", ...] + end + + test 'reopen!' do + assert { not File.exist?(TMP_DIR) } + + path = File.join(TMP_DIR, 'fluent.log') + logger = Fluent::Supervisor::LoggerInitializer.new(path, Fluent::Log::LEVEL_DEBUG, nil, nil, {}) + logger.init(:supervisor, 0) + message = "This is test message." + $log.info message + logger.reopen! + $log.info message + $log.out.close + + assert { File.read(path).lines.select{ |line| line.include?(message) }.size == 2 } + end + + test 'reopen! with rotate reopens the same file' do + assert { not File.exist?(TMP_DIR) } + + path = File.join(TMP_DIR, 'fluent.log') + logger = Fluent::Supervisor::LoggerInitializer.new(path, Fluent::Log::LEVEL_DEBUG, nil, nil, {}, log_rotate_age: 5) + logger.init(:supervisor, 0) + logger.reopen! + $log.out.close + + assert { Dir.entries(TMP_DIR).size == 3 } # [".", "..", "logfile.log", ...] + end end From 6107d009f035321eaf9f61a1012a180ae730064a Mon Sep 17 00:00:00 2001 From: Daijiro Fukuda Date: Wed, 15 Feb 2023 09:19:00 +0900 Subject: [PATCH 6/9] Test: Refactor LoggerInitializerTest Signed-off-by: Daijiro Fukuda --- test/test_logger_initializer.rb | 11 ++++++----- 1 file changed, 6 insertions(+), 5 deletions(-) diff --git a/test/test_logger_initializer.rb b/test/test_logger_initializer.rb index aac27ef5d7..dcca2f1411 100644 --- a/test/test_logger_initializer.rb +++ b/test/test_logger_initializer.rb @@ -15,8 +15,9 @@ class LoggerInitializerTest < ::Test::Unit::TestCase end test 'when path is given' do - path = File.join(TMP_DIR, 'fluent_with_path.log') + assert { not File.exist?(TMP_DIR) } + path = File.join(TMP_DIR, 'fluent_with_path.log') assert_false File.exist?(TMP_DIR) logger = Fluent::Supervisor::LoggerInitializer.new(path, Fluent::Log::LEVEL_DEBUG, nil, nil, {}) mock.proxy(File).chmod(0o777, TMP_DIR).never @@ -26,15 +27,15 @@ class LoggerInitializerTest < ::Test::Unit::TestCase end $log.out.close - assert_true File.exist?(TMP_DIR) + assert { File.exist?(TMP_DIR) } end test 'apply_options with log_dir_perm' do omit "NTFS doesn't support UNIX like permissions" if Fluent.windows? - path = File.join(TMP_DIR, 'fluent_with_path.log') + assert { not File.exist?(TMP_DIR) } - assert_false File.exist?(TMP_DIR) + path = File.join(TMP_DIR, 'fluent_with_path.log') logger = Fluent::Supervisor::LoggerInitializer.new(path, Fluent::Log::LEVEL_DEBUG, nil, nil, {}) mock.proxy(File).chmod(0o777, TMP_DIR).once @@ -44,7 +45,7 @@ class LoggerInitializerTest < ::Test::Unit::TestCase logger.apply_options(log_dir_perm: 0o777) $log.out.close - assert_true File.exist?(TMP_DIR) + assert { File.exist?(TMP_DIR) } assert_equal 0o777, (File.stat(TMP_DIR).mode & 0xFFF) end From 0d9581c7d041044c7dd8cd021402be6f2fc33351 Mon Sep 17 00:00:00 2001 From: Daijiro Fukuda Date: Wed, 15 Feb 2023 15:00:38 +0900 Subject: [PATCH 7/9] Test: Remove needless code Signed-off-by: Daijiro Fukuda --- test/test_logger_initializer.rb | 1 - 1 file changed, 1 deletion(-) diff --git a/test/test_logger_initializer.rb b/test/test_logger_initializer.rb index dcca2f1411..e1d97b1ac3 100644 --- a/test/test_logger_initializer.rb +++ b/test/test_logger_initializer.rb @@ -18,7 +18,6 @@ class LoggerInitializerTest < ::Test::Unit::TestCase assert { not File.exist?(TMP_DIR) } path = File.join(TMP_DIR, 'fluent_with_path.log') - assert_false File.exist?(TMP_DIR) logger = Fluent::Supervisor::LoggerInitializer.new(path, Fluent::Log::LEVEL_DEBUG, nil, nil, {}) mock.proxy(File).chmod(0o777, TMP_DIR).never From ade48570b0020745088f269248399f009b5782fa Mon Sep 17 00:00:00 2001 From: Daijiro Fukuda Date: Wed, 15 Feb 2023 16:16:13 +0900 Subject: [PATCH 8/9] Test: Make sure not to leave tmp files Signed-off-by: Daijiro Fukuda --- test/test_logger_initializer.rb | 84 ++++++++++++++------------------- 1 file changed, 36 insertions(+), 48 deletions(-) diff --git a/test/test_logger_initializer.rb b/test/test_logger_initializer.rb index e1d97b1ac3..149b397ce4 100644 --- a/test/test_logger_initializer.rb +++ b/test/test_logger_initializer.rb @@ -1,42 +1,40 @@ require_relative 'helper' require 'fluent/supervisor' require 'fileutils' +require 'pathname' class LoggerInitializerTest < ::Test::Unit::TestCase - TMP_DIR = File.expand_path(File.dirname(__FILE__) + "/tmp/logger_initializer#{ENV['TEST_ENV_NUMBER']}") - - setup do - FileUtils.rm_rf(TMP_DIR) rescue nil + def setup @stored_global_logger = $log - end - - teardown do - $log = @stored_global_logger + Dir.mktmpdir do |tmp_dir| + begin + @tmp_dir = Pathname(tmp_dir) + yield + ensure + $log = @stored_global_logger + end + end end test 'when path is given' do - assert { not File.exist?(TMP_DIR) } - - path = File.join(TMP_DIR, 'fluent_with_path.log') - logger = Fluent::Supervisor::LoggerInitializer.new(path, Fluent::Log::LEVEL_DEBUG, nil, nil, {}) - mock.proxy(File).chmod(0o777, TMP_DIR).never + path = @tmp_dir + 'log' + 'fluent_with_path.log' + logger = Fluent::Supervisor::LoggerInitializer.new(path.to_s, Fluent::Log::LEVEL_DEBUG, nil, nil, {}) + mock.proxy(File).chmod(0o777, path.parent.to_s).never assert_nothing_raised do logger.init(:supervisor, 0) end $log.out.close - assert { File.exist?(TMP_DIR) } + assert { path.parent.exist? } end test 'apply_options with log_dir_perm' do omit "NTFS doesn't support UNIX like permissions" if Fluent.windows? - assert { not File.exist?(TMP_DIR) } - - path = File.join(TMP_DIR, 'fluent_with_path.log') - logger = Fluent::Supervisor::LoggerInitializer.new(path, Fluent::Log::LEVEL_DEBUG, nil, nil, {}) - mock.proxy(File).chmod(0o777, TMP_DIR).once + path = @tmp_dir + 'log' + 'fluent_with_path.log' + logger = Fluent::Supervisor::LoggerInitializer.new(path.to_s, Fluent::Log::LEVEL_DEBUG, nil, nil, {}) + mock.proxy(File).chmod(0o777, path.parent.to_s).once assert_nothing_raised do logger.init(:supervisor, 0) @@ -44,15 +42,13 @@ class LoggerInitializerTest < ::Test::Unit::TestCase logger.apply_options(log_dir_perm: 0o777) $log.out.close - assert { File.exist?(TMP_DIR) } - assert_equal 0o777, (File.stat(TMP_DIR).mode & 0xFFF) + assert { path.parent.exist? } + assert_equal 0o777, (File.stat(path.parent).mode & 0xFFF) end test 'rotate' do - assert { not File.exist?(TMP_DIR) } - - path = File.join(TMP_DIR, 'fluent.log') - logger = Fluent::Supervisor::LoggerInitializer.new(path, Fluent::Log::LEVEL_DEBUG, nil, nil, {}, log_rotate_age: 5, log_rotate_size: 500) + path = @tmp_dir + 'log' + 'fluent.log' + logger = Fluent::Supervisor::LoggerInitializer.new(path.to_s, Fluent::Log::LEVEL_DEBUG, nil, nil, {}, log_rotate_age: 5, log_rotate_size: 500) logger.init(:supervisor, 0) begin 10.times.each do @@ -62,14 +58,12 @@ class LoggerInitializerTest < ::Test::Unit::TestCase $log.out.close end - assert { Dir.entries(TMP_DIR).size > 3 } # [".", "..", "logfile.log", ...] + assert { path.parent.entries.size > 3 } # [".", "..", "logfile.log", ...] end test 'rotate to max age' do - assert { not File.exist?(TMP_DIR) } - - path = File.join(TMP_DIR, 'fluent.log') - logger = Fluent::Supervisor::LoggerInitializer.new(path, Fluent::Log::LEVEL_DEBUG, nil, nil, {}, log_rotate_age: 5, log_rotate_size: 500) + path = @tmp_dir + 'log' + 'fluent.log' + logger = Fluent::Supervisor::LoggerInitializer.new(path.to_s, Fluent::Log::LEVEL_DEBUG, nil, nil, {}, log_rotate_age: 5, log_rotate_size: 500) logger.init(:supervisor, 0) begin 100.times.each do @@ -79,35 +73,31 @@ class LoggerInitializerTest < ::Test::Unit::TestCase $log.out.close end - assert { Dir.entries(TMP_DIR).size == 7 } # [".", "..", "logfile.log", ...] + assert { path.parent.entries.size == 7 } # [".", "..", "logfile.log", ...] end test 'files for each process with rotate on Windows' do omit "Only for Windows." unless Fluent.windows? - assert { not File.exist?(TMP_DIR) } - - path = File.join(TMP_DIR, 'fluent.log') - logger = Fluent::Supervisor::LoggerInitializer.new(path, Fluent::Log::LEVEL_DEBUG, nil, nil, {}, log_rotate_age: 5) + path = @tmp_dir + 'log' + 'fluent.log' + logger = Fluent::Supervisor::LoggerInitializer.new(path.to_s, Fluent::Log::LEVEL_DEBUG, nil, nil, {}, log_rotate_age: 5) logger.init(:supervisor, 0) $log.out.close - logger = Fluent::Supervisor::LoggerInitializer.new(path, Fluent::Log::LEVEL_DEBUG, nil, nil, {}, log_rotate_age: 5) + logger = Fluent::Supervisor::LoggerInitializer.new(path.to_s, Fluent::Log::LEVEL_DEBUG, nil, nil, {}, log_rotate_age: 5) logger.init(:worker0, 0) $log.out.close - logger = Fluent::Supervisor::LoggerInitializer.new(path, Fluent::Log::LEVEL_DEBUG, nil, nil, {}, log_rotate_age: 5) + logger = Fluent::Supervisor::LoggerInitializer.new(path.to_s, Fluent::Log::LEVEL_DEBUG, nil, nil, {}, log_rotate_age: 5) logger.init(:workers, 1) $log.out.close - assert { Dir.entries(TMP_DIR).size == 5 } # [".", "..", "logfile.log", ...] + assert { path.parent.entries.size == 5 } # [".", "..", "logfile.log", ...] end test 'reopen!' do - assert { not File.exist?(TMP_DIR) } - - path = File.join(TMP_DIR, 'fluent.log') - logger = Fluent::Supervisor::LoggerInitializer.new(path, Fluent::Log::LEVEL_DEBUG, nil, nil, {}) + path = @tmp_dir + 'log' + 'fluent.log' + logger = Fluent::Supervisor::LoggerInitializer.new(path.to_s, Fluent::Log::LEVEL_DEBUG, nil, nil, {}) logger.init(:supervisor, 0) message = "This is test message." $log.info message @@ -115,18 +105,16 @@ class LoggerInitializerTest < ::Test::Unit::TestCase $log.info message $log.out.close - assert { File.read(path).lines.select{ |line| line.include?(message) }.size == 2 } + assert { path.read.lines.select{ |line| line.include?(message) }.size == 2 } end test 'reopen! with rotate reopens the same file' do - assert { not File.exist?(TMP_DIR) } - - path = File.join(TMP_DIR, 'fluent.log') - logger = Fluent::Supervisor::LoggerInitializer.new(path, Fluent::Log::LEVEL_DEBUG, nil, nil, {}, log_rotate_age: 5) + path = @tmp_dir + 'log' + 'fluent.log' + logger = Fluent::Supervisor::LoggerInitializer.new(path.to_s, Fluent::Log::LEVEL_DEBUG, nil, nil, {}, log_rotate_age: 5) logger.init(:supervisor, 0) logger.reopen! $log.out.close - assert { Dir.entries(TMP_DIR).size == 3 } # [".", "..", "logfile.log", ...] + assert { path.parent.entries.size == 3 } # [".", "..", "logfile.log", ...] end end From 60c94ad0edbdae1832750558cbcfc7833dce5e11 Mon Sep 17 00:00:00 2001 From: Daijiro Fukuda Date: Thu, 16 Feb 2023 18:00:48 +0900 Subject: [PATCH 9/9] Test: Refactor logic of recovering global logger Signed-off-by: Daijiro Fukuda --- test/test_logger_initializer.rb | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/test/test_logger_initializer.rb b/test/test_logger_initializer.rb index 149b397ce4..a476841010 100644 --- a/test/test_logger_initializer.rb +++ b/test/test_logger_initializer.rb @@ -7,15 +7,15 @@ class LoggerInitializerTest < ::Test::Unit::TestCase def setup @stored_global_logger = $log Dir.mktmpdir do |tmp_dir| - begin - @tmp_dir = Pathname(tmp_dir) - yield - ensure - $log = @stored_global_logger - end + @tmp_dir = Pathname(tmp_dir) + yield end end + def teardown + $log = @stored_global_logger + end + test 'when path is given' do path = @tmp_dir + 'log' + 'fluent_with_path.log' logger = Fluent::Supervisor::LoggerInitializer.new(path.to_s, Fluent::Log::LEVEL_DEBUG, nil, nil, {})