作者：David Yanacek
 PDF  Kindle

深入研究日志

当我大学毕业后加入 Amazon 时，初次入职培训的其中一项是在我的开发人员桌面上启动并运行 amazon.com Web 服务器。我的第一次尝试并没有做好，而且我不清楚是哪里做错了。一位乐于助人的同事建议我打开日志看看是哪里出错了。而要这样做，他说我应该“cat 日志文件”。 当时我真以为同事们在和我开玩笑，或者在说一个关于猫的笑话，只不过我没听懂。我在大学里使用 Linux 只是为了编译、使用源代码控制和使用文本编辑器。所以，我不知道“cat”其实是一个命令，用来将文件内容输出到终端，之后，这些内容可以输入到其他程序中，以便查找模式。

同事们向我推荐了 cat、grep、sed 和 awk 等工具。我使用这套新工具在开发人员桌面上深入研究 amazon.com Web 服务器日志。经检测，Web 服务器应用程序已将各种有用信息发送到其日志中。这样一来，我可以通过查看日志知道缺少了哪项配置，导致 Web 服务器无法启动，或者导致我无法知道其可能在哪个地方崩溃或未能与下游服务通信。整个网站由许多动态部分组成，而且一开始对我来说基本上就是一个黑盒。但是，在深入研究系统之后，我学会了如何仅通过查看检测的输出来确定服务器的工作方式以及与其依赖关系交互的方式。

为何要进行检测

这些年来，我先后在 Amazon 的不同团队中工作，期间我发现检测是很有价值的透视工具，让我和其他 Amazon 员工能够清楚了解系统的工作方式。但是，检测的作用并不只是了解系统状况。它是 Amazon 运营文化的核心。卓有成效的检测能帮助我们了解我们带给客户的体验。
 
这种对运营绩效的关注贯穿我们整个公司。在与 amazon.com 关联的服务中，延迟增加会造成糟糕的购物体验，从而降低转化率。对于使用 AWS 的客户，他们依赖于 AWS 服务的高可用性和低延迟。
 
在 Amazon 内部，我们不只是考虑平均延迟。我们 更密切地关注延迟异常值，例如第 99.9 和第 99.99 百分位。这是因为，如果 1000 或 10000 个请求中有一个很慢，则仍然是糟糕的体验。我们发现，如果降低系统中的高百分位延迟，这会带来降低中值延迟的副作用。相比之下，如果降低中值延迟，较少会导致高百分位延迟降低。
 
我们关注高百分位延迟的另一个原因是：某个服务中的高延迟可能会在其他服务中产生乘数效应。Amazon 建立在面向服务的架构上。许多服务彼此协作来完成工作，例如在 amazon.com 上呈现网页。因此，如果调用链深处的服务的延迟增加（即使增加发生在高百分位中），会对最终用户感受到的延迟造成巨大的连锁反应。
 
Amazon 的大型系统由许多协同工作的服务组成。每个服务都由一支单独的团队开发和运营（大型“服务”由后台的多个服务或组件组成）。拥有服务的团队称为 服务拥有者。该团队的每个成员均像服务的拥有者和运营者一样思考，无论该成员是软件开发人员、网络工程师、经理还是任何其他角色。作为拥有者，团队设定与所有关联服务的运营绩效相关的目标。我们还确保能看到服务运营状况，以保证我们达成这些目标、处理出现的任何问题和促使自己在第二年达成更高的目标。为了设定目标和获得这种可见性，团队必须对系统进行检测。
检测还使我们能够有策略地探测和应对运营事件。
 
检测向运营控制面板提供数据，以便运营者能够查看实时指标。它还向警报提供数据，当系统发生意外行为时，警报便会触发并引起运营者关注。运营者使用详细的检测输出快速诊断出错的原因。这样一来，我们可以缓解问题，以后再设法防止问题复发。如果整个代码中未包含有效的检测机制，我们将要花费宝贵的时间来诊断问题。

测量对象

为了按照我们针对可用性和延迟制定的高标准来运营服务，作为服务拥有者，我们需要测量系统的具体表现。

