Haystack
获取企业支持
开始
📘 **TELUS Agriculture & Consumer Goods** 如何通过 **Haystack Agents** 转变促销交易
Python

编写专业的 Python 日志

提高项目中 Python 日志有效性的最佳实践和重要技巧

2023 年 4 月 13 日

如果您是一位**Python 开发者**，并且**一直为不一致**的**且无用的日志而烦恼**，那么这篇文章就是为您准备的！在这篇文章中，我们将讨论 structlog 如何帮助您编写日志，这些日志不仅能帮助您日常工作，还能强制执行某些最佳实践，以确保整个项目日志的一致性。

我们还将探讨常见的日志记录挑战以及 structlog 如何帮助克服它们。所以，无论您是初学者还是经验丰富的开发者，请继续阅读，了解 structlog 如何彻底改变您的日志记录过程！

过去，我经常忽视日志，只在它们有助于开发环境时才写一些。这些日志对于查找错误或验证代码是否按预期工作很有用，但它们仅限于本地调试。

在了解 structlog 后，我现在知道如何编写日志，这些日志不仅能帮助我日常工作，还能强制执行某些最佳实践，以确保整个项目日志的一致性。

这使得解析已发布应用程序的日志更加容易，并改善您在 Datadog 或 Grafana 等工具中的监控。

在本文中，我将分享我使用 structlog 的一些经验，并通过一个示例场景向您展示此库的强大功能。假设用户想要上传文件，并且我们已经创建了一个接受这些请求的端点。过去，我可能会这样写日志：

import logging  
...   
logging.debug("Start uploading file with name %s. Number of retries: %s", file_name, 0)  
...  
logging.error("Failed uploading file with name %s. Current retry: %s.", file_name, retries)  
...

基本上，这段代码片段没有什么问题，它会打印出以下日志。

Native python logger

这两行日志描述了请求期间发生的情况。但是，我们可以改进重试的表示方式，添加更多上下文，并使日志行更具可读性。

经典的日志记录挑战

在深入动手操作之前，让我们先根据上面的示例理解一些常见的日志记录挑战。

1. 缺少上下文信息

日志行精确地描述了 my_file 文件上传失败。在只有一个用户和一个客户端发送请求、数据存储在本地文件系统、所有请求顺序执行的开发环境中，此信息可能就足够了。

然而，在生产系统中遇到此类日志时，可能会出现以下典型问题：

  • 谁发起了此请求？
  • 用户属于哪个组织？
  • 我们连接到哪个文件存储？是否有会话标识符或有助于我们追溯错误的标识符？
  • 此日志行是否与请求标识符相关联？

为了在日志行中获取这些信息，我们需要将这些额外信息添加到每行日志中，而在最坏的情况下，需要多次从数据库中获取相同的值，以便在整个代码库中添加这些信息性上下文。

2. 从仅用于开发的日志到机器可读日志的过渡

根据环境的不同，您可能希望拥有经过美化处理的日志行，以便人类轻松阅读，同时在生产系统中提供机器可读格式。在我们的生产部署中，我们可能希望计算重试的总次数或按文件名过滤。在这种情况下，我们将需要运行子字符串匹配。编写允许您过滤事件的查询（甚至可能以类似 SQL 的方式）会容易得多。

select file_name from logs where retry_count > 1

3. 措辞不一致

同一 Python 模块内的日志行看起来彼此完全不同是很常见的。有时甚至会缺少重要信息。根据作者的不同，日志行的外观可能非常多样。实体可能以不同的名称引用，变量的值可能被添加到日志中（带或不带引号），或者它们的措辞可能在模块中发生变化。

这使得搜索特定事件变得困难且耗时。

Structlog

Structlog 提供了许多很棒的功能，可以帮助您更快、更轻松地编写日志。它有助于向日志记录器添加上下文数据，并提供模块化配置，用于以机器可读且对开发人员友好的方式解析日志行。

