libdecor.py

import logging
import time

from functools import wraps
from itertools import chain, starmap

logging.basicConfig(level=logging.DEBUG)
log = logging.getLogger(__name__)


def _arg_fmt(*args, **kwargs):
    """Positional and keyword argument formatter"""
    return ", ".join(chain(
        map(repr, args),
        starmap("{0}={1!r}".format, kwargs.items()),
        ))


def print_self_hook(level=logging.DEBUG):
    """Meta-decorator hook to print currently executing function and its args

    :level: log to a specific log level, default: logging.DEBUG == 10

    :returns: decorator function

    Example:

    >>> @print_self_hook()
    >>> def my_name_is(*args, **kwargs):
    >>>     pass
    >>>
    >>> my_name_is("dummy")
    """

    def wrapper(f):
        @wraps(f)
        def wrapped(*args, **kwargs):
            if log.getEffectiveLevel() <= level:
                # do this only if  the effective loglevel is less or equal to
                # the specified level to reduce performance impact
                log.log(level, "'{fn}({arg})'".format(
                    fn=f.__name__,
                    arg=_arg_fmt(*args, **kwargs)
                    ))
            return f(*args, **kwargs)
        return wrapped
    return wrapper


def print_self_mhook(level=logging.DEBUG):
    """Meta-decorator hook to print currently executing method and its args

    :level: log to a specific log level, default: logging.DEBUG == 10

    :returns: decorator function

    Example:

    >>> class Dummy(object):
    >>>
    >>>     @print_self_mhook()
    >>>     def my_name_is(self, *args, **kwargs):
    >>>         pass
    >>>
    >>> dummy = Dummy()
    >>> dummy.my_name_is("dummy")
    """

    def wrapper(f):
        @wraps(f)
        def wrapped(self, *args, **kwargs):
            if log.getEffectiveLevel() <= level:
                # do this only if  the effective loglevel is less or equal to
                # the specified level to reduce performance impact
                log.log(level, "'{cl}.{fn}({arg})'".format(
                    cl=repr(self),
                    fn=f.__name__,
                    arg=_arg_fmt(*args, **kwargs)
                    ))
            return f(self, *args, **kwargs)
        return wrapped
    return wrapper


def time_hook(level=logging.DEBUG):
    """Function execution timer hook meta-decorator

    :level: log to a specific log level, default: logging.DEBUG == 10

    :returns: decorator function

    Example:

    >>> from time import sleep
    >>>
    >>> @time_mhook(level=logging.WARN)
    >>> def loooong(*args, **kwargs):
    >>>     sleep(3)
    >>>
    >>> loooong()
    """

    def wrapper(f):
        @wraps(f)
        def wrapped(*args, **kwargs):
            if log.getEffectiveLevel() > level:
                # just return the result if the effective loglevel is above
                # specified level to reduce performance impact
                return f(*args, **kwargs)
            else:
                start = time.time()
                try:
                    result = f(*args, **kwargs)
                except Exception as e:
                    log.log(level,
                            "'{fn}({arg})' execution failed in {t} s".format(
                                fn=f.__name__,
                                arg=_arg_fmt(*args, **kwargs),
                                t=time.time() - start,
                                )
                            )
                    log.exception(e, exc_info=False)
                else:
                    log.log(level,
                            "'{fn}({arg})' executed in {t} s".format(
                                fn=f.__name__,
                                arg=_arg_fmt(*args, **kwargs),
                                t=time.time() - start,
                                )
                            )
                    return result
        return wrapped
    return wrapper


def time_mhook(level=logging.DEBUG):
    """Method execution timer hook meta-decorator

    :level: log to a specific log level, default: logging.DEBUG == 10

    :returns: decorator function

    Example:

    >>> from time import sleep
    >>>
    >>> class Dummy(object):
    >>>
    >>>     @time_mhook(level=logging.INFO)
    >>>     def loooong(self, *args, **kwargs):
    >>>         sleep(3)
    >>>
    >>> dummy = Dummy()
    >>> dummy.loooong()
    """

    def wrapper(f):
        @wraps(f)
        def wrapped(self, *args, **kwargs):
            if log.getEffectiveLevel() > level:
                # just return the result if the effective loglevel is above
                # specified level to reduce performance impact
                return f(self, *args, **kwargs)
            else:
                start = time.time()
                try:
                    result = f(self, *args, **kwargs)
                except Exception as e:
                    log.log(level,
                            "'{cl}.{fn}({arg})' execution failed in {t} s".format(
                                cl=repr(self),
                                fn=f.__name__,
                                arg=_arg_fmt(*args, **kwargs),
                                t=time.time() - start,
                                )
                            )
                    log.exception(e, exc_info=False)
                else:
                    log.log(level,
                            "'{cl}.{fn}({arg})' executed in {t} s".format(
                                cl=repr(self),
                                fn=f.__name__,
                                arg=_arg_fmt(*args, **kwargs),
                                t=time.time() - start,
                                )
                            )
                    return result
        return wrapped
    return wrapper


def log_hook(before="", after="", level=logging.DEBUG):
    """Function log hook meta-decorator

    :before: string formatted with the positional and keyword arguments from
            the decorated function and logged *before* execution
    :after: string formatted with the positional and keyword arguments from
            the decorated function and logged *after* execution
    :level: log to a specific log level, default: logging.DEBUG == 10

    :returns: decorator function

    Example:

    >>> @log_hook(before="Called with args: {0}, {1}",
    >>>           after="Done!",
    >>>           level=logging.INFO)
    >>> def yay(*args, **kwargs):
    >>>     pass
    >>>
    >>> yay("good", "job")
    """

    def wrapper(f):
        @wraps(f)
        def wrapped(*args, **kwargs):
            if log.getEffectiveLevel() > level:
                # just return the result if the effective loglevel is above
                # specified level to reduce performance impact
                return f(*args, **kwargs)
            else:
                if before:
                    log.log(level, before.format(*args, **kwargs))
                try:
                    result = f(*args, **kwargs)
                except Exception as e:
                    log.exception(e, exc_info=False)
                else:  # noexcept
                    if after:
                        log.log(level, after.format(*args, **kwargs))
                    return result
        return wrapped
    return wrapper


def log_mhook(before="", after="", level=logging.DEBUG):
    """Method log hook meta-decorator

    :before: string formatted with the positional and keyword arguments from
            the decorated function and logged *before* execution
    :after: string formatted with the positional and keyword arguments from
            the decorated function and logged *after* execution
    :level: log to a specific log level, default: logging.DEBUG == 10

    :returns: decorator function

    Example:

    >>> class Dummy(object):
    >>>
    >>>     @log_mhook(before="Called with args: {0}, {1}",
    >>>                after="Done!",
    >>>                level=logging.WARN)
    >>>     def yay(self, *args, **kwargs):
    >>>         pass
    >>>
    >>> dummy = Dummy()
    >>> dummy.yay("good", "job")
    """

    def wrapper(f):
        @wraps(f)
        def wrapped(self, *args, **kwargs):
            if log.getEffectiveLevel() > level:
                # just return the result if the effective loglevel is above
                # specified level to reduce performance impact
                return f(self, *args, **kwargs)
            else:
                if before:
                    log.log(level, before.format(*args, **kwargs))
                try:
                    result = f(self, *args, **kwargs)
                except Exception as e:
                    log.exception(e, exc_info=False)
                else:  # noexcept
                    if after:
                        log.log(level, after.format(*args, **kwargs))
                    return result
        return wrapped
    return wrapper