Logging and Warnings#

Parameterized objects provide methods for displaying logging messages and warnings in a way that can be controlled and redirected globally using the standard Python logging module (see the logging cookbook). Compared to using a Python logger directly, using these methods inside your Parameterized class helps users by making the messages consistent, each prepending with information about the Parameterized object where the call was made so that your users can understand what the message indicates.

By default, a Python logger named param will be instantiated to do the logging, but another logger can be supplied by setting param.parameterized.logger to it after importing param.parameterized.

Writing log messages#

Each logging message has an associated logging level that indicates how severe a condition is being described (DEBUG, VERBOSE, INFO (aka “message”), WARNING, ERROR, or CRITICAL). These levels are as defined by the logging module, except for the addition of VERBOSE as a level intermediate between DEBUG (internal debugging information) and INFO (user-relevant non-error messages).

The typical way to print a message is to call .param.log() with one of the following logging levels:

  • .param.log(param.DEBUG, ...): Detailed debugging information, not displayed onscreen by default.

  • .param.log(param.VERBOSE, ...): Additional sometimes-useful information, not displayed onscreen by default.

  • .param.log(param.INFO, ...): Informative message, displayed onscreen by default.

  • .param.log(param.WARNING, ...): Warning of an unexpected or inappropriate but non-fatal condition, displayed onscreen by default.

For convenience and to allow eventual integration with the Python warnings module, .param.warning( is available as an alias for .param.log(param.WARNING,:

  • .param.warning(...): Warning of an unexpected or inappropriate but non-fatal condition, displayed onscreen by default.

The arguments accepted in each case are the same as those of logging.debug(). Specifically, each call is like .param.debug(msg, *args, **kw), where msg is an old-style (‘%’) format string and the args and kwargs will be merged with that format string. E.g.:

import param

desired = 1
actual = 5

param.main.param.log(param.INFO, "Welcome!")
param.main.param.log(param.VERBOSE, "Local variables: %s", locals())
param.main.param.log(param.WARNING, "Value %02d is not %d", actual, desired)
param.main.param.warning("Value %02d is not %d", actual, desired)

INFO:param.main: Welcome!

WARNING:param.main: Value 05 is not 1

WARNING:param.main: Value 05 is not 1

Here we’ve used the default global Parameterized object param.main, useful for generic module-level messages, but more often you would make a call like self.param.log() inside a Parameterized class instead. You can see that the messages are each prefixed by the logging level, param (the name of the default logger), and the name of this object (main in this case). You can also see that, by default, verbose messages are not actually printed.

You may wonder (a) why the formatting string is “old style” , and (b) why the formatting values “actual, desired” are not combined directly with the formatting string. I.e., why not just use a Python3 f-string, like:

param.main.param.log(param.WARNING, f"Value {actual:02} is not {desired}") # Discouraged!

WARNING:param.main: Value 05 is not 1

The answer is that particularly for debug and verbose messages that could occur inside frequently executed code, we want logging to be “lazy”, in that we do not want to render a string representation for actual, desired, etc. unless we are actually printing the message. If we use an f-string or any other locally formatted string, the string formatting will be done whether or not the message will be displayed, potentially causing drastic slowdowns in your code. For instance, in the code above, the entire locals() dictionary would be iterated over, printed to strings. Of course, since the message isn’t being printed in that case, the entire format string would then be discarded, greatly slowing down the code without producing any output. To avoid that, the logging module has to defer the string substitution and handle that itself, and it was written before Python3, so it only supports old-style substitution. So, even though it is more awkward, it is highly recommended to use this old-style, lazy string formatting support.

Controlling the logging level#

You can use the param.parameterized.logging_level context manager to temporarily reduce or elevate the logging level while you execute code:

with param.logging_level('CRITICAL'):
    param.main.param.log(param.INFO, "Message 1")
    param.main.param.log(param.VERBOSE, "Verbose 1")

with param.logging_level('DEBUG'):
    param.main.param.log(param.INFO, "Message 2")
    param.main.param.log(param.VERBOSE, "Verbose 2")

INFO:param.main: Message 2

VERBOSE:param.main: Verbose 2

You can also set the value more globally (and permanently) on the logger object:

param.get_logger().setLevel(param.DEBUG)

param.main.param.log(param.INFO, "Message 2")
param.main.param.log(param.VERBOSE, "Verbose 2")

INFO:param.main: Message 2

VERBOSE:param.main: Verbose 2

For testing, continuous integration (CI), or other specific applications, you can also set param.parameterized.warnings_as_exceptions = True, which will cause your program to raise an exception the first time it encounters any warning.

Controlling the formatting of log messages#

The Python logging module provides many options for configuring how the log messages are generated. For complete control, you can instantiate your own logger and set param.parameterized.logger to it after importing param.parameterized.

A hook is provided for the relatively common case when you want to prefix each message with the time of day, a progress indication, a simulator time, or some other indication of a global state. Specifically, you can set param.parameterized.dbprint_prefix to a callable object returning a string. The object will be called when constructing each message:

from datetime import datetime
#param.parameterized.warnings_as_exceptions = True

param.parameterized.dbprint_prefix=lambda: str(datetime.now())

param.main.param.warning("Message 4")
param.main.param.warning("Message 5")

WARNING:param.main: 2024-03-22 08:45:14.266861: Message 4

WARNING:param.main: 2024-03-22 08:45:14.267552: Message 5

Counting warnings#

Typically, a program will abort if an error is encountered, making such a condition hard to miss, but warning messages might be lost in a sea of informational, verbose, or debug messages. Param keeps track of how many times .param.warning(...) (or its alias .param.log(param.WARNING, ...)) has been called, and it is often useful to print out that value at the end of a program run:

print(f"Run completed. {param.parameterized.warning_count} warnings were encountered.")

Run completed. 5 warnings were encountered.