在我们的例子中，这意味着我们在开发环境中获得漂亮的彩色日志行，并为我们的监控获得解析后的 JSON，将文件名添加为上下文数据，并使用更多便捷功能。值得注意的是，虽然原生日志记录器可以设置为以 JSON 格式记录，但 structlog 开箱即用地提供了此功能。

第一步 — 用 structlog 替换 Python 的原生日志记录器

让我们为上面的代码片段使用 structlog。我们需要获取日志记录器并将变量添加到我们的日志消息中。代码片段可能如下所示：

import structlog   
logger = structlog.get_logger()  
...   
logger.debug("Start uploading file.", file_name=file_name,retries=0)  
...  
logger.error("Failed uploading file.", file_name=file_name,retries=retries)  
...

我们首先注意到的是，变量不再加载到字符串中，而是作为 debug 和 error 方法的 kwargs。这不仅将这些变量的值添加到日志记录器中，还将键名绑定到日志消息。生成的日志行将如下所示：

与我们之前的解决方案相比，我们可以看到文件名和重试次数是通过映射键值对而不是将值作为原始字符串插入来添加到日志行中的。

第二步 — 将上下文数据绑定到日志记录器

通常，有两种方法可以使用 structlog 向日志记录器添加上下文数据。

**1. 显式绑定变量**，通过调用 .debug(…)。我们将更新之前的代码片段，首先将 file_name 绑定到日志记录器，然后使用日志记录器实例打印日志消息。

import structlog   
logger = structlog.get_logger()  
...   
log = logger.bind(file_name=file_name)  
log.debug("Start uploading file.", retries=0)  
...  
log.error("Failed uploading file.", retries=retries)  
...

这使我们可以从所有日志行中删除文件名，并将其移到顶部，只调用一次。Structlog 会负责将其添加到每行日志中。

**2. 隐式绑定上下文变量**，通过调用 structlog.contextvars.bind_contextvars(…) — 此函数使用 上下文变量，在同一线程中的日志记录器打印日志消息时使用。使用上下文变量打印相同日志消息的代码片段可能如下所示：

# /controller/file.py  
  
import structlog   
  
logger = structlog.get_logger()  
...   
structlog.contextvars.bind_contextvars(file_name=file_name)  
logger.debug("Start uploading file.", retries=0)  
...  
logger.error("Failed uploading file.", retries=retries)

但是，我们的场景**不是使用上下文变量为日志记录器添加值的首选用例**。正如我们在日志记录挑战中所学到的，在经典方法中经常缺少上下文数据。在处理文件之前，我们假设存在一个身份验证和授权机制来验证用户是否拥有对端点的访问权限。在像 FastAPI 这样的框架中，这项工作是在中间件中处理的。由于我们已经在此处获取了用户 ID 来验证请求，让我们将此键值对添加到日志记录器中：

# /auth/middleware.py   
  
def verify_user(request: Request) -> bool:  
 if not validate(request.token):  
  return False  
   
 user_id = get_user_id(request.token)  
 structlog.contextvars.bind_contextvars(user_id=user_id)  
 return True

这样，structlog 将负责为我们添加此上下文信息，而无需手动添加用户 ID。

第三步 — 为机器可读日志进行配置

在学习了如何使用 structlog 将信息附加到日志行后，我们现在希望将其配置为在我们的本地开发环境设置中发送美化后的日志行，以及为我们的日志服务发送解析后的 JSON。我们将遵循 structlog 文档中的第一个也是最简单的解决方案。在继续之前，我们需要理解 structlog 的两个概念：预处理器和渲染器。

**预处理器**用于扩展日志消息的内容。这可以通过添加时间戳、修改字段以混淆用户名或根据定义的条件删除日志行来完成。

**渲染器**用于控制日志行的表示。根据用例，它们可以显示美观的彩色日志行，或机器可读的 JSON。

编写这些节点的自定义实现提供了很大的可扩展性。

