fast logger with multiple modes and formats

Overview

PyPi module N/A
git repository https://bitbucket.org/arrizza-public/rb-falcon-logger
git command git clone git@bitbucket.org:arrizza-public/rb-falcon-logger.git
Verification Report https://arrizza.com/web-ver/rb-falcon-logger-report.html
Version Info
OS Language #Runs Last Run Cov%
Ubuntu 24.04 noble Ruby 3.2.3 765 2025-05-21 100.0

Summary

This is a ruby gem that provides a way to run a fast logger. see https://arrizza.com/python-falcon-logger.html for a python version

Sample code

see src/logger_tester.rb for a full example

Use doit script to run the logger.

TODO logger_tester args TODO multithreaded_tester

parameters and functions

Use these on the logger creation: @log = FalconLogger(path: etc, max_entries: etc, mode: etc.)

  • path: nil : (default) write to stdout
  • path: 'path/to/file' : write to the given file
  • max_entries: 10: flush the queue when this number of log entries is reached.
  • loop_delay: 0.250: check the queue this often. The longer the delay, the fast it runs.
  • Note: use max_entries: 1 and loop_delay: 0.001, to flush the queue as often as possible
  • set_verbose(true) - (default) print all log lines to stdout/file.
  • set_verbose(false) - only print err(), critical(), exception(), and bug() lines
  • @log.set_max_dots(num) set the number of dots to print before a newline is printed
  • use @log.save to force the queue to be saved. Generally not recommended.
  • use @log.term to clear out the queue and gracefully end the background thread

There are 3 modes: FalconLogger(mode: 'normal')

  • nil or 'normal': (default) writes a line to stdout or the file. See below for outputs
  • 'ut' or 'mock': useful in UTs. These do not write to stdout or to a file.
    • The lines are saved in an internal list accessible by: @log.ut_lines.
    • Use @log.ut_clear or @log.ut_lines = [] to empty it.
  • 'null': is useful when you don't want any output. No stdout, no file, no ut_lines.

There are 3 formats: 'elapsed' (default), 'prefix', 'none'

  • Use @log.set_format(fmt) to set the format to fmt

'elapsed' format outputs

These contain:

  • the number of MM:SS.nnn milliseconds since the last log line
    • if this the first log line, the current date time stamp is automatically printed: DTS 2025/05/11 16:21:43.170
    • if an hour goes by since the last DTS, then it is automatically printed
  • a prefix indicating the type of log line error, OK, Debug, etc.
@log.set_format('elapsed')  # the default format

# idx = 2

# === showing with elapsed time delays
# === @log.start("#{idx}:", 'start of dts values')
# === sleep(0.250)
# === @log.line("#{idx}:", 'start + 250ms')
# === sleep(0.123)
# === @log.line("#{idx}:", 'start + 373ms')
00:00.000 ==== 2: start of dts values
00:00.250      2: start + 250ms
00:00.373      2: start + 373ms

# === the automatic DTS line when 1 hour has elapsed or at the beginning
# === @log.start("#{idx}:", 'start')
          DTS  2025/05/21 19:01:11.154
00:00.000 ==== 2: start

# === @log.line("#{idx}:", 'line')
00:00.000      2: line

# === @log.highlight("#{idx}:", 'highlight')
00:00.000 ---> 2: highlight

# === @log.ok("#{idx}:", 'ok')
00:00.000 OK   2: ok

# === @log.err("#{idx}:", 'err')
00:00.000 ERR  2: err

# === @log.warn("#{idx}:", 'warn')
00:00.000 WARN 2: warn

# === @log.bug("#{idx}:", 'bug')
00:00.000 BUG  2: bug

# === @log.dbg("#{idx}:", 'dbg')
00:00.000 DBG  2: dbg

# === @log.raw("#{idx}", 'raw', 'line')
2 raw line

# === @log.output(nil, "#{idx}:", 'output (line nil)')
# === @log.output(21, "#{idx}:", 'output (line 21)')
00:00.000  --       2: output (line nil)
00:00.000  --   21] 2: output (line 21)

