Be Careful with Your F-strings

I love Python f-strings. They eliminate the pain of having to do the mental math around placeholders, tuple wrapping, and dealing with runtime errors when you do it wrong. Instead, they let you focus on the string being created, with the values you want in the string appearing in the place they’re needed. Here’s an example:

>>> name = "Siegescape"
>>> value = 24 * 60 * 60
>>> str = "%s: %i" % (name, value)  # old style
>>> str = f"{name}: {value}"  # much nicer!

The darker side of f-strings

A codebase I work on has standardized on using f-strings everywhere. I recently ran into a problem, though, using f-strings to perform some logging. The code in question runs in as an Amazon Lambda function, and a recent rollout resulted in some spikes in executing time. I dug in and isolated the code, did a bit of profiling, and discovered that the issue was a debug log statement, despite logging being turned off. The code looked something like this:

for event in events:
    logging.debug(f"Checking conditions for event {event}")
    for condition in conditions:
        did_condition_apply = apply_condition(condition, event)
        logging.debug(f"{conditions} {did_condition_apply}")

Nothing was being printed with debug turned off, so my brain said “nothing to look at here, let’s grab a beer!” What I overlooked, of course, is the fact that the string formatting within the f-string happens regardless of whether or not the statement is printed. As a result, the code was formatting thousands and thousands of long and complex conditions objects without needing them. Eliminating that line resulted in a 30X speedup!

Of course, this problem isn’t limited to f-strings: an old-style format string would have done the same thing. In fact, the logging module includes a facility for dealing with exactly this issue, but it’s (necessarily) based on old-style string formatting. Using this feature, I could rewrite the line within the nested loop above like so, without any performance penalty - the formatting only happens if the log message is printed:

logging.debug("%s %s", condition, did_condition_apply)

Of course, this stands out like a sore thumb in a codebase where all of the rest of the format strings are f-strings.

The real gotcha in my opinion is the fluidity with which you can include expressions in your f-strings, but which look like regular strings. When I glance at an f-string, i see a short, terse string; hiding within could be an arbitrarily large amount of code execution. I am reminded of my C/C++ days, when I heard the argument that constructors were too much of a cognitive load because they could hide an arbitrary amount of code, yet they seemed like they were no different than creating a basic type. Likewise, f-strings look like strings but are really vehicles for arbitrarily complex embedded expressions.

The moral: be careful with your f-strings!

Joseph Turner