This is a continuation of
RFC-29, and narrower in scope.
I would like to switch from using pex.logging to lsst.log in pipe_base. After that, all pipeline tasks (task or cmdLineTask) can switch to use lsst.log. With lsst::log (via log4cxx implementation) there are 6 logging levels (trace, debug, info, warn, error, fatal). Arbitrary integers will no longer be accepted as levels. In this framework it’s encouraged to use loggers with distinct, hierarchical names instead of custom levels.
In Python, I plan to use the recently added lsst.log Python interface, not through Python logging and LogHandler. For example:
For most tasks, little modifications are needed in Python, as long as the task’s own log attribute is used for logging. The “logdebug” method in pex_logging will be replaced by “debug”, and most will be format changes.
For CmdLineTasks, the namespace logging level control from the command line -- loglevel is preserved. The command line option -- logdest will be removed; the file destination is instead set through log4cxx configuration. As I understand, many people use this option for its default formatter with dataId attached with each log record. After switching to lsst::log, dataId can still be included in the logs. I’m thinking two possibilities: an command line option to include the dataId in log records, or an command line option to more easily supply user’s own log4cxx configuration file in which format can be set.
In C++, macros are used, e.g.
For logging one can use either one of the two macro families, the sprintf-based interface:
and the iostream-based interface:
The transition plan is to do this in stages: (1) individual logging not chained to CmdLineTask (e.g. daf_butlerUtils, or hard-coded and non-configurable logging), as they are not configurable through the command line task interface anyway. (2) Python-side logging for tasks/CmdLineTasks plus log in C ++. (3) Debug/Trace in C ++. They are typically run with unit tests and each package can be handled separately.
Logger names should generally start with the (fully-qualified) name of the module/file containing the logger. If the logger is saved as a variable in a class, it is often appropriate to name the logger after the class. Logger names use "." as component separators, not "::", even in C++.
In Python, comma-separated arguments are preferred over the string formatting so it is done only if the log record is to be printed.
Log levels should be used as follows:
- FATAL: for severe errors that may prevent further execution of the component
- ERROR: for errors that may still allow the execution to continue
- WARNING: for conditions that may indicate a problem but that allow continued execution
- INFO: for information that is of interest during normal execution including production
- DEBUG: for information that is of interest to developers but not of interest during production
- TRACE: for detailed information when debugging
For loggers used at DEBUG and TRACE levels, it is often desirable to add further components to the logger name; these would indicate which specific portion of the code or algorithm that the logged information pertains to.
The idea here is that the author understands the intent of the log message and can simply name it, without worrying about its relative importance or priority compared with other log messages in the same component. A person debugging the code would typically be looking at it and so would be able to determine the appropriate name to enable. The hierarchy allows all components to be easily enabled or disabled together.
As an alternative for TRACE loggers where there are different messages at increasing levels of verbosity but no specific component names that would be appropriate, or where increasing verbosity spans a number of levels of the component hierarchy, logger names can be prefixed with "TRACE1", "TRACE2", "TRACE3", etc. to indicate increasing verbosity.
Notice that all loggers in the hierarchy under a given component at a given trace level can be enabled easily using, e.g., "TRACE2.lsst.meas.algorithms.starSelector".
Getting a logger object and logging to that is preferred over logging using a string as the logger name. The latter can be used, for examples:
Developers are encouraged to insert log messages whenever and wherever they might be useful, with appropriate component names and levels.