Decorator to print function call details - paramet

Question

I want to make a function that being a decorator to another function will print that function call details - parameters names and effective values. My current implementation is this.

def describeFuncCall(func):
    '''Decorator to print function call details - parameters names and effective values'''
    def wrapper(*func_args, **func_kwargs):
        print 'func_code.co_varnames =', func.func_code.co_varnames
        print 'func_code.co_argcount =', func.func_code.co_argcount
        print 'func_args =', func_args
        print 'func_kwargs =', func_kwargs
        params = []
        for argNo in range(func.func_code.co_argcount):
            argName = func.func_code.co_varnames[argNo]
            argValue = func_args[argNo] if argNo < len(func_args) else func.func_defaults[argNo - func.func_code.co_argcount]
            params.append((argName, argValue))
        for argName, argValue in func_kwargs.items():
            params.append((argName, argValue))
        params = [ argName + ' = ' + repr(argValue) for argName, argValue in params]
        print(func.__name__ + ' ( ' +  ', '.join(params) + ' )')
        return func(*func_args, **func_kwargs)
    return wrapper


@describeFuncCall
def test(a, b = 4, c = 'blah-blah', *args, **kwargs):
    pass


test(1)
#test(1, 3)
#test(1, d = 5)
test(1, 2, 3, 4, 5, d = 6, g = 12.9)

Kinda works, but with some bugs:

For call

test(1, 2, 3, 4, 5, d = 6, g = 12.9)

it prints

test ( a = 1, b = 2, c = 3, d = 6, g = 12.9 ).

The expected result is

test ( a = 1, b = 2, c = 3, args = [4, 5], kwargs = {'d': 6, 'g': 12.9} )

I got stuck here. Can you help me to find the right solution?

Answer 1

@warvariuc's answer, upgraded to Python 3:

def dumpArgs(func):
    '''Decorator to print function call details - parameters names and effective values'''
    def wrapper(*func_args, **func_kwargs):
        arg_names = func.__code__.co_varnames[:func.__code__.co_argcount]
        args = func_args[:len(arg_names)]
        defaults = func.__defaults__ or ()
        args = args + defaults[len(defaults) - (func.__code__.co_argcount - len(args)):]
        params = list(zip(arg_names, args))
        args = func_args[len(arg_names):]
        if args: params.append(('args', args))
        if func_kwargs: params.append(('kwargs', func_kwargs))
        print(func.__name__ + ' (' + ', '.join('%s = %r' % p for p in params) + ' )')
        return func(*func_args, **func_kwargs)
    return wrapper  

@dumpArgs
def test(a, b = 4, c = 'blah-blah', *args, **kwargs):
    pass

test(1)
test(1, 3)
test(1, d = 5)
test(1, 2, 3, 4, 5, d = 6, g = 12.9)

Answer 2

Its a bit old post but wanted to add my bit. Solution given by warvariuc does not work in all cases. If a method have default values as well as we send named arguments while calling, it does not give proper output. e.g. we get two values of b.

test(1, b = 5)
test (a = 1, b = 4, c = 'blah-blah', kwargs = {'b': 5} )

Adding my modified code.

def print_args(func):
"""
Function to print all args of decorated function
"""
def wrapper(*func_args, **func_kwargs):
    arg_names = func.func_code.co_varnames[:func.func_code.co_argcount]
    args = func_args[:len(arg_names)]
    defaults = func.func_defaults or ()
    args = args + defaults[len(defaults) - (func.func_code.co_argcount - len(args)):]
    params = zip(arg_names, args)
    new_arg_list = [list(i) for i in params]
    for key in func_kwargs:
        for param in new_arg_list:
            if key == param[0]:
                param[1] = func_kwargs[key]
    new_arg_list = [tuple(i) for i in new_arg_list]
    print func.func_name + ' (' + ', '.join('%s = %r' % p for p in new_arg_list) + ' )'
    return func(*func_args, **func_kwargs)
return wrapper


@print_args
def test_params(a=7,b=5):
    pass

test_params(a=3)

Output

test_params (a = 3, b = 5 )

Answer 3

Here's how I solved it in Python 3, based on aliteralmind's answer, put more cleanly (PEP8) if I may say so. Majority of the inspiration for the cleanup came from the (currently) accepted answer by Robert King.

Code:

import logging


def log_function_entry_and_exit(decorated_function):
    """
    Function decorator logging entry + exit and parameters of functions.

    Entry and exit as logging.info, parameters as logging.DEBUG.
    """
    from functools import wraps

    @wraps(decorated_function)
    def wrapper(*dec_fn_args, **dec_fn_kwargs):
        # Log function entry
        func_name = decorated_function.__name__
        log = logging.getLogger(func_name)
        log.info('Entering {}()...'.format(func_name))

        # get function params (args and kwargs)
        arg_names = decorated_function.__code__.co_varnames
        params = dict(
            args=dict(zip(arg_names, dec_fn_args)),
            kwargs=dec_fn_kwargs)

        log.debug(
            "\t" + ', '.join([
                '{}={}'.format(str(k), repr(v)) for k, v in params.items()]))
        # Execute wrapped (decorated) function:
        out = decorated_function(*dec_fn_args, **dec_fn_kwargs)
        log.info('Done running {}()!'.format(func_name))

        return out
    return wrapper


@log_function_entry_and_exit
def func1(a, b, c):
    print("\n\ty'elo2!\n")
@log_function_entry_and_exit
def a(x, y, z):
    print("\n\ty'elo!\n")

LOG_FORMAT = '[{}] !%(levelname)s! %(funcName)s: %(message)s'.format(
    _get_current_time_string(just_time_string=True))
logging.basicConfig(format=LOG_FORMAT, level=logging.DEBUG)

a(x=1, y="b", z={'c': 2})
func1(2, b="y", c={'z': 4})
func1(2, "y", {'z': 4})

Output:

In [6]: a(x=1, y="b", z={'c': 2})
   ...: func1(2, b="y", c={'z': 4})
   ...: func1(2, "y", {'z': 4})
   ...:
[2016.09.22 - 17:31:48] !INFO! wrapper: Entering a()...
[2016.09.22 - 17:31:48] !DEBUG! wrapper:        kwargs={'x': 1, 'z': {'c': 2}, 'y': 'b'}, args={}

        y'elo!

[2016.09.22 - 17:31:48] !INFO! wrapper: Done running a()!
[2016.09.22 - 17:31:48] !INFO! wrapper: Entering func1()...
[2016.09.22 - 17:31:48] !DEBUG! wrapper:        kwargs={'c': {'z': 4}, 'b': 'y'}, args={'a': 2}

        y'elo2!

[2016.09.22 - 17:31:48] !INFO! wrapper: Done running func1()!
[2016.09.22 - 17:31:48] !INFO! wrapper: Entering func1()...
[2016.09.22 - 17:31:48] !DEBUG! wrapper:        kwargs={}, args={'c': {'z': 4}, 'a': 2, 'b': 'y'}

        y'elo2!

[2016.09.22 - 17:31:48] !INFO! wrapper: Done running func1()!

Note: The wrapper string in the output represents the function name of whatever makes the logging.X() message call.

Example in use:

In [1]: from meh import execute_os_command

In [2]: from meh import LOG_FORMAT

In [3]: import logging

In [4]:     logging.basicConfig(format=LOG_FORMAT, level=logging.INFO)
   ...:
   ...:     logging.info("Entered script...\n")
   ...:
   ...:     result = execute_os_command(cmd=["echo", "trololol"])
   ...:     print("\n{}\n".format(result))
   ...:     execute_os_command(cmd=["echo", "trololol"], dry_run=True)
   ...:
   ...:     logging.info("Exiting script...\n")
   ...:
[2016.09.22 - 17:42:19] !INFO! <module>: Entered script...

[2016.09.22 - 17:42:19] !INFO! wrapper: Entering execute_os_command()...
[2016.09.22 - 17:42:19] !INFO! execute_os_command: Executing:
[2016.09.22 - 17:42:19] !INFO! execute_os_command:       echo trololol
[2016.09.22 - 17:42:19] !INFO! execute_os_command:   Waiting for above command to finish execution...
[2016.09.22 - 17:42:19] !INFO! wrapper: Done running execute_os_command()!

