Serhat Teker

Posted on Nov 4, 2019 • Originally published at tech.serhatteker.com on Jul 20, 2019

Python Debug Decorators

#python #debug #decorator #logging

Sometimes when debugging we like to print/log out all the inputs and outputs of a method: name, args, kwargs, dict etc.

We would have some IDE debug features for this purpose but sometimes we need manual debugging.

And while manual debugging I don't want to write logger.debug(<messsage>) to every one of two lines of a module.

The solution: Python Decorators

First configure a logger. For detail go to our post Python Logging Configuration. Then crate a module for our debugger decorators

#!/usr/bin/env python3
# -*- coding: utf-8 -*-

# utils/debuggers.py


class Debugger(object):
    """ Debug a method and return it back"""

    enabled = False

    def __init__(self, func):
        self.func = func

    def __call__(self, *args, **kwargs):
        if self.enabled:
            logger.debug(f'Entering : {self.func.__name__}')
            logger.debug(f'args, kwargs : {args, kwargs}')
            logger.debug(f'{self.func.__name__} returned : {self.func(*args, **kwargs)}')

        return self.func(*args, **kwargs)

Then call it and decorate your method like below:

#!/usr/bin/env python3
# -*- coding: utf-8 -*-

# main.py

from utils.debuggers import Debugger


@Debugger
def my_func(a, b, c, d):
    return a + b + c + d


if __name__ == "__main__":
    Debugger.enabled = True

    args_dict = dict(
        a=1,
        b=2,
        c=5,
        d=-10
    )

    my_func(**args_dict)

Output will be like:

2019-07-21 18:43:25,635 [DEBUG] __main__: Entering : my_func
2019-07-21 18:43:25,635 [DEBUG] __main__: args, kwargs: ((), {'a': 1, 'b': 2, 'c': 5, 'd': -10})
2019-07-21 18:43:25,635 [DEBUG] __main__: my_func returned -2

If you want a function instead of a class for debugging:

#!/usr/bin/env python3
# -*- coding: utf-8 -*-

# utils/decorators.py

import functools


def debugmethod(func):
    """ Debug a method and return it back"""

    @functools.wraps(func)
    def wrapper(*args, **kwargs):
        return_value = func(*args, **kwargs)

        logger.debug(f'Calling : {func.__name__}')
        logger.debug(f'args, kwargs: {args, kwargs}')
        logger.debug(f'{func.__name__} returned {return_value}')

        return return_value

    return wrapper

Also if you like to know the execution time of the method;

#!/usr/bin/env python3
# -*- coding: utf-8 -*-

# utils/decorators.py

import time


def timerun(func):
    """ Calculate the execution time of a method and return it back"""

    @functools.wraps(func)
    def wrapper(*args, **kwargs):
        start = time.time()
        result = func(*args, **kwargs)
        duration = time.time() - start

        logger.debug(f"Duration of {func.__name__} function was {duration}.")
        return result
    return wrapper

Output:

2019-07-21 18:43:25,636 [DEBUG] __main__: Duration of my_func was 0.00023937225341796875.

You can combine your decorators as below:

#!/usr/bin/env python3
# -*- coding: utf-8 -*-

# main.py

from utils.debuggers import debugmethod, timerun


@timerun
@debugmethod
def my_func(a, b, c, d):
    return a + b + c + d


if __name__ == "__main__":
    Debugger.enabled = True

    args_dict = dict(
        a=1,
        b=2,
        c=5,
        d=-10
    )

    my_func(**args_dict)

Output should be like this:

2019-07-21 18:43:25,635 [DEBUG] __main__: Calling : my_func
2019-07-21 18:43:25,635 [DEBUG] __main__: args, kwargs: ((), {'a': 1, 'b': 2, 'c': 5, 'd': -10})
2019-07-21 18:43:25,635 [DEBUG] __main__: my_func returned -2
2019-07-21 18:43:25,636 [DEBUG] __main__: Duration of my_func was 0.00023937225341796875.

OK, all done.