Tracer Ammunition for Python code. See test case how to use it.

test_tracer.py

import sys, logging
from unittest import TestCase
from tracer import trace, profile, log, slow_down, timer, debug


class TestTrace(TestCase):

    def setUp(self):
        root = logging.getLogger()
        root.setLevel(logging.DEBUG)

    @trace
    def test_trace(name, location="World"):
        """ Nothing important here, but you can
            print(f"Hello {name} in {location}!")
        """
        pass

    @profile
    def test_needs_time(self):
        for _ in range(1000):
            pass

    @log
    def test_call_log_decorator(self):
        pass

    def test_alternative_debugger(self):
        
        @debug
        def sum(a, b):
            return a + b
        self.assertEquals(4, sum(3, 1))

    def test_return_value(self):
        
        @log
        def sum(a, b):
            return a + b

        self.assertEquals(4, sum(3, 1))

    def test_slow_down(self):
        @slow_down(rate=0.5)
        def countdown():
            for i in range(10,0):
                print(i)
        countdown()
    
    def test_timer(self):
        @timer
        def countdown():
            for i in range(10,0):
                print(i)
        countdown()

tracer.py

from time import time_ns, perf_counter, sleep
import functools
from logging import debug, info


def trace(func):
    """ Decorator to trace function calls and exits. """
    @functools.wraps(func)
    def log_wrapper(*args, **kwargs):
        debug(f"Entering function {func.__name__}({args}, {kwargs}).")
        return func(*args, **kwargs)
        debug(f"Exiting function {func.__name__}.")
    
    return log_wrapper


def profile(func):
    """ Decorator to measure time of function call. """
    @functools.wraps(func)
    def profile_wrapper(*args, **kwargs):
        debug(f"Entering function {func.__name__}({args}, {kwargs}).")
        start = time_ns()
        return func(*args, **kwargs)
        duration = time_ns() - start
        debug(f"Function {func.__name__} finished after {duration} nanoseconds.")
    
    return profile_wrapper


def log(func):
    """ Simply log function calls """
    @functools.wraps(func)
    def log_wrapper(*args, **kwargs):
        info(f"{func.__name__}")
        return func(*args, **kwargs)
    
    return log_wrapper


def timer(func):
    """Print the runtime of the decorated function"""
    @functools.wraps(func)
    def wrapper_timer(*args, **kwargs):
        start_time = perf_counter()    # 1
        value = func(*args, **kwargs)
        end_time = perf_counter()      # 2
        run_time = end_time - start_time    # 3
        debug(f"Finished {func.__name__!r} in {run_time:.4f} secs")
        return value
    return wrapper_timer


def slow_down(_func=None, *, rate=1):
    """Sleep given amount of seconds before calling the function"""
    def decorator_slow_down(func):
        @functools.wraps(func)
        def wrapper_slow_down(*args, **kwargs):
            sleep(rate)
            return func(*args, **kwargs)
        return wrapper_slow_down

    if _func is None:
        return decorator_slow_down
    else:
        return decorator_slow_down(_func)


def debug(func):
    """Print the function signature and return value"""
    @functools.wraps(func)
    def wrapper_debug(*args, **kwargs):
        args_repr = [repr(a) for a in args]
        kwargs_repr = [f"{k}={v!r}" for k, v in kwargs.items()]
        signature = ", ".join(args_repr + kwargs_repr)
        debug(f"Calling {func.__name__}({signature})")
        value = func(*args, **kwargs)
        debug(f"{func.__name__!r} returned {value!r}") 
        return value
    return wrapper_debug