我们将使用默认的 structlog 预处理器来定义日志行的内容。下图说明了如何处理使用 structlog 日志记录器的日志行。在输出步骤之后，我们根据环境添加一个渲染器，该渲染器将日志行格式化为人类可读或机器可读的输出。

来自 structlog 文档的日志架构

我们首先配置一组处理器，它们添加时间戳、设置日志级别并合并步骤 2 中使用的上下文变量。

import structlog  
from structlog.dev import ConsoleRenderer  
from structlog.processors import JSONRenderer  
  
# Timestamper preprocessor that to add unified timestamps to each log  
timestamper = structlog.processors.TimeStamper(fmt="iso", utc=True)  
  
# Structlog preprocessors  
structlog_processors = [  
  structlog.stdlib.add_log_level  
    structlog.processors.add_log_level,  
    structlog.contextvars.merge_contextvars,  
    structlog.processors.StackInfoRenderer(),  
    structlog.dev.set_exc_info,  
    timestamper,  
]

现在，我们希望定义一个函数，该函数根据环境设置返回 structlogs 的 ConsoleRenderer 或 JSONRenderer，并将此渲染器附加到处理器。

# __init__.py  
  
from structlog.dev import ConsoleRenderer  
from structlog.processors import JSONRenderer  
  
def get_renderer() -> Union[JSONRenderer, ConsoleRenderer]:  
    """  
    Get renderer based on the environment settings  
    :return structlog renderer  
    """  
    if os.get("DEV_LOGS", True):  
        return ConsoleRenderer()  
    return JSONRenderer()  
  
  
## Structlog  
structlog.configure(  
    processors=structlog_processors + [get_renderer()],  
    wrapper_class=structlog.stdlib.BoundLogger,  
    context_class=dict,  
    logger_factory=structlog.PrintLoggerFactory(),  
    cache_logger_on_first_use=False,  
)

⚠️ 这将只影响您的应用程序内打印的日志行，而不会影响您的应用程序中使用的模块产生的日志。如果您也希望这些日志以 JSON 格式化，则需要按照 structlog 文档的教程 3 进行操作。

将环境变量 DEV_LOGS 设置为 False 后，我们的日志行将以原始 JSON 格式打印。

Logs parsed as dictionaries

此格式现在可用于您的监控系统，并且可以轻松解析和聚合，因为它不再是文本流，而是易于解析的 JSON 流。

在我们的本地环境中，我们仍然可以使用旧的彩色日志行。

Pretified logs

局限性

虽然 structlog 本身不能解决日志记录的所有不一致之处，但它可以帮助实现更一致、更少出错的工作流程。

为了提高我们代码库的一致性，我们使用了一组默认的命名约定。虽然这些约定无法强制执行，但它们有助于对如何编写日志达成共识。

  1. <entity>_id <- **(必需)** 必须将每个处理的实体（例如文件）添加到日志记录器中。
  2. <entity>_name <- **(可选)** 可以添加每个实体（例如文件），并带有 _name 后缀以提高可读性。
  3. <entity>_<additional_key> <- **(可选)** 允许添加实体的附加属性，键名为后缀。
  4. <custom_usecase_specific_field> ← **(可选)** 有时，您可能需要添加特定于用例的信息。在这种情况下，您可以使用任意其他键。但是，如果可能，建议遵循 1-3 的命名约定。

这当然不是唯一的命名方式，但这是我们觉得最有效的一种。

摘要

我们已经了解到：

  1. 使用键值对格式的变量有助于创建统一的日志消息并推广一致的命名约定。
  2. 可以通过将变量绑定到日志记录器或使用上下文变量隐式添加上下文数据，从而用有用的元数据丰富日志行。
  3. 选择一个 structlog 渲染器，可以根据环境轻松地将日志行解析为机器可读或美化的人类友好格式。

**关于我：** 我是一名驻科隆的开发者，在 deepset 工作。我是构建“deepset Cloud”的团队成员，该团队由开源框架 Haystack 提供支持。

Kristof Herrmann
Kristof Herrmann 软件工程师
LinkedIn GitHub