原文：Structured Logging: The Best Friend You’ll Want When Things Go Wrong

介绍

   在这篇文章里，我们重点介绍结构化日志。我们讨论是是什么，为什么好，以及如何构建一个框架更好的与我们当前基于Elastic stack的日志后端集成，使我们更好，更高效记日志。

   结构化日志是我们竭力做的很大一部分，结构化日志能让我们减少bug解决时间（MTTR），中断时帮助开发人员更快地缓解问题。

什么是日志？

   日志是包含有关系统中发生一些事件的几行文本信息，并且起着帮助我们了解后端正在发生的事情的重要作用。日志通常放置于重要事件的代码中（例如：成功操作某些数据库，或者指派司机给乘客），或我们感兴趣留意的代码中。

   当有错误时，正常开发者做的第一件事情就是查看日志——有点像浏览系统的历史，并且找出发生了什么。因此，在服务中断、错误、构建失败时，日志成为开发人员最好的朋友。

现在的日志具有不同的格式和功能

• 日志格式：从基于键-值（像syslog）到非常结构化和详细（像JSON）。由于日志主要用于开发者的眼睛，因此日志详细和结构化程度决定了开发者查询和阅读日志的速度。数据越结构化——每行日志就越大，尽管更易于查询和包含更丰富的信息。
• 等级日志（或日志等级）：不同等级对应着不同重要性的日志。可见性可限制单个等级，仅限于某些重要性或等级以上的日志（如：仅记录WARN和更高等级）。通常日志等级在生产环境中是静态的，查找DEBUG等级的日志通常需要重新部署。
• 日志集后端：日志有不同的日志集后端，也意味着不同的后端（如：Splunk, Kibana等）决定了日志的样式或者用他们能做些什么。一些人可能比其他人使用的更多。
• 因果顺序：日志可能也可能不会保存写入的实际时间。这很重要，因为时间的确切程度决定了我们通过日志预测事件顺序的准确程度。
• 日志关联：我们服务于后端服务的无数请求。能看到与特定请求或特定事件相关的所有日志，帮助我们深入到特定请求的相关信息中（例如：试图登记骑乘的特定乘客）。

   将此与过多可用的日志库结合起来，很容易让开发人员懵逼，无法决定使用什么。此外，每个库都有自己的优缺点，因此讨论可能很快变得主观化和极端化——因此，为你的程序选择适当的库和后端非常重要。

   我们在Grab中使用不同类型的日志库。然而，随着需求的变化——我们也发现我们自己正在重新评估日志策略。

Grab中日志的状况

   Grab的Golang服务的数量持续增长。大多数服务使用syslog键值格式的日志，由于简单，并且容易读写，因此是服务端程序中最常见的格式。所有这些日志可能是少量的公共库实现，不同的服务直接引用这些库来使用。

   我们使用基于云的SaaS供应商作为这些日志的前端，应用程序产出的日志写入文件中并发送给我们的日志供应商，从而可以实时查看和查询。很长一段时间里使用的非常不错，也无任何磕绊。

   然而，随着时间推移，我们的日志清单上升到了前所未有的等级，发现我们自己正在重新审视并且重新评估如何记日志。出现的一些问题：

• 减少日志量的努力在某些程度上是成功的——但也是艰巨而痛苦的。一部分原因是几乎所有的日志都是单一的日志等级——INFO

图1：使用日志等级

   这个问题不是在单个服务中，而是在所有服务都很普遍。为了缓解，有些服务对日志抽样，有些服务完全删除了日志。后者会后患无穷，因此我们必须改善日志等级。

• 当时对我们来说使用供应商有点昂贵，也有些顾虑——主要受限于DSL(查询语言)。有很多优秀的开源的替代方案——Elastic stack是其中的一个。我们的工程师确信我们可以管理我们的日志基础架构并更好地管理成本——这导致了提议构建Elastic堆栈日志集群。 Elasticsearch比我们当时的供应商强得多，而且我们当前的库不足以充分利用其功能，因此我们需要在日志中有更好的结构并轻松与Elastic堆栈集成的库。
• 我们的日志库中有些小问题：
  • 单一的初始化方案更难做单元测试
  • 单一的日志接口减少了日志核心功能的扩展性，因为几乎所有服务直接导入日志接口
  • 不支持多写的开箱即用。
