Enable log rotate for log (#1235)

* Add two arguments `--log-rotate-age` and `--log-rotate-size`

* Pass `log_rotate_age` and `log_rotate_size` option to `ServerEngine::DaemonLogger`

* Add logdevio tests

* Fix failed tests

* Use strings as a constant variable and specify a rescue type

* Use a keyword argument to add optoins.

* Use a timezone helper method

* Add a test to assert rotate size

* SIZE -> BYTES

lib/fluent/command/fluentd.rb

@@ -81,6 +81,23 @@
   opts[:log_path] = s
 }
 
+ROTATE_AGE = %w(daily weekly monthly)
+op.on('--log-rotate-age AGE', 'generations to keep rotated log files') {|age|
+  if ROTATE_AGE.include?(age)
+    opts[:log_rotate_age] = age
+  else
+    begin
+      opts[:log_rotate_age] = Integer(age)
+    rescue TypeError
+      usage "log-rotate-age should be #{rotate_ages.join(', ')} or a number"
+    end
+  end
+}
+
+op.on('--log-rotate-size BYTES', 'sets the byte size to rotate log files') {|s|
+  opts[:log_rotate_size] = s.to_i
+}
+
 op.on('-i', '--inline-config CONFIG_STRING', "inline config which is appended to the config file on-the-fly") {|s|
   opts[:inline_config] = s
 }
@@ -270,4 +287,3 @@
 else
   Fluent::Supervisor.new(opts).run_worker
 end
-

lib/fluent/log.rb

@@ -15,6 +15,7 @@
 #
 
 require 'forwardable'
+require 'logger'
 
 module Fluent
   class Log
@@ -442,4 +443,32 @@ def terminate
       @log.reset
     end
   end
+
+  # This class delegetes some methods which are used in `Fluent::Logger` to a instance variable(`dev`) in `Logger::LogDevice` class
+  # https://github.com/ruby/ruby/blob/7b2d47132ff8ee950b0f978ab772dee868d9f1b0/lib/logger.rb#L661
+  class LogDeviceIO < Logger::LogDevice
+    def flush
+      if @dev.respond_to?(:flush)
+        @dev.flush
+      else
+        super
+      end
+    end
+
+    def tty?
+      if @dev.respond_to?(:tty?)
+        @dev.tty?
+      else
+        super
+      end
+    end
+
+    def sync=(v)
+      if @dev.respond_to?(:sync=)
+        @dev.sync = v
+      else
+        super
+      end
+    end
+  end
 end

lib/fluent/supervisor.rb

@@ -230,11 +230,17 @@ def self.load_config(path, params = {})
       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']
       rpc_endpoint = system_config.rpc_endpoint
       enable_get_dump = system_config.enable_get_dump
 
       log_opts = {suppress_repeated_stacktrace: suppress_repeated_stacktrace}
-      logger_initializer = Supervisor::LoggerInitializer.new(log_path, log_level, chuser, chgroup, log_opts)
+      logger_initializer = Supervisor::LoggerInitializer.new(
+        log_path, log_level, chuser, chgroup, log_opts,
+        log_rotate_age: log_rotate_age,
+        log_rotate_size: log_rotate_size
+      )
       # this #init sets initialized logger to $log
       logger_initializer.init
       logger = $log
@@ -295,42 +301,48 @@ def self.load_config(path, params = {})
     end
 
     class LoggerInitializer
-      def initialize(path, level, chuser, chgroup, opts)
+      def initialize(path, level, chuser, chgroup, opts, log_rotate_age: nil, log_rotate_size: nil)
         @path = path
         @level = level
         @chuser = chuser
         @chgroup = chgroup
         @opts = opts
+        @log_rotate_age = log_rotate_age
+        @log_rotate_size = log_rotate_size
       end
 
       def init
         if @path && @path != "-"
-          @io = File.open(@path, "a")
+          @logdev = if @log_rotate_age || @log_rotate_size
+                     Fluent::LogDeviceIO.new(@path, shift_age: @log_rotate_age, shift_size: @log_rotate_size)
+                   else
+                     File.open(@path, "a")
+                   end
           if @chuser || @chgroup
             chuid = @chuser ? ServerEngine::Privilege.get_etc_passwd(@chuser).uid : nil
             chgid = @chgroup ? ServerEngine::Privilege.get_etc_group(@chgroup).gid : nil
             File.chown(chuid, chgid, @path)
           end
         else
-          @io = STDOUT
+          @logdev = STDOUT
         end
 
         dl_opts = {}
         # subtract 1 to match serverengine daemon logger side logging severity.
         dl_opts[:log_level] = @level - 1