为获得必需的遥测数据，服务拥有者从多个位置测量运营绩效，以便从多个角度了解各组件的端到端具体表现。这即使在简单的架构中也很复杂。思考一下客户通过负载均衡器调用的某个服务：该服务与远程缓存和远程数据库通信。我们希望每个组件都发送有关其行为的指标。我们还希望获得反映每个组件对其他组件的行为有何感受的指标。将来自所有这些角度的指标汇集起来时，服务拥有者能迅速查明问题的起源并挖掘出原因。

许多 AWS 服务都会自动提供有关您的资源的运营见解。例如，Amazon DynamoDB 提供有关成功率、错误率和延迟的 Amazon CloudWatch 指标（由该服务测量）。但是，当我们构建使用这些服务的系统时，我们需要获得高很多的可见性，以便了解系统的具体表现。检测需要显式代码来记录任务要执行多长时间、某些代码路径多久执行一次、与任务执行的工作相关的元数据和任务的哪些部分成功或失败。如果团队未添加显式检测，则检测可能会被迫将其自己的服务作为黑盒来运营。

例如，如果我们实现了一个按产品 ID 来检索产品信息的服务 API 操作，代码可能会类似下例所示。此代码依次在本地缓存、远程缓存和数据库中查找产品信息：

public GetProductInfoResponse getProductInfo(GetProductInfoRequest request) {

  // check our local cache
  ProductInfo info = localCache.get(request.getProductId());
  
  // check the remote cache if we didn't find it in the local cache
  if (info == null) {
    info = remoteCache.get(request.getProductId());
	
	localCache.put(info);
  }
  
  // finally check the database if we didn't have it in either cache
  if (info == null) {
    info = db.query(request.getProductId());
	
	localCache.put(info);
	remoteCache.put(info);
  }
  
  return info;
}

如果我运营此服务，我需要在此代码中进行大量检测才能了解此服务在生产系统中的行为。我需要能够对失败或缓慢的请求进行故障排查，以及监视不同依赖关系未达下限或行为不当的趋势和迹象。下面是相同的代码，但带有一些问题注释（我需要能够解答这些与整个生产系统相关或针对特定请求的问题）：

public GetProductInfoResponse getProductInfo(GetProductInfoRequest request) {

  // Which product are we looking up?
  // Who called the API? What product category is this in?

  // Did we find the item in the local cache?
  ProductInfo info = localCache.get(request.getProductId());
  
  if (info == null) {
    // Was the item in the remote cache?
    // How long did it take to read from the remote cache?
    // How long did it take to deserialize the object from the cache?
    info = remoteCache.get(request.getProductId());
	
    // How full is the local cache?
    localCache.put(info);
  }
  
  // finally check the database if we didn't have it in either cache
  if (info == null) {
    // How long did the database query take?
    // Did the query succeed? 
    // If it failed, is it because it timed out? Or was it an invalid query? Did we lose our database connection?
    // If it timed out, was our connection pool full? Did we fail to connect to the database? Or was it just slow to respond?
    info = db.query(request.getProductId());
	
    // How long did populating the caches take? 
    // Were they full and did they evict other items? 
    localCache.put(info);
    remoteCache.put(info);
  }
  
  // How big was this product info object? 
  return info;
}

用于解答所有这些问题和更多问题的代码比实际业务逻辑长很多。某些库可以帮助减少检测代码数量，但开发人员仍必须提出与这些库将需要的可见性有关的问题，然后必须特意在检测中写出这些问题。

在对流经分布式系统的请求进行故障排查时，如果只是根据一次交互来查看该请求，可能难以了解发生的情况。要整合全局，我们发现将有关所有这些系统的测量结果汇集到一处很有用。在我们可以这样做之前，必须检测每个服务，以记录每个任务的跟踪 ID，并将该跟踪 ID 传播到协同完成该任务的其他每个服务。可以根据需要在事后跨系统针对特定跟踪 ID 集中进行检测，也可以使用 AWS X-Ray 之类的服务近实时地集中进行检测。

向下钻取

通过检测，可以在多个级别（从浏览指标以了解是否存在因过于微小而无法触发警报的任何异常，到进行调查以找出这些异常的原因）进行故障排查。

在最高级别，检测聚合到可以触发警报并显示在控制面板上的指标中。这些聚合指标可让运营者监视总体请求速率、服务调用的延迟和错误率。借助这些警报和指标，我们能够知道应调查的异常或变化。

