Decorators – redux

Recently I blogged about how decorators are best thing since sliced bread and how to create them. I had example code like this:

def logged(fn):
    """
    Decorator to perform logging
    """
    logger_name = str(fn)
    logger = logging.getLogger(logger_name)

    def log(*args, **kwargs):
        """
        Log function call
        """
        call_message = ' '.join([logger_name,
                                 'call',
                                 ':',
                                 str(args),
                                 str(kwargs)])

        logger.debug(call_message)

        result = fn(*args, **kwargs)

        result_message = ' '.join([logger_name,
                                   'return',
                                   ':',
                                   str(result)])

        logger.debug(result_message)

        return result

    return log

It works just fine and gets the job done, but it also has at least two major issues. First one is that the decorator is masking signature of the function it is used to decorate. This in turn causes trouble when generating API-documentation with Sphinx. Instead of correct parameters, you end up with not-so-useful function_name(*args, **kwargs). Same thing applies with docstring, which in turn makes help-function useless in interactive mode. Also, in case of multiple decorators, there is some repeating code that I could live without.

Nice solution to all these is decorator library. It adds a decorator, that can turn any function into a decorator, while preserving signature and docstring. When using decorator library, the previous example turns into:

@decorator
def logged(wrapped_function, *args, **kwargs):
    """
    Decorator to perform logging
    """
    logger_name = str(wrapped_function)
    logger = logging.getLogger(logger_name)

    call_message = ' '.join([logger_name,
                             'call',
                             ':',
                             str(args),
                             str(kwargs)])

    logger.debug(call_message)

    result = wrapped_function(*args, **kwargs)

    result_message = ' '.join([logger_name,
                                   'return',
                                   ':',
                                   str(result)])

    logger.debug(result_message)

    return result

Pretty nice and clean I think. A drawback is that lose some flexibility since there is no way (as far as I know) to write logic that happens before decorator is applied. All the logic shown in the logged-function is logic that gets executed when the wrapped function is called. In this example, logger_name is taken from calling function each and every time the function is called. In the previous example, the name is resolved only once (when the decorator is created).

Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s