1

I have a debug logging method in my program that just prints the passed in string to sys.stderr if debug is True:

def debug_log(str):
    if debug:
        print(str, file=sys.stderr)

However, I'm currently passing in some f strings containing expressions that would be time-consuming computations once I go from my debugging data set with a few hundred items to my production dataset with a few million items. If I have a line in my code like:

debug_log(f'{sum([author_dict[a].get("count") for a in author_dict.keys()])} count total in author_dict')

am I correct to assume that that sum is going to get computed when I call debug_log, rather than only happening inside debug_log when it goes to actually do the print statement? And if that's the case is there a clean way to set this up so that it doesn't do the computation when debug is False? (Otherwise I'll just comment out the lines where that's going to matter before I run in production)

PurpleVermont
  • 1,179
  • 4
  • 18
  • 46
  • 2
    No. But the `logging` module does that. – mkrieger1 Feb 19 '22 at 22:47
  • 2
    The f-string is evaluated when the line containing it is being executed. On a complicated line some other thing may happen first, but as soon Python needs the value of the expression, it is evaluated and then passed. If you want to pass a template string, you can just pass the string without `f` and call `.format()` on it later, or you can use the specific features of something like the `logging` module if you only need that. – Grismar Feb 19 '22 at 22:52

2 Answers2

1

As pointed out in the comments, arguments are evaluated eagerly, f-strings included. To make the evaluation lazy, The logging functions accept *args and **kwargs for example, as explained here.


Now, a clean way would be using strings that are subsequently format()ed instead of f-strings, but if f-string are just too much convenient you can still use lambdas (only when lazy-evaluation is needed). You could change the debug_log function in something like this:

def debug_log(log):
    if not debug: return
    str_log = log() if callable(log) and log.__name__ == '<lambda>' else log
    print(str_log, file=sys.stderr)

A few examples should make everything more clear.


Eager evaluation is good

If you need to print an argument that does not need to be lazily evaluated, then nothing is different from before:

>>> debug = False
>>> debug_log('hello')
>>> debug = True
>>> debug_log('hello')
hello

Lazy evaluation necessary

Now suppose you have a function like this one:

def test():
    print('please print me if necessary')
    return 'done'

If called inside debug_log as-is, then

>>> debug = False
>>> debug_log(test())
please print me if necessary

But, of course, you do not want to see please print me if necessary because debug = False. So, the clean way would be:

>>> debug = False
>>> debug_log(lambda: f'we are {test()}')
>>> debug = True
>>> debug_log(lambda: f'we are {test()}')
please print me if necessary
we are done

Basically, by enclosing an f-string inside a lambda, you can be sure that it is executed only when the lambda is actually called.

Marco Luzzara
  • 5,540
  • 3
  • 16
  • 42
0

This question slightly overlaps with another one, to which I also gave my answer. I'll duplicate it here and supplement it a little.

The fact is that I wrote my own library implementing lazy f-strings. It is fully compatible with the logging library.

Install it:

pip install fazy

And use:

import f

number = 33
print(f('{number} kittens drink milk'))

To check that this library does what you expect, that is, it postpones the creation of a line for logging, try this piece of code:

from time import sleep
import logging
import f


class LongPrintable:
    def __init__(self, data):
        self.data = data

    def __str__(self):
        sleep(10.0)
        return str(self.data)


logging.basicConfig(
    level=logging.INFO,
    format="%(asctime)s [%(levelname)s] %(message)s",
    handlers=[
        logging.StreamHandler(),
    ]
)

number = LongPrintable(33)
logging.debug(f('{number} kittens drink milk'))

As you can see, this code is executed almost instantly, and does not fall asleep for 10 seconds, as one might expect. However, if you replace logging.debug with logging.info, the code will fall asleep, because in this case the string will actually be used inside logging and it will take time to calculate it.

Read more about the features and limitations of this library in its documentation.

Evgeniy Blinov
  • 351
  • 3
  • 3