打印函数调用细节（参数名称和值）的装饰器？

Question

我想写一个函数，这个函数可以装饰另一个函数，目的是打印出被装饰函数的调用细节，比如参数的名字和实际的值。现在我的实现是这样的。

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)

这个方法有点用，但也有一些问题：

比如当我调用

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

它打印出来的是

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

我期望的结果是

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

我在这里卡住了。你能帮我找到正确的解决方案吗？

Answer 1

这是我在Python 3中解决这个问题的方法，灵感主要来自于aliteralmind的回答，我觉得我整理得更清晰了（符合PEP8标准）。大部分的清理灵感来自于Robert King的（目前）被接受的回答。

代码（test.py）：

#!/usr/bin/env python3

import functools
import inspect
import logging
import time


class CustomFormatter(logging.Formatter):
    """
    Custom formatter, overrides funcName with value of name_override if it exists

    Inspired by; https://stackoverflow.com/a/7004565/1503549
    """
    def format(self, record):
        if hasattr(record, 'func_name'):
            record.funcName = record.func_name
        return super(CustomFormatter, self).format(record)


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.
    """

    @functools.wraps(decorated_function)
    def wrapper(*dec_fn_args, **dec_fn_kwargs):
        # Log function entry
        func_name = decorated_function.__name__
        name_dict = dict(func_name=func_name)
        logging.info(f"Entering {func_name}()...", extra=name_dict)

        # Log function params (args and kwargs)
        func_args = inspect.signature(decorated_function).bind(*dec_fn_args, **dec_fn_kwargs).arguments
        func_args_str = ', '.join(
            f"{var_name} = {var_value}"
            for var_name, var_value
            in func_args.items()
        )
        logging.debug(f"\t{func_args_str}", extra=name_dict)

        # Execute wrapped (decorated) function:
        out = decorated_function(*dec_fn_args, **dec_fn_kwargs)

        time.sleep(1)   # Test to ensure timestamp is real
        logging.info(f"Done running {func_name}()!", extra=name_dict)

        return out
    return wrapper


@log_function_entry_and_exit
def func2(*args, **kwargs):
    print('\t\thello')


@log_function_entry_and_exit
def func1(a, b, c):
    func2(1, 2, 3, 4, b=5)
    print('Hello2!')


if __name__ == '__main__':
    log = logging.getLogger()

    # Must get handler to set format
    handler = logging.StreamHandler()   # Get default root logger
    handler.setFormatter(
        CustomFormatter(
            (
                '[%(asctime)s]'
                ' %(levelname)s:%(funcName)s():%(lineno)s>'
                ' %(message)s'
            ),
            datefmt='%Y-%m-%dT%H:%M:%S',
        )
    )

    # Set logLevel
    log.setLevel(logging.DEBUG)
    handler.setLevel(logging.DEBUG)

    # Combine the two again
    log.addHandler(handler)

    log.info('yolo!', extra=dict(func_name='__main__'))

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

输出：

[2020-06-11 22:22:15] 0 x10an14@x10-desktop:~/Desktop/testy
-> $ python3 test.py 
[2020-06-11T22:22:53] INFO:__main__():88> yolo!
[2020-06-11T22:22:53] INFO:func1():33> Entering func1()...
[2020-06-11T22:22:53] DEBUG:func1():42>     a = 2, b = y, c = {'z': 4}
[2020-06-11T22:22:53] INFO:func2():33> Entering func2()...
[2020-06-11T22:22:53] DEBUG:func2():42>     args = (1, 2, 3, 4), kwargs = {'b': 5}
        hello
[2020-06-11T22:22:54] INFO:func2():48> Done running func2()!
Hello2!
[2020-06-11T22:22:55] INFO:func1():48> Done running func1()!
[2020-06-11 22:22:55] 0 x10an14@x10-desktop:~/Desktop/testy
-> $ 

当我获得了被称为“时间和精力”的神奇资源时，我想尝试一下LOG_FORMAT，看看如何把wrapper这个子字符串替换成函数调用的文件名和行号=)

编辑（2020-06-11）：在@Gahan的评论（2020-06-10）提示后，修复了wrapper的问题。

似乎不可能通过logging模块让一个包装器报告被包装/装饰函数的行号（参考https://stackoverflow.com/a/8339710/1503549）。也许可以利用wrapt来实现这个目的？

Answer 2

这是适用于Python 3.6及以上版本的更新版本

import inspect
from functools import wraps

def dump_args(func):
    """
    Decorator to print function call details.

    This includes parameters names and effective values.
    """

    @wraps(func)
    def wrapper(*args, **kwargs):
        func_args = inspect.signature(func).bind(*args, **kwargs).arguments
        func_args_str = ", ".join(map("{0[0]} = {0[1]!r}".format, 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)

---

旧版本

---

带有默认值的工作版本：

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)

结果：

>>> 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 3

抱歉，内容有点乱。我修改了一些来自函数参数轻松输出的代码，这段代码原本在Python装饰器库里。

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)

输出结果：

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