logging.isEnabledFor vs lazyjoin class benchmark

isEnabledFor_vs_class_benchmark.py

import logging
logging.basicConfig(level=logging.INFO)
logger = logging.getLogger("log")


def simple():
    if logger.isEnabledFor(logging.DEBUG):
        logger.debug(
            'Stupid log message ' + ' '.join([str(i) for i in range(20)])
        )
    # Do something


class lazyjoin:
    def __init__(self, s, items):
        self.s = s
        self.items = items

    def __str__(self):
        return self.s.join(self.items)


def lazy():
    logger.debug(
        'Stupid log message %s', lazyjoin(' ', (str(i) for i in range(20)))
    )
    # Do something

if __name__ == '__main__':
    import timeit
    print(min(timeit.repeat("simple()", setup="from __main__ import simple")))
    print(min(timeit.repeat("lazy()", setup="from __main__ import lazy")))

my result:

$ python isEnabledFor_vs_class_benchmark.py
2.8991405550041236
13.408140633997391

for the record, doing the following resulted in almost the same result for both methods. It does describe a real scenario in my case, in which the lazy logging method doesn't need any parameters and simply takes stuff from self to generate the debug message (you can see what I ended up doing here)

    import logging
    logging.basicConfig(level=logging.INFO)
    logger = logging.getLogger("log")


    def simple():
        if logger.isEnabledFor(logging.DEBUG):
            logger.debug(
                'Stupid log message ' + ' '.join([str(i) for i in range(20)])
            )
        # Do something


    class lazyjoin:
        def __init__(self, s, items):
            self.s = s
            self.items = items

        def __str__(self):
            return self.s.join(self.items)


    def lazy(lazy_log):
        logger.debug(
            'Stupid log message %s', lazy_log
        )
        # Do something

    if __name__ == '__main__':
        import timeit
        print(min(timeit.repeat("simple()", setup="from __main__ import simple")))
        print(min(timeit.repeat("lazy(lazy_log)", setup="from __main__ import lazy, lazyjoin; lazy_log = lazyjoin(' ', (str(i) for i in range(20)))")))

EDIT: syntax highligting added by @schnittstabil

@guyarad You're ignoring the time needed to create the lazyjoin instance lazy_log:

setup="… lazy_log = lazyjoin(' ', (str(i) for i in range(20)))"

For a real world scenario you have to measure that time too.

At the time of writing my stackoverflow answer, logger.isEnabledFor(logging.DEBUG) was 4 times faster than creating a lazyjoin instance.
See also my stackoverflow answer to Python: how to do lazy debug logging.

---

Nevertheless, even in your scenario, I see no need to create those expensive LazyLogging instances.
Instead you could use a simple and efficient lazy_debug function:

def lazy_debug(logger, msg, fn):
    if logger.isEnabledFor(logging.DEBUG):
        logger.debug(msg, fn())

class MyClass(object):
    def __init__(self):
        pass

    def _debug_1(self):
        return "my debugging string 1"

    def _debug_2(self):
        return "my debugging string 2"

    def _debug_3(self):
        return "my debugging string 3"

    def m_1(self):
        lazy_debug(logger, "Info: %s", self._debug_1)

    def m_2(self):
        lazy_debug(logger, "Info: %s", self._debug_2)

    def m_3(self):
        lazy_debug(logger, "Info: %s", self._debug_3)

If you want to improve this, you may extend the logger class with a lazy_debug method, which is hard though, IIRC.