看到异常后，我们需要找出发生异常的原因。我们依靠通过更多检测建立的指标来解答该问题。通过检测执行请求处理过程的不同部分所需的时间，我们可以看到处理过程的哪个部分比平常慢或更频繁地触发错误。

虽然聚合计时器和指标可能可以帮助我们排除原因或确定重点调查领域，但它们并不总能提供全面的解释。例如，我们可能可以从指标中知道错误来自某特定的 API 操作，但这些指标可能并未充分揭示该操作为何失败的细节。此时，我们查看服务发送的该时间窗口的原始详细日志数据。原始日志会显示问题的起源 – 所发生的特定错误，或者触发某些边缘情况的特定请求方面。

如何进行检测

需要编写代码才能进行检测。这意味着在我们实现新功能时，我们需要花时间添加额外的代码，以指出发生的事情、它已成功还是已失败以及耗用了多长时间。由于检测是这样一种常见的编码任务，多年来 Amazon 内部形成了一套做法来处理通用模式：通用检测库标准化，以及基于结构化日志的指标报告标准化。

指标检测库标准化帮助库作者向库使用者提供库工作方式的可见性。例如，常用的 HTTP 客户端与这些通用库集成在一起，因此，如果服务团队执行对其他服务的远程调用，他们将自动获得有关这些调用的检测。

在被检测的应用程序运行并执行工作时，生成的遥测数据将写入到结构化日志文件中。通常，该数据作为每个“工作单元”的一个日志条目发送，而不管这是对 HTTP 服务的请求还是从队列中取出的消息。

在 Amazon 内部，应用程序中的测量结果并不聚合起来，但有时会刷新到指标聚合系统中。各部分工作的所有计时器和计数器均写入到日志文件中。通过这样做，另一个系统将在事后处理日志和计算聚合指标。这样一来，我们最终获得了各种数据（从高级别的聚合运营指标到请求级别的详细故障排查数据），而这是通过一种代码检测方法实现的。在 Amazon 内部，我们首先记录日志，之后再产生聚合指标。

通过日志记录进行检测

我们通常在检测服务后发送两种类型的日志数据：请求数据和调试数据。请求日志数据通常表示为结构化日志条目（每个工作单元一个条目）。此数据包含有关以下各项的属性：请求、请求发出者、请求目的、事情多久发生一次的计数器和事情占用多长时间的计时器。对于在服务中发生的每件事情，请求日志起着审计日志和跟踪的作用。调试数据包含应用程序发送的任何调试行的非结构化数据或松散结构化数据。通常，这些数据是非结构化日志条目，例如 Log4j 错误或警告日志行。在 Amazon 内部，这两种类型的数据通常发送到不同的日志文件中，这部分是出于历史原因，但另一个原因是使用同构的日志条目格式进行日志分析可能比较方便。

像 CloudWatch Logs 代理这样的代理实时处理这两种类型的日志数据，并将日志发送给 CloudWatch Logs。接下来，CloudWatch Logs 会近实时地产生有关服务的聚合指标。Amazon CloudWatch Alarms 读取这些聚合指标并触发警报。

虽然为每个请求记录如此多的细节可能成本高昂，但在 Amazon 内部，我们发现这样做非常重要。毕竟，我们需要调查可用性波动、延迟激增和客户报告的问题。如果没有详细的日志，我们无法向客户提供答案，而且无法改善他们的服务。 

深入了解详细信息

监视和警报是一个很大的主题。在本文中，我们不讨论类似以下这些的主题：设置和调整警报阈值、组织运营控制面板、从服务器端和客户端测量性能、持续运行“金丝雀”应用程序以及选择适用于聚合指标和分析日志的系统。

本文重点讨论检测应用程序以产生正确原始测量数据的必要性。我们将说明 Amazon 内部团队在检测应用程序时努力做到或避免的事情。

请求日志最佳实践

在本节中，我将介绍与记录“每个工作单元”的结构化数据相关的良好习惯，这些习惯是我们在 Amazon 逐渐学会的。符合这些标准的日志包含：表示事情多久发生一次的计数器、包含事情占用的时间长度的计时器和包含每个工作单元相关元数据的属性。

