Logging Guidelines

注意

这些指南中的许多最初是作为 一个跨项目规范 编写的。

动机

一致且统一的日志格式将更好地使云管理员能够监控和维护他们的环境。因此，本文档提供了关于开发人员如何在代码中使用日志的最佳实践指南。

将变量添加到日志消息

应该延迟字符串插值，由日志记录代码处理，而不是在日志记录调用点进行处理。例如，不要这样做

# WRONG
LOG.info('some message: variable=%s' % variable)

而是使用这种风格

# RIGHT
LOG.info('some message: variable=%s', variable)

这允许日志包跳过创建格式化的日志消息，如果由于当前的日志级别而不会发出该消息。

日志级别定义

注意

以下定义最初来自 StackOverflow 上一个流行的答案。

DEBUG

显示所有内容，并且由于生成的日志量巨大，可能不适合正常的生产操作。

INFO

通常表示成功的服务启动/停止、版本以及此类非错误相关的数据。这应包括大量已完成的积极工作单元（例如启动计算服务、创建用户、删除卷等）。

AUDIT（审计）

不应使用此级别。所有先前在 AUDIT 级别上的消息应更改为 INFO，或发送到通知队列。(AUDIT 的起源是 NASA 特定的需求，导致混淆/滥用，并且与当前代码无关。)

WARNING（警告）

表示可能存在系统性问题；潜在的预测性故障通知。

ERROR

已发生错误，管理员应研究该事件。

CRITICAL

已发生错误，系统可能不稳定；需要立即引起管理员的注意。

从操作员角度来看的日志级别

我们可以从操作员的角度以以下方式思考（注意：我们不是在这里指定操作员策略，只是试图为不熟悉这些消息将如何解释的开发人员设定基调）

CRITICAL

ZOMG！集群着火了！呼叫所有值班人员，叫醒所有人。这是一个不可恢复的错误，该错误具有或可能导致服务中断或大规模降级。

ERROR

云中出现严重问题：应立即通过电子邮件/传呼机通知管理员。值班人员预计会响应。

WARNING（警告）

有些事情不对劲；应该在下个工作周进行调查。管理员应将消除警告作为正常工作的一部分。

INFO

正常状态消息，显示在系统正常运行下通过的可以测量的积极工作单元。不应过于冗长，以至于用噪声淹没真实信号。不应是连续的“我还活着！”消息。有关更多详细信息，请参阅 INFO 和以上级别的日志消息应代表一个“工作单元”。

DEBUG

开发人员日志记录级别。仅当您有兴趣阅读大量有关正在发生的事情的额外信息时才启用。有关更多详细信息，请参阅 调试开始/结束消息。

TRACE（跟踪）

在支持此级别的函数中，详细说明每个参数和操作，以帮助诊断微妙的错误。仅应为感兴趣的特定区域启用此级别，否则日志量将不堪重负。应预期一些系统性能下降。

总体日志记录原则

以下原则应适用于所有消息。

调试开始/结束消息

在 DEBUG 日志级别上，标记操作的开始和结束以跟踪流程的进度（这些流程可能在完成工作单元之前出错）通常非常重要。

应该通过存在带有指示完成该起始点的“开始”消息来清楚地表明这一点。

在真实的 OpenStack 环境中，很多事情都在并行发生。服务中有多个工作者，云中有多个服务实例。

INFO 和以上级别的日志消息应代表一个“工作单元”

INFO 日志级别定义为：“正常状态消息，显示在系统正常运行下通过的可以测量的积极工作单元。”

可测量的单位工作应由一个简短的句子片段描述，使用过去时态的动词和名词来描述一些重要的事情。

示例

Instance spawned

Instance destroyed

Volume attached

Image failed to copy

像“started”（开始）、“finished”（完成）或任何以“ing”结尾的动词都是非工作单元消息的标志。

INFO 的良好和不良用例示例

以下是一些 INFO 的良好和不良用例示例。在良好的示例中，我们可以看到“名词/动词”片段表示一个工作单元。“Successfully”（成功）可能多余，可以删除。

良好

2014-01-26 15:36:10.597 28297 INFO nova.virt.libvirt.driver [-]
[instance: b1b8e5c7-12f0-4092-84f6-297fe7642070] Instance spawned
successfully.

2014-01-26 15:36:14.307 28297 INFO nova.virt.libvirt.driver [-]
[instance: b1b8e5c7-12f0-4092-84f6-297fe7642070] Instance destroyed
successfully.

在不良示例中，我们看到将跟踪级别思维放入 INFO 级别及以上的消息中

不良

