News for hackers. Stuff that matters.
Re:Flake8-Logging by kstrauser on Tuesday September 12, 2023 @12:20AM (#37476905)
I tried it for science:

    import logging
    import timeit

    LOG = logging.getLogger()

    ip = "1.2.3.4"
    request = "/index.html"
    duration = 1.5

    print(timeit.timeit("LOG.info('%s: %s (%s)', ip, request, duration)", globals=globals()))

    print(timeit.timeit("LOG.info(f'{ip}: {request} ({duration})')", globals=globals()))
1,000,000 iterations of the flake8-happy logging took 0.090s. The f-string version took 0.264.

On one hand, the flake8 version is significantly faster if the log messages aren't emitted. On the other, the "slow" f-string version ran 4 million times a second while inside a timing harness. That's likely to be a trivial percent of any interesting program's CPU time unless it's inside a timing-critical inner loop, in which case don't do that.

For an extra data point, I bumped that up to `LOG.warning()` and re-ran the tests. A million flake8 runs took 4.617. A million f-string runs took 4.553s. If you're actually emitting the debugging record, f-strings are slightly faster. Huh, interesting. Today I learned!

I'll continue to use f-string logging in common cases. When it's slower, it's so very slightly slower that I don't care. But as others have mentioned, the `extra` argument when using flake8-style logging is brilliant for emitting structured data that's easier to parse later.

There are no comments on this comment yet.