我们的记录方式

• 为每个工作单元发送一个请求日志条目。 工作单元通常是指我们的服务收到的一个请求或它从队列中取出的一条消息。我们为服务收到的每个请求编写一个服务日志条目。我们并不将多个工作单元组合在一起。这样一来，在对失败的请求进行故障排查时，我们只需查看一个日志条目。该请求的相关输入参数（指示请求尝试做的事情）、发起者是谁的相关信息以及所有计时和计数器信息都包含在这个条目中。
• 为指定的请求最多发送一个请求日志条目。 在非阻塞的服务实现中，为处理管道中的每个阶段发送一个单独的日志条目似乎较为方便。但是，我们将一个句柄联结到靠近管道中阶段之间的单个“指标对象”，然后在所有阶段完成后将指标作为整体序列化并输出，这种做法让我们更成功地排除这些系统的故障。每个工作单元具有多个日志条目会使日志分析变得更困难，并会使已经很高的日志记录开销成倍增加。如果我们编写新的非阻塞服务，我们会尝试预先规划指标的日志记录生命周期，这是因为过后再重构和修复会非常困难。
• 将长时间运行的任务分解为多个日志条目。 与前面的建议相反，如果我们有一个长时间运行（数分钟或数小时）且类似于工作流程的任务，我们可能会决定定期发送一个单独的日志条目，以便我们能确定是否正取得进展或者在哪个地方减慢了速度。
• 在执行验证等操作之前记录有关请求的详细信息。 我们发现，以下这一点对故障排除和审计日志记录很重要：充分记录有关请求的信息，以便我们知道请求尝试完成的事情。我们也发现尽早记录这些信息（在请求可能被验证、身份验证或限制逻辑拒绝之前）很重要。如果我们记录传入请求中的信息，我们会确保在记录之前对输入进行清理（编码、转义和截断）。例如，如果发起者传入一个服务日志条目，我们不希望它包含长度为 1MB 的字符串。否则，会出现填满磁盘的风险，并导致我们在日志存储方面付出超过预期的代价。另一个清理示例是筛选出与日志格式相关的 ASCII 控制字符或转义序列。如果发起者传入自己的服务日志条目，而且能够将其注入到我们的日志中，这可能会造成混乱！ 另请参阅：https://xkcd.com/327/
• 找出方法记录更详细的信息。 对某些类型的问题进行故障排查时，日志中未包含与造成问题的请求相关的充足细节，导致无法找出请求失败的原因。服务中可能提供了这些信息，但信息量可能太大，以致于无法一直能证明记录这些信息是合理的。以下做法可能很有用：设置一个配置旋钮，您可以在调查问题时转动此旋钮，以暂时提高日志的详细程度。您可以在单个主机上或者为单个客户端或在队列中按照某个采样率转动此旋钮。完成后务必记得重新调小此旋钮。
• 使指标名称保持简短，但不要太短。 Amazon 使用相同的服务日志序列化已超过 15 年。在此序列化中，每个计数器和计时器名称均在每个服务日志条目中以纯文本形式重复。为了帮助最大程度减少日志记录开销，我们使用简短但具有描述性的计时器名称。Amazon 正在开始采用新的序列化格式，该格式基于名为 Amazon Ion 的二进制序列化协议。最后，务必要选择日志分析工具能理解的格式，而且该格式还要在序列化、反序列化和存储方面尽可能地高效。
• 确保日志卷足够大，能在最大吞吐量下处理日志记录。 我们在最大持续负载甚至过载的情况下对服务进行数小时的负载测试。我们需要确保在我们的服务处理超限流量时，服务仍然具有资源按照日志产生新日志条目的速度发走日志，否则磁盘最终将会填满。您也可以将日志记录配置为在不同于根分区的文件系统分区上进行，以免系统在面对过多的日志记录活动时崩溃。我们稍后会讨论此问题的其他缓解措施（例如使用与吞吐量成正比的动态采样），但无论采用何种策略，关键是要进行测试。
• 思考磁盘填满时的系统行为。在服务器的磁盘填满时，服务器无法将日志记录到磁盘中。如果发生这种情况，服务是应停止接受请求，还是应删除日志并在无监控的情况下继续运营？ 在无日志记录的情况下运营充满风险，因此，我们对系统进行测试，确保检测到服务器磁盘将满的状况。
• 同步时钟。 众所周知，分布式系统中的“时间”概念很复杂。我们在分布式算法中并不依赖时钟同步，但要发挥日志的作用，必须实现时钟同步。我们运行 Chrony 或 ntpd 之类的守护程序来实现时钟同步，而且我们监控服务器的时钟偏差。为了更轻松地做到这一点，请参阅 Amazon Time Sync Service。
• 为可用性指标发送零计数。错误计数很有用，但错误百分比同样很有用。要通过检测确定“可用性百分比”指标，我们发现很有用的一个策略是：在请求成功时发送 1，而在请求失败时发送 0。所产生的指标的“平均”统计数据即为可用率。在其他情况下，特意发送数据点 0 也可能很有用。例如，如果应用程序执行领导选举，那么，在某个进程成为领导时定期发送 1，而在该进程不是领导时发送 0，可能对于监视跟随者的状况很有用。这样一来，如果某进程停止发送 0，可以更容易地知道该进程中出现了错误，而且，如果领导发生了状况，该进程将无法接任领导。

