作者 Torsten Mosis  是 systemticks GmbH的软件架构师

原文：Structured Logging – for a better system understanding

1、开篇

正如 Raphael 关于理解系统的博文中所述，在复杂系统中隔离和定位错误是一项非常具有挑战的任务。因为功能的实现总是复杂的、分布式的，跨越系统层级的，并且使用了来自许多不同组织架构、不同供应商的设备和技术。

一种比较可行的克服这些困难的方案是以一种一致的、明确的和机器可读的格式来记录系统中最有价值的信息。这种方法称为结构化日志记录。在配套工具的支持下，这些追踪数据有助于更深入地了解你的系统的运行活动，使你能够理解组件之间的相互作用。

相反，当日志仅仅作为纯非结构化文本数据使用时，很难获得任何有用的信息，尤其是在自动化日志分析的场景下。

2、分布式系统中的典型缺点

接下来，我们谈论的是分布式系统中有哪些缺点，为什么它们如此难以被发现？

2.1 接口调用的顺序不对

这是最突出的问题之一，同时也是最难发现的问题类型之一。跟踪它可能会让人很上头，比如这种情况，整个调用流并未按预期顺序来实现，整体功能肯定是无法完全正常工作的，但可能测试的调用居然获得了预期的响应。

2.2 长时间运行的请求

从功能的角度来看，该服务的行为符合预期：只要输入参数调用后就能返回一个有效结果。但是从结果来看，客户却无法完成他的任务，因为服务的响应时间太长了。可能不是你的服务接口引起的，而是调用链中的另一个服务接口。

2.3 冗余调用

在某些情况下，一个服务接口被同一个客户端以相同的参数频繁地调用。这可能是在循环调用接口的情况下作为意外而发生。但也可能是有意为之，因为客户端懒得自己缓存管理状态信息。无论怎样，这都会导致一个非功能性的问题，比如高cpu负载，因为在接口调用的背后可能会有一个巨大的call hierarchy，而这个call hierarchy会被反复触发……

2.4 其他故障

在调用接口时没有满足一些前提条件或后置条件，一个服务被一个未经授权的客户调用，多个客户不能同时得到服务，或者参数值超出范围，都可能会导致更多的故障。当然这里只是列举了一部分故障来源，除此之外还有很多。

但它们都有一个共同点，即如果你还没有记录能贯穿上下文的日志的观念，就很难识别出它们。

3、什么是需要记录的有价值的信息？

首先，需要确定在我们的应用场景中哪些信息是至关重要的，也就是说所有那些帮助我们梳理出软件组件之间是如何相互作用的信息。因为服务接口代表着系统的最前沿，所以肯定要使用结构化日志来记录跟他们相关的信息。

3.1 接口签名

由于我们主要是监控服务接口调用，所以我们需要记录所有的上下文数据，以便能将单条日志明明白白的追溯到是哪个原始接口的调用引发的。

接口签名的日志通常包含了以下名称和/或标识符：

• 接口
• 软件组件（实现该接口的）
• 被调用的方法或函数名
• 与该方法或函数一起携带的参数
  

为了使它更容易理解，请想象以下承载我们元数据的json结构。

这个结构是随意的，这里仅是一个示例用于说明目的。在生产代码中，你可以选择任意其他格式，也许还可以编码成流行的协议，如protobuf或message pack。

3.2 通信上下文

其次，我们需要将下边这样一些数据添加到我们的日志中，以便我们通过这些数据能识别出是谁在调用谁的接口：

• 消息类型（例如请求、响应、广播、事件等）
• 消息的发送者
• 消息的接收者

3.3 额外的元数据

根据我们的架构和技术环境，用更有价值的元数据来丰富我们的日志也是很有用的，比如说：

• 消息序列号
• 会话 ID
• 实例 ID
• 进程 ID
• 线程 ID

当这些信息都以如此一致和确定的方式提供后，可想而知，我们可以轻松地以编程的方式来处理这些数据并获得有价值的结果。

3.4 检查可用的内置元数据

我们还应该清楚，工程中的日志组件已经为我们提供了一些有用的内置元数据。例如，Android 日志组件的 API 强制我们显式指定日志级别和标签以及实际日志内容：

private static final String TAG = "MyApplication";
Log.i(TAG, "My important trace")

当在日志文件中看到相应的日志记录时，我们也会意识到，框架为我们隐式地放置了一些额外的元数据：

10-18 11:05:19.112  4612  4628 I MyApplication: My important trace

• 时间信息（10-18 11:05:19.112）
• 进程 ID (4612)
• 线程 ID (4628)

其他日志框架可能会提供不同的或更多的元数据，例如行号、类名、方法名等。通常可以配置日志内容和布局。在某些情况下，还可以动态附加一些额外的上下文信息。

由于在大多数项目中，底层的日志框架是不可调整的，我们应该首先检查它为我们提供了哪些可用的内置元数据。最终，我们需要将我们收集的元数据与内置元数据对齐，以避免冗余。

4、如何一致地记录日志？

众所周知：软件接口会随着时间的推移而发展。但是，如果日志是手动实现的，并且不与更改的接口一起维护，则日志会保持不变。这是一个潜在的风险，因为日志分析可能会把我们引向错误的方向，甚至让我们得出错误的结论，仅仅是因为日志数据与接口规范不一致。

因此，只要有可能，我们就应该避免手动记录服务接口调用。

4.1 生成的日志记录优于手动记录的日志

假设我们很幸运，在我们的项目结构中，服务接口是可用的声明性模型，用接口描述语言（IDL）或任何其他机器可读的模式指定。这些模型是生成处理信息发送和接收的模板代码的输入。这也是我们钩住并生成相应的日志调用的地方。

4.2 非侵入性的日志记录

在一些技术环境中，系统甚至可能为我们提供挂钩到消息传输机制本身的设施。如果是这种情况，我们应该更偏向选择这种方式，在框架内拦截消息。然后，应用程序代码将保持不变。

4.3 面向切面的日志记录

我们也可能有机会遇到允许使用面向切面编程 (AOP) 的技术环境。一些编程语言（如 Java）具有可用的 AOP 实现。它可以将横切关注点（如日志记录）从应用程序代码中分离出来。检查你的基础设施提供了什么，但通常有一种方法可以避免手动记录。

5、结论

我们现在有了如何为服务接口应用结构化日志的指南和方法。我们对什么、如何、在哪里以及何时以一致的方式记录有价值的数据有了一个概念。最后，我们需要检查结构化日志方法如何在你的环境中实际应用。但这不能笼统地回答，因为这在很大程度上取决于你的要求和现有的基础技术架构。

通信和消息传输框架的作用范围是很巨大的。这同样适用于日志基础设施。它们的API和设施能力会推动结构化日志在你的项目结构中实现的方式。