• 如果我们写个日志库，必须要解决这些问题——并鼓励使用最佳实践
• Grab的关键路径（单个订单流程请求经过的服务数量）大小已经增长了。平均，单个订单请求涉及的微服务——每一个都不同。因此，我们大规模的运营时，很有必要对单个请求容易地查看流经的所有的服务日志——然而这不是我们的日志库自动完成的功能。因此，我们也想要更容易、更好的日志关联。
• 日志是某个时间点的事件。事件的顺序给与我们系统发生了什么的完整历史。然而，我们Golang服务的核心日志库没有保存日志的产生时间（而是写入时间）。这导致了在几微妙内产生的日志造成混乱。这不仅使开发者的生活更困难，而且几乎无法准确的获得系统的历史事件。这就是我们想改进和启用因果排序的日志——是了解系统事件的关键一步。

为什么改变？

   如上所述，我们知道怎么记日志会有些问题。为了最好的解决问题，并且在不影响现有的架构和服务尽量的解决问题，决定从头启动一个新库。这个库应该能解决已知的问题，也包含修改现有的库无法实现的功能。扼要重述，我们想解决的：

• 增加日志等级
• 更好的日志结构
• 容易集成到Elastic stack
• 鼓励使用最佳实践
• 日志关联更容易、更好
• 改进并启用日志的因果排序，以便更好地了解服务分配

调查结构化日志。结构化日志在全世界非常受欢迎，广泛被采用。容易的集成到我们的Elastic stack中，也解决了我们的很多痛点。

结构化日志

   记住我们之前的问题和需求，我们用Golang新建了一个库，有一下功能：

动态日志等级

允许我们在运行时从配置管理系统改变初始化的日志等级——这是之前无法做到和被鼓励的。

现在，日志等级更有实际意义。现在开发人员可以用常用的WARN或者INFO部署，当出现问题时，仅更改配置就能更新日志的等级到DEBUG,并且调试时他们的服务能输出更多的日志。这也有助于我们控制日志成本。我们支持和我们的配置管理系统简单容易低集成。

日志结构一致性

日志天生是无结构化的，不像数据库模式的死板或者自由格式的文本那样无结构化。我们 Elastic stack后端主要基于带有映射（像松散的模式）的索引（类似于表）。为此，我们需要用一致性结构的JSON输出（例如，在相同JSON字段下不能输出整数和字符串，因为这会导致Elasticsearch索引失败）。另外，我们意识到我们的主要目标之一是控制日志成本，因为几乎每个字段的结构和索引都没有意义——只添加对我们有用的结构。

为了解决这些，我们构建一个允许我们确定地为日志添加结构。这是建立在我们可以用特殊的字段名和类型添加键值对的架构之上。根据该模式生成代码，并使用生成的代码确保事物的一致的格式且不会中断。我们称这种模式（键名和类型对的集合）为Common Grab Log Schema (CGLS)。我们仅向CGLS中添加结构是很重要的——CGLS中包含的所有内容在不同的字段中格式化，其他内容在生成的JSON中的单个字段中格式化。这有助于保持我们的结构一直并且易于使用Elastic stack。

图2：Golang后端服务的通用抓取日志架构概述

支持使用Grab-Kit即插即用

   我们通过对Grab-Kit内部支持进行初始化，使用简单并且开箱即用，因此，开发者无需修改即可使用。此外，作为整体的一部分，我们基于追踪中存在的请求ID添加了自动的日志关联，这确保了具有该跟踪ID的特定请求生成所有日志。

