python - 使用带有日志装饰器的 functools.wraps

Question

我正在尝试编写一个简单的装饰器，在调用装饰函数之前记录给定的语句。记录的语句应该看起来都来自同一个函数，我认为这是 functools.wraps() 的目的。

为什么会出现以下代码:

import logging
logging.basicConfig(
    level=logging.DEBUG,
    format='%(funcName)20s - %(message)s')

from functools import wraps

def log_and_call(statement):
    def decorator(func):
        @wraps(func)
        def wrapper(*args, **kwargs):
            logging.info(statement)            
            return func(*args, **kwargs)
        return wrapper
    return decorator


@log_and_call("This should be logged by 'decorated_function'")
def decorated_function():
    logging.info('I ran')

decorated_function()

导致如下日志语句:

             wrapper - This should be logged by 'decorated_function'
  decorated_function - I ran

我认为对 wraps 的调用会用 decorated_function 的名称重命名 wrapper。

我正在使用 python 2.7.1。

Answer 1

不幸的是 logging 使用函数代码对象来推断名称。您可以使用 extra 来解决此问题。关键字参数为记录指定一些附加属性，然后您可以在格式化期间使用这些属性。你可以这样做:

logging.basicConfig(
    level=logging.DEBUG,
    format='%(real_func_name)20s - %(message)s',
)

...

logging.info(statement, extra={'real_func_name': func.__name__})

这种方法的唯一缺点是您每次都必须传入 extra 字典。为避免这种情况，您可以使用自定义格式化程序并让它覆盖 funcName:

import logging
from functools import wraps

class CustomFormatter(logging.Formatter):
    """Custom formatter, overrides funcName with value of name_override if it exists"""
    def format(self, record):
        if hasattr(record, 'name_override'):
            record.funcName = record.name_override
        return super(CustomFormatter, self).format(record)

# setup logger and handler
logger = logging.getLogger(__file__)
handler = logging.StreamHandler()
logger.setLevel(logging.DEBUG)
handler.setLevel(logging.DEBUG)
handler.setFormatter(CustomFormatter('%(funcName)20s - %(message)s'))
logger.addHandler(handler)

def log_and_call(statement):
    def decorator(func):
        @wraps(func)
        def wrapper(*args, **kwargs):
            # set name_override to func.__name__
            logger.info(statement, extra={'name_override': func.__name__})
            return func(*args, **kwargs)
        return wrapper
    return decorator

@log_and_call("This should be logged by 'decorated_function'")
def decorated_function():
    logger.info('I ran')

decorated_function()

你想要什么:

% python logging_test.py
  decorated_function - This should be logged by 'decorated_function'
  decorated_function - I ran