我们记录的内容

• 记录所有依赖关系的可用性和延迟。 我们发现这在解答“请求为何很慢？”或“请求为何失败？”问题时特别有用。 如果没有此日志，我们只能将依赖关系的图形与服务的图形进行比较，并且猜测是否因依赖服务的延迟激增导致我们调查的请求失败。许多服务和客户端框架都会自动联结指标，但另一些框架（例如 AWS 开发工具包）需要手动进行检测。
• 分解每个调用、每个资源、每个状态代码等的依赖关系指标。 如果我们在同一工作单元中与同一个依赖关系交互多次，我们会将有关每次调用的指标分别包括在内，并明确每个请求与哪个资源交互。例如，在调用 Amazon DynamoDB 时，某些团队发现将每个表、每个错误代码甚至每个重试次数的计时和延迟指标包括在内很有用。这样一来，可以更容易对以下这种情况进行故障排查：因条件检查失败进行重试，但服务的响应速度很慢。这些指标还揭示了此类情况：客户端之所以感知到延迟增加，实际原因是限制重试或对结果集进行分页，而不是数据包丢失或网络延迟。
• 访问内存队列深度时记录这些深度。 如果请求与队列进行交互，而且我们正从队列中取出对象或将对象放入队列中，我们会在到达当前队列深度时将其记录到指标对象中。对于内存中队列，可以通过非常廉价的方式获得此信息。对于分布式队列，在响应 API 调用时可以免费获得此元数据。此日志记录将在未来帮助查找积压工作和延迟的来源。此外，当我们从队列中取出对象时，我们会测量对象在队列中停留的时间长度。这意味着我们首先需要将自己的“排入队列时间”指标添加到消息中，然后再将消息排入队列。
• 为每个错误原因添加一个额外的计数器。考虑添加代码，对每个失败请求的特定错误原因进行计数。应用程序日志将包含导致失败的信息和详细的异常消息。但是，我们还发现，无需在应用程序日志中挖掘该信息即可在指标中看到一段时间内的错误原因趋势很有用。对于每个失败异常类，可以很方便地从一个单独的指标开始。
• 按原因类别组织错误。 如果所有错误均归入同一指标，该指标会变得具有干扰性和没有用处。至少，我们发现将属于“客户端出错”的错误与属于“服务器出错”的错误相分开很重要。 除此之外，进一步细分可能很有用。例如，在 DynamoDB 中，客户端可能会发起条件写入请求，如果这些请求修改的项不符合请求中的前提条件，这些请求会返回错误。这些错误是特意造成的，而且我们预计它们会偶尔发生。但是，来自客户端的“无效请求”错误极有可能是我们需要修复的错误。
• 记录有关工作单元的重要元数据。 在结构化指标日志中，我们还包含了有关请求的充足元数据，以便我们以后能确定请求来自谁和请求尝试做什么。这包括了客户在遇到问题向我们求助时希望我们的日志包含的元数据。例如，DynamoDB 会记录请求与之交互的表的名称，以及类似于读取操作是否是一致性读取的元数据。但是，它不会记录存储到数据库或从数据库检索的数据。
• 通过访问控制和加密来保护日志。由于日志包含某种程度的敏感信息，因此我们采取多种措施来保护这些数据。这些措施包括：加密日志，规定只有对问题进行故障排查的操作人员才能访问日志，以及定期检查这种访问是否符合基准。
• 避免将过于敏感的信息放入日志中。 日志需要包含一些敏感信息才能发挥作用。在 Amazon 内部，我们发现，在日志中包含可指出给定的请求来自谁的充足信息很重要，但我们不会包含过于敏感的信息，例如不影响处理请求的路由或行为的请求参数。例如，如果代码对客户消息进行解析，但解析失败，则很重要的是不要记录负载，以便保护客户隐私，不过，这很难做到，就像以后的故障排除一样。我们使用工具以选择加入而不是选择移出的方式来决定可以记录的信息，以防止记录以后添加的新敏感参数。Amazon API Gateway 之类的服务允许配置可以包含在其访问日志中的数据，这起到了有效的选择加入机制的作用。
• 记录跟踪 ID 并在后端调用中传播该 ID。给定的客户请求可能涉及许多协同工作的服务。许多 AWS 请求可能仅涉及两三个服务，而 amazon.com 请求可能会涉及多得多的服务。为了在排除分布式系统的故障时清楚了解所发生的事情，我们在这些系统之间传播同一个跟踪 ID，以便能将来自不同系统的日志排列起来，从而看到故障在哪里发生。跟踪 ID 是一种元请求 ID，由作为工作单元起点的“前门”服务贴附到分布式工作单元上。AWS X-Ray 是一种通过提供此传播的一部分而起到帮助作用的服务。我们发现它对于将跟踪传播到依赖关系很重要。在多线程环境中，让框架代表我们进行此传播非常困难，而且很容易出错，因此，我们已经习惯了在方法签名中传递跟踪 ID 和其他请求内容（例如指标对象！）。我们还发现在方法签名中传递上下文对象很方便，这样做让我们将来在找到要传递的相似模式时无需进行重构。对于 AWS 团队，事情不仅涉及到排除我们系统的故障，还涉及到客户排除其系统的故障。在 AWS 服务代表客户彼此交互时，客户依赖在这些服务之间传递的 AWS X-Ray 跟踪。它需要我们在服务之间传播客户 AWS X-Ray 跟踪 ID，以便它们能获得完整的跟踪数据。
• 根据状态代码和大小记录不同的延迟指标。错误响应的速度通常很快，例如访问被拒绝、限制和验证错误的响应。如果客户端开始高速受到限制，这可能会让人产生延迟良好的错觉。为了避免此指标污染问题，我们为成功的响应记录一个单独的计时器，并在控制面板和警报中重点关注该指标，而不是使用通用的时间指标。同样，如果操作可能会变慢（具体取决于输入大小或响应大小），我们会考虑发送经过分类的延迟指标，例如 SmallRequestLatency 和 LargeRequestLatency。此外，我们确保请求和响应受到适当的限制，以避免复杂的断流和故障模式，但是，即使在仔细设计的服务中，这种指标分桶方法也能隔离客户行为和阻止令人分心的干扰信息进入控制面板。