{'stderr': '', 'stdout': 'trololol\n', 'command': ['echo', 'trololol'], 'returncode': 0, 'stdin': None, 'timedout': False}

[2016.09.22 - 17:42:19] !INFO! wrapper: Entering execute_os_command()...
[2016.09.22 - 17:42:19] !INFO! execute_os_command: Would have executed:
[2016.09.22 - 17:42:19] !INFO! execute_os_command:       echo trololol
[2016.09.22 - 17:42:19] !INFO! execute_os_command: Exiting execute_os_command()...
[2016.09.22 - 17:42:19] !INFO! wrapper: Done running execute_os_command()!
[2016.09.22 - 17:42:19] !INFO! <module>: Exiting script...


In [5]:

When I get the magical resources known as "time and energy", I'm interested in playing around with LOG_FORMAT, and figure out how I can replace the wrapper substring with say filename and linenumber of function invocation =)

Answer 4

Here is the updated version for Python 3.6+

import inspect

def dump_args(func):
    """Decorator to print function call details - parameters names and effective values.
    """
    def wrapper(*args, **kwargs):
        func_args = inspect.signature(func).bind(*args, **kwargs).arguments
        func_args_str =  ', '.join('{} = {!r}'.format(*item) for item in func_args.items())
        print(f'{func.__module__}.{func.__qualname__} ( {func_args_str} )')
        return func(*args, **kwargs)
    return wrapper

@dump_args
def test(a, b=4, c='blah-blah', *args, **kwargs):
    pass

test(1)
test(1, 3)
test(1, d=5)
test(1, 2, 3, 4, 5, d=6, g=12.9)

---

Old version

---

Working version with default values:

def dumpArgs(func):
    '''Decorator to print function call details - parameters names and effective values'''
    def wrapper(*func_args, **func_kwargs):
        arg_names = func.func_code.co_varnames[:func.func_code.co_argcount]
        args = func_args[:len(arg_names)]
        defaults = func.func_defaults or ()
        args = args + defaults[len(defaults) - (func.func_code.co_argcount - len(args)):]
        params = zip(arg_names, args)
        args = func_args[len(arg_names):]
        if args: params.append(('args', args))
        if func_kwargs: params.append(('kwargs', func_kwargs))
        print func.func_name + ' (' + ', '.join('%s = %r' % p for p in params) + ' )'
        return func(*func_args, **func_kwargs)
    return wrapper  

@dumpArgs
def test(a, b = 4, c = 'blah-blah', *args, **kwargs):
    pass

test(1)
test(1, 3)
test(1, d = 5)
test(1, 2, 3, 4, 5, d = 6, g = 12.9)

Result:

>>> test  (  a = 1, b = 4, c = 'blah-blah' )
test  (  a = 1, b = 3, c = 'blah-blah' )
test  (  a = 1, b = 4, c = 'blah-blah', kwargs = {'d': 5} )
test  (  a = 1, b = 2, c = 3, args = (4, 5), kwargs = {'d': 6, 'g': 12.9} )

Answer 5

Sorry its a bit messy. I modified some code from http://wiki.python.org/moin/PythonDecoratorLibrary#Easy_Dump_of_Function_Arguments

def dump_args(func):
    "This decorator dumps out the arguments passed to a function before calling it"
    argnames = func.func_code.co_varnames[:func.func_code.co_argcount]
    fname = func.func_name
    def echo_func(*args,**kwargs):
        print fname, "(", ', '.join(
            '%s=%r' % entry
            for entry in zip(argnames,args[:len(argnames)])+[("args",list(args[len(argnames):]))]+[("kwargs",kwargs)]) +")"
    return echo_func

@dump_args
def test(a, b = 4, c = 'blah-blah', *args, **kwargs):
    pass

test(1, 2, 3, 4, 5, d = 6, g = 12.9)

output:

test ( a=1, b=2, c=3, args=[4, 5], kwargs={'d': 6, 'g': 12.9})