Simple benchmark on functions using loggers and decorators.

benchmark.log

__main__.function_to_benchmark|0:00:00.000172
__main__.function_to_benchmark|0:00:01.001560
__main__.function_to_benchmark|0:00:02.001992

benchmark_using_loggers.py

from datetime import datetime
from time import sleep
from logging.handlers import MemoryHandler
import logging


LOGGER_NAME = 'benchmark'
LOGGER_OUTFILE = LOGGER_NAME + '.log'
LOGGER_LEVEL = 100


def benchmark_decorator(func):
    def wrapped_func(*args, **kwargs):
        start_t = datetime.now()
        func(*args, **kwargs)
        end_t = datetime.now()

        # Use our custom logger
        logger = logging.getLogger(LOGGER_NAME)
        # Don't propagate to the parent(s)
        logger.propagate = False

        # Add the handler if not already present
        if not logger.hasHandlers():
            # Log to a buffer in memory, if the buffer is full flush it to the target
            logger.addHandler(MemoryHandler(4096, target=logging.FileHandler(LOGGER_OUTFILE, mode='w+')))

        # Log with the custom logger at a custom level
        logger.log(LOGGER_LEVEL, '%s|%s', __name__ + "." + func.__name__, str(end_t - start_t))

    return wrapped_func


@benchmark_decorator
def function_to_benchmark(time: int):
    print('sleep for {}'.format(time))
    sleep(time)
    logging.info("sleep() finished")

if __name__ == "__main__":
    # Add a custom level for benchmarks
    logging.addLevelName(LOGGER_LEVEL, LOGGER_NAME)
    logging.basicConfig(level=logging.INFO)

    # Run the benchmark
    for i in range(3):
        function_to_benchmark(i)