Module log

A global logging module that logs to REAPER's console.

This module provides many conveniences and performance improvements over REAPER's native ShowConsoleMsg(). All log lines are prefixed with timestamp and log level, and format strings with variable arguments are supported.

Messages logged within this module are queued until the end of the defer update cycle, which provides significant performance benefits. If for some reason you need the log message to display immediately, you can use log.flush(). But this is very rarely needed.

Use a module-local log variable

This module is automatically available under rtk.log but it is idiomatic to assign it to a module-local log variable:

local rtk = require('rtk')
local log = rtk.log

-- Set the current log level to INFO
log.level = log.INFO
-- This log line won't show on the console because DEBUG is less
-- severe than the current INFO level.
log.debug('the current log level is %s', log.level_name(log.level))
-- Meanwhile, this one will display.
log.critical('self destruct sequence initiated')

Another major feature of this module is for timing code blocks with microsecond precision, and which can even be nested so you can see the time spent in the constituent parts of an overall expensive task:

function compute()
   log.time_start('expensive-thing')
   do_something_expensive()
   log.time_end()
end

log.time_start('mytask')
preamble()
for i = 1, 42 do
    compute()
end
log.time_end_report('finished doing some task')

The resulting output to the console would look something like:

  21:30:05.137 [DEBUG]  (162 / 162 ms)  finished doing some task
          1.          mytask: 162.1551 ms  (1)
          2. expensive-thing:  41.4113 ms  (42)

Synopsis

Fields
level logconst

read/write

Current log level, set to one of the log level constants (default log.ERROR)

timer_threshold logconst

read/write

Log level at or below which timers are logged (default log.INFO)

log.level logconst read/write

Current log level, set to one of the log level constants (default log.ERROR). Lines logged levels equal to or more severe than this value will appear on REAPER's console.

log.timer_threshold logconst read/write

Log level at or below which timers are logged (default log.INFO). See log.time_start() for more details

Log Level Constants

These constants are used to control the log level. The numeric values for each of the constants is included below, where higher values means greater severity.

You can define your own log levels, just don't reuse one of the numeric values below for your custom log level.

log.CRITICAL

50

log.ERROR

40

log.WARNING

30

log.INFO

20

log.DEBUG

10

log.DEBUG2

9

Module Functions

Synopsis

Functions
log.critical()

Logs a message with level CRITICAL

log.error()

Logs a message with level ERROR

log.warning()

Logs a message with level WARNING

log.info()

Logs a message with level INFO

log.debug()

Logs a message with level DEBUG

log.debug2()

Logs a message with level DEBUG2

log.exception()

Logs a message with level ERROR and includes a stack trace

log.trace()

Logs a stack trace at the given level

log.log()

Logs a message at any level

log.logf()

A variant of log() that allows format arguments to be passed as a function

log.flush()

Immediately write any queued log messages to the console

log.level_name()

Gets the printable name of one of the log level constants

log.clear()

Clears REAPER's console

log.time_start()

Begins a timer to track the duration between log events

log.time_end()

Stops the last timer started by log.time_start()

log.time_end_report()

Stops the last timer started by log.time_start() and shows a summary of named timers

log.time_end_report_if()

Stops the last timer started by log.time_start() and shows a summary of named timers of the given conditional is true

log.critical(fmt, ...)

Logs a message with level CRITICAL.

Parameters
fmt (string)

a format string according to Lua's native string.format().

... (any)

zero or more optional arguments according to the given format string.

log.error(fmt, ...)

Logs a message with level ERROR. Arguments are as with log.critical().

log.warning(fmt, ...)

Logs a message with level WARNING. Arguments are as with log.critical().

log.info(fmt, ...)

Logs a message with level INFO. Arguments are as with log.critical().

log.debug(fmt, ...)

Logs a message with level DEBUG. Arguments are as with log.critical().

log.debug2(fmt, ...)

Logs a message with level DEBUG2. Arguments are as with log.critical().

log.exception(fmt, ...)

Logs a message with level ERROR and includes a stack trace.

The stack trace displayed will include a frame from within this function, but that can be ignored.

Arguments are as with log.critical().

log.trace(level)

Logs a stack trace at the given level.

The stack trace displayed will include a frame from within this function, but that can be ignored.

Parameters
level (logconst or nil)

the log level at which to log the trace, or log.DEBUG if not specified.

log.log(level, fmt, ...)

Logs a message at any level.

Parameters
level (logconst)

the log level at which to log the message

fmt (string)

a format string according to Lua's native string.format().

... (any)

zero or more optional arguments according to the given format string.

log.logf(level, fmt, func)

A variant of log() that allows format arguments to be passed as a function.

The supplied function would only be invoked if the log level was such that the message would get written, and it's expected to return the arguments for the format string.

This is useful for lazy-evaluating arguments to avoid the overhead of expensive arguments if the log level is such that we would never print it anyway.

log.logf(log.DEBUG, '%d of these arguments is expensive: %s', function()
    return 1, get_expensive_thing()
end)
Parameters
level (logconst)

the log level at which to log the message

fmt (string)

a format string according to Lua's native string.format().

func (function)

a function that returns the format string arguments.

log.flush()

Immediately write any queued log messages to the console.

Messages are normally queued and written to REAPER's console at the end of the update cycle, which provides a noticeable performance improvement when logging a lot of content. But this function can be called explicitly to immediately flush queued messages to the console.

log.level_name(level)

Gets the printable name of one of the log level constants.

Parameters
level (logconst)

the log level whose name to fetch

Return Values
(string)

the name of the log level

log.clear(level)

Clears REAPER's console.

Parameters
level (logconst or nil)

the level at or below which the current log level must be in order for the console to be cleared. If nil, the console is cleared regardless of current log level.

log.time_start(name)

Begins a timer to track the duration between log events.

After this function is called, all subsequent logged messages will include timer information (amount of time since the last log line, and the amount of cumulative time since the last log.time_start() call was made) until the timer is stopped with log.time_end().

log.time_start() can safely be nested, but you must be sure to call log.time_end() the same number of times.

Named timers can be used to track the total time spent in code sections and provide a final report on execution time and number of calls, acting as a poor-man's profiler. See log.time_end_report() for more.

Parameters
name (string or nil)

the optional name of the timer for a final report. If no name is given, subsequent log messages still show delta time and total time, but no final report is possible.

log.time_end(fmt, ...)

Stops the last timer started by log.time_start().

In addition to stopping the last timer, the optional log message, if provided, is logged at DEBUG level.

Arguments are as with log.critical().

log.time_end_report(fmt, ...)

Stops the last timer started by log.time_start() and shows a summary of named timers.

The current state of any named timers (those where a name value was passed to log.time_start()) will be dumped following the optional log message, which is logged at DEBUG.

The timer report shows all named timers in the order they were started, the culumlative total for each timer, and the number of times the code block was executed.

The report will only display when log.level is at or below log.timer_threshold.

Arguments are as with log.critical().

log.time_end_report_if(show, fmt, ...)

Stops the last timer started by log.time_start() and shows a summary of named timers of the given conditional is true.

Note

This is bit more than just syntactic sugar for wrapping log.time_end_report() in an if statement because the last timer started by log.time_start() is stopped regardless. The conditional show only controls whether the report is logged.

Parameters
show (bool)

if true, the report will be written to the console

fmt (string)

a format string according to Lua's native string.format().

... (any)

zero or more optional arguments according to the given format string.