Instantly share code, notes, and snippets.

Embed
What would you like to do?
logging.isEnabledFor vs lazyjoin class benchmark
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")))
@schnittstabil

This comment has been minimized.

Copy link
Owner Author

schnittstabil commented Mar 5, 2014

my result:

$ python isEnabledFor_vs_class_benchmark.py
2.8991405550041236
13.408140633997391
@guyarad

This comment has been minimized.

Copy link

guyarad commented Nov 1, 2016

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

@schnittstabil

This comment has been minimized.

Copy link
Owner Author

schnittstabil commented Nov 1, 2016

@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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment