The stdlib logging package in Python encourages the C-style message format string and passing variables as arguments to its log method. For example,

logging.debug("Result x = %d, y = %d" % (x, y))  # Bad
logging.debug("Result x = %d, y = %d", x, y)     # Good

or

logging.debug("Result x = %(x)d, y = %(y)d" % {"x": x, "y": y})  # Bad
logging.debug("Result x = %(x)d, y = %(y)d", {"x": x, "y": y})   # Good

As the message does not need to be formatted when the logging level is set higher than the value set for the logger, we would waste time formatting the string in the “bad” cases above, when the message does not get logged at all. The “good” cases avoid this by deferring formatting until the logger finds it necessary.

Sometimes, though, we may want to log debug messages with values that are expensive to compute. For example, in the above example, what if y depends on x, and the function that does the computation, e.g.,

def get_y(x):
    ... expensive computation ...
    return result

is rather expensive? If this is done only for the purpose of the debug message, that would be a wasteful computation when the logging level is higher than the value at which the result is logged.

Lazy Function Evaluation with logging

Fortunately, it is easy to add lazy evaluation of function using a custom dict and functools.partial.

import logging
from collections import UserDict
from functools import partial


class Args(UserDict):
    def __getitem__(self, key):
        value = super().__getitem__(key)
        if callable(value):
            value = value()
        return value


def get_y(x):
    # ... expensive computation ...
    return result


logging.debug("Result x = %(x)d, y = %(y)d", Args(x=x, y=partial(get_y, x)))

The idea is to use partial to defer the execution of the function,¹ and store it in a dict-like object that is aware of the need to call the function on access through the key.