如何在异常钩子中利用exc_info替换日志记录的来源信息？

当日志调用时传入exc_info参数，能否用它来填充日志记录的文件、行号等位置信息，替代默认的日志调用位置？

我用sys.excepthook捕获未捕获的异常，常规日志的位置信息（文件、行号、函数名）是基于日志被调用的位置生成的。这导致异常钩子中生成的日志记录，位置信息指向钩子函数本身，而非异常实际发生的位置。

代码示例 #

文件1: log_record_test.py #

# File log_record_test.py
import logging
import log_record_setup
import sys


sys.excepthook = log_record_setup.exc_hook
logger = logging.getLogger()
logger.addHandler(log_record_setup.LogHandler())


def test():
    logger.critical("Normal logging here")


def test2():
    raise TypeError()


test()
test2()

文件2: log_record_setup.py #

# File log_record_setup.py
import logging

logger = logging.getLogger("TestLogger")


class LogHandler(logging.Handler):
    def __init__(self):
        super(LogHandler, self).__init__()

    def emit(self, record):
        self.format(record)
        log_record_dict = record.__dict__.copy()
        print(f"{log_record_dict['filename']} at {log_record_dict['lineno']} within {log_record_dict['funcName']}")


def exc_hook(exc_type, exc_value, tb):
    logger.critical("Error happened", exc_info=(exc_type, exc_value, tb))

当前运行输出 #

运行log_record_test.py后，输出如下：

log_record_test.py at 12 within test
log_record_setup.py at 18 within exc_hook

第一个日志输出符合预期，但第二个对应test2抛出的异常，日志位置指向了钩子函数exc_hook，而非TypeError实际抛出的test2函数位置。

解决方案 #

方案1：在异常钩子中手动替换位置信息 #

直接在exc_hook里解析traceback，提取异常发生的真实位置，通过extra参数覆盖日志记录的默认位置字段：

修改后的log_record_setup.py代码：

# File log_record_setup.py
import logging
import traceback
import os

logger = logging.getLogger("TestLogger")


class LogHandler(logging.Handler):
    def __init__(self):
        super(LogHandler, self).__init__()

    def emit(self, record):
        self.format(record)
        log_record_dict = record.__dict__.copy()
        print(f"{log_record_dict['filename']} at {log_record_dict['lineno']} within {log_record_dict['funcName']}")


def exc_hook(exc_type, exc_value, tb):
    # 解析traceback获取异常栈帧列表
    tb_frames = traceback.extract_tb(tb)
    # 取最后一个帧（异常实际抛出的位置）
    if tb_frames:
        last_frame = tb_frames[-1]
        filename = os.path.basename(last_frame.filename)
        lineno = last_frame.lineno
        funcname = last_frame.name
    else:
        # 异常栈为空时回退到钩子位置
        filename = os.path.basename(__file__)
        lineno = 25
        funcname = "exc_hook"
    
    # 用extra参数覆盖日志位置信息
    logger.critical(
        "Error happened",
        exc_info=(exc_type, exc_value, tb),
        extra={
            'filename': filename,
            'lineno': lineno,
            'funcName': funcname
        }
    )

修改后运行输出：

log_record_test.py at 12 within test
log_record_test.py at 17 within test2

方案2：用日志过滤器自动处理（更通用） #

如果希望所有带exc_info的日志都自动替换位置信息，可以自定义一个日志过滤器，无需修改每个日志调用：

修改后的log_record_setup.py代码：

# File log_record_setup.py
import logging
import traceback
import os

logger = logging.getLogger("TestLogger")


class LogHandler(logging.Handler):
    def __init__(self):
        super(LogHandler, self).__init__()

    def emit(self, record):
        self.format(record)
        log_record_dict = record.__dict__.copy()
        print(f"{log_record_dict['filename']} at {log_record_dict['lineno']} within {log_record_dict['funcName']}")


class ExceptionLocationFilter(logging.Filter):
    def filter(self, record):
        # 检查日志是否携带异常信息
        if record.exc_info is not None:
            _, _, tb = record.exc_info
            tb_frames = traceback.extract_tb(tb)
            if tb_frames:
                last_frame = tb_frames[-1]
                record.filename = os.path.basename(last_frame.filename)
                record.lineno = last_frame.lineno
                record.funcName = last_frame.name
        return True

# 给日志器添加过滤器
logger.addFilter(ExceptionLocationFilter())


def exc_hook(exc_type, exc_value, tb):
    # 保持原有写法即可，过滤器自动处理位置替换
    logger.critical("Error happened", exc_info=(exc_type, exc_value, tb))

这种方式更灵活，所有传入exc_info的日志都会自动替换为异常真实发生的位置。

内容的提问来源于stack exchange，提问作者Jerakin