1 # frozen_string_literal: true
2 # logger.rb - simple logging utility
3 # Copyright (C) 2000-2003, 2005, 2008, 2011 NAKAMURA, Hiroshi <nahi@ruby-lang.org>.
5 # Documentation:: NAKAMURA, Hiroshi and Gavin Sinclair
7 # You can redistribute it and/or modify it under the same terms of Ruby's
8 # license; either the dual license version in 2003, or any later version.
11 # A simple system for logging messages. See Logger for more documentation.
17 require_relative 'logger/version'
18 require_relative 'logger/formatter'
19 require_relative 'logger/log_device'
20 require_relative 'logger/severity'
21 require_relative 'logger/errors'
23 # \Class \Logger provides a simple but sophisticated logging utility that
24 # you can use to create one or more
25 # {event logs}[https://en.wikipedia.org/wiki/Logging_(software)#Event_logs]
27 # Each such log contains a chronological sequence of entries
28 # that provides a record of the program's activities.
30 # == About the Examples
32 # All examples on this page assume that \Logger has been required:
38 # Create a log with Logger.new:
41 # logger = Logger.new('t.log')
42 # # Size-based rotated logging: 3 10-megabyte files.
43 # logger = Logger.new('t.log', 3, 10485760)
44 # # Period-based rotated logging: daily (also allowed: 'weekly', 'monthly').
45 # logger = Logger.new('t.log', 'daily')
46 # # Log to an IO stream.
47 # logger = Logger.new($stdout)
49 # Add entries (level, message) with Logger#add:
51 # logger.add(Logger::DEBUG, 'Maximal debugging info')
52 # logger.add(Logger::INFO, 'Non-error information')
53 # logger.add(Logger::WARN, 'Non-error warning')
54 # logger.add(Logger::ERROR, 'Non-fatal error')
55 # logger.add(Logger::FATAL, 'Fatal error')
56 # logger.add(Logger::UNKNOWN, 'Most severe')
58 # Close the log with Logger#close:
64 # You can add entries with method Logger#add:
66 # logger.add(Logger::DEBUG, 'Maximal debugging info')
67 # logger.add(Logger::INFO, 'Non-error information')
68 # logger.add(Logger::WARN, 'Non-error warning')
69 # logger.add(Logger::ERROR, 'Non-fatal error')
70 # logger.add(Logger::FATAL, 'Fatal error')
71 # logger.add(Logger::UNKNOWN, 'Most severe')
73 # These shorthand methods also add entries:
75 # logger.debug('Maximal debugging info')
76 # logger.info('Non-error information')
77 # logger.warn('Non-error warning')
78 # logger.error('Non-fatal error')
79 # logger.fatal('Fatal error')
80 # logger.unknown('Most severe')
82 # When you call any of these methods,
83 # the entry may or may not be written to the log,
84 # depending on the entry's severity and on the log level;
85 # see {Log Level}[rdoc-ref:Logger@Log+Level]
87 # An entry always has:
89 # - A severity (the required argument to #add).
90 # - An automatically created timestamp.
99 # logger = Logger.new($stdout)
100 # logger.add(Logger::INFO, 'My message.', 'mung')
101 # # => I, [2022-05-07T17:21:46.536234 #20536] INFO -- mung: My message.
103 # The default format for an entry is:
105 # "%s, [%s #%d] %5s -- %s: %s\n"
107 # where the values to be formatted are:
109 # - \Severity (one letter).
112 # - \Severity (word).
116 # You can use a different entry format by:
118 # - Setting a custom format proc (affects following entries);
119 # see {formatter=}[Logger.html#attribute-i-formatter].
120 # - Calling any of the methods above with a block
121 # (affects only the one entry).
122 # Doing so can have two benefits:
124 # - Context: the block can evaluate the entire program context
125 # and create a context-dependent message.
126 # - Performance: the block is not evaluated unless the log level
127 # permits the entry actually to be written:
129 # logger.error { my_slow_message_generator }
131 # Contrast this with the string form, where the string is
132 # always evaluated, regardless of the log level:
134 # logger.error("#{my_slow_message_generator}")
138 # The severity of a log entry has two effects:
140 # - Determines whether the entry is selected for inclusion in the log;
141 # see {Log Level}[rdoc-ref:Logger@Log+Level].
142 # - Indicates to any log reader (whether a person or a program)
143 # the relative importance of the entry.
147 # The timestamp for a log entry is generated automatically
148 # when the entry is created.
150 # The logged timestamp is formatted by method
151 # {Time#strftime}[rdoc-ref:Time#strftime]
152 # using this format string:
154 # '%Y-%m-%dT%H:%M:%S.%6N'
158 # logger = Logger.new($stdout)
159 # logger.add(Logger::INFO)
160 # # => I, [2022-05-07T17:04:32.318331 #20536] INFO -- : nil
162 # You can set a different format using method #datetime_format=.
166 # The message is an optional argument to an entry method:
168 # logger = Logger.new($stdout)
169 # logger.add(Logger::INFO, 'My message')
170 # # => I, [2022-05-07T18:15:37.647581 #20536] INFO -- : My message
172 # For the default entry formatter, <tt>Logger::Formatter</tt>,
173 # the message object may be:
175 # - A string: used as-is.
176 # - An Exception: <tt>message.message</tt> is used.
177 # - Anything else: <tt>message.inspect</tt> is used.
179 # *Note*: Logger::Formatter does not escape or sanitize
180 # the message passed to it.
181 # Developers should be aware that malicious data (user input)
182 # may be in the message, and should explicitly escape untrusted data.
184 # You can use a custom formatter to escape message data;
185 # see the example at {formatter=}[Logger.html#attribute-i-formatter].
189 # The program name is an optional argument to an entry method:
191 # logger = Logger.new($stdout)
192 # logger.add(Logger::INFO, 'My message', 'mung')
193 # # => I, [2022-05-07T18:17:38.084716 #20536] INFO -- mung: My message
195 # The default program name for a new logger may be set in the call to
196 # Logger.new via optional keyword argument +progname+:
198 # logger = Logger.new('t.log', progname: 'mung')
200 # The default program name for an existing logger may be set
201 # by a call to method #progname=:
203 # logger.progname = 'mung'
205 # The current program name may be retrieved with method
206 # {progname}[Logger.html#attribute-i-progname]:
208 # logger.progname # => "mung"
212 # The log level setting determines whether an entry is actually
213 # written to the log, based on the entry's severity.
215 # These are the defined severities (least severe to most severe):
217 # logger = Logger.new($stdout)
218 # logger.add(Logger::DEBUG, 'Maximal debugging info')
219 # # => D, [2022-05-07T17:57:41.776220 #20536] DEBUG -- : Maximal debugging info
220 # logger.add(Logger::INFO, 'Non-error information')
221 # # => I, [2022-05-07T17:59:14.349167 #20536] INFO -- : Non-error information
222 # logger.add(Logger::WARN, 'Non-error warning')
223 # # => W, [2022-05-07T18:00:45.337538 #20536] WARN -- : Non-error warning
224 # logger.add(Logger::ERROR, 'Non-fatal error')
225 # # => E, [2022-05-07T18:02:41.592912 #20536] ERROR -- : Non-fatal error
226 # logger.add(Logger::FATAL, 'Fatal error')
227 # # => F, [2022-05-07T18:05:24.703931 #20536] FATAL -- : Fatal error
228 # logger.add(Logger::UNKNOWN, 'Most severe')
229 # # => A, [2022-05-07T18:07:54.657491 #20536] ANY -- : Most severe
231 # The default initial level setting is Logger::DEBUG, the lowest level,
232 # which means that all entries are to be written, regardless of severity:
234 # logger = Logger.new($stdout)
235 # logger.level # => 0
236 # logger.add(0, "My message")
237 # # => D, [2022-05-11T15:10:59.773668 #20536] DEBUG -- : My message
239 # You can specify a different setting in a new logger
240 # using keyword argument +level+ with an appropriate value:
242 # logger = Logger.new($stdout, level: Logger::ERROR)
243 # logger = Logger.new($stdout, level: 'error')
244 # logger = Logger.new($stdout, level: :error)
245 # logger.level # => 3
247 # With this level, entries with severity Logger::ERROR and higher
248 # are written, while those with lower severities are not written:
250 # logger = Logger.new($stdout, level: Logger::ERROR)
252 # # => E, [2022-05-11T15:17:20.933362 #20536] ERROR -- : nil
253 # logger.add(2) # Silent.
255 # You can set the log level for an existing logger
256 # with method #level=:
258 # logger.level = Logger::ERROR
260 # These shorthand methods also set the level:
262 # logger.debug! # => 0
263 # logger.info! # => 1
264 # logger.warn! # => 2
265 # logger.error! # => 3
266 # logger.fatal! # => 4
268 # You can retrieve the log level with method #level.
270 # logger.level = Logger::ERROR
271 # logger.level # => 3
273 # These methods return whether a given
274 # level is to be written:
276 # logger.level = Logger::ERROR
277 # logger.debug? # => false
278 # logger.info? # => false
279 # logger.warn? # => false
280 # logger.error? # => true
281 # logger.fatal? # => true
283 # == Log File Rotation
285 # By default, a log file is a single file that grows indefinitely
286 # (until explicitly closed); there is no file rotation.
288 # To keep log files to a manageable size,
289 # you can use _log_ _file_ _rotation_, which uses multiple log files:
291 # - Each log file has entries for a non-overlapping
293 # - Only the most recent log file is open and active;
294 # the others are closed and inactive.
296 # === Size-Based Rotation
298 # For size-based log file rotation, call Logger.new with:
300 # - Argument +logdev+ as a file path.
301 # - Argument +shift_age+ with a positive integer:
302 # the number of log files to be in the rotation.
303 # - Argument +shift_size+ as a positive integer:
304 # the maximum size (in bytes) of each log file;
305 # defaults to 1048576 (1 megabyte).
309 # logger = Logger.new('t.log', 3) # Three 1-megabyte files.
310 # logger = Logger.new('t.log', 5, 10485760) # Five 10-megabyte files.
312 # For these examples, suppose:
314 # logger = Logger.new('t.log', 3)
316 # Logging begins in the new log file, +t.log+;
317 # the log file is "full" and ready for rotation
318 # when a new entry would cause its size to exceed +shift_size+.
320 # The first time +t.log+ is full:
322 # - +t.log+ is closed and renamed to +t.log.0+.
323 # - A new file +t.log+ is opened.
325 # The second time +t.log+ is full:
327 # - +t.log.0 is renamed as +t.log.1+.
328 # - +t.log+ is closed and renamed to +t.log.0+.
329 # - A new file +t.log+ is opened.
331 # Each subsequent time that +t.log+ is full,
332 # the log files are rotated:
334 # - +t.log.1+ is removed.
335 # - +t.log.0 is renamed as +t.log.1+.
336 # - +t.log+ is closed and renamed to +t.log.0+.
337 # - A new file +t.log+ is opened.
339 # === Periodic Rotation
341 # For periodic rotation, call Logger.new with:
343 # - Argument +logdev+ as a file path.
344 # - Argument +shift_age+ as a string period indicator.
348 # logger = Logger.new('t.log', 'daily') # Rotate log files daily.
349 # logger = Logger.new('t.log', 'weekly') # Rotate log files weekly.
350 # logger = Logger.new('t.log', 'monthly') # Rotate log files monthly.
354 # logger = Logger.new('t.log', 'daily')
356 # When the given period expires:
358 # - The base log file, +t.log+ is closed and renamed
359 # with a date-based suffix such as +t.log.20220509+.
360 # - A new log file +t.log+ is opened.
361 # - Nothing is removed.
363 # The default format for the suffix is <tt>'%Y%m%d'</tt>,
364 # which produces a suffix similar to the one above.
365 # You can set a different format using create-time option
366 # +shift_period_suffix+;
367 # see details and suggestions at
368 # {Time#strftime}[rdoc-ref:Time#strftime].
371 _, name, rev = %w$Id$
373 name = name.chomp(",v")
375 name = File.basename(__FILE__)
377 rev ||= "v#{VERSION}"
378 ProgName = "#{name}/#{rev}"
382 # Logging severity threshold (e.g. <tt>Logger::INFO</tt>).
384 @level_override[Fiber.current] || @level
387 # Sets the log level; returns +severity+.
388 # See {Log Level}[rdoc-ref:Logger@Log+Level].
390 # Argument +severity+ may be an integer, a string, or a symbol:
392 # logger.level = Logger::ERROR # => 3
393 # logger.level = 3 # => 3
394 # logger.level = 'error' # => "error"
395 # logger.level = :error # => :error
397 # Logger#sev_threshold= is an alias for Logger#level=.
400 @level = Severity.coerce(severity)
403 # Adjust the log level during the block execution for the current Fiber only
405 # logger.with_level(:debug) do
406 # logger.debug { "Hello" }
408 def with_level(severity)
409 prev, @level_override[Fiber.current] = level, Severity.coerce(severity)
414 @level_override[Fiber.current] = prev
416 @level_override.delete(Fiber.current)
421 # Program name to include in log messages.
422 attr_accessor :progname
424 # Sets the date-time format.
426 # Argument +datetime_format+ should be either of these:
428 # - A string suitable for use as a format for method
429 # {Time#strftime}[rdoc-ref:Time#strftime].
430 # - +nil+: the logger uses <tt>'%Y-%m-%dT%H:%M:%S.%6N'</tt>.
432 def datetime_format=(datetime_format)
433 @default_formatter.datetime_format = datetime_format
436 # Returns the date-time format; see #datetime_format=.
439 @default_formatter.datetime_format
442 # Sets or retrieves the logger entry formatter proc.
444 # When +formatter+ is +nil+, the logger uses Logger::Formatter.
446 # When +formatter+ is a proc, a new entry is formatted by the proc,
447 # which is called with four arguments:
449 # - +severity+: The severity of the entry.
450 # - +time+: A Time object representing the entry's timestamp.
451 # - +progname+: The program name for the entry.
452 # - +msg+: The message for the entry (string or string-convertible object).
454 # The proc should return a string containing the formatted entry.
456 # This custom formatter uses
457 # {String#dump}[rdoc-ref:String#dump]
458 # to escape the message string:
460 # logger = Logger.new($stdout, progname: 'mung')
461 # original_formatter = logger.formatter || Logger::Formatter.new
462 # logger.formatter = proc { |severity, time, progname, msg|
463 # original_formatter.call(severity, time, progname, msg.dump)
465 # logger.add(Logger::INFO, "hello \n ''")
466 # logger.add(Logger::INFO, "\f\x00\xff\\\"")
470 # I, [2022-05-13T13:16:29.637488 #8492] INFO -- mung: "hello \n ''"
471 # I, [2022-05-13T13:16:29.637610 #8492] INFO -- mung: "\f\x00\xFF\\\""
473 attr_accessor :formatter
475 alias sev_threshold level
476 alias sev_threshold= level=
478 # Returns +true+ if the log level allows entries with severity
479 # Logger::DEBUG to be written, +false+ otherwise.
480 # See {Log Level}[rdoc-ref:Logger@Log+Level].
482 def debug?; level <= DEBUG; end
484 # Sets the log level to Logger::DEBUG.
485 # See {Log Level}[rdoc-ref:Logger@Log+Level].
487 def debug!; self.level = DEBUG; end
489 # Returns +true+ if the log level allows entries with severity
490 # Logger::INFO to be written, +false+ otherwise.
491 # See {Log Level}[rdoc-ref:Logger@Log+Level].
493 def info?; level <= INFO; end
495 # Sets the log level to Logger::INFO.
496 # See {Log Level}[rdoc-ref:Logger@Log+Level].
498 def info!; self.level = INFO; end
500 # Returns +true+ if the log level allows entries with severity
501 # Logger::WARN to be written, +false+ otherwise.
502 # See {Log Level}[rdoc-ref:Logger@Log+Level].
504 def warn?; level <= WARN; end
506 # Sets the log level to Logger::WARN.
507 # See {Log Level}[rdoc-ref:Logger@Log+Level].
509 def warn!; self.level = WARN; end
511 # Returns +true+ if the log level allows entries with severity
512 # Logger::ERROR to be written, +false+ otherwise.
513 # See {Log Level}[rdoc-ref:Logger@Log+Level].
515 def error?; level <= ERROR; end
517 # Sets the log level to Logger::ERROR.
518 # See {Log Level}[rdoc-ref:Logger@Log+Level].
520 def error!; self.level = ERROR; end
522 # Returns +true+ if the log level allows entries with severity
523 # Logger::FATAL to be written, +false+ otherwise.
524 # See {Log Level}[rdoc-ref:Logger@Log+Level].
526 def fatal?; level <= FATAL; end
528 # Sets the log level to Logger::FATAL.
529 # See {Log Level}[rdoc-ref:Logger@Log+Level].
531 def fatal!; self.level = FATAL; end
534 # Logger.new(logdev, shift_age = 0, shift_size = 1048576, **options)
536 # With the single argument +logdev+,
537 # returns a new logger with all default options:
539 # Logger.new('t.log') # => #<Logger:0x000001e685dc6ac8>
541 # Argument +logdev+ must be one of:
543 # - A string filepath: entries are to be written
544 # to the file at that path; if the file at that path exists,
545 # new entries are appended.
546 # - An IO stream (typically +$stdout+, +$stderr+. or an open file):
547 # entries are to be written to the given stream.
548 # - +nil+ or +File::NULL+: no entries are to be written.
552 # Logger.new('t.log')
553 # Logger.new($stdout)
555 # The keyword options are:
557 # - +level+: sets the log level; default value is Logger::DEBUG.
558 # See {Log Level}[rdoc-ref:Logger@Log+Level]:
560 # Logger.new('t.log', level: Logger::ERROR)
562 # - +progname+: sets the default program name; default is +nil+.
563 # See {Program Name}[rdoc-ref:Logger@Program+Name]:
565 # Logger.new('t.log', progname: 'mung')
567 # - +formatter+: sets the entry formatter; default is +nil+.
568 # See {formatter=}[Logger.html#attribute-i-formatter].
569 # - +datetime_format+: sets the format for entry timestamp;
571 # See #datetime_format=.
572 # - +binmode+: sets whether the logger writes in binary mode;
573 # default is +false+.
574 # - +shift_period_suffix+: sets the format for the filename suffix
575 # for periodic log file rotation; default is <tt>'%Y%m%d'</tt>.
576 # See {Periodic Rotation}[rdoc-ref:Logger@Periodic+Rotation].
578 def initialize(logdev, shift_age = 0, shift_size = 1048576, level: DEBUG,
579 progname: nil, formatter: nil, datetime_format: nil,
580 binmode: false, shift_period_suffix: '%Y%m%d')
582 self.progname = progname
583 @default_formatter = Formatter.new
584 self.datetime_format = datetime_format
585 self.formatter = formatter
588 if logdev && logdev != File::NULL
589 @logdev = LogDevice.new(logdev, shift_age: shift_age,
590 shift_size: shift_size,
591 shift_period_suffix: shift_period_suffix,
596 # Sets the logger's output stream:
598 # - If +logdev+ is +nil+, reopens the current output stream.
599 # - If +logdev+ is a filepath, opens the indicated file for append.
600 # - If +logdev+ is an IO stream
601 # (usually <tt>$stdout</tt>, <tt>$stderr</tt>, or an open File object),
602 # opens the stream for append.
606 # logger = Logger.new('t.log')
607 # logger.add(Logger::ERROR, 'one')
609 # logger.add(Logger::ERROR, 'two') # Prints 'log writing failed. closed stream'
611 # logger.add(Logger::ERROR, 'three')
613 # File.readlines('t.log')
615 # # ["# Logfile created on 2022-05-12 14:21:19 -0500 by logger.rb/v1.5.0\n",
616 # # "E, [2022-05-12T14:21:27.596726 #22428] ERROR -- : one\n",
617 # # "E, [2022-05-12T14:23:05.847241 #22428] ERROR -- : three\n"]
619 def reopen(logdev = nil)
620 @logdev&.reopen(logdev)
624 # Creates a log entry, which may or may not be written to the log,
625 # depending on the entry's severity and on the log level.
626 # See {Log Level}[rdoc-ref:Logger@Log+Level]
627 # and {Entries}[rdoc-ref:Logger@Entries] for details.
631 # logger = Logger.new($stdout, progname: 'mung')
632 # logger.add(Logger::INFO)
633 # logger.add(Logger::ERROR, 'No good')
634 # logger.add(Logger::ERROR, 'No good', 'gnum')
638 # I, [2022-05-12T16:25:31.469726 #36328] INFO -- mung: mung
639 # E, [2022-05-12T16:25:55.349414 #36328] ERROR -- mung: No good
640 # E, [2022-05-12T16:26:35.841134 #36328] ERROR -- gnum: No good
642 # These convenience methods have implicit severity:
651 def add(severity, message = nil, progname = nil)
653 if @logdev.nil? or severity < level
668 format_message(format_severity(severity), Time.now, progname, message))
673 # Writes the given +msg+ to the log with no formatting;
674 # returns the number of characters written,
675 # or +nil+ if no log device exists:
677 # logger = Logger.new($stdout)
678 # logger << 'My message.' # => 10
688 # Equivalent to calling #add with severity <tt>Logger::DEBUG</tt>.
690 def debug(progname = nil, &block)
691 add(DEBUG, nil, progname, &block)
694 # Equivalent to calling #add with severity <tt>Logger::INFO</tt>.
696 def info(progname = nil, &block)
697 add(INFO, nil, progname, &block)
700 # Equivalent to calling #add with severity <tt>Logger::WARN</tt>.
702 def warn(progname = nil, &block)
703 add(WARN, nil, progname, &block)
706 # Equivalent to calling #add with severity <tt>Logger::ERROR</tt>.
708 def error(progname = nil, &block)
709 add(ERROR, nil, progname, &block)
712 # Equivalent to calling #add with severity <tt>Logger::FATAL</tt>.
714 def fatal(progname = nil, &block)
715 add(FATAL, nil, progname, &block)
718 # Equivalent to calling #add with severity <tt>Logger::UNKNOWN</tt>.
720 def unknown(progname = nil, &block)
721 add(UNKNOWN, nil, progname, &block)
724 # Closes the logger; returns +nil+:
726 # logger = Logger.new('t.log')
727 # logger.close # => nil
728 # logger.info('foo') # Prints "log writing failed. closed stream"
730 # Related: Logger#reopen.
737 # \Severity label for logging (max 5 chars).
738 SEV_LABEL = %w(DEBUG INFO WARN ERROR FATAL ANY).freeze
740 def format_severity(severity)
741 SEV_LABEL[severity] || 'ANY'
744 def format_message(severity, datetime, progname, msg)
745 (@formatter || @default_formatter).call(severity, datetime, progname, msg)