2014-01-26 15:36:11.198 INFO nova.virt.libvirt.driver
[req-ded67509-1e5d-4fb2-a0e2-92932bba9271
FixedIPsNegativeTestXml-1426989627 FixedIPsNegativeTestXml-38506689]
[instance: fd027464-6e15-4f5d-8b1f-c389bdb8772a] Creating image

2014-01-26 15:36:11.525 INFO nova.virt.libvirt.driver
[req-ded67509-1e5d-4fb2-a0e2-92932bba9271
FixedIPsNegativeTestXml-1426989627 FixedIPsNegativeTestXml-38506689]
[instance: fd027464-6e15-4f5d-8b1f-c389bdb8772a] Using config drive

2014-01-26 15:36:12.326 AUDIT nova.compute.manager
[req-714315e2-6318-4005-8f8f-05d7796ff45d FixedIPsTestXml-911165017
FixedIPsTestXml-1315774890] [instance:
b1b8e5c7-12f0-4092-84f6-297fe7642070] Terminating instance

2014-01-26 15:36:12.570 INFO nova.virt.libvirt.driver
[req-ded67509-1e5d-4fb2-a0e2-92932bba9271
FixedIPsNegativeTestXml-1426989627 FixedIPsNegativeTestXml-38506689]
[instance: fd027464-6e15-4f5d-8b1f-c389bdb8772a] Creating config
drive at
/opt/stack/data/nova/instances/fd027464-6e15-4f5d-8b1f
-c389bdb8772a/disk.config

这主要是过度共享问题。在 INFO 级别，这些阶段实际上不需要完全沟通。

消息不需要一个秘密解码器

不良

2014-01-26 15:36:14.256 28297 INFO nova.compute.manager [-]
Lifecycle event 1 on VM b1b8e5c7-12f0-4092-84f6-297fe7642070

通常，在使用常量或枚举时，请确保在发送到用户之前将它们转换回用户字符串。

特定事件类型

除了上述指南之外，还存在非常具体的其他建议。这些是指导方针，而不是必须遵守的硬性规则，因此应始终运用常识。

WSGI 请求

  • 应在 INFO 级别记录。

  • 应每个请求记录一次。

  • 应包含足够的信息来了解请求的内容（但不要过多，以免使日志不堪重负）。

最后一点值得注意的是，某些 POST API 请求不包含足够的信息在 URL 中来确定 API 做了什么。例如，Nova 服务器操作（其中 POST 包含方法名称），虽然包含 POST 请求有效负载可能过于冗长，因此应运用常识。

理由：操作员应该能够轻松地查看他们的用户在他们的云中发出的 API 请求，以了解他们的用户对他们的云的使用模式。

操作员弃用警告

  • 应在 WARN 级别记录。

  • 在可能的情况下，应在每个服务启动时记录一次（而不是在代码中的每个请求上）。但是，跟踪是否已经发出警告可能很棘手，因此应根据常识确定最佳方法。

  • 应包括关于如何迁移到弃用状态的说明。

理由：操作员需要知道他们的云配置的某些方面现在已被弃用，并且将来需要进行更改。他们需要足够的线索来弄清楚如何做到这一点。

REST API 弃用警告

  • 不应记录高于 DEBUG 级别，因为这些不是面向操作员的消息。

  • 不应记录超过每个 REST API 使用/项目一次，绝对不是在每个 REST API 调用上。

理由：REST API 的用户无法访问系统日志。因此，在 WARNING 级别记录是在告诉错误的人他们正在使用弃用的 API。

应通过用户界面机制（例如与新 API 版本关联的 API 变更说明）来沟通用户界面 API 的弃用。

日志中的堆栈跟踪

  • 应该是特殊事件，用于无法预见且系统尚未恢复的情况。

  • 应在 ERROR 级别记录。

  • 应被开发团队视为高优先级错误。

理由：OpenStack 的当前行为非常喜欢堆栈跟踪。许多现有的堆栈跟踪在日志中被认为是正常的。这大大增加了找到 OpenStack 中实际问题的根本原因所需的时间。

非 OpenStack 组件的日志记录

OpenStack 使用了大量的库，这些库有自己对日志记录的定义。这导致了在正常日志中存在大量来自不同库的无关信息。

因此，应调整所有第三方库的日志级别，以便仅记录实际错误。

当前建议的第三方库设置

  • amqp=WARN

  • boto=WARN

  • qpid=WARN

  • sqlalchemy=WARN

  • suds=INFO

  • iso8601=WARN

  • requests.packages.urllib3.connectionpool=WARN

  • urllib3.connectionpool=WARN

测试

请参阅 https://blueprints.launchpad.net/nova/+spec/clean-logs 提供的测试

参考