From cf85d042d8f570377f7bd82bb62f5404128bc5c6 Mon Sep 17 00:00:00 2001 From: ganmacs Date: Tue, 13 Sep 2016 15:32:08 +0900 Subject: [PATCH 1/9] Add two arguments `--log-rotate-age` and `--log-rotate-size` --- lib/fluent/command/fluentd.rb | 18 +++++++++++++++++- 1 file changed, 17 insertions(+), 1 deletion(-) diff --git a/lib/fluent/command/fluentd.rb b/lib/fluent/command/fluentd.rb index e8cec4bd3f..2242cbdb95 100644 --- a/lib/fluent/command/fluentd.rb +++ b/lib/fluent/command/fluentd.rb @@ -81,6 +81,23 @@ opts[:log_path] = s } +op.on('--log-rotate-age AGE', 'generations to keep rotated log files') {|age| + rotate_ages = %w(daily weekly monthly) + if rotate_ages.include?(age) + opts[:log_rotate_age] = age + else + begin + opts[:log_rotate_age] = Integer(age) + rescue + usage "log-rotate-age should be #{rotate_ages.join(', ')} or a number" + end + end +} + +op.on('--log-rotate-size SIZE', 'sets the 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 - From c8575e57180eaaf6b16db15d5fd342da5300b932 Mon Sep 17 00:00:00 2001 From: ganmacs Date: Fri, 16 Sep 2016 10:58:05 +0900 Subject: [PATCH 2/9] Pass `log_rotate_age` and `log_rotate_size` option to `ServerEngine::DaemonLogger` --- lib/fluent/log.rb | 29 +++++++++++++++++++++++++++++ lib/fluent/supervisor.rb | 32 ++++++++++++++++++++++++-------- test/test_log.rb | 32 ++++++++++++++++++++++++++++++++ test/test_supervisor.rb | 24 ++++++++++++++++++++++++ 4 files changed, 109 insertions(+), 8 deletions(-) diff --git a/lib/fluent/log.rb b/lib/fluent/log.rb index 903a3882cd..524225d754 100644 --- a/lib/fluent/log.rb +++ b/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 diff --git a/lib/fluent/supervisor.rb b/lib/fluent/supervisor.rb index 7a722d94ed..518c47e1e8 100644 --- a/lib/fluent/supervisor.rb +++ b/lib/fluent/supervisor.rb @@ -230,11 +230,15 @@ 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_rotate_age, log_rotate_size, log_opts + ) # this #init sets initialized logger to $log logger_initializer.init logger = $log @@ -295,42 +299,48 @@ def self.load_config(path, params = {}) end class LoggerInitializer - def initialize(path, level, chuser, chgroup, opts) + def initialize(path, level, chuser, chgroup, log_rotate_age, log_rotate_size, opts) @path = path @level = level @chuser = chuser @chgroup = chgroup + @log_rotate_age = log_rotate_age + @log_rotate_size = log_rotate_size @opts = opts 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,6 +391,8 @@ 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] @@ -388,7 +400,9 @@ def initialize(opt) @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_rotate_age, @log_rotate_size, log_opts + ) @finished = false end @@ -512,6 +526,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 diff --git a/test/test_log.rb b/test/test_log.rb index a3f339fe21..823529afa2 100644 --- a/test/test_log.rb +++ b/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,33 @@ 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, '20160421'], + rotate_weekly_age: ['weekly', 100000, DAY_SEC * 7, '20160423'], + rotate_monthly_age: ['monthly', 100000, DAY_SEC * 31, '20160430'], + rotate_size: [1, 100, 0, '0'], + ) + def test_log_with_logdevio(expected) + rotate_age, rotate_size, travel_term, suffix = 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.travel(travel_term) + + msg2 = 'b' * 101 + log.info msg2 + assert_match msg2, File.read(path) + assert_match msg, File.read("#{path}.#{suffix}") + end end class PluginLoggerTest < Test::Unit::TestCase diff --git a/test/test_supervisor.rb b/test/test_supervisor.rb index 6fba0c3ad2..bc655b0912 100644 --- a/test/test_supervisor.rb +++ b/test/test_supervisor.rb @@ -18,6 +18,8 @@ class SupervisorTest < ::Test::Unit::TestCase 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 +321,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 From ae21535819ceecce271c67763c24742314c74d39 Mon Sep 17 00:00:00 2001 From: ganmacs Date: Fri, 16 Sep 2016 10:58:18 +0900 Subject: [PATCH 3/9] Add logdevio tests --- test/test_log.rb | 38 ++++++++++++++++++++++++++++++++++++++ 1 file changed, 38 insertions(+) diff --git a/test/test_log.rb b/test/test_log.rb index 823529afa2..489ff16db5 100644 --- a/test/test_log.rb +++ b/test/test_log.rb @@ -602,3 +602,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 From b4c61014295ac06f6017a94abd2137be190aacf7 Mon Sep 17 00:00:00 2001 From: ganmacs Date: Fri, 16 Sep 2016 16:22:21 +0900 Subject: [PATCH 4/9] Fix failed tests --- test/test_log.rb | 24 +++++++++++++++++------- test/test_supervisor.rb | 3 +-- 2 files changed, 18 insertions(+), 9 deletions(-) diff --git a/test/test_log.rb b/test/test_log.rb index 489ff16db5..925cec5a2b 100644 --- a/test/test_log.rb +++ b/test/test_log.rb @@ -412,13 +412,19 @@ def test_level_reload DAY_SEC = 60 * 60 * 24 data( - rotate_daily_age: ['daily', 100000, DAY_SEC, '20160421'], - rotate_weekly_age: ['weekly', 100000, DAY_SEC * 7, '20160423'], - rotate_monthly_age: ['monthly', 100000, DAY_SEC * 31, '20160430'], + 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) - rotate_age, rotate_size, travel_term, suffix = expected + old = ENV['TZ'] + ENV['TZ'] = 'utc' + @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) @@ -429,12 +435,16 @@ def test_log_with_logdevio(expected) log.info msg assert_match msg, File.read(path) - Timecop.travel(travel_term) + Timecop.freeze(@timestamp + travel_term) msg2 = 'b' * 101 log.info msg2 - assert_match msg2, File.read(path) - assert_match msg, File.read("#{path}.#{suffix}") + c = File.read(path) + + assert_match msg2, c + assert_not_equal msg, c + ensure + ENV['TZ'] = old end end diff --git a/test/test_supervisor.rb b/test/test_supervisor.rb index bc655b0912..0f803f1de0 100644 --- a/test/test_supervisor.rb +++ b/test/test_supervisor.rb @@ -14,10 +14,9 @@ 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 From 761be6d3d27af5a09ee77deb76d0fedf0c721bb8 Mon Sep 17 00:00:00 2001 From: ganmacs Date: Fri, 23 Sep 2016 10:49:54 +0900 Subject: [PATCH 5/9] Use strings as a constant variable and specify a rescue type --- lib/fluent/command/fluentd.rb | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/lib/fluent/command/fluentd.rb b/lib/fluent/command/fluentd.rb index 2242cbdb95..ab0460b2d5 100644 --- a/lib/fluent/command/fluentd.rb +++ b/lib/fluent/command/fluentd.rb @@ -81,14 +81,14 @@ opts[:log_path] = s } +ROTATE_AGE = %w(daily weekly monthly) op.on('--log-rotate-age AGE', 'generations to keep rotated log files') {|age| - rotate_ages = %w(daily weekly monthly) - if rotate_ages.include?(age) + if ROTATE_AGE.include?(age) opts[:log_rotate_age] = age else begin opts[:log_rotate_age] = Integer(age) - rescue + rescue TypeError usage "log-rotate-age should be #{rotate_ages.join(', ')} or a number" end end From 7846fa4af49d93a47ab824af52abeda22346dcdf Mon Sep 17 00:00:00 2001 From: ganmacs Date: Fri, 23 Sep 2016 10:50:53 +0900 Subject: [PATCH 6/9] Use a keyword argument to add optoins. --- lib/fluent/supervisor.rb | 12 ++++++++---- 1 file changed, 8 insertions(+), 4 deletions(-) diff --git a/lib/fluent/supervisor.rb b/lib/fluent/supervisor.rb index 518c47e1e8..98081e0855 100644 --- a/lib/fluent/supervisor.rb +++ b/lib/fluent/supervisor.rb @@ -237,7 +237,9 @@ def self.load_config(path, params = {}) log_opts = {suppress_repeated_stacktrace: suppress_repeated_stacktrace} logger_initializer = Supervisor::LoggerInitializer.new( - log_path, log_level, chuser, chgroup, log_rotate_age, log_rotate_size, log_opts + 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 @@ -299,14 +301,14 @@ def self.load_config(path, params = {}) end class LoggerInitializer - def initialize(path, level, chuser, chgroup, log_rotate_age, log_rotate_size, 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 - @opts = opts end def init @@ -401,7 +403,9 @@ def initialize(opt) @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_rotate_age, @log_rotate_size, log_opts + @log_path, @log_level, @chuser, @chgroup, log_opts, + log_rotate_age: @log_rotate_age, + log_rotate_size: @log_rotate_size ) @finished = false end From 4b86ef88112542315983d637cbb5c2f9e7e6cedc Mon Sep 17 00:00:00 2001 From: ganmacs Date: Fri, 23 Sep 2016 11:06:49 +0900 Subject: [PATCH 7/9] Use a timezone helper method --- test/test_log.rb | 42 +++++++++++++++++++++--------------------- 1 file changed, 21 insertions(+), 21 deletions(-) diff --git a/test/test_log.rb b/test/test_log.rb index 925cec5a2b..6d42680ed0 100644 --- a/test/test_log.rb +++ b/test/test_log.rb @@ -418,33 +418,33 @@ def test_level_reload rotate_size: [1, 100, 0, '0'], ) def test_log_with_logdevio(expected) - old = ENV['TZ'] - ENV['TZ'] = 'utc' - @timestamp = Time.parse("2016-04-21 00:00:00 +0000") - @timestamp_str = @timestamp.strftime("%Y-%m-%d %H:%M:%S %z") - Timecop.freeze(@timestamp) + 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}" + 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) + 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) - msg = 'a' * 101 - log.info msg - assert_match msg, File.read(path) + Timecop.freeze(@timestamp + travel_term) - Timecop.freeze(@timestamp + travel_term) + msg2 = 'b' * 101 + log.info msg2 + c = File.read(path) - msg2 = 'b' * 101 - log.info msg2 - c = File.read(path) + assert_match msg2, c + assert_not_equal msg, c + end + end - assert_match msg2, c - assert_not_equal msg, c - ensure - ENV['TZ'] = old end end From 7bf4ab42be90a976d5f08806707b080a91e9f700 Mon Sep 17 00:00:00 2001 From: ganmacs Date: Fri, 23 Sep 2016 11:07:11 +0900 Subject: [PATCH 8/9] Add a test to assert rotate size --- test/test_log.rb | 41 +++++++++++++++++++++++++++++++++++++++++ 1 file changed, 41 insertions(+) diff --git a/test/test_log.rb b/test/test_log.rb index 6d42680ed0..10d2ce9454 100644 --- a/test/test_log.rb +++ b/test/test_log.rb @@ -445,6 +445,47 @@ def test_log_with_logdevio(expected) 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 From b5513d1d03e1878e7c4c565f3aca82f99a91b3a0 Mon Sep 17 00:00:00 2001 From: ganmacs Date: Fri, 23 Sep 2016 14:29:36 +0900 Subject: [PATCH 9/9] SIZE -> BYTES --- lib/fluent/command/fluentd.rb | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/fluent/command/fluentd.rb b/lib/fluent/command/fluentd.rb index ab0460b2d5..5c11eab6a4 100644 --- a/lib/fluent/command/fluentd.rb +++ b/lib/fluent/command/fluentd.rb @@ -94,7 +94,7 @@ end } -op.on('--log-rotate-size SIZE', 'sets the size to rotate log files') {|s| +op.on('--log-rotate-size BYTES', 'sets the byte size to rotate log files') {|s| opts[:log_rotate_size] = s.to_i }