可配置的日志格式

   我们主要的需求是构建一个有足够的表现和一致性，以便更好的与Elastic stack后端集成，在下游无需经过花哨的解析。因此，该日志库具有的表现力和可配置性足以允许任何日志格式（我们可以对不同功能的用例写不同的日志格式，例如，开发设置中的可读格式和产品设置中的输出JSON格式），默认是输出JSON格式。这确保了我们可以生成与Elastic stack兼容的日志输出，但仍然可以针对不同的用例进行配置。

支持不同格式的多写

作为日志库功能扩展的一部分，我们需要足够的可配置性，以便能够发送不同的日志到有不一样的设置的不同地方。例如，异步发送易读的格式的FATAL日志到Slack，同时将所有的常用日志发送的我们的Elastic stack后端。该日志库包括支持将这些”核心“连接到任意可能的程度——确保这些日志器被用在此类高度专业化的情况。

开发中类似生产环境的日志

开发者从一开始就看到了控制台日志，然而，有结构化的JSON日志一般认为是产品的日志，而且更易于搜索。为了更好的在开发过程中利用，并且让开发者直接在Kibana中看到他们的日志，我们提供了docker化版本的Kibana，可以在本地运行以接收结构化日志。这可以让开发者直接使用结构化日志并且在Kibana中看到——就像生产环境中那样。

这个日志库让我们用更好的方式打日志。最显而易见的影响是我们能简单的访问日志，能够使用更好的过滤和条件来更好的查询。

图3：开发中类似生产环境的日志

因果顺序

有精确历史记录的事件让在生产环境的系统中调试问题更容易——因为仅看到历史记录就能很快的猜测出错误原因并且修复。为此，结构化日志库在日志器中添加了精确的写入时的纳秒时间戳。这与类似JSON结构化的格式结合让根据这些字段排序所有的日志成为可能——因此我们以他们发生的确切的顺序看日志——在日志中实现因果顺序。这是看起来的低调，但是使调试容易的强大功能。

图4：使用Y'ALL的因果顺序日志

但为什么要结构化记日志？

现在你已经知道了我们日志策略背后的历史和原因，让我们总结下从中获得的福利。

一开始，有明确定义和结构化（像JSON）的日志有很多好处，包括但不仅限于：

• 更好的根本原因分析： 使用结构化日志，我们可以提取和执行更强大的查询，这对于非结构化的日志是不可能的。开发人员可以在查找与情况相关的日志时进行更多信息性查询。不仅于此，日志关联和因果顺序对更好的理解分布式日志成为可能。不像无结构的数据，我们仅局限于全文或者少数的日志类型，结构化日志达到了全新的水平。

• 更高的透明度或更好的可观察性：使用结构化日志，提高了系统发生情况的可见性——因为现在你可以用更好，更有变现力的方式记录信息。这可让你更透明的观察系统发生的情况，并且让你系统在更长的周期内更容易的维护和调试。

• 更好的标准化：使用单一，定义明确，结构化的方式去记日志使我们的日志标准化——这减少了通过日志确定系统发生的事件的认知，并且更易采用。而不是通过100种不同类型的日志，而是只有一种格式。这也是日志库的目标之一——通过Golang后端服务日志库的标准化使用。

我们还获得额外的好处：

• 动态日志等级： 使代码中的日志等级富有意义——我们可以用基线设置部署，并且仅当我们需要的时候切换到更低的等级（debug等级的日志）。有助于我们降低日志成本，同样也减少开发人员在调试时通常需要搜查的无关日志。

• 日志中面向未来的一致性： 通过采用通用模式，确保我们坚持使用相同的模式，即使明天我们的日志基础架构改变——我们做好未来的准备。我们可以简单在我们的日志器中暴露一个函数，而不是手动地指定要记录的内容。

• 开发中类似生产的日志环境： docker化的Kibana使开发人员享受到与生产环境中的Kibana同样的好处。这也更激励开发认识使用Elastic stack并探索它的功能，像基于日志数据构建仪表盘，有更好的查看方式，等等。

希望你喜欢这篇文章并发现它的有用之处。欢迎提出意见和更正。