Windows: Fix a bug that the wrong log file is reopened with log rotate setting when flushing or graceful reloading

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?

test/test_logger_initializer.rb

@@ -1,46 +1,120 @@
 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']}")
-
-  teardown do
-    begin
-      FileUtils.rm_rf(TMP_DIR)
-    rescue => _
+  def setup
+    @stored_global_logger = $log
+    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
-    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
+    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_true 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?
 
-    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).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)
     end
-
     logger.apply_options(log_dir_perm: 0o777)
-    assert_true File.exist?(TMP_DIR)
-    assert_equal 0o777, (File.stat(TMP_DIR).mode & 0xFFF)
+    $log.out.close
+
+    assert { path.parent.exist? }
+    assert_equal 0o777, (File.stat(path.parent).mode & 0xFFF)
+  end
+
+  test 'rotate' do
+    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
+        $log.info "This is test message. This is test message. This is test message."
+      end
+    ensure
+      $log.out.close
+    end
+
+    assert { path.parent.entries.size > 3 } # [".", "..", "logfile.log", ...]
+  end
+
+  test 'rotate to max age' do
+    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
+        $log.info "This is test message. This is test message. This is test message."
+      end
+    ensure
+      $log.out.close
+    end
+
+    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?
+
+    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.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.to_s, Fluent::Log::LEVEL_DEBUG, nil, nil, {}, log_rotate_age: 5)
+    logger.init(:workers, 1)
+    $log.out.close
+
+    assert { path.parent.entries.size == 5 } # [".", "..", "logfile.log", ...]
+  end
+
+  test 'reopen!' do
+    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
+    logger.reopen!
+    $log.info message
+    $log.out.close
+
+    assert { path.read.lines.select{ |line| line.include?(message) }.size == 2 }
+  end
+
+  test 'reopen! with rotate reopens the same file' do
+    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 { path.parent.entries.size == 3 } # [".", "..", "logfile.log", ...]
   end
 end