2012-11-05 19:49:57 -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'
|
2003-09-29 03:27:57 -04:00
|
|
|
require 'tempfile'
|
2003-09-19 22:51:06 -04:00
|
|
|
|
|
|
|
class TestLogger < Test::Unit::TestCase
|
|
|
|
include Logger::Severity
|
|
|
|
|
|
|
|
def setup
|
|
|
|
@logger = Logger.new(nil)
|
2008-11-18 02:18:29 -05:00
|
|
|
end
|
|
|
|
|
2003-09-19 22:51:06 -04:00
|
|
|
class Log
|
|
|
|
attr_reader :label, :datetime, :pid, :severity, :progname, :msg
|
|
|
|
def initialize(line)
|
2009-10-20 11:08:38 -04:00
|
|
|
/\A(\w+), \[([^#]*)#(\d+)\]\s+(\w+) -- (\w*): ([\x0-\xff]*)/ =~ line
|
2003-09-19 22:51:06 -04:00
|
|
|
@label, @datetime, @pid, @severity, @progname, @msg = $1, $2, $3, $4, $5, $6
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
|
|
|
def log_add(logger, severity, msg, progname = nil, &block)
|
2005-08-20 09:43:46 -04:00
|
|
|
log(logger, :add, severity, msg, progname, &block)
|
2003-09-19 22:51:06 -04:00
|
|
|
end
|
|
|
|
|
2005-08-20 09:43:46 -04:00
|
|
|
def log(logger, msg_id, *arg, &block)
|
2005-09-13 09:13:41 -04:00
|
|
|
Log.new(log_raw(logger, msg_id, *arg, &block))
|
|
|
|
end
|
|
|
|
|
|
|
|
def log_raw(logger, msg_id, *arg, &block)
|
* test/csv/test_features.rb, test/logger/test_logger.rb
test/mkmf/test_have_macro.rb, test/net/http/test_http.rb,
test/openssl/test_config.rb, test/psych/test_encoding.rb,
test/psych/test_exception.rb, test/psych/test_psych.rb,
test/psych/test_tainted.rb, test/readline/test_readline.rb,
test/rexml/test_contrib.rb, test/ruby/test_autoload.rb,
test/ruby/test_beginendblock.rb, test/ruby/test_exception.rb,
test/ruby/test_file.rb, test/ruby/test_io.rb,
test/ruby/test_marshal.rb, test/ruby/test_process.rb,
test/ruby/test_require.rb, test/ruby/test_rubyoptions.rb,
test/syslog/test_syslog_logger.rb, test/webrick/test_httpauth.rb,
test/zlib/test_zlib.rb: Use Tempfile.create.
git-svn-id: svn+ssh://ci.ruby-lang.org/ruby/trunk@40400 b2dd03c8-39d4-4d8f-98ff-823fe69b080e
2013-04-20 19:03:52 -04:00
|
|
|
Tempfile.create(File.basename(__FILE__) + '.log') {|logdev|
|
|
|
|
logger.instance_eval { @logdev = Logger::LogDevice.new(logdev) }
|
|
|
|
logger.__send__(msg_id, *arg, &block)
|
|
|
|
logdev.rewind
|
|
|
|
logdev.read
|
|
|
|
}
|
2003-09-19 22:51:06 -04:00
|
|
|
end
|
|
|
|
|
|
|
|
def test_level
|
|
|
|
@logger.level = UNKNOWN
|
|
|
|
assert_equal(UNKNOWN, @logger.level)
|
|
|
|
@logger.level = INFO
|
|
|
|
assert_equal(INFO, @logger.level)
|
|
|
|
@logger.sev_threshold = ERROR
|
|
|
|
assert_equal(ERROR, @logger.sev_threshold)
|
|
|
|
@logger.sev_threshold = WARN
|
|
|
|
assert_equal(WARN, @logger.sev_threshold)
|
|
|
|
assert_equal(WARN, @logger.level)
|
|
|
|
|
|
|
|
@logger.level = DEBUG
|
|
|
|
assert(@logger.debug?)
|
|
|
|
assert(@logger.info?)
|
|
|
|
@logger.level = INFO
|
|
|
|
assert(!@logger.debug?)
|
|
|
|
assert(@logger.info?)
|
|
|
|
assert(@logger.warn?)
|
|
|
|
@logger.level = WARN
|
|
|
|
assert(!@logger.info?)
|
|
|
|
assert(@logger.warn?)
|
|
|
|
assert(@logger.error?)
|
|
|
|
@logger.level = ERROR
|
|
|
|
assert(!@logger.warn?)
|
|
|
|
assert(@logger.error?)
|
|
|
|
assert(@logger.fatal?)
|
|
|
|
@logger.level = FATAL
|
|
|
|
assert(!@logger.error?)
|
|
|
|
assert(@logger.fatal?)
|
|
|
|
@logger.level = UNKNOWN
|
|
|
|
assert(!@logger.error?)
|
|
|
|
assert(!@logger.fatal?)
|
|
|
|
end
|
|
|
|
|
2015-11-17 09:15:25 -05:00
|
|
|
def test_symbol_level
|
|
|
|
logger_symbol_levels = {
|
|
|
|
debug: DEBUG,
|
|
|
|
info: INFO,
|
|
|
|
warn: WARN,
|
|
|
|
error: ERROR,
|
|
|
|
fatal: FATAL,
|
|
|
|
unknown: UNKNOWN,
|
|
|
|
DEBUG: DEBUG,
|
|
|
|
INFO: INFO,
|
|
|
|
WARN: WARN,
|
|
|
|
ERROR: ERROR,
|
|
|
|
FATAL: FATAL,
|
|
|
|
UNKNOWN: UNKNOWN,
|
|
|
|
}
|
|
|
|
logger_symbol_levels.each do |symbol, level|
|
|
|
|
@logger.level = symbol
|
|
|
|
assert(@logger.level == level)
|
|
|
|
end
|
|
|
|
assert_raise(ArgumentError) { @logger.level = :something_wrong }
|
|
|
|
end
|
|
|
|
|
|
|
|
def test_string_level
|
|
|
|
logger_string_levels = {
|
|
|
|
'debug' => DEBUG,
|
|
|
|
'info' => INFO,
|
|
|
|
'warn' => WARN,
|
|
|
|
'error' => ERROR,
|
|
|
|
'fatal' => FATAL,
|
|
|
|
'unknown' => UNKNOWN,
|
|
|
|
'DEBUG' => DEBUG,
|
|
|
|
'INFO' => INFO,
|
|
|
|
'WARN' => WARN,
|
|
|
|
'ERROR' => ERROR,
|
|
|
|
'FATAL' => FATAL,
|
|
|
|
'UNKNOWN' => UNKNOWN,
|
|
|
|
}
|
|
|
|
logger_string_levels.each do |string, level|
|
|
|
|
@logger.level = string
|
|
|
|
assert(@logger.level == level)
|
|
|
|
end
|
|
|
|
assert_raise(ArgumentError) { @logger.level = 'something_wrong' }
|
|
|
|
end
|
|
|
|
|
2003-09-19 22:51:06 -04:00
|
|
|
def test_progname
|
|
|
|
assert_nil(@logger.progname)
|
|
|
|
@logger.progname = "name"
|
|
|
|
assert_equal("name", @logger.progname)
|
|
|
|
end
|
|
|
|
|
|
|
|
def test_datetime_format
|
2016-11-04 22:39:09 -04:00
|
|
|
verbose, $VERBOSE = $VERBOSE, false
|
2003-09-19 22:51:06 -04:00
|
|
|
dummy = STDERR
|
|
|
|
logger = Logger.new(dummy)
|
|
|
|
log = log_add(logger, INFO, "foo")
|
|
|
|
assert_match(/^\d\d\d\d-\d\d-\d\dT\d\d:\d\d:\d\d.\s*\d+ $/, log.datetime)
|
2005-08-20 09:43:46 -04:00
|
|
|
logger.datetime_format = "%d%b%Y@%H:%M:%S"
|
2003-09-19 22:51:06 -04:00
|
|
|
log = log_add(logger, INFO, "foo")
|
2005-08-20 09:43:46 -04:00
|
|
|
assert_match(/^\d\d\w\w\w\d\d\d\d@\d\d:\d\d:\d\d$/, log.datetime)
|
2003-09-19 22:51:06 -04:00
|
|
|
logger.datetime_format = ""
|
|
|
|
log = log_add(logger, INFO, "foo")
|
|
|
|
assert_match(/^$/, log.datetime)
|
2016-11-04 22:39:09 -04:00
|
|
|
ensure
|
|
|
|
$VERBOSE = verbose
|
2003-09-19 22:51:06 -04:00
|
|
|
end
|
|
|
|
|
2005-09-13 09:13:41 -04:00
|
|
|
def test_formatter
|
|
|
|
dummy = STDERR
|
|
|
|
logger = Logger.new(dummy)
|
|
|
|
# default
|
|
|
|
log = log(logger, :info, "foo")
|
|
|
|
assert_equal("foo\n", log.msg)
|
|
|
|
# config
|
|
|
|
logger.formatter = proc { |severity, timestamp, progname, msg|
|
|
|
|
"#{severity}:#{msg}\n\n"
|
|
|
|
}
|
|
|
|
line = log_raw(logger, :info, "foo")
|
|
|
|
assert_equal("INFO:foo\n\n", line)
|
|
|
|
# recover
|
|
|
|
logger.formatter = nil
|
|
|
|
log = log(logger, :info, "foo")
|
|
|
|
assert_equal("foo\n", log.msg)
|
|
|
|
# again
|
|
|
|
o = Object.new
|
|
|
|
def o.call(severity, timestamp, progname, msg)
|
|
|
|
"<<#{severity}-#{msg}>>\n"
|
|
|
|
end
|
|
|
|
logger.formatter = o
|
|
|
|
line = log_raw(logger, :info, "foo")
|
2013-01-20 08:25:58 -05:00
|
|
|
assert_equal("<""<INFO-foo>>\n", line)
|
2005-09-13 09:13:41 -04:00
|
|
|
end
|
|
|
|
|
2003-09-19 22:51:06 -04:00
|
|
|
def test_initialize
|
|
|
|
logger = Logger.new(STDERR)
|
|
|
|
assert_nil(logger.progname)
|
|
|
|
assert_equal(DEBUG, logger.level)
|
|
|
|
assert_nil(logger.datetime_format)
|
|
|
|
end
|
|
|
|
|
2016-04-18 06:45:40 -04:00
|
|
|
def test_initialize_with_level
|
|
|
|
# default
|
|
|
|
logger = Logger.new(STDERR)
|
|
|
|
assert_equal(Logger::DEBUG, logger.level)
|
|
|
|
# config
|
|
|
|
logger = Logger.new(STDERR, level: :info)
|
|
|
|
assert_equal(Logger::INFO, logger.level)
|
|
|
|
end
|
|
|
|
|
|
|
|
def test_initialize_with_progname
|
|
|
|
# default
|
|
|
|
logger = Logger.new(STDERR)
|
|
|
|
assert_equal(nil, logger.progname)
|
|
|
|
# config
|
|
|
|
logger = Logger.new(STDERR, progname: :progname)
|
|
|
|
assert_equal(:progname, logger.progname)
|
|
|
|
end
|
|
|
|
|
|
|
|
def test_initialize_with_formatter
|
|
|
|
# default
|
|
|
|
logger = Logger.new(STDERR)
|
|
|
|
log = log(logger, :info, "foo")
|
|
|
|
assert_equal("foo\n", log.msg)
|
|
|
|
# config
|
|
|
|
logger = Logger.new(STDERR, formatter: proc { |severity, timestamp, progname, msg|
|
|
|
|
"#{severity}:#{msg}\n\n"
|
|
|
|
})
|
|
|
|
line = log_raw(logger, :info, "foo")
|
|
|
|
assert_equal("INFO:foo\n\n", line)
|
|
|
|
end
|
|
|
|
|
|
|
|
def test_initialize_with_datetime_format
|
|
|
|
# default
|
|
|
|
logger = Logger.new(STDERR)
|
|
|
|
log = log_add(logger, INFO, "foo")
|
|
|
|
assert_match(/^\d\d\d\d-\d\d-\d\dT\d\d:\d\d:\d\d.\s*\d+ $/, log.datetime)
|
|
|
|
# config
|
|
|
|
logger = Logger.new(STDERR, datetime_format: "%d%b%Y@%H:%M:%S")
|
|
|
|
log = log_add(logger, INFO, "foo")
|
|
|
|
assert_match(/^\d\d\w\w\w\d\d\d\d@\d\d:\d\d:\d\d$/, log.datetime)
|
|
|
|
end
|
|
|
|
|
2015-11-17 08:58:57 -05:00
|
|
|
def test_reopen
|
|
|
|
logger = Logger.new(STDERR)
|
|
|
|
logger.reopen(STDOUT)
|
|
|
|
assert_equal(STDOUT, logger.instance_variable_get(:@logdev).dev)
|
|
|
|
end
|
|
|
|
|
2020-03-28 12:16:00 -04:00
|
|
|
def test_reopen_nil_logdevice
|
|
|
|
logger = Logger.new(File::NULL)
|
|
|
|
assert_nothing_raised do
|
|
|
|
logger.reopen(STDOUT)
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
2003-09-19 22:51:06 -04:00
|
|
|
def test_add
|
|
|
|
logger = Logger.new(nil)
|
|
|
|
logger.progname = "my_progname"
|
|
|
|
assert(logger.add(INFO))
|
|
|
|
log = log_add(logger, nil, "msg")
|
|
|
|
assert_equal("ANY", log.severity)
|
|
|
|
assert_equal("my_progname", log.progname)
|
|
|
|
logger.level = WARN
|
|
|
|
assert(logger.log(INFO))
|
2003-09-29 03:27:57 -04:00
|
|
|
assert_nil(log_add(logger, INFO, "msg").msg)
|
2003-09-19 22:51:06 -04:00
|
|
|
log = log_add(logger, WARN, nil) { "msg" }
|
|
|
|
assert_equal("msg\n", log.msg)
|
|
|
|
log = log_add(logger, WARN, "") { "msg" }
|
|
|
|
assert_equal("\n", log.msg)
|
|
|
|
assert_equal("my_progname", log.progname)
|
|
|
|
log = log_add(logger, WARN, nil, "progname?")
|
|
|
|
assert_equal("progname?\n", log.msg)
|
|
|
|
assert_equal("my_progname", log.progname)
|
2017-07-20 12:47:26 -04:00
|
|
|
#
|
|
|
|
logger = Logger.new(nil)
|
|
|
|
log = log_add(logger, INFO, nil, false)
|
|
|
|
assert_equal("false\n", log.msg)
|
2003-09-19 22:51:06 -04:00
|
|
|
end
|
|
|
|
|
2019-06-04 18:07:26 -04:00
|
|
|
def test_add_binary_data_with_binmode_logdev
|
|
|
|
EnvUtil.with_default_internal(Encoding::UTF_8) do
|
|
|
|
begin
|
|
|
|
tempfile = Tempfile.new("logger")
|
|
|
|
tempfile.close
|
|
|
|
filename = tempfile.path
|
|
|
|
File.unlink(filename)
|
|
|
|
|
|
|
|
logger = Logger.new filename, binmode: true
|
|
|
|
logger.level = Logger::DEBUG
|
|
|
|
|
|
|
|
str = +"\x80"
|
|
|
|
str.force_encoding("ASCII-8BIT")
|
|
|
|
|
|
|
|
logger.add Logger::DEBUG, str
|
|
|
|
assert_equal(2, File.binread(filename).split(/\n/).size)
|
|
|
|
ensure
|
|
|
|
logger.close
|
|
|
|
tempfile.unlink
|
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
2003-09-19 22:51:06 -04:00
|
|
|
def test_level_log
|
|
|
|
logger = Logger.new(nil)
|
|
|
|
logger.progname = "my_progname"
|
2005-08-20 09:43:46 -04:00
|
|
|
log = log(logger, :debug, "custom_progname") { "msg" }
|
2003-09-19 22:51:06 -04:00
|
|
|
assert_equal("msg\n", log.msg)
|
|
|
|
assert_equal("custom_progname", log.progname)
|
|
|
|
assert_equal("DEBUG", log.severity)
|
|
|
|
assert_equal("D", log.label)
|
|
|
|
#
|
2005-08-20 09:43:46 -04:00
|
|
|
log = log(logger, :debug) { "msg_block" }
|
2003-09-19 22:51:06 -04:00
|
|
|
assert_equal("msg_block\n", log.msg)
|
|
|
|
assert_equal("my_progname", log.progname)
|
2005-08-20 09:43:46 -04:00
|
|
|
log = log(logger, :debug, "msg_inline")
|
2003-09-19 22:51:06 -04:00
|
|
|
assert_equal("msg_inline\n", log.msg)
|
|
|
|
assert_equal("my_progname", log.progname)
|
|
|
|
#
|
2005-08-20 09:43:46 -04:00
|
|
|
log = log(logger, :info, "custom_progname") { "msg" }
|
2003-09-19 22:51:06 -04:00
|
|
|
assert_equal("msg\n", log.msg)
|
|
|
|
assert_equal("custom_progname", log.progname)
|
|
|
|
assert_equal("INFO", log.severity)
|
|
|
|
assert_equal("I", log.label)
|
|
|
|
#
|
2005-08-20 09:43:46 -04:00
|
|
|
log = log(logger, :warn, "custom_progname") { "msg" }
|
2003-09-19 22:51:06 -04:00
|
|
|
assert_equal("msg\n", log.msg)
|
|
|
|
assert_equal("custom_progname", log.progname)
|
|
|
|
assert_equal("WARN", log.severity)
|
|
|
|
assert_equal("W", log.label)
|
|
|
|
#
|
2005-08-20 09:43:46 -04:00
|
|
|
log = log(logger, :error, "custom_progname") { "msg" }
|
2003-09-19 22:51:06 -04:00
|
|
|
assert_equal("msg\n", log.msg)
|
|
|
|
assert_equal("custom_progname", log.progname)
|
|
|
|
assert_equal("ERROR", log.severity)
|
|
|
|
assert_equal("E", log.label)
|
|
|
|
#
|
2005-08-20 09:43:46 -04:00
|
|
|
log = log(logger, :fatal, "custom_progname") { "msg" }
|
2003-09-19 22:51:06 -04:00
|
|
|
assert_equal("msg\n", log.msg)
|
|
|
|
assert_equal("custom_progname", log.progname)
|
|
|
|
assert_equal("FATAL", log.severity)
|
|
|
|
assert_equal("F", log.label)
|
|
|
|
#
|
2005-08-20 09:43:46 -04:00
|
|
|
log = log(logger, :unknown, "custom_progname") { "msg" }
|
2003-09-19 22:51:06 -04:00
|
|
|
assert_equal("msg\n", log.msg)
|
|
|
|
assert_equal("custom_progname", log.progname)
|
|
|
|
assert_equal("ANY", log.severity)
|
|
|
|
assert_equal("A", log.label)
|
|
|
|
end
|
|
|
|
|
|
|
|
def test_close
|
|
|
|
r, w = IO.pipe
|
|
|
|
assert(!w.closed?)
|
|
|
|
logger = Logger.new(w)
|
|
|
|
logger.close
|
|
|
|
assert(w.closed?)
|
|
|
|
r.close
|
|
|
|
end
|
|
|
|
|
|
|
|
class MyError < StandardError
|
|
|
|
end
|
|
|
|
|
|
|
|
class MyMsg
|
|
|
|
def inspect
|
|
|
|
"my_msg"
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
|
|
|
def test_format
|
|
|
|
logger = Logger.new(nil)
|
|
|
|
log = log_add(logger, INFO, "msg\n")
|
|
|
|
assert_equal("msg\n\n", log.msg)
|
|
|
|
begin
|
|
|
|
raise MyError.new("excn")
|
|
|
|
rescue MyError => e
|
|
|
|
log = log_add(logger, INFO, e)
|
|
|
|
assert_match(/^excn \(TestLogger::MyError\)/, log.msg)
|
2003-09-19 22:54:52 -04:00
|
|
|
# expects backtrace is dumped across multi lines. 10 might be changed.
|
|
|
|
assert(log.msg.split(/\n/).size >= 10)
|
2003-09-19 22:51:06 -04:00
|
|
|
end
|
|
|
|
log = log_add(logger, INFO, MyMsg.new)
|
|
|
|
assert_equal("my_msg\n", log.msg)
|
|
|
|
end
|
2003-09-23 10:12:42 -04:00
|
|
|
|
|
|
|
def test_lshift
|
|
|
|
r, w = IO.pipe
|
|
|
|
logger = Logger.new(w)
|
|
|
|
logger << "msg"
|
2018-03-17 02:41:35 -04:00
|
|
|
IO.select([r], nil, nil, 0.1)
|
2003-09-23 10:12:42 -04:00
|
|
|
w.close
|
|
|
|
msg = r.read
|
|
|
|
r.close
|
|
|
|
assert_equal("msg", msg)
|
|
|
|
#
|
|
|
|
r, w = IO.pipe
|
|
|
|
logger = Logger.new(w)
|
|
|
|
logger << "msg2\n\n"
|
2018-03-17 02:41:35 -04:00
|
|
|
IO.select([r], nil, nil, 0.1)
|
2003-09-23 10:12:42 -04:00
|
|
|
w.close
|
|
|
|
msg = r.read
|
|
|
|
r.close
|
|
|
|
assert_equal("msg2\n\n", msg)
|
|
|
|
end
|
2019-09-06 18:28:05 -04:00
|
|
|
|
|
|
|
class CustomLogger < Logger
|
|
|
|
def level
|
|
|
|
INFO
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
|
|
|
def test_overriding_level
|
|
|
|
logger = CustomLogger.new(nil)
|
|
|
|
log = log(logger, :info) { "msg" }
|
|
|
|
assert_equal "msg\n", log.msg
|
|
|
|
#
|
|
|
|
log = log(logger, :debug) { "msg" }
|
|
|
|
assert_nil log.msg
|
|
|
|
end
|
2020-03-28 12:11:41 -04:00
|
|
|
|
|
|
|
def test_does_not_instantiate_log_device_for_File_NULL
|
|
|
|
l = Logger.new(File::NULL)
|
|
|
|
assert_nil(l.instance_variable_get(:@logdev))
|
|
|
|
end
|
2003-09-19 22:51:06 -04:00
|
|
|
end
|