Python 如何创建记录异常日志的装饰器

Question

有一天，我突然想要创建一个用于捕获并记录异常的装饰器，我在 Github 上发现一个颇为复杂的例子，该例子启发了我，并让我写下了以下代码：

# exception_decor.py
import logging

def create_logger():
  """
  Creates a logging object and returns it
  """
  logger = logging.getLogger("example_logger")
  logger.setLevel(logging.INFO)
  # create the logging file handler
  fh = logging.FileHandler("/path/to/test.log")
  fmt = '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
  formatter = logging.Formatter(fmt)
  fh.setFormatter(formatter)
  # add handler to logger object
  logger.addHandler(fh)
  return logger

def exception(function):
  """
  A decorator that wraps the passed in function and logs 
  exceptions should one occur
  """
  def wrapper(*args, **kwargs):
    logger = create_logger()
    try:
      return function(*args, **kwargs)
    except:
      # log the exception
      err = "There was an exception in  "
      err += function.__name__
      logger.exception(err)
    # re-raise the exception
    raise
  return wrapper

在这段代码中，定义了两个函数. 第一个函数创建并返回了一个 logging 对象. 第二个函数为我们的装饰器函数，其中我们将传入的函数包裹进一个 try/except 中，并使用 logger 记录下任何产生的异常. 同时你还会发现，我还记录下了产生异常的函数名。

现在让我们测试一下这个装饰器. 创建一个新 Python 脚本并添加以下代码. 请确保这个新 Python 脚本与上面创建装饰器的脚本在同一个目录下。

from exception_decor import exception
 
@exception
def zero_divide():
  1 / 0
 
if __name__ == '__main__':
  zero_divide()

当你在命令行中运行该代码后，你会发现多出了一个日志文件，其内容为:

  2016-06-09 08:26:50,874 - example_logger - ERROR - There was an exception in  zero_divide
Traceback (most recent call last):
  File "/home/mike/exception_decor.py", line 29, in wrapper
  return function(*args, **kwargs)
  File "/home/mike/test_exceptions.py", line 5, in zero_divide
  1 / 0
ZeroDivisionError: integer division or modulo by zero

我觉得这份代码很方便，我希望你们大家也会觉得有用。

UPDATE: 一个热心的读者提出，将代码泛化成从外界传递一个 logger 对象到装饰器会更好些. 那么然我们来看看如何实现它!

1 传递 logger 到我们的装饰器中

首先，将原始的代码中的 logging 代码拆到自己的模块中。 假设放到文件 exception_logger.py 中. 下面是源代码：

# exception_logger.py
import logging
def create_logger():
  """
  Creates a logging object and returns it
  """
  logger = logging.getLogger("example_logger")
  logger.setLevel(logging.INFO)
  # create the logging file handler
  fh = logging.FileHandler(r"/path/to/test.log")
  fmt = '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
  formatter = logging.Formatter(fmt)
  fh.setFormatter(formatter)
  # add handler to logger object
  logger.addHandler(fh)
  return logger
logger = create_logger()

然后我们修改装饰器代码，使之接受一个 logger 为参数并保存为 exception_decor.py

# exception_decor.py

import functools


def exception(logger):
  """
  A decorator that wraps the passed in function and logs 
  exceptions should one occur

  @param logger: The logging object
  """

  def decorator(func):

    def wrapper(*args, **kwargs):
      try:
        return func(*args, **kwargs)
      except:
        # log the exception
        err = "There was an exception in  "
        err += func.__name__
        logger.exception(err)

      # re-raise the exception
      raise
    return wrapper
  return decorator

你会发现我们定义了多层嵌套的函数。 请看仔细并理解其中的意思。 最后，我们需要修改一下测试的代码：

from exception_decor import exception
from exception_logger import logger

@exception(logger)
def zero_divide():
  1 / 0

if __name__ == '__main__':
  zero_divide()

代码中，我们导入了装饰器和 logger 对象。 然后我们将装饰器作用于要记录的函数，并且我们给该装饰器传递了一个 logger 对象。 你运行该测试代码后，会发现产生了与第一个测试相同的文件。