2014-02-21 02:04:25 -05:00
|
|
|
# coding: US-ASCII
|
2015-12-16 00:07:31 -05:00
|
|
|
# frozen_string_literal: false
|
2019-07-15 01:39:10 -04:00
|
|
|
require_relative 'helper'
|
2014-02-21 02:04:25 -05:00
|
|
|
require 'tempfile'
|
|
|
|
require 'tmpdir'
|
|
|
|
|
|
|
|
class TestLogDevice < Test::Unit::TestCase
|
|
|
|
class LogExcnRaiser
|
|
|
|
def write(*arg)
|
|
|
|
raise 'disk is full'
|
|
|
|
end
|
|
|
|
|
|
|
|
def close
|
|
|
|
end
|
|
|
|
|
|
|
|
def stat
|
|
|
|
Object.new
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
|
|
|
def setup
|
|
|
|
@tempfile = Tempfile.new("logger")
|
|
|
|
@tempfile.close
|
|
|
|
@filename = @tempfile.path
|
|
|
|
File.unlink(@filename)
|
|
|
|
end
|
|
|
|
|
|
|
|
def teardown
|
|
|
|
@tempfile.close(true)
|
|
|
|
end
|
|
|
|
|
|
|
|
def d(log, opt = {})
|
2019-09-06 16:37:31 -04:00
|
|
|
Logger::LogDevice.new(log, **opt)
|
2014-02-21 02:04:25 -05:00
|
|
|
end
|
|
|
|
|
|
|
|
def test_initialize
|
|
|
|
logdev = d(STDERR)
|
|
|
|
assert_equal(STDERR, logdev.dev)
|
|
|
|
assert_nil(logdev.filename)
|
2015-06-01 22:18:44 -04:00
|
|
|
assert_raise(TypeError) do
|
2014-02-21 02:04:25 -05:00
|
|
|
d(nil)
|
|
|
|
end
|
|
|
|
#
|
|
|
|
logdev = d(@filename)
|
|
|
|
begin
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.exist?(@filename)
|
|
|
|
assert_predicate(logdev.dev, :sync)
|
2019-06-04 18:07:26 -04:00
|
|
|
refute_predicate(logdev.dev, :binmode?)
|
2014-02-21 02:04:25 -05:00
|
|
|
assert_equal(@filename, logdev.filename)
|
|
|
|
logdev.write('hello')
|
|
|
|
ensure
|
|
|
|
logdev.close
|
|
|
|
end
|
2019-12-19 22:19:45 -05:00
|
|
|
# create logfile which is already exist.
|
2014-02-21 02:04:25 -05:00
|
|
|
logdev = d(@filename)
|
|
|
|
begin
|
2019-06-04 18:07:26 -04:00
|
|
|
assert_predicate(logdev.dev, :sync)
|
|
|
|
refute_predicate(logdev.dev, :binmode?)
|
2014-02-21 02:04:25 -05:00
|
|
|
logdev.write('world')
|
|
|
|
logfile = File.read(@filename)
|
|
|
|
assert_equal(2, logfile.split(/\n/).size)
|
|
|
|
assert_match(/^helloworld$/, logfile)
|
|
|
|
ensure
|
|
|
|
logdev.close
|
|
|
|
end
|
2019-05-16 20:35:21 -04:00
|
|
|
# logfile object with path
|
|
|
|
tempfile = Tempfile.new("logger")
|
|
|
|
tempfile.sync = true
|
|
|
|
logdev = d(tempfile)
|
|
|
|
begin
|
|
|
|
logdev.write('world')
|
|
|
|
logfile = File.read(tempfile.path)
|
|
|
|
assert_equal(1, logfile.split(/\n/).size)
|
|
|
|
assert_match(/^world$/, logfile)
|
|
|
|
assert_equal(tempfile.path, logdev.filename)
|
|
|
|
ensure
|
|
|
|
logdev.close
|
|
|
|
File.unlink(tempfile)
|
|
|
|
tempfile.close(true)
|
|
|
|
end
|
2014-02-21 02:04:25 -05:00
|
|
|
end
|
|
|
|
|
|
|
|
def test_write
|
|
|
|
r, w = IO.pipe
|
|
|
|
logdev = d(w)
|
|
|
|
logdev.write("msg2\n\n")
|
|
|
|
IO.select([r], nil, nil, 0.1)
|
|
|
|
w.close
|
|
|
|
msg = r.read
|
|
|
|
r.close
|
|
|
|
assert_equal("msg2\n\n", msg)
|
|
|
|
#
|
|
|
|
logdev = d(LogExcnRaiser.new)
|
|
|
|
class << (stderr = '')
|
2017-10-23 10:05:07 -04:00
|
|
|
alias write concat
|
2014-02-21 02:04:25 -05:00
|
|
|
end
|
|
|
|
$stderr, stderr = stderr, $stderr
|
|
|
|
begin
|
|
|
|
assert_nothing_raised do
|
|
|
|
logdev.write('hello')
|
|
|
|
end
|
|
|
|
ensure
|
|
|
|
logdev.close
|
|
|
|
$stderr, stderr = stderr, $stderr
|
|
|
|
end
|
|
|
|
assert_equal "log writing failed. disk is full\n", stderr
|
|
|
|
end
|
|
|
|
|
|
|
|
def test_close
|
|
|
|
r, w = IO.pipe
|
|
|
|
logdev = d(w)
|
|
|
|
logdev.write("msg2\n\n")
|
|
|
|
IO.select([r], nil, nil, 0.1)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_not_predicate(w, :closed?)
|
2014-02-21 02:04:25 -05:00
|
|
|
logdev.close
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_predicate(w, :closed?)
|
2014-02-21 02:04:25 -05:00
|
|
|
r.close
|
|
|
|
end
|
|
|
|
|
2015-11-17 08:58:57 -05:00
|
|
|
def test_reopen_io
|
|
|
|
logdev = d(STDERR)
|
|
|
|
old_dev = logdev.dev
|
|
|
|
logdev.reopen
|
|
|
|
assert_equal(STDERR, logdev.dev)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_not_predicate(old_dev, :closed?)
|
2015-11-17 08:58:57 -05:00
|
|
|
end
|
|
|
|
|
|
|
|
def test_reopen_io_by_io
|
|
|
|
logdev = d(STDERR)
|
|
|
|
old_dev = logdev.dev
|
|
|
|
logdev.reopen(STDOUT)
|
|
|
|
assert_equal(STDOUT, logdev.dev)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_not_predicate(old_dev, :closed?)
|
2015-11-17 08:58:57 -05:00
|
|
|
end
|
|
|
|
|
|
|
|
def test_reopen_io_by_file
|
|
|
|
logdev = d(STDERR)
|
|
|
|
old_dev = logdev.dev
|
|
|
|
logdev.reopen(@filename)
|
|
|
|
begin
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.exist?(@filename)
|
2015-11-17 08:58:57 -05:00
|
|
|
assert_equal(@filename, logdev.filename)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_not_predicate(old_dev, :closed?)
|
2015-11-17 08:58:57 -05:00
|
|
|
ensure
|
|
|
|
logdev.close
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
|
|
|
def test_reopen_file
|
|
|
|
logdev = d(@filename)
|
|
|
|
old_dev = logdev.dev
|
2015-11-17 19:53:14 -05:00
|
|
|
|
2015-11-17 08:58:57 -05:00
|
|
|
logdev.reopen
|
|
|
|
begin
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.exist?(@filename)
|
2015-11-17 08:58:57 -05:00
|
|
|
assert_equal(@filename, logdev.filename)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_predicate(old_dev, :closed?)
|
2015-11-17 08:58:57 -05:00
|
|
|
ensure
|
|
|
|
logdev.close
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
|
|
|
def test_reopen_file_by_io
|
|
|
|
logdev = d(@filename)
|
|
|
|
old_dev = logdev.dev
|
|
|
|
logdev.reopen(STDOUT)
|
|
|
|
assert_equal(STDOUT, logdev.dev)
|
|
|
|
assert_nil(logdev.filename)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_predicate(old_dev, :closed?)
|
2015-11-17 08:58:57 -05:00
|
|
|
end
|
|
|
|
|
|
|
|
def test_reopen_file_by_file
|
|
|
|
logdev = d(@filename)
|
|
|
|
old_dev = logdev.dev
|
2015-11-17 19:53:14 -05:00
|
|
|
|
|
|
|
tempfile2 = Tempfile.new("logger")
|
|
|
|
tempfile2.close
|
|
|
|
filename2 = tempfile2.path
|
|
|
|
File.unlink(filename2)
|
|
|
|
|
|
|
|
logdev.reopen(filename2)
|
2015-11-17 08:58:57 -05:00
|
|
|
begin
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.exist?(filename2)
|
2015-11-17 19:53:14 -05:00
|
|
|
assert_equal(filename2, logdev.filename)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_predicate(old_dev, :closed?)
|
2015-11-17 08:58:57 -05:00
|
|
|
ensure
|
|
|
|
logdev.close
|
2015-11-17 19:53:14 -05:00
|
|
|
tempfile2.close(true)
|
2015-11-17 08:58:57 -05:00
|
|
|
end
|
|
|
|
end
|
|
|
|
|
2014-02-21 02:04:25 -05:00
|
|
|
def test_shifting_size
|
|
|
|
tmpfile = Tempfile.new([File.basename(__FILE__, '.*'), '_1.log'])
|
|
|
|
logfile = tmpfile.path
|
|
|
|
logfile0 = logfile + '.0'
|
|
|
|
logfile1 = logfile + '.1'
|
|
|
|
logfile2 = logfile + '.2'
|
|
|
|
logfile3 = logfile + '.3'
|
|
|
|
tmpfile.close(true)
|
|
|
|
File.unlink(logfile) if File.exist?(logfile)
|
|
|
|
File.unlink(logfile0) if File.exist?(logfile0)
|
|
|
|
File.unlink(logfile1) if File.exist?(logfile1)
|
|
|
|
File.unlink(logfile2) if File.exist?(logfile2)
|
|
|
|
logger = Logger.new(logfile, 4, 100)
|
|
|
|
logger.error("0" * 15)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.exist?(logfile)
|
|
|
|
assert_file.not_exist?(logfile0)
|
2014-02-21 02:04:25 -05:00
|
|
|
logger.error("0" * 15)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.exist?(logfile0)
|
|
|
|
assert_file.not_exist?(logfile1)
|
2014-02-21 02:04:25 -05:00
|
|
|
logger.error("0" * 15)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.exist?(logfile1)
|
|
|
|
assert_file.not_exist?(logfile2)
|
2014-02-21 02:04:25 -05:00
|
|
|
logger.error("0" * 15)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.exist?(logfile2)
|
|
|
|
assert_file.not_exist?(logfile3)
|
2014-02-21 02:04:25 -05:00
|
|
|
logger.error("0" * 15)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.not_exist?(logfile3)
|
2014-02-21 02:04:25 -05:00
|
|
|
logger.error("0" * 15)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.not_exist?(logfile3)
|
2014-02-21 02:04:25 -05:00
|
|
|
logger.close
|
|
|
|
File.unlink(logfile)
|
|
|
|
File.unlink(logfile0)
|
|
|
|
File.unlink(logfile1)
|
|
|
|
File.unlink(logfile2)
|
|
|
|
|
|
|
|
tmpfile = Tempfile.new([File.basename(__FILE__, '.*'), '_2.log'])
|
|
|
|
logfile = tmpfile.path
|
|
|
|
logfile0 = logfile + '.0'
|
|
|
|
logfile1 = logfile + '.1'
|
|
|
|
logfile2 = logfile + '.2'
|
|
|
|
logfile3 = logfile + '.3'
|
|
|
|
tmpfile.close(true)
|
|
|
|
logger = Logger.new(logfile, 4, 150)
|
|
|
|
logger.error("0" * 15)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.exist?(logfile)
|
|
|
|
assert_file.not_exist?(logfile0)
|
2014-02-21 02:04:25 -05:00
|
|
|
logger.error("0" * 15)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.not_exist?(logfile0)
|
2014-02-21 02:04:25 -05:00
|
|
|
logger.error("0" * 15)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.exist?(logfile0)
|
|
|
|
assert_file.not_exist?(logfile1)
|
2014-02-21 02:04:25 -05:00
|
|
|
logger.error("0" * 15)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.not_exist?(logfile1)
|
2014-02-21 02:04:25 -05:00
|
|
|
logger.error("0" * 15)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.exist?(logfile1)
|
|
|
|
assert_file.not_exist?(logfile2)
|
2014-02-21 02:04:25 -05:00
|
|
|
logger.error("0" * 15)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.not_exist?(logfile2)
|
2014-02-21 02:04:25 -05:00
|
|
|
logger.error("0" * 15)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.exist?(logfile2)
|
|
|
|
assert_file.not_exist?(logfile3)
|
2014-02-21 02:04:25 -05:00
|
|
|
logger.error("0" * 15)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.not_exist?(logfile3)
|
2014-02-21 02:04:25 -05:00
|
|
|
logger.error("0" * 15)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.not_exist?(logfile3)
|
2014-02-21 02:04:25 -05:00
|
|
|
logger.error("0" * 15)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.not_exist?(logfile3)
|
2014-02-21 02:04:25 -05:00
|
|
|
logger.close
|
|
|
|
File.unlink(logfile)
|
|
|
|
File.unlink(logfile0)
|
|
|
|
File.unlink(logfile1)
|
|
|
|
File.unlink(logfile2)
|
|
|
|
end
|
|
|
|
|
|
|
|
def test_shifting_age_variants
|
|
|
|
logger = Logger.new(@filename, 'daily')
|
|
|
|
logger.info('daily')
|
|
|
|
logger.close
|
|
|
|
logger = Logger.new(@filename, 'weekly')
|
|
|
|
logger.info('weekly')
|
|
|
|
logger.close
|
|
|
|
logger = Logger.new(@filename, 'monthly')
|
|
|
|
logger.info('monthly')
|
|
|
|
logger.close
|
|
|
|
end
|
|
|
|
|
2019-10-14 21:08:10 -04:00
|
|
|
def test_invalid_shifting_age
|
2019-12-15 22:33:13 -05:00
|
|
|
assert_raise(ArgumentError) { Logger::Period.next_rotate_time(Time.now, 'invalid') }
|
2019-10-14 21:08:10 -04:00
|
|
|
assert_raise(ArgumentError) { Logger::Period.previous_period_end(Time.now, 'invalid') }
|
|
|
|
end
|
|
|
|
|
2014-02-21 02:04:25 -05:00
|
|
|
def test_shifting_age
|
|
|
|
yyyymmdd = Time.now.strftime("%Y%m%d")
|
|
|
|
filename1 = @filename + ".#{yyyymmdd}"
|
|
|
|
filename2 = @filename + ".#{yyyymmdd}.1"
|
|
|
|
filename3 = @filename + ".#{yyyymmdd}.2"
|
|
|
|
begin
|
|
|
|
logger = Logger.new(@filename, 'now')
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.exist?(@filename)
|
|
|
|
assert_file.not_exist?(filename1)
|
|
|
|
assert_file.not_exist?(filename2)
|
|
|
|
assert_file.not_exist?(filename3)
|
2014-02-21 02:04:25 -05:00
|
|
|
logger.info("0" * 15)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.exist?(@filename)
|
|
|
|
assert_file.exist?(filename1)
|
|
|
|
assert_file.not_exist?(filename2)
|
|
|
|
assert_file.not_exist?(filename3)
|
2014-02-21 02:04:25 -05:00
|
|
|
logger.warn("0" * 15)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.exist?(@filename)
|
|
|
|
assert_file.exist?(filename1)
|
|
|
|
assert_file.exist?(filename2)
|
|
|
|
assert_file.not_exist?(filename3)
|
2014-02-21 02:04:25 -05:00
|
|
|
logger.error("0" * 15)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.exist?(@filename)
|
|
|
|
assert_file.exist?(filename1)
|
|
|
|
assert_file.exist?(filename2)
|
|
|
|
assert_file.exist?(filename3)
|
2014-02-21 02:04:25 -05:00
|
|
|
ensure
|
|
|
|
logger.close if logger
|
|
|
|
[filename1, filename2, filename3].each do |filename|
|
|
|
|
File.unlink(filename) if File.exist?(filename)
|
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
2016-04-18 11:07:31 -04:00
|
|
|
def test_shifting_period_suffix
|
2016-04-18 11:54:45 -04:00
|
|
|
['%Y%m%d', '%Y-%m-%d', '%Y'].each do |format|
|
|
|
|
if format == '%Y%m%d' # default
|
|
|
|
logger = Logger.new(@filename, 'now', 1048576)
|
|
|
|
else # config
|
|
|
|
logger = Logger.new(@filename, 'now', 1048576, shift_period_suffix: format)
|
|
|
|
end
|
2016-04-18 11:07:31 -04:00
|
|
|
begin
|
|
|
|
yyyymmdd = Time.now.strftime(format)
|
|
|
|
filename1 = @filename + ".#{yyyymmdd}"
|
|
|
|
filename2 = @filename + ".#{yyyymmdd}.1"
|
|
|
|
filename3 = @filename + ".#{yyyymmdd}.2"
|
|
|
|
logger.info("0" * 15)
|
|
|
|
logger.info("0" * 15)
|
|
|
|
logger.info("0" * 15)
|
2016-04-19 00:14:38 -04:00
|
|
|
assert_file.exist?(@filename)
|
|
|
|
assert_file.exist?(filename1)
|
|
|
|
assert_file.exist?(filename2)
|
|
|
|
assert_file.exist?(filename3)
|
2016-04-18 11:07:31 -04:00
|
|
|
ensure
|
|
|
|
logger.close if logger
|
|
|
|
[filename1, filename2, filename3].each do |filename|
|
|
|
|
File.unlink(filename) if File.exist?(filename)
|
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
2014-02-21 02:04:25 -05:00
|
|
|
def test_shifting_size_in_multiprocess
|
|
|
|
tmpfile = Tempfile.new([File.basename(__FILE__, '.*'), '_1.log'])
|
|
|
|
logfile = tmpfile.path
|
|
|
|
logfile0 = logfile + '.0'
|
|
|
|
logfile1 = logfile + '.1'
|
|
|
|
logfile2 = logfile + '.2'
|
|
|
|
tmpfile.close(true)
|
|
|
|
File.unlink(logfile) if File.exist?(logfile)
|
|
|
|
File.unlink(logfile0) if File.exist?(logfile0)
|
|
|
|
File.unlink(logfile1) if File.exist?(logfile1)
|
|
|
|
File.unlink(logfile2) if File.exist?(logfile2)
|
|
|
|
begin
|
2016-11-16 01:59:41 -05:00
|
|
|
stderr = run_children(2, [logfile], "#{<<-"begin;"}\n#{<<-'end;'}")
|
|
|
|
begin;
|
2014-02-21 02:04:25 -05:00
|
|
|
logger = Logger.new(ARGV[0], 4, 10)
|
|
|
|
10.times do
|
|
|
|
logger.info '0' * 15
|
|
|
|
end
|
2016-11-16 01:59:41 -05:00
|
|
|
end;
|
2014-02-21 02:04:25 -05:00
|
|
|
assert_no_match(/log shifting failed/, stderr)
|
|
|
|
assert_no_match(/log writing failed/, stderr)
|
|
|
|
assert_no_match(/log rotation inter-process lock failed/, stderr)
|
|
|
|
ensure
|
|
|
|
File.unlink(logfile) if File.exist?(logfile)
|
|
|
|
File.unlink(logfile0) if File.exist?(logfile0)
|
|
|
|
File.unlink(logfile1) if File.exist?(logfile1)
|
|
|
|
File.unlink(logfile2) if File.exist?(logfile2)
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
|
|
|
def test_shifting_age_in_multiprocess
|
|
|
|
yyyymmdd = Time.now.strftime("%Y%m%d")
|
|
|
|
begin
|
2016-11-16 01:59:41 -05:00
|
|
|
stderr = run_children(2, [@filename], "#{<<-"begin;"}\n#{<<-'end;'}")
|
|
|
|
begin;
|
2014-02-21 02:04:25 -05:00
|
|
|
logger = Logger.new(ARGV[0], 'now')
|
|
|
|
10.times do
|
|
|
|
logger.info '0' * 15
|
|
|
|
end
|
2016-11-16 01:59:41 -05:00
|
|
|
end;
|
2014-02-21 02:04:25 -05:00
|
|
|
assert_no_match(/log shifting failed/, stderr)
|
|
|
|
assert_no_match(/log writing failed/, stderr)
|
|
|
|
assert_no_match(/log rotation inter-process lock failed/, stderr)
|
|
|
|
ensure
|
|
|
|
Dir.glob("#{@filename}.#{yyyymmdd}{,.[1-9]*}") do |filename|
|
|
|
|
File.unlink(filename) if File.exist?(filename)
|
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
|
|
|
def test_open_logfile_in_multiprocess
|
|
|
|
tmpfile = Tempfile.new([File.basename(__FILE__, '.*'), '_1.log'])
|
|
|
|
logfile = tmpfile.path
|
|
|
|
tmpfile.close(true)
|
|
|
|
begin
|
|
|
|
20.times do
|
2016-11-16 01:59:41 -05:00
|
|
|
run_children(2, [logfile], "#{<<-"begin;"}\n#{<<-'end;'}")
|
|
|
|
begin;
|
2014-02-21 02:04:25 -05:00
|
|
|
logfile = ARGV[0]
|
|
|
|
logdev = Logger::LogDevice.new(logfile)
|
|
|
|
logdev.send(:open_logfile, logfile)
|
2016-11-16 01:59:41 -05:00
|
|
|
end;
|
2014-02-21 02:04:25 -05:00
|
|
|
assert_equal(1, File.readlines(logfile).grep(/# Logfile created on/).size)
|
|
|
|
File.unlink(logfile)
|
|
|
|
end
|
|
|
|
ensure
|
|
|
|
File.unlink(logfile) if File.exist?(logfile)
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
|
|
|
def test_shifting_size_not_rotate_too_much
|
2014-05-29 09:12:38 -04:00
|
|
|
logdev0 = d(@filename)
|
|
|
|
logdev0.__send__(:add_log_header, @tempfile)
|
2014-02-21 02:04:25 -05:00
|
|
|
header_size = @tempfile.size
|
|
|
|
message = "*" * 99 + "\n"
|
|
|
|
shift_size = header_size + message.size * 3 - 1
|
|
|
|
opt = {shift_age: 1, shift_size: shift_size}
|
|
|
|
|
|
|
|
Dir.mktmpdir do |tmpdir|
|
|
|
|
begin
|
|
|
|
log = File.join(tmpdir, "log")
|
|
|
|
logdev1 = d(log, opt)
|
|
|
|
logdev2 = d(log, opt)
|
|
|
|
|
|
|
|
assert_file.identical?(log, logdev1.dev)
|
|
|
|
assert_file.identical?(log, logdev2.dev)
|
|
|
|
|
|
|
|
3.times{logdev1.write(message)}
|
|
|
|
assert_file.identical?(log, logdev1.dev)
|
|
|
|
assert_file.identical?(log, logdev2.dev)
|
|
|
|
|
|
|
|
logdev1.write(message)
|
|
|
|
assert_file.identical?(log, logdev1.dev)
|
|
|
|
assert_file.identical?(log + ".0", logdev2.dev)
|
|
|
|
|
|
|
|
logdev2.write(message)
|
|
|
|
assert_file.identical?(log, logdev1.dev)
|
|
|
|
assert_file.identical?(log, logdev2.dev)
|
|
|
|
|
|
|
|
logdev1.write(message)
|
|
|
|
assert_file.identical?(log, logdev1.dev)
|
|
|
|
assert_file.identical?(log, logdev2.dev)
|
|
|
|
ensure
|
|
|
|
logdev1.close if logdev1
|
|
|
|
logdev2.close if logdev2
|
|
|
|
end
|
|
|
|
end
|
2014-05-29 09:12:38 -04:00
|
|
|
ensure
|
|
|
|
logdev0.close
|
2014-02-21 02:04:25 -05:00
|
|
|
end unless /mswin|mingw/ =~ RUBY_PLATFORM
|
|
|
|
|
2014-02-21 02:11:03 -05:00
|
|
|
def test_shifting_midnight
|
|
|
|
Dir.mktmpdir do |tmpdir|
|
2016-11-16 01:59:41 -05:00
|
|
|
assert_in_out_err([*%W"--disable=gems -rlogger -C#{tmpdir} -"], "#{<<-"begin;"}\n#{<<-'end;'}")
|
|
|
|
begin;
|
2014-02-21 02:11:03 -05:00
|
|
|
begin
|
|
|
|
module FakeTime
|
|
|
|
attr_accessor :now
|
|
|
|
end
|
|
|
|
|
|
|
|
class << Time
|
|
|
|
prepend FakeTime
|
|
|
|
end
|
|
|
|
|
|
|
|
log = "log"
|
|
|
|
File.open(log, "w") {}
|
2016-11-16 01:59:42 -05:00
|
|
|
File.utime(*[Time.mktime(2014, 1, 2, 0, 0, 0)]*2, log)
|
2014-02-21 02:11:03 -05:00
|
|
|
|
|
|
|
Time.now = Time.mktime(2014, 1, 2, 23, 59, 59, 999000)
|
|
|
|
dev = Logger::LogDevice.new(log, shift_age: 'daily')
|
|
|
|
dev.write("#{Time.now} hello-1\n")
|
2016-11-16 01:59:42 -05:00
|
|
|
File.utime(Time.now, Time.now, log)
|
2014-02-21 02:11:03 -05:00
|
|
|
|
|
|
|
Time.now = Time.mktime(2014, 1, 3, 1, 1, 1)
|
|
|
|
dev.write("#{Time.now} hello-2\n")
|
2016-11-16 01:59:42 -05:00
|
|
|
File.utime(Time.now, Time.now, log)
|
2014-02-21 02:11:03 -05:00
|
|
|
ensure
|
|
|
|
dev.close
|
|
|
|
end
|
|
|
|
end;
|
|
|
|
|
|
|
|
bug = '[GH-539]'
|
|
|
|
log = File.join(tmpdir, "log")
|
2014-02-21 22:18:36 -05:00
|
|
|
cont = File.read(log)
|
|
|
|
assert_match(/hello-2/, cont)
|
|
|
|
assert_not_match(/hello-1/, cont)
|
2014-02-21 02:11:03 -05:00
|
|
|
assert_file.for(bug).exist?(log+".20140102")
|
|
|
|
assert_match(/hello-1/, File.read(log+".20140102"), bug)
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
2019-08-21 00:28:14 -04:00
|
|
|
env_tz_works = /linux|darwin|freebsd|openbsd/ =~ RUBY_PLATFORM # borrow from test/ruby/test_time_tz.rb
|
2015-10-26 23:00:38 -04:00
|
|
|
|
2015-10-27 03:18:14 -04:00
|
|
|
def test_shifting_weekly
|
|
|
|
Dir.mktmpdir do |tmpdir|
|
2016-11-16 01:59:41 -05:00
|
|
|
assert_in_out_err([{"TZ"=>"UTC"}, *%W"-rlogger -C#{tmpdir} -"], "#{<<-"begin;"}\n#{<<-'end;'}")
|
|
|
|
begin;
|
2015-10-27 03:18:14 -04:00
|
|
|
begin
|
|
|
|
module FakeTime
|
|
|
|
attr_accessor :now
|
|
|
|
end
|
|
|
|
|
|
|
|
class << Time
|
|
|
|
prepend FakeTime
|
|
|
|
end
|
|
|
|
|
|
|
|
log = "log"
|
|
|
|
File.open(log, "w") {}
|
|
|
|
Time.now = Time.utc(2015, 12, 14, 0, 1, 1)
|
2016-11-16 01:59:42 -05:00
|
|
|
File.utime(Time.now, Time.now, log)
|
|
|
|
|
2015-10-27 03:18:14 -04:00
|
|
|
dev = Logger::LogDevice.new("log", shift_age: 'weekly')
|
|
|
|
|
|
|
|
Time.now = Time.utc(2015, 12, 19, 12, 34, 56)
|
|
|
|
dev.write("#{Time.now} hello-1\n")
|
|
|
|
File.utime(Time.now, Time.now, log)
|
|
|
|
|
|
|
|
Time.now = Time.utc(2015, 12, 20, 0, 1, 1)
|
|
|
|
dev.write("#{Time.now} hello-2\n")
|
2016-11-16 01:59:42 -05:00
|
|
|
File.utime(Time.now, Time.now, log)
|
2015-10-27 03:18:14 -04:00
|
|
|
ensure
|
|
|
|
dev.close if dev
|
|
|
|
end
|
|
|
|
end;
|
|
|
|
log = File.join(tmpdir, "log")
|
|
|
|
cont = File.read(log)
|
|
|
|
assert_match(/hello-2/, cont)
|
|
|
|
assert_not_match(/hello-1/, cont)
|
|
|
|
log = Dir.glob(log+".*")
|
|
|
|
assert_equal(1, log.size)
|
|
|
|
log, = *log
|
|
|
|
cont = File.read(log)
|
|
|
|
assert_match(/hello-1/, cont)
|
|
|
|
assert_equal("2015-12-19", cont[/^[-\d]+/])
|
|
|
|
assert_equal("20151219", log[/\d+\z/])
|
|
|
|
end
|
|
|
|
end if env_tz_works
|
|
|
|
|
2016-10-07 20:06:57 -04:00
|
|
|
def test_shifting_monthly
|
|
|
|
Dir.mktmpdir do |tmpdir|
|
2016-11-16 01:59:41 -05:00
|
|
|
assert_in_out_err([{"TZ"=>"UTC"}, *%W"-rlogger -C#{tmpdir} -"], "#{<<-"begin;"}\n#{<<-'end;'}")
|
|
|
|
begin;
|
2016-10-07 20:06:57 -04:00
|
|
|
begin
|
|
|
|
module FakeTime
|
|
|
|
attr_accessor :now
|
|
|
|
end
|
|
|
|
|
|
|
|
class << Time
|
|
|
|
prepend FakeTime
|
|
|
|
end
|
|
|
|
|
|
|
|
log = "log"
|
|
|
|
File.open(log, "w") {}
|
|
|
|
Time.now = Time.utc(2015, 12, 14, 0, 1, 1)
|
2016-11-16 01:59:42 -05:00
|
|
|
File.utime(Time.now, Time.now, log)
|
|
|
|
|
2016-10-07 20:06:57 -04:00
|
|
|
dev = Logger::LogDevice.new("log", shift_age: 'monthly')
|
|
|
|
|
|
|
|
Time.now = Time.utc(2015, 12, 31, 12, 34, 56)
|
|
|
|
dev.write("#{Time.now} hello-1\n")
|
|
|
|
File.utime(Time.now, Time.now, log)
|
|
|
|
|
|
|
|
Time.now = Time.utc(2016, 1, 1, 0, 1, 1)
|
|
|
|
dev.write("#{Time.now} hello-2\n")
|
2016-11-16 01:59:42 -05:00
|
|
|
File.utime(Time.now, Time.now, log)
|
2016-10-07 20:06:57 -04:00
|
|
|
ensure
|
|
|
|
dev.close if dev
|
|
|
|
end
|
|
|
|
end;
|
|
|
|
log = File.join(tmpdir, "log")
|
|
|
|
cont = File.read(log)
|
|
|
|
assert_match(/hello-2/, cont)
|
|
|
|
assert_not_match(/hello-1/, cont)
|
|
|
|
log = Dir.glob(log+".*")
|
|
|
|
assert_equal(1, log.size)
|
|
|
|
log, = *log
|
|
|
|
cont = File.read(log)
|
|
|
|
assert_match(/hello-1/, cont)
|
|
|
|
assert_equal("2015-12-31", cont[/^[-\d]+/])
|
|
|
|
assert_equal("20151231", log[/\d+\z/])
|
|
|
|
end
|
|
|
|
end if env_tz_works
|
|
|
|
|
2014-02-21 02:45:55 -05:00
|
|
|
def test_shifting_dst_change
|
|
|
|
Dir.mktmpdir do |tmpdir|
|
2016-11-16 01:59:41 -05:00
|
|
|
assert_in_out_err([{"TZ"=>"Europe/London"}, *%W"--disable=gems -rlogger -C#{tmpdir} -"], "#{<<-"begin;"}\n#{<<-'end;'}")
|
|
|
|
begin;
|
2014-02-21 02:45:55 -05:00
|
|
|
begin
|
|
|
|
module FakeTime
|
|
|
|
attr_accessor :now
|
|
|
|
end
|
|
|
|
|
|
|
|
class << Time
|
|
|
|
prepend FakeTime
|
|
|
|
end
|
|
|
|
|
|
|
|
log = "log"
|
|
|
|
File.open(log, "w") {}
|
|
|
|
|
|
|
|
Time.now = Time.mktime(2014, 3, 30, 0, 1, 1)
|
|
|
|
File.utime(Time.now, Time.now, log)
|
|
|
|
|
|
|
|
dev = Logger::LogDevice.new(log, shift_age: 'daily')
|
|
|
|
dev.write("#{Time.now} hello-1\n")
|
|
|
|
File.utime(*[Time.mktime(2014, 3, 30, 0, 2, 3)]*2, log)
|
|
|
|
|
|
|
|
Time.now = Time.mktime(2014, 3, 31, 0, 1, 1)
|
|
|
|
dev.write("#{Time.now} hello-2\n")
|
2016-11-16 01:59:42 -05:00
|
|
|
File.utime(Time.now, Time.now, log)
|
2014-02-21 02:45:55 -05:00
|
|
|
ensure
|
|
|
|
dev.close
|
|
|
|
end
|
|
|
|
end;
|
|
|
|
|
|
|
|
log = File.join(tmpdir, "log")
|
|
|
|
cont = File.read(log)
|
|
|
|
assert_match(/hello-2/, cont)
|
|
|
|
assert_not_match(/hello-1/, cont)
|
|
|
|
assert_file.exist?(log+".20140330")
|
|
|
|
end
|
2015-10-26 23:00:38 -04:00
|
|
|
end if env_tz_works
|
|
|
|
|
|
|
|
def test_shifting_weekly_dst_change
|
|
|
|
Dir.mktmpdir do |tmpdir|
|
2016-11-16 01:59:41 -05:00
|
|
|
assert_separately([{"TZ"=>"Europe/London"}, *%W"-rlogger -C#{tmpdir} -"], "#{<<-"begin;"}\n#{<<-'end;'}")
|
|
|
|
begin;
|
2015-10-26 23:00:38 -04:00
|
|
|
begin
|
|
|
|
module FakeTime
|
|
|
|
attr_accessor :now
|
|
|
|
end
|
|
|
|
|
|
|
|
class << Time
|
|
|
|
prepend FakeTime
|
|
|
|
end
|
|
|
|
|
|
|
|
log = "log"
|
|
|
|
File.open(log, "w") {}
|
|
|
|
Time.now = Time.mktime(2015, 10, 25, 0, 1, 1)
|
2016-11-16 01:59:42 -05:00
|
|
|
File.utime(Time.now, Time.now, log)
|
|
|
|
|
2015-10-26 23:00:38 -04:00
|
|
|
dev = Logger::LogDevice.new("log", shift_age: 'weekly')
|
|
|
|
dev.write("#{Time.now} hello-1\n")
|
2016-11-16 01:59:42 -05:00
|
|
|
File.utime(Time.now, Time.now, log)
|
2015-10-26 23:00:38 -04:00
|
|
|
ensure
|
|
|
|
dev.close if dev
|
|
|
|
end
|
|
|
|
end;
|
|
|
|
log = File.join(tmpdir, "log")
|
|
|
|
cont = File.read(log)
|
|
|
|
assert_match(/hello-1/, cont)
|
|
|
|
end
|
|
|
|
end if env_tz_works
|
2014-02-21 02:45:55 -05:00
|
|
|
|
2016-10-07 20:06:57 -04:00
|
|
|
def test_shifting_monthly_dst_change
|
|
|
|
Dir.mktmpdir do |tmpdir|
|
2016-11-16 01:59:41 -05:00
|
|
|
assert_separately([{"TZ"=>"Europe/London"}, *%W"-rlogger -C#{tmpdir} -"], "#{<<-"begin;"}\n#{<<-'end;'}")
|
|
|
|
begin;
|
2016-10-07 20:06:57 -04:00
|
|
|
begin
|
|
|
|
module FakeTime
|
|
|
|
attr_accessor :now
|
|
|
|
end
|
|
|
|
|
|
|
|
class << Time
|
|
|
|
prepend FakeTime
|
|
|
|
end
|
|
|
|
|
|
|
|
log = "log"
|
|
|
|
File.open(log, "w") {}
|
|
|
|
Time.now = Time.utc(2016, 9, 1, 0, 1, 1)
|
2016-11-16 01:59:42 -05:00
|
|
|
File.utime(Time.now, Time.now, log)
|
|
|
|
|
2016-10-07 20:06:57 -04:00
|
|
|
dev = Logger::LogDevice.new("log", shift_age: 'monthly')
|
|
|
|
|
|
|
|
Time.now = Time.utc(2016, 9, 8, 7, 6, 5)
|
|
|
|
dev.write("#{Time.now} hello-1\n")
|
|
|
|
File.utime(Time.now, Time.now, log)
|
|
|
|
|
|
|
|
Time.now = Time.utc(2016, 10, 9, 8, 7, 6)
|
|
|
|
dev.write("#{Time.now} hello-2\n")
|
2016-11-16 01:59:42 -05:00
|
|
|
File.utime(Time.now, Time.now, log)
|
2016-10-07 20:06:57 -04:00
|
|
|
|
|
|
|
Time.now = Time.utc(2016, 10, 9, 8, 7, 7)
|
|
|
|
dev.write("#{Time.now} hello-3\n")
|
2016-11-16 01:59:42 -05:00
|
|
|
File.utime(Time.now, Time.now, log)
|
2016-10-07 20:06:57 -04:00
|
|
|
ensure
|
|
|
|
dev.close if dev
|
|
|
|
end
|
|
|
|
end;
|
|
|
|
log = File.join(tmpdir, "log")
|
|
|
|
cont = File.read(log)
|
|
|
|
assert_match(/hello-2/, cont)
|
|
|
|
assert_not_match(/hello-1/, cont)
|
|
|
|
log = Dir.glob(log+".*")
|
|
|
|
assert_equal(1, log.size)
|
|
|
|
log, = *log
|
|
|
|
cont = File.read(log)
|
|
|
|
assert_match(/hello-1/, cont)
|
|
|
|
assert_equal("2016-09-08", cont[/^[-\d]+/])
|
|
|
|
assert_equal("20160930", log[/\d+\z/])
|
|
|
|
end
|
|
|
|
end if env_tz_works
|
|
|
|
|
2016-11-16 01:59:42 -05:00
|
|
|
def test_shifting_midnight_exist_file
|
|
|
|
Dir.mktmpdir do |tmpdir|
|
|
|
|
assert_in_out_err([*%W"--disable=gems -rlogger -C#{tmpdir} -"], "#{<<-"begin;"}\n#{<<-'end;'}")
|
|
|
|
begin;
|
|
|
|
begin
|
|
|
|
module FakeTime
|
|
|
|
attr_accessor :now
|
|
|
|
end
|
|
|
|
|
|
|
|
class << Time
|
|
|
|
prepend FakeTime
|
|
|
|
end
|
|
|
|
|
|
|
|
log = "log"
|
|
|
|
File.open(log, "w") {}
|
|
|
|
File.utime(*[Time.mktime(2014, 1, 2, 0, 0, 0)]*2, log)
|
|
|
|
|
|
|
|
Time.now = Time.mktime(2014, 1, 2, 23, 59, 59, 999000)
|
|
|
|
dev = Logger::LogDevice.new(log, shift_age: 'daily')
|
|
|
|
dev.write("#{Time.now} hello-1\n")
|
|
|
|
dev.close
|
|
|
|
File.utime(Time.now, Time.now, log)
|
|
|
|
|
|
|
|
Time.now = Time.mktime(2014, 1, 3, 1, 1, 1)
|
|
|
|
dev = Logger::LogDevice.new(log, shift_age: 'daily')
|
|
|
|
dev.write("#{Time.now} hello-2\n")
|
|
|
|
File.utime(Time.now, Time.now, log)
|
|
|
|
ensure
|
|
|
|
dev.close
|
|
|
|
end
|
|
|
|
end;
|
|
|
|
|
|
|
|
bug = '[GH-539]'
|
|
|
|
log = File.join(tmpdir, "log")
|
|
|
|
cont = File.read(log)
|
|
|
|
assert_match(/hello-2/, cont)
|
|
|
|
assert_not_match(/hello-1/, cont)
|
|
|
|
assert_file.for(bug).exist?(log+".20140102")
|
|
|
|
assert_match(/hello-1/, File.read(log+".20140102"), bug)
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
|
|
|
env_tz_works = /linux|darwin|freebsd/ =~ RUBY_PLATFORM # borrow from test/ruby/test_time_tz.rb
|
|
|
|
|
|
|
|
def test_shifting_weekly_exist_file
|
|
|
|
Dir.mktmpdir do |tmpdir|
|
|
|
|
assert_in_out_err([{"TZ"=>"UTC"}, *%W"-rlogger -C#{tmpdir} -"], "#{<<-"begin;"}\n#{<<-'end;'}")
|
|
|
|
begin;
|
|
|
|
begin
|
|
|
|
module FakeTime
|
|
|
|
attr_accessor :now
|
|
|
|
end
|
|
|
|
|
|
|
|
class << Time
|
|
|
|
prepend FakeTime
|
|
|
|
end
|
|
|
|
|
|
|
|
log = "log"
|
|
|
|
File.open(log, "w") {}
|
|
|
|
Time.now = Time.utc(2015, 12, 14, 0, 1, 1)
|
|
|
|
File.utime(Time.now, Time.now, log)
|
|
|
|
|
|
|
|
dev = Logger::LogDevice.new("log", shift_age: 'weekly')
|
|
|
|
|
|
|
|
Time.now = Time.utc(2015, 12, 19, 12, 34, 56)
|
|
|
|
dev.write("#{Time.now} hello-1\n")
|
|
|
|
dev.close
|
|
|
|
File.utime(Time.now, Time.now, log)
|
|
|
|
|
|
|
|
Time.now = Time.utc(2015, 12, 20, 0, 1, 1)
|
|
|
|
dev = Logger::LogDevice.new("log", shift_age: 'weekly')
|
|
|
|
dev.write("#{Time.now} hello-2\n")
|
|
|
|
File.utime(Time.now, Time.now, log)
|
|
|
|
ensure
|
|
|
|
dev.close if dev
|
|
|
|
end
|
|
|
|
end;
|
|
|
|
log = File.join(tmpdir, "log")
|
|
|
|
cont = File.read(log)
|
|
|
|
assert_match(/hello-2/, cont)
|
|
|
|
assert_not_match(/hello-1/, cont)
|
|
|
|
log = Dir.glob(log+".*")
|
|
|
|
assert_equal(1, log.size)
|
|
|
|
log, = *log
|
|
|
|
cont = File.read(log)
|
|
|
|
assert_match(/hello-1/, cont)
|
|
|
|
assert_equal("2015-12-19", cont[/^[-\d]+/])
|
|
|
|
assert_equal("20151219", log[/\d+\z/])
|
|
|
|
end
|
|
|
|
end if env_tz_works
|
|
|
|
|
|
|
|
def test_shifting_monthly_exist_file
|
|
|
|
Dir.mktmpdir do |tmpdir|
|
|
|
|
assert_in_out_err([{"TZ"=>"UTC"}, *%W"-rlogger -C#{tmpdir} -"], "#{<<-"begin;"}\n#{<<-'end;'}")
|
|
|
|
begin;
|
|
|
|
begin
|
|
|
|
module FakeTime
|
|
|
|
attr_accessor :now
|
|
|
|
end
|
|
|
|
|
|
|
|
class << Time
|
|
|
|
prepend FakeTime
|
|
|
|
end
|
|
|
|
|
|
|
|
log = "log"
|
|
|
|
File.open(log, "w") {}
|
|
|
|
Time.now = Time.utc(2015, 12, 14, 0, 1, 1)
|
|
|
|
File.utime(Time.now, Time.now, log)
|
|
|
|
|
|
|
|
dev = Logger::LogDevice.new("log", shift_age: 'monthly')
|
|
|
|
|
|
|
|
Time.now = Time.utc(2015, 12, 31, 12, 34, 56)
|
|
|
|
dev.write("#{Time.now} hello-1\n")
|
|
|
|
dev.close
|
|
|
|
File.utime(Time.now, Time.now, log)
|
|
|
|
|
|
|
|
Time.now = Time.utc(2016, 1, 1, 0, 1, 1)
|
|
|
|
dev = Logger::LogDevice.new("log", shift_age: 'monthly')
|
|
|
|
dev.write("#{Time.now} hello-2\n")
|
|
|
|
File.utime(Time.now, Time.now, log)
|
|
|
|
ensure
|
|
|
|
dev.close if dev
|
|
|
|
end
|
|
|
|
end;
|
|
|
|
log = File.join(tmpdir, "log")
|
|
|
|
cont = File.read(log)
|
|
|
|
assert_match(/hello-2/, cont)
|
|
|
|
assert_not_match(/hello-1/, cont)
|
|
|
|
log = Dir.glob(log+".*")
|
|
|
|
assert_equal(1, log.size)
|
|
|
|
log, = *log
|
|
|
|
cont = File.read(log)
|
|
|
|
assert_match(/hello-1/, cont)
|
|
|
|
assert_equal("2015-12-31", cont[/^[-\d]+/])
|
|
|
|
assert_equal("20151231", log[/\d+\z/])
|
|
|
|
end
|
|
|
|
end if env_tz_works
|
|
|
|
|
2014-02-21 02:04:25 -05:00
|
|
|
private
|
|
|
|
|
|
|
|
def run_children(n, args, src)
|
|
|
|
r, w = IO.pipe
|
|
|
|
[w, *(1..n).map do
|
|
|
|
f = IO.popen([EnvUtil.rubybin, *%w[--disable=gems -rlogger -], *args], "w", err: w)
|
|
|
|
f.puts(src)
|
|
|
|
f
|
|
|
|
end].each(&:close)
|
|
|
|
stderr = r.read
|
|
|
|
r.close
|
|
|
|
stderr
|
|
|
|
end
|
|
|
|
end
|