-        logger = ServerEngine::DaemonLogger.new(@io, dl_opts)
+        logger = ServerEngine::DaemonLogger.new(@logdev, dl_opts)
         $log = Fluent::Log.new(logger, @opts)
         $log.enable_color(false) if @path
         $log.enable_debug if @level <= Fluent::Log::LEVEL_DEBUG
       end
 
       def stdout?
-        @io == STDOUT
+        @logdev == STDOUT
       end
 
       def reopen!
         if @path && @path != "-"
-          @io.reopen(@path, "a")
+          @logdev.reopen(@path, "a")
         end
         self
       end
@@ -381,14 +393,20 @@ def initialize(opt)
       @process_name = nil
 
       @log_level = opt[:log_level]
+      @log_rotate_age = opt[:log_rotate_age]
+      @log_rotate_size = opt[:log_rotate_size]
       @suppress_interval = opt[:suppress_interval]
       @suppress_config_dump = opt[:suppress_config_dump]
       @without_source = opt[:without_source]
       @signame = opt[:signame]
 
       @suppress_repeated_stacktrace = opt[:suppress_repeated_stacktrace]
       log_opts = {suppress_repeated_stacktrace: @suppress_repeated_stacktrace}
-      @log = LoggerInitializer.new(@log_path, @log_level, @chuser, @chgroup, log_opts)
+      @log = LoggerInitializer.new(
+        @log_path, @log_level, @chuser, @chgroup, log_opts,
+        log_rotate_age: @log_rotate_age,
+        log_rotate_size: @log_rotate_size
+      )
       @finished = false
     end
 
@@ -512,6 +530,8 @@ def supervise
       params['inline_config'] = @inline_config
       params['log_path'] = @log_path
       params['log_level'] = @log_level
+      params['log_rotate_age'] = @log_rotate_age
+      params['log_rotate_size'] = @log_rotate_size
       params['chuser'] = @chuser
       params['chgroup'] = @chgroup
       params['use_v1_config'] = @use_v1_config

test/test_log.rb

@@ -2,9 +2,14 @@
 require 'fluent/engine'
 require 'fluent/log'
 require 'timecop'
+require 'logger'
 
 class LogTest < Test::Unit::TestCase
+  TMP_DIR = File.expand_path(File.dirname(__FILE__) + "/tmp/log/#{ENV['TEST_ENV_NUMBER']}")
+
   def setup
+    FileUtils.rm_rf(TMP_DIR)
+    FileUtils.mkdir_p(TMP_DIR)
     @log_device = Fluent::Test::DummyLogDevice.new
     @timestamp = Time.parse("2016-04-21 11:58:41 +0900")
     @timestamp_str = @timestamp.strftime("%Y-%m-%d %H:%M:%S %z")
@@ -404,6 +409,84 @@ def test_level_reload
     # check fluentd log side level is also changed
     assert_equal(Fluent::Log::LEVEL_DEBUG, log.level)
   end
+
+  DAY_SEC = 60 * 60 * 24
+  data(
+    rotate_daily_age: ['daily', 100000, DAY_SEC + 1],
+    rotate_weekly_age: ['weekly', 100000, DAY_SEC * 7 + 1],
+    rotate_monthly_age: ['monthly', 100000, DAY_SEC * 31 + 1],
+    rotate_size: [1, 100, 0, '0'],
+  )
+  def test_log_with_logdevio(expected)
+    with_timezone('utc') do
+      @timestamp = Time.parse("2016-04-21 00:00:00 +0000")
+      @timestamp_str = @timestamp.strftime("%Y-%m-%d %H:%M:%S %z")
+      Timecop.freeze(@timestamp)
+
+      rotate_age, rotate_size, travel_term = expected
+      path = "#{TMP_DIR}/log-dev-io-#{rotate_size}-#{rotate_age}"
+
+      logdev = Fluent::LogDeviceIO.new(path, shift_age: rotate_age, shift_size: rotate_size)
+      logger = ServerEngine::DaemonLogger.new(logdev)
+      log = Fluent::Log.new(logger)
+
+      msg = 'a' * 101
+      log.info msg
+      assert_match msg, File.read(path)
+
+      Timecop.freeze(@timestamp + travel_term)
+
+      msg2 = 'b' * 101
+      log.info msg2
+      c = File.read(path)
+
+      assert_match msg2, c
+      assert_not_equal msg, c
+    end
+  end
+
+  def test_log_rotates_specifed_size_with_logdevio
+    with_timezone('utc') do
+      rotate_age = 2
+      rotate_size = 100
+      path = "#{TMP_DIR}/log-dev-io-#{rotate_size}-#{rotate_age}"
+      path0 = path + '.0'
+      path1 = path + '.1'
+
+      logdev = Fluent::LogDeviceIO.new(path, shift_age: rotate_age, shift_size: rotate_size)
+      logger = ServerEngine::DaemonLogger.new(logdev)
+      log = Fluent::Log.new(logger)
+
+      msg = 'a' * 101
+      log.info msg
+      assert_match msg, File.read(path)
+      assert_true File.exist?(path)
+      assert_true !File.exist?(path0)
+      assert_true !File.exist?(path1)
+
+      # create log.0
+      msg2 = 'b' * 101
+      log.info msg2
+      c = File.read(path)
+      c0 = File.read(path0)
+      assert_match msg2, c
+      assert_match msg, c0
+      assert_true File.exist?(path)
+      assert_true File.exist?(path0)
+      assert_true !File.exist?(path1)
+
+      # rotate
+      msg3 = 'c' * 101
+      log.info msg3
+      c = File.read(path)
+      c0 = File.read(path0)
+      assert_match msg3, c
+      assert_match msg2, c0
+      assert_true File.exist?(path)
+      assert_true File.exist?(path0)
+      assert_true !File.exist?(path1)
+    end
+  end
 end
 
 class PluginLoggerTest < Test::Unit::TestCase