应用程序日志最佳实践

本节介绍与记录非结构化调试日志数据相关的良好习惯，这些习惯是我们在 Amazon 学会的。

• 确保应用程序日志不包含垃圾信息。 为了帮助在测试环境中进行开发和调试，我们可能会在请求路径上包含 INFO 和 DEBUG 级别的日志语句，但是，我们考虑在生产环境中禁用这些日志级别。我们并不依赖应用程序日志来存放请求跟踪信息，而是将服务日志当作跟踪信息的存放地，我们在其中可以轻松产生指标和查看一段时间内的总体趋势。但是，这里不存在非黑即白的规则。我们的方法是：不断审查日志，看看日志的干扰性是过高还是不够高，然后随时间过去而调整日志级别。例如，我们在深入研究日志时，经常发现干扰性过高的日志语句或者我们希望拥有的指标。幸运的是，这些改进通常易于进行，因此，我们养成了将后续快速积压的条目存档以保持日志整洁的习惯。
• 包含对应的请求 ID。 在我们对应用程序日志中的错误进行故障排查时，我们常常希望看到与触发该错误的请求或发起者有关的详细信息。如果两个日志均包含相同的请求 ID，则我们可以轻松地从一个日志跳转到另一个日志。如果正确配置了应用程序日志记录库，这些库将会写出对应的请求 ID，而且该请求 ID 将设置为 ThreadLocal。如果应用程序是多线程的，在线程开始处理新请求时特别要注意设置正确的请求 ID。
• 限制向应用程序日志写入垃圾错误信息的频率。通常，服务不会向应用程序日志发送大量信息，但如果它突然开始显示大量错误，它可能会突然开始以很高的速度写入非常大的日志条目（带有堆栈跟踪）。我们发现了一种预防此问题的方法，即限制指定的日志记录程序记录日志的频率。
• 优先使用格式字符串而不是 String#format 或字符串连接。较旧的应用程序日志 API 操作接受单个字符串消息而不是 log4j2 的 varargs 格式字符串 API。如果使用 DEBUG 语句来检测代码，但在 ERROR 级别下配置生产环境，则格式化会被忽略的 DEBUG 消息字符串可能是浪费工夫。某些日志记录 API 操作支持传入任何这些对象：仅在将写入日志条目的情况下，才会调用对象的 toString() 方法。
• 记录失败的服务调用返回的请求 ID。 如果调用某个服务且该服务返回错误，它可能会返回请求 ID。我们发现在日志中包含请求 ID 很有用，这样做能让我们在需要跟进该服务拥有者时有办法让他们轻松找到自己的相应服务日志条目。不过，超时错误会带来麻烦，原因是服务可能尚未返回请求 ID，或者客户端库可能未解析该 ID。尽管如此，如果我们获得了服务返回的请求 ID，我们会记录该 ID。