#=== lines = ["#{idx}: num_output (line 1)", "#{idx}: num_output (line 2)"]
#=== @log.num_output(lines)
00:00.000  --    1] 2: num_output (line 1)
00:00.000  --    2] 2: num_output (line 2)

# === @log.check(true, "#{idx}:", 'check true')
# === @log.check(false, "#{idx}:", 'check false')
00:00.000 OK   2: check true
00:00.000 ERR  2: check false

# === lines = ["#{idx}: check_all (line 1)", "#{idx}: check_all (line 2)"]
# === @log.check_all(true, 'check_all true title', lines)
00:00.000 OK   check_all true title: true
00:00.000 OK      - 2: check_all (line 1)
00:00.000 OK      - 2: check_all (line 2)

# === info = { 'key1' => ['val1'] }
# === @log.json(info, "#{idx}:", 'json', 'list (json/hash)')
00:00.000      2: json list (json/hash)
00:00.000  >   {
00:00.000  >     "key1": [
00:00.000  >       "val1"
00:00.000  >     ]
00:00.000  >   }

#=== val = "\x00\x01\x02\x03\x04\x05\x06\x07\x08\x09\x0A\x0B\x0C\x0D\x0E\x0F\x10\x11"
#=== @log.hex(val, "#{idx}:", 'hex long')
00:00.000      2: hex long
00:00.000          0 0x00: 00 01 02 03 04 05 06 07   08 09 0A 0B 0C 0D 0E 0F
00:00.000         16 0x10: 10 11

# === @log.debug("#{idx}:", 'debug')
00:00.000 DBG  2: debug

# === @log.info("#{idx}:", 'info')
00:00.000      2: info

# === @log.warning("#{idx}:", 'warning')
00:00.000 WARN 2: warning

# === @log.error("#{idx}:", 'error')
00:00.000 ERR  2: error

# === @log.critical("#{idx}:", 'critical')
00:00.000 CRIT 2: critical

# === val = 5
# === begin
# ===   val /= 0
# === rescue ZeroDivisionError => e   # <== note: use max_lines: 1 to reduce the amount of output you need
# ===   @log.exception(e)
# === end
# === @log.line("after excp; val=#{val}")
00:00.000 EXCP divided by 0
00:00.000 EXCP Backtrace:
00:00.000 EXCP    <snip>/logger_tester.rb:178:in `/'
00:00.000 EXCP    <snip>/logger_tester.rb:178:in `_log_exception'
00:00.000 EXCP    <snip>/logger_tester.rb:88:in `block in run'
    
# === @log.full_dts
       DTS  2025/05/11 16:21:43.170

'prefix' format outputs

These are the same as elapsed format, except no elapsed times. Use ./doit normal prefix to see an example.

@log.set_format('prefix')

# === @log.ok("#{idx}:", 'ok')
OK   2: ok
# === @log.err("#{idx}:", 'err')
ERR  2: err
<snip>

'none' format outputs

These are the same as elapsed/prefix format, except no elapsed times or prefixes Use ./doit normal none to see an example.

@log.set_format('none')

# === @log.ok("#{idx}:", 'ok')
2: ok
# === @log.err("#{idx}:", 'err')
2: err
<snip>

dots

To put out a series of dots to show progress, use @log.dot.

Periodically a newline is printed. The default is 25, use @log.set_max_dots(nn) to change it

./doit examples

  • Use ./doit file to generate a file out/sample.log
  • Use ./doit null to use mode: 'null', no output, no file generated
  • Use ./doit ut or ./doit mock to use mode: 'ut'. This mode can be used in unit tests.
  • Use ./doit thread to see an example of a multithreaded use of the logger. The default is:
    • 100 client threads
    • each client thread putting in 1000 entries onto the queue.
    • There are random delays between each push() between 0 and 250ms
    • each client thread logs it is putting an entry on the queue using FalconLogger
    • 1 background thread checking that queue, and printing any entries using FalconLogger
    • This takes just over 2m (on my PC)

- John Arrizza