@@ -570,3 +653,41 @@ def test_terminate
     plugin.terminate
   end
 end
+
+class LogDeviceIOTest < Test::Unit::TestCase
+  test 'flush' do
+    io = StringIO.new
+    logdev = Fluent::LogDeviceIO.new(io)
+    assert_equal io, logdev.flush
+
+    io.instance_eval { undef :flush }
+    logdev = Fluent::LogDeviceIO.new(io)
+    assert_raise NoMethodError do
+      logdev.flush
+    end
+  end
+
+  test 'tty?' do
+    io = StringIO.new
+    logdev = Fluent::LogDeviceIO.new(io)
+    assert_equal io.tty?, logdev.tty?
+
+    io.instance_eval { undef :tty? }
+    logdev = Fluent::LogDeviceIO.new(io)
+    assert_raise NoMethodError do
+      logdev.tty?
+    end
+  end
+
+  test 'sync=' do
+    io = StringIO.new
+    logdev = Fluent::LogDeviceIO.new(io)
+    assert_true logdev.sync = true
+
+    io.instance_eval { undef :sync= }
+    logdev = Fluent::LogDeviceIO.new(io)
+    assert_raise NoMethodError do
+      logdev.sync = true
+    end
+  end
+end

test/test_supervisor.rb

@@ -14,10 +14,11 @@ class SupervisorTest < ::Test::Unit::TestCase
   include ServerModule
   include WorkerModule
 
-  TMP_DIR = File.dirname(__FILE__) + "/tmp/config#{ENV['TEST_ENV_NUMBER']}"
+  TMP_DIR = File.expand_path(File.dirname(__FILE__) + "/tmp/supervisor#{ENV['TEST_ENV_NUMBER']}")
 
   def setup
-    FileUtils.mkdir_p('test/tmp/supervisor')
+    FileUtils.rm_rf(TMP_DIR)
+    FileUtils.mkdir_p(TMP_DIR)
   end
 
   def write_config(path, data)
@@ -319,6 +320,28 @@ def test_logger
     # test that DamonLogger#level= overwrites Fluent.log#level
     logger.level = 'debug'
     assert_equal Fluent::Log::LEVEL_DEBUG, $log.level
+
+    assert_equal 5, logger.instance_variable_get(:@rotate_age)
+    assert_equal 1048576, logger.instance_variable_get(:@rotate_size)
+  end
+
+  data(
+    daily_age: 'daily',
+    weekly_age: 'weekly',
+    monthly_age: 'monthly',
+    integer_age: 2,
+  )
+  def test_logger_with_rotate_age_and_rotate_size(rotate_age)
+    opts = Fluent::Supervisor.default_options.merge(
+      log_path: "#{TMP_DIR}/test", log_rotate_age: rotate_age, log_rotate_size: 10
+    )
+    sv = Fluent::Supervisor.new(opts)
+    log = sv.instance_variable_get(:@log)
+    log.init
+
+    assert_equal Fluent::LogDeviceIO, $log.out.class
+    assert_equal rotate_age, $log.out.instance_variable_get(:@shift_age)
+    assert_equal 10, $log.out.instance_variable_get(:@shift_size)
   end
 
   def create_debug_dummy_logger