高吞吐量服务最佳实践

对于 Amazon 的绝大多数服务，为每个请求进行日志记录不会强行加上不合理的成本开销。吞吐量较高的服务会进入较为灰色的区域，但我们通常仍会为每个请求进行日志记录。例如，DynamoDB 最高峰时每秒处理超过 2000 万个请求（仅仅是 Amazon 内部的流量），因此人们很自然会假定该服务不会记录非常多的信息，但实际上，出于故障排除以及审计和合规原因，它会记录每个请求。下面提供了一些高级技巧，我们在 Amazon 使用这些技巧在每个主机吞吐量较高的情况下更高效地进行日志记录：

• 以采样方式进行记录。 考虑每隔 N 个条目写入一个条目，而不是写入每个条目。每个条目还要包含跳过的条目数量，以便指标聚合系统可以估计它计算的指标中的真正日志数量。蓄水池采样之类的其他采样算法提供了更具代表性的样本。在其他算法中，日志记录错误或缓慢的请求优先于成功的快速请求。但是，使用采样时会失去帮助客户和排除特定故障的能力。某些合规要求完全禁止采样。
• 将序列化和日志刷新卸载到一个单独的线程。 这是很容易进行的更改，而且很常用。
• 频繁轮换日志。 每小时转换一次日志文件的日志看起来很方便，能减少您需要处理的文件，不过每分钟轮换一次能在几个方面带来改进。例如，读取并压缩日志文件的代理将从页面缓存而不是磁盘读取该文件，而且压缩和发送日志所需的 CPU 和 IO 操作将分散到整个小时中执行，而不是总是在小时结束时触发。
• 写入预先压缩的日志。 如果日志发送代理在向存档服务发送日志之前压缩日志，则系统 CPU 和磁盘将定期出现操作高峰。通过将压缩的日志流式传输到磁盘，可以分摊此开销并将磁盘 IO 操作减少一半。不过这会带来一些风险。我们发现，使用能在应用程序崩溃时处理截断的文件的压缩算法很有用。
• 写入到 ramdisk/tmpfs。 让服务将日志写入到内存（直至日志从服务器中发走）可能比写入到磁盘更为容易。根据我们的经验，这在每分钟而不是每小时轮换一次日志的情况下效果最好。
• 在内存中聚合。 如果必须在单台计算机上每秒处理数万个事务，则为每个请求写入一个日志条目可能会因代价过高而不可行。但是，跳过这一步会显著降低可观测性，因此，我们发现不过早进行优化很有帮助。
• 监视资源利用率。 我们密切关注我们离某些扩展限制还有多近。我们测量每个服务器的 IO 和 CPU 资源使用状况，以及日志记录代理使用这些资源的数量。在执行负载测试时，我们让这些测试运行足够长的时间，以便证明日志发送代理能够跟上吞吐量。

