使用Python的logging模块记录trace_id

Question

我的程序导入一个库，并且仅使用其中的一个函数，称为

do_stuff()

。该库在每个模块中都以通常的方式设置了记录器。主程序也有以相同方式设置的记录器。

import logging
logger = logging.getLogger(__name__)

我想在library的日志中添加一个trace_id，只是为了将来更容易检索。所有库日志都应为每次调用添加相同的 ID。例如，它应该看起来像：

[INFO] log in main program
[INFO] [abcdef] first log in library call 1
[INFO] [abcdef] second log in library call 1
[INFO] [abcdef] third log in library call 1
[INFO] back to main
[INFO] [qwerty] first log in library call 2
[INFO] [qwerty] second log in library call 2
[INFO] [qwerty] third log in library call 2
[INFO] program end

我研究了

opentelemetry

的Python实现，但对于我的目的来说它似乎不必要地复杂。我还尝试使用自定义记录器类，但似乎无法让它工作。

Answer 1

简单的解决方案：使用记录器的名称作为trace_id

这是最简单的：当您调用

getLogger

时，您可以传入该记录器的名称。我们可以使用该名称来代替

trace_id

。这是项目的结构：

├── lib1.py
├── lib2.py
└── main.py

# main.py
import logging

import lib1
import lib2

logging.basicConfig(
    level=logging.INFO,
    format="[%(levelname)s] [%(name)s] %(message)s",
)
logger = logging.getLogger("main")


def main():
    """Entry"""
    logger.info("log in main program")
    lib1.do_stuff()
    logger.info("back to main")
    lib2.do_stuff()
    logger.info("program end")


if __name__ == "__main__":
    main()

# lib1.py
import logging

logger = logging.getLogger("abcdef")


def do_stuff():
    logger.info("first log in library call 1")
    logger.info("second log in library call 1")
    logger.info("third log in library call 1")

# lib2.py
import logging

logger = logging.getLogger("qwerty")


def do_stuff():
    logger.info("first log in library call 2")
    logger.info("second log in library call 2")
    logger.info("third log in library call 2")

输出：

[INFO] [main] log in main program
[INFO] [abcdef] first log in library call 1
[INFO] [abcdef] second log in library call 1
[INFO] [abcdef] third log in library call 1
[INFO] [main] back to main
[INFO] [qwerty] first log in library call 2
[INFO] [qwerty] second log in library call 2
[INFO] [qwerty] third log in library call 2
[INFO] [main] program end

我喜欢这个解决方案，因为它很简单，我们不需要做任何额外的事情来获得我们想要的功能。如果由于某种原因，这不起作用，我想提供另一种解决方案，其中涉及

logging.LoggerAdapter

解决方案：使用logging.LoggerAdapter

参考：LoggerAdapter

在此解决方案中，我将创建一个记录器适配器

MyLogger

，它将接收现有记录器对象和

trace_id

并返回一个新的记录器对象。

在此解决方案中，项目如下所示：

├── lib1.py
├── lib2.py
├── main.py
└── mylogger.py

注意添加了 mylogger.py 模块。

# main.py
import logging

import lib1
import lib2

logging.basicConfig(
    level=logging.DEBUG,
    format="[%(levelname)s] %(message)s",
)


def main():
    logger = logging.getLogger(__name__)
    logger.info("log in main program")
    lib1.do_stuff()
    logger.info("back to main")
    lib2.do_stuff()
    logger.info("program end")


if __name__ == "__main__":
    main()

# mylogger.py
import logging


# doc: https://docs.python.org/3/library/logging.html#logging.LoggerAdapter
class MyLogger(logging.LoggerAdapter):
    def process(self, msg, kwargs):
        trace_id = self.extra.get("trace_id")
        if trace_id:
            msg = f"[{trace_id}] {msg}"
        return msg, kwargs

    @classmethod
    def new(cls, trace_id):
        """Create a new logger with trace_id."""
        logger = logging.getLogger(__name__)
        new_logger = cls(logger, {"trace_id": trace_id})
        return new_logger

# lib1.py
from mylogger import MyLogger

logger = MyLogger.new("abcdef")


def do_stuff():
    """This is in library 1"""
    logger.info("first log in library call 1")
    logger.info("second log in library call 1")
    logger.info("third log in library call 1")

# lib2.py
from mylogger import MyLogger

logger = MyLogger.new("qwerty")


def do_stuff():
    """This is in library 2"""
    logger.info("first log in library call 2")
    logger.info("second log in library call 2")
    logger.info("third log in library call 2")

输出：

[INFO] log in main program
[INFO] [abcdef] first log in library call 1
[INFO] [abcdef] second log in library call 1
[INFO] [abcdef] third log in library call 1
[INFO] back to main
[INFO] [qwerty] first log in library call 2
[INFO] [qwerty] second log in library call 2
[INFO] [qwerty] third log in library call 2
[INFO] program end

此解决方案创建一个类

MyLogger

，它将

trace_id

添加到日志输出中。请注意，

MyLogger

使用 2 个参数进行初始化：(1) 现有的记录器对象，以及 (2) 字典。该字典将成为方法

self.extra

中的

process()

。有关详细信息，请参阅文档。为了简单起见，我创建了一个类函数

new

，让调用者更简单。

方法

process

接受一条消息，加上 kwargs 并使用

trace_id

修改该消息并返回——这就是它所需要的，其余的将由

logging

框架处理。

这个解决方案比第一个更复杂。这就是为什么我更喜欢第一个。