test/mri/logger/test_logger.rb

   1 require 'test/unit'
   2 require 'logger'
   3 require 'tempfile'
   4
   5
   6 class TestLoggerSeverity < Test::Unit::TestCase
   7   def test_enum
   8     logger_levels = Logger.constants
   9     levels = ["WARN", "UNKNOWN", "INFO", "FATAL", "DEBUG", "ERROR"]
  10     Logger::Severity.constants.each do |level|
  11       assert(levels.include?(level))
  12       assert(logger_levels.include?(level))
  13     end
  14     assert_equal(levels.size, Logger::Severity.constants.size)
  15   end
  16 end
  17
  18
  19 class TestLogger < Test::Unit::TestCase
  20   include Logger::Severity
  21
  22   def setup
  23     @logger = Logger.new(nil)
  24   end
  25
  26   class Log
  27     attr_reader :label, :datetime, :pid, :severity, :progname, :msg
  28     def initialize(line)
  29       /\A(\w+), \[([^#]*)#(\d+)\]\s+(\w+) -- (\w*): ([\x0-\xff]*)/ =~ line
  30       @label, @datetime, @pid, @severity, @progname, @msg = $1, $2, $3, $4, $5, $6
  31     end
  32   end
  33
  34   def log_add(logger, severity, msg, progname = nil, &block)
  35     log(logger, :add, severity, msg, progname, &block)
  36   end
  37
  38   def log(logger, msg_id, *arg, &block)
  39     Log.new(log_raw(logger, msg_id, *arg, &block))
  40   end
  41
  42   def log_raw(logger, msg_id, *arg, &block)
  43     logdev = Tempfile.new(File.basename(__FILE__) + '.log')
  44     logger.instance_eval { @logdev = Logger::LogDevice.new(logdev) }
  45     logger.__send__(msg_id, *arg, &block)
  46     logdev.open
  47     msg = logdev.read
  48     logdev.close
  49     msg
  50   end
  51
  52   def test_level
  53     @logger.level = UNKNOWN
  54     assert_equal(UNKNOWN, @logger.level)
  55     @logger.level = INFO
  56     assert_equal(INFO, @logger.level)
  57     @logger.sev_threshold = ERROR
  58     assert_equal(ERROR, @logger.sev_threshold)
  59     @logger.sev_threshold = WARN
  60     assert_equal(WARN, @logger.sev_threshold)
  61     assert_equal(WARN, @logger.level)
  62
  63     @logger.level = DEBUG
  64     assert(@logger.debug?)
  65     assert(@logger.info?)
  66     @logger.level = INFO
  67     assert(!@logger.debug?)
  68     assert(@logger.info?)
  69     assert(@logger.warn?)
  70     @logger.level = WARN
  71     assert(!@logger.info?)
  72     assert(@logger.warn?)
  73     assert(@logger.error?)
  74     @logger.level = ERROR
  75     assert(!@logger.warn?)
  76     assert(@logger.error?)
  77     assert(@logger.fatal?)
  78     @logger.level = FATAL
  79     assert(!@logger.error?)
  80     assert(@logger.fatal?)
  81     @logger.level = UNKNOWN
  82     assert(!@logger.error?)
  83     assert(!@logger.fatal?)
  84   end
  85
  86   def test_progname
  87     assert_nil(@logger.progname)
  88     @logger.progname = "name"
  89     assert_equal("name", @logger.progname)
  90   end
  91
  92   def test_datetime_format
  93     dummy = STDERR
  94     logger = Logger.new(dummy)
  95     log = log_add(logger, INFO, "foo")
  96     assert_match(/^\d\d\d\d-\d\d-\d\dT\d\d:\d\d:\d\d.\s*\d+ $/, log.datetime)
  97     logger.datetime_format = "%d%b%Y@%H:%M:%S"
  98     log = log_add(logger, INFO, "foo")
  99     assert_match(/^\d\d\w\w\w\d\d\d\d@\d\d:\d\d:\d\d$/, log.datetime)
 100     logger.datetime_format = ""
 101     log = log_add(logger, INFO, "foo")
 102     assert_match(/^$/, log.datetime)
 103   end
 104
 105   def test_formatter
 106     dummy = STDERR
 107     logger = Logger.new(dummy)
 108     # default
 109     log = log(logger, :info, "foo")
 110     assert_equal("foo\n", log.msg)
 111     # config
 112     logger.formatter = proc { |severity, timestamp, progname, msg|
 113       "#{severity}:#{msg}\n\n"
 114     }
 115     line = log_raw(logger, :info, "foo")
 116     assert_equal("INFO:foo\n\n", line)
 117     # recover
 118     logger.formatter = nil
 119     log = log(logger, :info, "foo")
 120     assert_equal("foo\n", log.msg)
 121     # again
 122     o = Object.new
 123     def o.call(severity, timestamp, progname, msg)
 124       "<<#{severity}-#{msg}>>\n"
 125     end
 126     logger.formatter = o
 127     line = log_raw(logger, :info, "foo")
 128     assert_equal("<<INFO-foo>>\n", line)
 129   end
 130
 131   def test_initialize
 132     logger = Logger.new(STDERR)
 133     assert_nil(logger.progname)
 134     assert_equal(DEBUG, logger.level)
 135     assert_nil(logger.datetime_format)
 136   end
 137
 138   def test_add
 139     logger = Logger.new(nil)
 140     logger.progname = "my_progname"
 141     assert(logger.add(INFO))
 142     log = log_add(logger, nil, "msg")
 143     assert_equal("ANY", log.severity)
 144     assert_equal("my_progname", log.progname)
 145     logger.level = WARN
 146     assert(logger.log(INFO))
 147     assert_nil(log_add(logger, INFO, "msg").msg)
 148     log = log_add(logger, WARN, nil) { "msg" }
 149     assert_equal("msg\n", log.msg)
 150     log = log_add(logger, WARN, "") { "msg" }
 151     assert_equal("\n", log.msg)
 152     assert_equal("my_progname", log.progname)
 153     log = log_add(logger, WARN, nil, "progname?")
 154     assert_equal("progname?\n", log.msg)
 155     assert_equal("my_progname", log.progname)
 156   end
 157
 158   def test_level_log
 159     logger = Logger.new(nil)
 160     logger.progname = "my_progname"
 161     log = log(logger, :debug, "custom_progname") { "msg" }
 162     assert_equal("msg\n", log.msg)
 163     assert_equal("custom_progname", log.progname)
 164     assert_equal("DEBUG", log.severity)
 165     assert_equal("D", log.label)
 166     #
 167     log = log(logger, :debug) { "msg_block" }
 168     assert_equal("msg_block\n", log.msg)
 169     assert_equal("my_progname", log.progname)
 170     log = log(logger, :debug, "msg_inline")
 171     assert_equal("msg_inline\n", log.msg)
 172     assert_equal("my_progname", log.progname)
 173     #
 174     log = log(logger, :info, "custom_progname") { "msg" }
 175     assert_equal("msg\n", log.msg)
 176     assert_equal("custom_progname", log.progname)
 177     assert_equal("INFO", log.severity)
 178     assert_equal("I", log.label)
 179     #
 180     log = log(logger, :warn, "custom_progname") { "msg" }
 181     assert_equal("msg\n", log.msg)
 182     assert_equal("custom_progname", log.progname)
 183     assert_equal("WARN", log.severity)
 184     assert_equal("W", log.label)
 185     #
 186     log = log(logger, :error, "custom_progname") { "msg" }
 187     assert_equal("msg\n", log.msg)
 188     assert_equal("custom_progname", log.progname)
 189     assert_equal("ERROR", log.severity)
 190     assert_equal("E", log.label)
 191     #
 192     log = log(logger, :fatal, "custom_progname") { "msg" }
 193     assert_equal("msg\n", log.msg)
 194     assert_equal("custom_progname", log.progname)
 195     assert_equal("FATAL", log.severity)
 196     assert_equal("F", log.label)
 197     #
 198     log = log(logger, :unknown, "custom_progname") { "msg" }
 199     assert_equal("msg\n", log.msg)
 200     assert_equal("custom_progname", log.progname)
 201     assert_equal("ANY", log.severity)
 202     assert_equal("A", log.label)
 203   end
 204
 205   def test_close
 206     r, w = IO.pipe
 207     assert(!w.closed?)
 208     logger = Logger.new(w)
 209     logger.close
 210     assert(w.closed?)
 211     r.close
 212   end
 213
 214   class MyError < StandardError
 215   end
 216
 217   class MyMsg
 218     def inspect
 219       "my_msg"
 220     end
 221   end
 222
 223   def test_format
 224     logger = Logger.new(nil)
 225     log = log_add(logger, INFO, "msg\n")
 226     assert_equal("msg\n\n", log.msg)
 227     begin
 228       raise MyError.new("excn")
 229     rescue MyError => e
 230       log = log_add(logger, INFO, e)
 231       assert_match(/^excn \(TestLogger::MyError\)/, log.msg)
 232       # expects backtrace is dumped across multi lines.  10 might be changed.
 233       assert(log.msg.split(/\n/).size >= 10)
 234     end
 235     log = log_add(logger, INFO, MyMsg.new)
 236     assert_equal("my_msg\n", log.msg)
 237   end
 238
 239   def test_lshift
 240     r, w = IO.pipe
 241     logger = Logger.new(w)
 242     logger << "msg"
 243     read_ready, = IO.select([r], nil, nil, 0.1)
 244     w.close
 245     msg = r.read
 246     r.close
 247     assert_equal("msg", msg)
 248     #
 249     r, w = IO.pipe
 250     logger = Logger.new(w)
 251     logger << "msg2\n\n"
 252     read_ready, = IO.select([r], nil, nil, 0.1)
 253     w.close
 254     msg = r.read
 255     r.close
 256     assert_equal("msg2\n\n", msg)
 257   end
 258 end
 259
 260 class TestLogDevice < Test::Unit::TestCase
 261   def d(log)
 262     Logger::LogDevice.new(log)
 263   end
 264
 265   def test_initialize
 266     logdev = d(STDERR)
 267     assert_equal(STDERR, logdev.dev)
 268     assert_nil(logdev.filename)
 269     assert_raises(TypeError) do
 270       d(nil)
 271     end
 272     #
 273     filename = __FILE__ + ".#{$$}"
 274     begin
 275       logdev = d(filename)
 276       assert(File.exist?(filename))
 277       assert(logdev.dev.sync)
 278       assert_equal(filename, logdev.filename)
 279     ensure
 280       logdev.close
 281       File.unlink(filename)
 282     end
 283   end
 284
 285   def test_write
 286     r, w = IO.pipe
 287     logdev = d(w)
 288     logdev.write("msg2\n\n")
 289     read_ready, = IO.select([r], nil, nil, 0.1)
 290     w.close
 291     msg = r.read
 292     r.close
 293     assert_equal("msg2\n\n", msg)
 294   end
 295
 296   def test_close
 297     r, w = IO.pipe
 298     logdev = d(w)
 299     logdev.write("msg2\n\n")
 300     read_ready, = IO.select([r], nil, nil, 0.1)
 301     assert(!w.closed?)
 302     logdev.close
 303     assert(w.closed?)
 304     r.close
 305   end
 306
 307   def test_shifting_size
 308     logfile = File.basename(__FILE__) + '_1.log'
 309     logfile0 = logfile + '.0'
 310     logfile1 = logfile + '.1'
 311     logfile2 = logfile + '.2'
 312     logfile3 = logfile + '.3'
 313     File.unlink(logfile) if File.exist?(logfile)
 314     File.unlink(logfile0) if File.exist?(logfile0)
 315     File.unlink(logfile1) if File.exist?(logfile1)
 316     File.unlink(logfile2) if File.exist?(logfile2)
 317     logger = Logger.new(logfile, 4, 100)
 318     logger.error("0" * 15)
 319     assert(File.exist?(logfile))
 320     assert(!File.exist?(logfile0))
 321     logger.error("0" * 15)
 322     assert(File.exist?(logfile0))
 323     assert(!File.exist?(logfile1))
 324     logger.error("0" * 15)
 325     assert(File.exist?(logfile1))
 326     assert(!File.exist?(logfile2))
 327     logger.error("0" * 15)
 328     assert(File.exist?(logfile2))
 329     assert(!File.exist?(logfile3))
 330     logger.error("0" * 15)
 331     assert(!File.exist?(logfile3))
 332     logger.error("0" * 15)
 333     assert(!File.exist?(logfile3))
 334     logger.close
 335     File.unlink(logfile)
 336     File.unlink(logfile0)
 337     File.unlink(logfile1)
 338     File.unlink(logfile2)
 339
 340     logfile = File.basename(__FILE__) + '_2.log'
 341     logfile0 = logfile + '.0'
 342     logfile1 = logfile + '.1'
 343     logfile2 = logfile + '.2'
 344     logfile3 = logfile + '.3'
 345     logger = Logger.new(logfile, 4, 150)
 346     logger.error("0" * 15)
 347     assert(File.exist?(logfile))
 348     assert(!File.exist?(logfile0))
 349     logger.error("0" * 15)
 350     assert(!File.exist?(logfile0))
 351     logger.error("0" * 15)
 352     assert(File.exist?(logfile0))
 353     assert(!File.exist?(logfile1))
 354     logger.error("0" * 15)
 355     assert(!File.exist?(logfile1))
 356     logger.error("0" * 15)
 357     assert(File.exist?(logfile1))
 358     assert(!File.exist?(logfile2))
 359     logger.error("0" * 15)
 360     assert(!File.exist?(logfile2))
 361     logger.error("0" * 15)
 362     assert(File.exist?(logfile2))
 363     assert(!File.exist?(logfile3))
 364     logger.error("0" * 15)
 365     assert(!File.exist?(logfile3))
 366     logger.error("0" * 15)
 367     assert(!File.exist?(logfile3))
 368     logger.error("0" * 15)
 369     assert(!File.exist?(logfile3))
 370     logger.close
 371     File.unlink(logfile)
 372     File.unlink(logfile0)
 373     File.unlink(logfile1)
 374     File.unlink(logfile2)
 375   end
 376 end