部署合适的日志分析工具

在 Amazon 内部，我们运营自己编写的服务，因此，我们全都需要成为它们的故障排除专家。这包括能够毫不费力地进行日志分析。我们可以使用许多工具 – 从用于查看相对较少日志的本地日志分析，到用于筛选并聚合来自海量日志的结果的分布式日志分析。

我们发现，斥资为团队提供日志分析工具和 Runbook 很重要。如果日志现在很小，但预计服务会随着时间过去不断增长，则我们会关注当前的工具何时会停止扩展，以便我们投资采用分布式日志分析解决方案。

本地日志分析

为了执行日志分析过程，可能需要具备使用不同 Linux 命令行实用程序的经验。例如，对于常见的“在日志中找到最大流量生成者的 IP 地址”任务，只需执行以下命令：

cat log | grep -P "^RemoteIp=" | cut -d= -f2 | sort | uniq -c | sort -nr | head -n20

但是，还可以使用许多其他实用的工具来解答有关日志的更复杂问题，这些工具包括：

• jq: https://stedolan.github.io/jq/
• RecordStream: https://github.com/benbernard/RecordStream

分布式日志分析

任何大数据分析服务都可以用来执行分布式日志分析，这些服务包括 Amazon EMR、Amazon Athena、Amazon Aurora、Amazon Redshift 等。但是，某些服务附带了日志记录系统，例如 Amazon CloudWatch Logs。

• CloudWatch Logs Insights
• AWS X-Ray：https://thinkwithwp.com/xray/
• Amazon Athena：https://thinkwithwp.com/athena/

结论

作为服务拥有者和软件开发人员，我花费了大量时间来查看检测的输出（控制面板上的图形、各个日志文件）和使用分布式日志分析工具（例如 CloudWatch Logs Insights）。我最喜欢做几件事情。当我在完成某些挑战性任务后需要休息时，我会一边养精蓄锐，一边研究某些日志。我首先会提出一些问题，例如“为何此指标会在这里出现峰值？”，或者“可以降低此操作的延迟吗？”。 在我的问题造成僵局时，我通常会找出将在代码中很有用的某种检测，然后添加该检测、进行测试并向队友发送要审查的代码。

虽然许多指标随附于我们使用的托管服务，但我们需要花费大量心思来检测我们自己的服务，以便获得有效运营这些服务所需的可见性。如果出现运营事件，我们需要迅速确定发生问题的原因，以及能缓解该问题的对策。控制面板上包含合适的指标很重要，这能让我们快速执行该诊断。此外，由于我们不断改变服务、添加新功能和改变服务与其依赖关系交互的方式，因此，更新和添加正确检测的练习一直都在进行。

• “Look at your data”，作者：前 Amazon 员工 John Rauser：https://www.youtube.com/watch?v=coNDCIMH8bk（在 13:22 处，他逐字输出日志，以便更好地查看日志）
• “Investigating anomalies”，作者：前 Amazon 员工 John Rauser：https://www.youtube.com/watch?v=-3dw09N5_Aw
• “How humans see data”，作者：前 Amazon 员工 John Rauser：https://www.youtube.com/watch?v=fSgEeI2Xpdc
• https://www.akamai.com/uk/en/about/news/press/2017-press/akamai-releases-spring-2017-state-of-online-retail-performance-report.jsp

关于作者

David Yanacek
David Yanacek

David Yanacek 是 AWS Lambda 的高级首席工程师。自 2006 年以来，David 一直在 Amazon 从事软件开发工作，之前致力于 Amazon DynamoDB 和 AWS IoT 以及内部 Web 服务框架和队列运营自动化系统的开发。在工作中，David 最喜欢做的就是执行日志分析并筛选操作指标，进而找到逐步提升系统运行流畅性的方法。

相关内容

通过负载卸除机制来避免过载 避免无法克服的队列积压