Logging and Progress Reporting#

LensKit provides support code for logging and progress reporting. This code lives in the lenskit.logging package and provides several capabilities:

  • Logger acquisition functions with useful defaults.

  • Backend-independent progress reporting, with colorful progress bars (via Rich) on terminals.

  • Easy logging configuration for recommender scripts, supporting log files and verbosity options, along with environment variables for logging levels.

  • Integration between structlog and Python logging.

  • Tracking resource consumption for recommender experiment tasks (via Task).

  • Collecting log output from subprocesses in process-based parallel computation.

Logging Configuration#

When writing code that uses LensKit, such as experiment runners, the LoggingConfig class provides an easy way to set up logging for common command-line scenarios. Common usage looks like this (where options is a variable of command-line options from argparse or similar):

lc = LoggingConfig()
# turn on verbosity if requested
if options.verbose:
    lc.set_verbose()
# if there is a log file, send DEBUG-level messages there
if options.log_file:
    lc.set_log_file(options.log_file, logging.DEBUG)
# set up the logging
lc.apply()

Calling LoggingConfig.apply() configures both Python standard library logging and structlog to log in a consistent format to stderr (and to the log file, if configured), sets up progress bars, routes Python warnings to the log system, and generally makes sure that LensKit and other code emitting logs (including your code) will send them to useful places.

For setup with even less code, but less flexibility, you can use the basic_logging() function.

Environment Variables and Defaults#

LoggingConfig.apply() looks for settings in the following places, in decreasing order of priority:

  1. The explicitly-called methods (e.g. set_verbose()).

  2. Environment variables (see below).

  3. Built-in default: print INFO and higher-level messages to the console.

Several environment variables control logging behavior if explicit configuration methods are not called, allowing you to configure logging even when your scripts are run by other tools like DVC.

LK_LOG_LEVEL#

The log level for console log output. Defaults to INFO.

LK_LOG_FILE#

Path to a log file to receive log messages.

LK_LOG_FILE_LEVEL#

The level for messages going to the log file. Defaults to the console log level; this allows you to send DEBUG messages to the file while only INFO messages go to the console.

Emitting Log Messages#

When writing LensKit code that needs to emit log messages, use LensKit’s get_logger() function. This wraps Structopt’s get_logger in a proxy that has more useful LensKit defaults (only emitting warnings and errors when logging has not been configured). The resulting logger can be used like any other Structlog or standard library logger.

Structlog loggers are lazy, resolving their configurations when they are bound with variables. When emitting many log messages in a loop or function, we recommend calling structlog.typing.BindableLogger.bind() to get a bound logger with the configuration resolved, which will be much faster for repeated fine-grained logging messages.

Progress Reporting#

LensKit provides a simple progress bar façade for reporting progress in batch inference, model training, etc. See the lenskit.logging.progress modules for details, if you are implementing components from which you want to report progress. The key entry point is to call item_progress() to create a progress bar. LensKit automatically handles routing progress to the appropriate backend.