Log++云原生世界中的日志记录

摘要

日志记录是软件开发与部署生命周期的基本组成部分，但日志支持通常只是通过有限的库API或第三方模块事后提供。鉴于日志在现代云、移动和物联网开发工作流程中的关键作用、相关API的独特需求，以及利用语义知识进行优化的机会，我们认为日志记录应作为语言和运行时设计的核心部分纳入其中。本文针对现代云原生工作流程，重新思考了记录器的设计。

基于现代日志记录的一系列设计原则，我们构建了一个日志系统，该系统支持对禁用的日志语句接近零开销、对启用的日志语句低成本的延迟复制、日志输出的选择性持久化、跨不同库的日志输出统一控制，以及与现代基于云的部署集成的DevOps支持。为了评估这些概念，我们实现了用于托管在Node.js上的JavaScript应用程序的Log++记录器。

1 引言

日志记录一直是软件开发者深入了解其应用程序的重要工具[25,30, 32]。然而，随着以DevOps为导向的工作流程变得越来越普遍，日志记录在构建应用程序时正受到越来越多的重视[11, 32]。推动这一转变的一个关键领域是基于云的应用程序的使用以及应用监控仪表板（如Stack Driver[27],N|Solid[21],或AppInsights）的集成 [1]，这些仪表板会摄取来自应用程序的日志，将这些信息与系统的其他方面进行关联，并以开发者友好的仪表板格式呈现结果。这些仪表板提供的附加价值以及快速响应数据的能力，使得丰富的日志数据成为应用程序开发中不可或缺的一部分。

现有的日志库实现（通过核心或第三方库提供）无法充分满足现代应用程序的日志记录需求。因此，开发者必须谨慎使用这些记录器，以限制不良的性能影响 [34]和日志泛滥[11, 34]，并努力控制来自其他模块的日志输出到适当的通道，以及弄清楚如何有效解析从各种来源写入的数据。请考虑图1中的JavaScript代码，它说明了Node.js[19]开发者今天遇到的具体问题。

日志记录的一个主要问题是，看似无害的操作可能会意外引入严重的性能问题。在现有的日志框架中，即使日志级别被禁用（例如通常被禁用的调试和追踪级别），生成和格式化日志消息的代码仍然会被执行。这可能是由于源语言的急切求值语义，或是由于在使用宏等变通方法的语言中，编译器优化对死代码消除的支持有限所致。其结果是，某些代码看起来似乎不会被执行，但实际上却带来了巨大的寄生开销。例如，在默认级别下，logger.debug语句不会向日志输出内容，但在每次循环执行时仍会创建字面量对象并生成格式化字符串。这种开销导致开发人员倾向于从代码中主动删除这些语句，而不是依赖运行时在部署应用程序时消除其开销。

接下来是日志泛滥[11, 34]的问题，即在调试时可能需要详细级别的日志记录出现问题时，日志会被大量无关紧要的噪声输出填满。一个典型的例子是logger.info消息，记录了check调用的参数和结果，如图1所示。在执行成功的情况下，该日志语句的内容并无意义，生成该日志的开销以及日志文件中增加的噪声完全是额外负担。然而，如果check语句失败，则了解导致失败之前发生的事件信息对于诊断和修复问题可能至关重要。在当前的日志框架中，这不可避免地构成了一个难题；只要需要跟踪历史，就必须添加日志语句，并接受由此带来的开销和噪声。

冗长的日志记录与在日志消息中包含时间戳和主机信息等关键但大量的元数据的趋势相结合，进一步加剧了对日志记录性能的担忧。计算时间戳或主机名字串的成本虽然不高，但将其格式化为消息的开销却不容忽视，尤其是在成千上万甚至数百万条日志消息的情况下，可能导致意外的性能下降。

现代开发者在日志记录方面的实践通常涉及将日志数据进行后处理，以导入到Elastic Stack[7]或Splunk[26]等分析框架中。然而，如printf或拼接值风格的消息格式自由定义方式，难以被机器解析。现代日志框架，如log4j[13],pino[23], bunyan[3],等，虽提供了一定程度的一致性格式化和结构化输出支持，但从根本上说，该问题仍需开发团队通过编码规范和代码审查来解决。

我们考虑的最后一个问题是在集成多个软件模块时日益凸显的难题，每个模块可能使用不同形式的日志记录。在我们的示例中，我们有console.log写入到标准输出，以及一个名为pino的流行日志框架被配置为写入文件。因此，部分日志输出将显示在控制台，而其他输出将保存到文件中。此外，如果开发者将pino的日志输出级别从info更改为warn，这不会影响控制台输出的日志输出级别。开发者可以在一定程度上通过强制代码使用单一的日志框架来解决此问题，但他们并不总是能够控制外部库所使用的日志框架。

为了解决这些问题，我们提出了一种方法，即将日志记录视为编程语言和运行时设计/实现中的一等特性，而不仅仅是一个可包含的库。采用这种观点，我们可以利用语言语义、针对性的编译器优化以及运行时中的语义知识，提供一个统一且高性能的日志记录API。

本文的贡献包括：
- 认为日志记录是编程的一个基本方面，应作为语言、编译器和运行时设计中的一等部分包含在内。
- 一种新颖的双层方法，用于日志生成和写入，允许程序员立即记录执行数据，但仅在数据被证明是有趣/相关时才产生将其写入日志的开销。
- 通过这种双层方法，我们展示了如何分离并支持在遇到错误条件时将日志记录用于调试，以及为遥测目的监控通用应用程序行为的需求。
- 一系列创新的日志格式和日志级别管理技术，可提供一致且统一的日志输出，便于管理和输入到其他工具中。
- 一个用Node.js实现的示例，用于证明关键思想可应用于现有语言/运行时，并为性能评估中的使用提供一个具备生产质量的实现。

2 设计

本节描述了利用语言、运行时或编译器支持来解决第1节中概述的日志记录相关通用挑战的机遇。我们可以大致将其分为两类——面向性能和面向功能。

2.1 日志记录性能

设计原则1 在已禁用的日志级别下，日志语句的开销在运行时应为零。这包括日志操作的直接开销以及构建格式化字符串和处理任何参数的间接开销。此外，禁用或启用日志语句不应改变应用程序的语义。

当日志框架作为库被包含时，编译器/JIT通常无法深入理解记录器的启用/禁用语义。因此，编译器/JIT将无法完全消除与已禁用日志语句相关的死代码，从而导致每个已禁用的日志语句产生单独较小但广泛存在的寄生开销。这些开销由于分布广泛且单个量小，可能非常难以诊断，但其总和可能占应用程序运行时间的几个百分点。为避免此类寄生开销，我们建议将日志原语纳入编程语言的核心规范中；如果不可行，则应添加编译器/JIT专项优化以提升其性能。

将日志语义提升到语言规范级别的一项额外优势是，能够静态验证日志的使用，并处理日志表达式求值期间发生的错误。常见错误包括格式说明符违规[28]，意外状态修改[5, 16]在日志消息计算过程中，以及其他日志反模式[4]。如果语言语义规定了日志API，则这两类错误都可以进行静态检查，以避免在更改日志级别时出现或消失的运行时错误或海森bug。

设计原则2 。启用日志记录状态的开销包含两个部分—— (1) 计算日志语句参数集的开销，以及 (2) 格式化并将这些数据写入日志的开销。计算参数值的开销通常是不可避免的，且必须在关键执行路径上完成。然而，应尽可能降低第(2)项的开销，或将其移出关键执行路径。

为了最大限度地降低计算日志语句参数的开销并加快其处理速度，我们提出了一种新颖的日志格式规范机制，该机制采用预处理和存储的日志格式，以及一组日志扩展项，可在日志中作为简写使用，以指定那些常见但计算代价高或较复杂的日志参数值。使用预处理的格式消息使我们能够节省时间，类型检查和每个参数的处理无需解析格式化字符串；此外，我们不再立即字符串化每个参数，而是可以对参数进行快速的不可变副本复制，稍后再进行格式化。扩展对象提供了便捷的方式向日志中添加数据，例如当前日期/时间、主机IP或当前请求ID[14]，这些数据若需频繁显式计算，将更加耗费资源或不够方便。通过批量处理日志消息，并在后台线程上执行格式化工作，我们可以消除主线程上的格式化开销。

2.2 日志功能

设计原则3 。日志记录在现代系统中扮演着两个相关但又有些冲突的角色。第一个角色是提供有关错误发生前事件序列的详细信息，以帮助开发者进行问题分类处理和复现问题。第二个角色是提供通用遥测信息，并对应应用程序的整体行为提供可见性。这一观察引出了第三个设计原则：日志记录应同时支持这两项任务，且不损害其中任何一项的有效性。

为了支持这些不同的角色，我们提出了一种双层日志方法。在第一层，所有消息最初以+不可变的参数格式存储到内存缓冲区中。该操作具有高性能，适用于调试所需的详细日志信息的高频写入。此外，当遇到错误时，可以将详细日志的全部内容刷写到持久化日志中，以辅助调试。在第二层，这些详细消息可以被过滤掉，仅保留专注于高层级遥测的消息进行格式化并写入持久化日志。这种过滤可避免过度详细的信息对保存的日志造成污染，同时保留监控应用程序整体状态所需的必要数据[11, 32]。

设计原则4 。日志代码不应掩盖其所支持的应用程序的逻辑。因此，记录器应提供覆盖常见情况的专用日志原语，例如条件日志，以避免开发者为了日志记录而专门在应用程序中添加新的逻辑流程。

通常涉及额外控制或数据流逻辑的常见场景包括条件日志（仅在满足特定条件时写入消息）、子记录器（用于处理特定子任务，且通常由开发者实现）

内存缓冲区
Lroot Lc1 Lcj
级别
过滤器
类别
过滤器 类别
格式
Emit
过滤器
Emit
处理器 异步
格式化器
异步 传输 回调 传输
日志调用日志调用日志调用 记录器
配置
级别
过滤器
级别
过滤器
…
消息处理
Age Size

3 实现

根据第3节中概述的设计原则，当前时间我们介绍Log++1的实现，它实现了这些记录器在Node.js[19]运行时的设计目标。可以将满足我们设计目标所需的许多功能作为库或使用原生 API扩展绑定（N‐API [18]）来实现，但其他功能需要核心运行时支持。对于这些核心更改，我们会直接修改 ChakraCore JavaScript引擎和核心Node实现。

3.1 实现概述

日志系统分为五个主要组件：(1) 管理全局记录器状态、消息过滤器、消息格式和配置；(2) 消息处理器和内存缓冲区；(3) 输出过滤器和处理器；(4) 格式化器；(5) 最后是传输。这些组件及其之间的关系如图2所示，并在本节其余部分详细说明。

3.2 JavaScript实现

日志状态管理器 我们首先查看实现中的组件是全局日志状态管理器。该组件负责跟踪所有已创建的记录器，其中哪一个（如果有）是根记录器，启用的日志级别+类别，以及已定义的消息格式。记录器在Lroot和Lcj…Lcj中显示为图2，每个记录器都关联一个级别过滤器，用于控制其启用/禁用的日志级别。全局类别过滤器则用于全局范围内控制类别的启用/禁用。

如示例代码所示，应用程序的不同部分创建了多个记录器。一个名为“app”的记录器在图3中主应用的第2行创建，而另一个名为“foo”的记录器则在模块foo.js中创建，该模块来自图4中包含的主app.js文件。根据设计原则5，我们不希望包含的子模块foo.js能够意外地更改主应用的日志级别（第9行上调用setOutputLevel）。我们还允许根记录器启用/禁用这些子记录器的日志输出。

为了支持这些功能，Log++记录器会维护一个所有已创建记录器的列表，以及一个特殊的根记录器，该根记录器是在应用程序主模块中创建的第一个记录器。在更新日志级别或创建新记录器时，我们会检查操作是否来自根记录器，如果不是，则要么将调用转换为无操作，要么查看根记录器的配置以确定是否需要覆盖任何参数。这些功能满足了如设计原则5中所述的从多个模块控制日志记录的需求。

在我们的运行示例中，状态管理器将拦截在foo.js第2行创建记录器的操作。由于此处创建的记录器不是根记录器，我们将拦截此构造过程，将内存日志级别设置为被重写的（默认）WARN级别，而非标准的DETAIL值，阻止在第9行修改emit-level，并将新创建的记录器存储在子记录器列表中。

跟踪所有已创建的子记录器列表，可让开发者在同一模块的多个文件之间共享单个记录器。记录器构造函数中的名称参数以记录器为键，如果在多个位置使用相同的键，则将返回同一个记录器对象。

最后，状态管理器负责维护当前的输出级别、启用/禁用的类别以及子记录器覆盖信息。每个记录器都有独立的日志级别，可用于写入内存日志。然而，状态管理器为所有记录器维护一个全局的启用/禁用类别集合，以及一个用于最终发出处理的全局日志级别，只有根记录器被允许更新该全局日志级别。

在我们的示例中，主应用在第12行和第14行的 Perf类别中有日志语句，用于将包含当前挂钟时间的消息写入日志。第一条日志语句发生在Perf类别启用之前，因此不会被处理。在第13行启用Perf类别后，第14行的日志操作将被处理，并生成一条消息保存到内存日志中。

消息格式 为了提升性能并支持对日志输出的机器解析，我们采用了一种语义化日志记录方法，即日志调用将格式信息和消息参数复制到次要位置，而不是立即进行格式化。这种实现方式满足了设计原则2的需求。由于复制操作是低成本的，因此能最大限度地减少对主线程的性能影响，并允许格式化器为其发出的所有消息构建解析器，以便后续用于解析日志。现代软件开发也倾向于在日志中使用一致的样式和数据值。因此，Log++鼓励开发者将日志记录操作拆分为两个组件：
- 使用addFormat方法定义格式，该方法接受一个格式化字符串或JSON格式对象，将其处理为优化表示，然后保存以供后续使用。
- 在日志语句中通过传递先前生成的格式标识符和参数列表来使用先前定义的格式。

除了以编程方式处理单个日志格式（如图3第3行所示）外，我们还允许程序员从JSON格式文件中批量加载格式。这使得团队可以拥有统一的日志消息集合，能够在启动时快速加载/处理，并在应用程序执行过程中重复使用。一旦加载，所有格式对象都将保存在Formats组件中，如图2所示，当处理日志语句时可根据需要加载这些对象。

记录器消息的格式为：

{
  formatName: 字符串, //格式名称
  formatString: 字符串, // 原始格式化字符串
  formatterEntries: {
    kind: 数字, //标签指示条目类型
    argPosition?: 数字, //参数列表中的位置
    expandDepth?: 数字, //JSON 展开深度
    expandLength?: 数字 //JSON 展开长度
  }[]
}

这种表示方式使我们能够快速扫描和处理日志语句的参数，如内存消息处理部分所述。类型信息不仅用于标识格式化参数时预期的值类型（例如数字、字符串等），还用于支持format宏。

为了支持对一些不易（或代价较高）计算的常见值进行简单高效的日志记录，我们提供了格式宏。典型的例子包括在日志消息中添加当前挂钟时间或主机名。在JavaScript中，这些操作需要显式调用开销较大的复合API序列，例如new Date().toISOString()或require(’os’).hostname()。相反，我们允许开发者在其格式化字符串中使用特殊的宏#walltime（如图3第11行所示）或#host，然后记录器会通过优化的内部路径获取所需值。在这些情况下，类型字段被设置为宏对应的枚举值，而参数位置未定义。支持的宏格式化器列表包括：
- #host – 主机名称
- #app – 根应用的名称
- #logger – 记录器的名称
- #source – 日志语句的源代码位置（文件，行号）
- #wallclock – 挂钟时间戳（ISO格式）
- #timestamp – 逻辑时间戳
- #request – 当前请求ID（针对HTTP请求）

一种常见的日志记录做法是将原始对象以JSON格式包含在消息中。这种方式便于在消息中包含丰富的数据，但当开发者预期为小对象的实际对象却相当大时，可能会导致意外的过度日志记录负载。为了防止这种情况，我们有一个专门的JSON风格处理器，可在格式化期间限制对象展开的深度/长度。expandDepth和expandLength参数提供了对此深度/长度的控制，开发者可以在格式化字符串中调整这些参数，以捕获比默认值更多（或更少）的信息。

内存消息处理 内存缓冲区被实现为块结构的链表：

{
  标签: Uint8Array,
  数据: Float64 Array,
  字符串: 字符串[],
  属性: map<数字, 字符串>
}

为了实现数据从我们的JavaScript记录器前端到处理格式化的C++ N‐API代码之间的高效编组，我们将所有值编码为基于64位的表示形式（存储在数据属性中）。我们使用一组枚举标签（存储在标签属性中）来跟踪对应64位值的类型。对于字符串和对象属性值，我们有特殊处理方式，如下所述，这些处理方式使用了字符串数组和属性映射。

在实现语义日志系统时，需要保持的关键不变量是：日志调用发生时与参数被处理用于格式化时，每个参数的值不得发生变化。根据语言语义，某些值（包括布尔值、数字和字符串）是不可变的，因此我们可以直接将这些值或引用复制到我们的内存数组中。然而，当参数是可变对象时，我们必须采取显式措施。一个简单的解决方案是立即对参数进行toJSON字符串化，虽然这样可以防止变异并支持语义格式化，但会牺牲我们期望获得的性能提升。相反，我们使用以下代码将对象递归展平到内存缓冲区中：

function addExpandedObject(obj, depth, length) {
  //如果值处于循环中
  if (this.jsonCycleSet.has(obj)) {
    this.addTagEntry(CycleTag);
    return;
  }

  if (depth === 0) {
    this.addTagEntry(DepthBoundTag);
    return;
  }

  //设置处理为true以进行循环检测
  this.jsonCycleSet.add(obj);
  this.addTagEntry(LParenTag);

  let lengthRemain = length;
  for (const p in obj) {
    if (lengthRemain <= 0) {
      this.addTagEntry(LengthBoundTag);
      break;
    }
    lengthRemain--;

    this.addPropertyEntry(p);
    this.addGeneralEntry(obj[p], depth - 1, length);
  }

  //设置处理为false以进行循环检测
  this.jsonCycleSet.delete(obj);
  this.addTagEntry(RParenTag);
}

此代码是消息处理组件中所示的从格式和记录器调用参数转换的一部分，如图2所示。该代码首先检查是否处于循环中或已达到深度限制。如果发生其中任一情况，我们则分别将一个特殊标签循环标签或深度限制标签放入标签数组并返回。否则，我们通过更新循环信息、在缓冲区中添加特殊的左括号标签以及枚举对象属性，继续对对象图进行前序遍历。对于每个属性，我们检查是否达到长度限制，若达到则添加特殊的长度限制标签并在需要时中断；否则，我们将属性和属性值信息添加到内存缓冲区。属性值p是一种很可能会重复出现的特殊字符串值，因此我们使用从属性到唯一数字标识符的映射压缩并将其转换为一个数字，然后通过addPropertyEntry函数存储到内存缓冲区的数据组件中。

相关值会通过addGeneralEntry调用进行递归处理，根据值的类型进行分支：布尔值和数字直接转换为Float64表示形式，字符串通过字符串数组中的索引进行映射，Date对象则使用valueOf方法转换为64位时间戳。与标准JSON格式化类似，其他值会被简化，但不同于直接丢弃它们，我们使用特殊的不透明值标签（OpaqueValueTag）。在所有属性处理完毕后，我们更新循环跟踪信息，并添加一个结束的右括号标签（RParenTag）。

为了说明这段代码在实际中的工作方式，考虑处理对象参数的情况：

{
  f: 3, g: 'ok',
  o:{ g:( x)=> x}
}

内存缓冲区的最终状态如图5所示。在此示例中，我们可以看到对象结构如何被展平并存入缓冲区，其中’{‘和’}’标签用于表示每个对象的边界。每个属性已在映射表中注册（分配一个新的数字标识符），并存储在数据数组中。例如，属性g被映射为1，并且在对象结构的两次出现中，标签数组中的条目均设置为’p’以表示属性，而数据数组中的值则设置为对应的数字标识符1。数值和布尔值按显而易见的方式进行映射：数值直接映射，布尔值映射为0/1，并设置相应的标签值。与属性类似，字符串值’ok’被映射到字符串数组中的整数索引0。最后，由于函数不可序列化，与id属性相关联的值被丢弃，我们仅在标签数组的相应位置存储不透明值标签（’?’）。

消息暂存 内存中的设计使我们能够通过缓冲一段时间内的高详细度消息来支持设计原则3，以便在需要进行诊断时使用，然后异步地将高层级遥测消息经过过滤后刷新到持久存储中。每当一条消息被写入内存缓冲区时，我们会进行简单的写入计数检查，以限制刷新速率，即自上次刷新以来已写入的消息数量。如果写入的消息数量超过此阈值，我们将在事件循环上安排一次异步刷新过程。刷新代码根据当前的发出级别对消息进行过滤，并处理所有超过指定年龄或内存阈值的消息。“图2”中的过滤/处理步骤的实现如下：

function processMsgs(当前位置, 缓冲区, dest, 年龄, size) {
  let 当前时间 = new Date();
  let cpos = 当前位置;

  while(cpos < buff.entryCount()) {
    if(!ageCheck(buff, cpos, now, age) || !sizeCheck(buff, cpos, size)) {
      return;
    }

    if(!isEmitLevEnabled(buff.data[cpos])) {
      cpos = scanAndDiscardMsg(buff, cpos);
    } else {
      cpos = copyMsg(buff, cpos, dest);
    }
  }
}

这段代码通过循环遍历传入的内存缓冲区buff中的消息，持续处理缓冲区中的消息，直到ageCheck或sizeCheck条件不再满足为止。这些条件分别检查消息是否比从当前时间起算指定的年龄更老，以及总体内存消耗是否小于大小。设置年龄限制的目的是防止过早丢弃可能对调试有用的相关日志消息；而设置大小条件的目的是确保即使消息尚未达到老化时限，发生大量突发日志的应用程序也不会导致过度内存消耗。

如果在执行过程中遇到问题（当前定义为未处理的异常或以非零代码退出），记录器将立即把所有记录器消息刷新到序列化器，而不论其年龄或级别。这确保了开发者在诊断问题时可以获得最大程度的详细信息。

Log++还支持通过forceFlush方法进行程序化的强制刷新，以便在出现开发者需要了解但不会导致严重故障的问题时使用。

发射回调 一旦内存缓冲区被处理完毕，记录器会将过滤后的日志消息集传递给后台异步格式化器（见第3.3节），当格式化完成后，默认会调用一个回调函数进入JavaScript应用程序。对于常见情况，我们提供了简单的默认回调，将其写入标准输出，或者如果提供了流，则通过该流输出日志。在最一般的情况下，用户可以为记录器配置一个自定义回调，该回调将接收格式化的日志数据，执行任何所需的后处理，并将数据发送到任意（或多个）接收端。

3.3 原生格式化和OptionalNative发出

后台异步格式化器在图2中通过原生代码使用N‐API[18]模块实现。该代码不属于GC管理的宿主JavaScript引擎，因此我们必须在开始后台处理之前完全复制所需的所有数据（这一限制将在第3.5节中讨论如何放宽）。然而，一旦数据复制完成，格式化线程就可以与主线JavaScript线程并行运行，并可以使用优化的C++格式化实现。这使我们能够降低整体格式化开销，并将此开销完全从JavaScript执行的关键路径中移除。

除了后台格式化之外，Log++还支持后台发射，如异步传输模块在图2中所示。我们无需将格式化数据移回JavaScript引擎进行输出，而是可以直接将这些日志数据写入文件、标准输出，或在配置时由原生代码层提供的远程URL。这使我们能够跳过将格式化数据重新编组为JavaScript字符串的过程，同时减少了JavaScript回调的数量以及主线程上花费的相关时间。

默认情况下，原生格式化器生成符合JSON规范的输出。然而，这种输出在传输和存储时可能较为冗长，因此我们提供了序列化格式和压缩选项以进行优化。除了JSON外，用户还可以将记录器配置为使用一种简单的二进制编码格式进行格式化，该格式虽然不是人类可读的，但更加紧凑且在编码时计算更高效。对于任一格式，记录器还可以配置为使用Node.js核心中已包含的zlib库对格式化数据进行压缩。

3.4 日志API

如设计原则4所述，经常会出现仅简单调用日志语句不足以满足需求的情况，此时开发者通常需要添加显式的日志记录特定逻辑。为了避免这种混乱以及潜在的错误源，我们提供了一个更丰富的日志原语集合：
- 条件日志 ，它允许用户指定一个守卫日志语句执行的条件。这消除了在代码中引入特定于日志的控制流的需要。
- childloggers 创建一个记录器对象，该对象会为其上调用的所有日志操作添加指定的前缀（常用于子组件中的日志记录）。
- 请求特定日志 ，它允许开发者为特定的请求ID设置不同的日志级别和启用的类别。这对于基于云的应用程序来说是一个常见的需求，尤其是在参与采样分布式日志系统时。
- 区间边界 ，它在区间开始时写入一条日志消息，并接受一个负载，该负载可在写入该区间的结束事件时被访问。这允许在日志操作之间透明地传递相关数据，而不是显式传递。

这些记录器的实用示例，即条件日志，如图1所示，其中第14行的条件仅用于日志目的。使用我们的条件日志API，此检查和日志组合可替换为单行代码
logger.warnIf(!ok,"错误...") 。

3.5 自定义运行时实现

前面的部分描述了Log++记录器，它可以在Node.js中作为纯用户空间模块实现，并且已经公开可用。然而，存在一些问题、优化和改进需要与运行时和/或编译器进行紧密交互。本节将介绍这些问题以及我们如何在Node‐ChakraCore中探索其实现，[20],即运行微软 ChakraCore JavaScript引擎的Node.js版本。

格式和可变性检查 日志记录中两种特定的编程错误是：为提供的格式说明符使用了不匹配的参数，以及日志相关代码中意外产生的副作用。Log++认为，只要有可能，记录器调用不应导致应用程序失败，而应在输出格式化时注明无效参数。先前的研究[28]已经展示了如何对日志参数进行静态类型检查。类似的方法可以结合纯度分析方面的研究[5, 16]，以确保日志语句中执行的任何代码都不会修改外部可见的状态。这些功能至少需要在如eslint[8],之类的代码检查工具中提供支持，或与语言本身集成。

零成本禁用日志 开发者普遍不相信通过设置级别或类别禁用日志记录后不会继续影响性能。因此，项目中常常频繁出现代码变更：为完成某项任务添加日志记录，之后又将其删除以避免性能问题。这不仅浪费了大量开发者时间，还增加了意外引入回归问题的风险，并阻碍了在应用程序中建立全面的日志代码基础。

要确保禁用的日志语句真正实现零开销，需要与语言规范和即时编译器进行协作。为了避免评估那些将立即被丢弃的日志参数所带来的寄生开销（例如图1中第8行），我们必须在级别、类别以及（可选）条件检查完成之后才延迟评估这些参数。我们还希望即时编译器能特别识别日志语句周围的守卫，积极优化守卫路径，并对仅用于日志参数的计算执行死代码消除或代码移动。

字符串和属性的快速处理 JavaScript对象属性和字符串是日志消息中频繁出现的值。如果我们仅限于使用JavaScript和N‐API接口，我们不得不将这些属性视为字符串，并且在emit处理器的暂存阶段处理这些字符串时，我们必须进行防御性复制，否则当格式化程序访问底层内存时，JavaScript引擎的垃圾回收（GC）可能会移动这些字符串，从而导致数据竞争和数据损坏。

现代JavaScript引擎在处理对象属性时，使用内部的数字PropertyIdentifiers而不是字符串。这种方式更加紧凑，并且对引擎而言处理效率更高；而在我们的记录器中，这将允许我们仅需将一个整数复制到内存缓冲区，而无需创建自己的索引方案。因此，我们提供了一个新的JavaScript API，loggerGetPropertyId，它返回属性字符串对应的内部数字标识符，用于消息暂存。

为了避免在格式化器中与数据编组和复制字符串数据相关的开销，我们需要引入三个API。第一个是一对方法：JavaScript中的loggerRefString，它会通知JavaScript引擎需要对字符串进行引用计数、扁平化和驻留（如有必要），并返回一个唯一的数值；另一个是loggerReleaseString方法，用于递减引用计数并在需要时解除字符串的固定。这些方法使我们在消息暂存阶段传输字符串时避免了复制操作。由于不同的JavaScript引擎使用不同内部字符宽度，我们添加了getNativeStringCharSize方法来确定字符串是utf8还是utf16编码。结合getRawBytes方法获取底层缓冲区，以及createStringWithBytes方法创建字符串，这使得我们在格式化过程中能够避免任何编码转换。

优先感知的I/O管理 我们考虑的最后一个优化是确保与日志记录相关的I/O和计算不会干扰响应用户操作的高优先级代码。在我们的实现中，消息暂存和格式化的日志数据上传是在UV事件循环上完成的。该循环没有任何优先级的概念，因此我们可能会意外地使用处理日志数据的代码阻塞响应用户操作的代码。为了避免这种情况，我们可以在现有的Node事件循环处理算法中添加一个特殊的日志工作队列，但我们认为优先级的概念具有根本性的价值，应明确地添加到Node中[14]。这种优先级Promise机制使得在后台任务级别添加与日志记录相关的回调变得非常简单，从而确保日志记录活动能够及时完成，同时不影响用户的响应性。

4 评估

鉴于Log++的实现，第3节本节重点评估所得到的系统及其如何满足第2节中概述的设计目标。

在评估中，我们使用了以下四个微基准测试，每个测试均运行10000次迭代。我们还使用了一个基于流行的express[9]框架构建的服务器，该框架提供用于查询标准普尔500指数公司数据的RESTAPI。所有基准测试均在配备Intel Xeon E5‐1650处理器（6核，3.50GHz）、32GB内存和固态硬盘的设备上运行。软件堆栈为Windows 10 (17134) 和Node v10.0。

// 基本
log.info("hello world -- 记录器")

// 字符串
log.info(" hello%s","world")

// 复合 
log.info(" hello%s%j%d","世界",{ obj: true}, 4)

// 计算 
log.info(" hello at%j with%j%n--%s", new Date(),[" i",{ f: i, g:"#"+ i}], i − 5,( i% 2=== 0?"ok":"skip"))

4.1 微基准测试

我们的首次评估采用了当前Node.js日志记录领域的最新技术方法。这些方法包括内置的console方法、debug[6]记录器、bunyan[3]记录器，以及pino[23]记录器。每个基准测试运行10次，剔除最高和最低时间，报告剩余运行次数的平均值。

表1中的结果表1显示了不同日志框架之间性能的巨大差异（跨度接近 10×倍）。在所有基准测试中，与其他现有日志框架中性能最佳者相比，Log++始终是最快的记录器，至少快1.8-2.1×倍。

4.2 日志记录优化的影响

为了了解每项设计选择和优化对性能的贡献程度，我们考察了Log++中特定功能的表2显示了Log++的基线性能、禁用后台格式化线程时的记录器（同步-懒惰）、同时禁用后台格式化以及内存缓冲区中日志消息批处理时的记录器（同步-严格）。我们还研究了在格式化前丢弃日志以及通过多级日志记录功能禁用日志语句对性能的影响。层级(50%)行显示的是当50%的日志语句处于信息级别且50%是

和层级（33%）行分别显示了50%的日志消息仅处于内存级别，以及33%的日志消息仅处于内存级别且33%完全被禁用时的性能。)

在扩展对象宏的格式中使用第3.2节，也可以在提高日志记录性能方面发挥重要作用。表3研究了使用这些宏记录值与手动计算、格式化和记录它们的开销之间的性能差异。

如表3所示，在需要添加当前机器的主机名或普遍需要包含当前日期/时间（挂钟时间）等场景中，使用展开宏可带来巨大的性能提升，分别为258×和4.7×。而在其他情况下，例如获取当前应用程序名称或单调递增的时间戳值，性能提升虽较小但也不容忽视，分别为51%和12%。此时的主要优势在于日志代码更简洁清晰。

4.3 日志性能

前面的章节评估了Log++在核心日志记录任务中相对于其他记录器的性能，并通过微基准测试探讨了各种设计选择的影响。本节评估日志记录对支持查询的标准普尔500指数公司的数据。我们使用autocannon[2]在默认负载生成设置中，为服务创建持续10秒的一致负载。

作为对比，我们包含了内置的控制台方法以及pino[23]记录器，此外还有Log++在默认设置下的表现。

此应用程序突显了将日志记录用作遥测源与诊断工具之间的矛盾。我们已将其更新为使用两个日志级别：DETAIL和INFO。在默认运行中，我们在两个级别都进行日志记录，并包含一种情况，levels，其中Log++在内存中记录详细级别较高的日志，但仅在较低级别发出日志。

表4中的结果表明，使用专为现代开发需求而设计且注重性能的日志记录框架，可能对应用程序产生显著影响。在每秒处理的响应数方面，Log++使服务器吞吐量从每秒6668次请求提升至8645次，提高了30%。此外，Log++将响应时间从1.18ms降低至0.67ms，减少了43%。尽管使用了缓冲区和批处理，理论上可能会增加响应延迟的波动性，但响应的标准差实际上也略有下降。

表4中的结果还表明，除了通过使用Log++作为直接替代所带来的改进之外，还可以通过重构日志语句以利用多级别日志功能，进一步改善记录器的行为。对于Log++（级别）行，应用程序被修改为在DETAIL级别编写与调试相关但不适用于常规遥测的日志语句。这使得这些日志语句在需要诊断时被存储在内存缓冲区中，但不会被格式化和发出。因此，吞吐量进一步增加了4%至8958，延迟平均额外降低了13%至0.58毫秒。

4.4 日志数据大小

我们评估的最后一个指标是Log++如何用于减少日志数据所消耗的存储和网络容量。Table 5显示了在启用压缩的情况下运行服务器基准测试时每秒生成的日志大小（Compressed列），以及多级日志记录在无需格式化/发出所有日志数据方面的效果。

如Table5所示，压缩以及在多级设置中丢弃详细（且冗余）消息的能力，显著减少了需要传输和存储的数据大小。正如预期，压缩对日志数据非常有效，将日志大小从2.54 MB/s减少到0.13 MB/s，降幅达94.5%。一旦确定某些消息对调试无用，丢弃这些冗余消息的能力也具有显著的独立影响，可使数据大小减少53.7%。结合这两种优化，总体数据大小减少了惊人的96.7%，从2.54 MB/s降至仅0.08 MB/s。

5 相关工作

尽管日志记录是许多软件开发工作流程中的基本组成部分，但学术界对其整体关注较少，据我们所知，目前尚无关于核心日志框架设计的显式研究工作。

日志记录的最新技术 ：现有的日志框架提供了本研究中描述的部分系统的简化版本。最近，语义化日志记录的概念出现在Java[13]和C# [24]的日志记录器中。然而，JavaScript中普遍使用JSON风格对象进行日志记录，而Java或C#中主要使用基本类型值，这一差异带来了挑战，我们通过第3.2节中的扁平化算法高效地解决了该问题。缓冲和格式化日志记录也是非常常见的设计选择，例如pino[23]或bunyan[3],，但它们主要关注缓冲格式化数据或使用纯JSON进行结构化。相比之下，本工作在内存缓冲设计中缓冲复合数据+消息格式信息，并支持JSON风格格式以及可解析的printf风格消息。

日志实践 ：以往研究最接近的主题集中在对实际日志使用情况的实证研究以及支持良好日志实践的工具[11, 32]。通过对开源软件项目[32]进行大规模评估，研究了涉及日志代码的代码变更，以了解开发者如何以及为何使用日志记录。针对闭源应用程序[11]的研究得出了许多相同的结论。这些研究提供了有价值的见解，被用于提炼本文所采用的设计原则。

改进的日志记录 ：一个更广泛的研究领域是支持记录器使用的最佳实践技术。从类型系统的角度来看，[28]开发了一种类型系统和检查器，以确保格式说明符及其参数具有良好的类型。LCAnalyzer的研究[4]提出了帮助开发者发现不良日志使用情况的技术。其他工作开发了多种工具，例如LogAdvisor[34],、LogEnhancer[33],和ErrLog[31],，这些工具可帮助开发者识别应记录的位置和值，以支持后续的诊断或分析操作。

日志分析 ：关于使用日志来支持其他软件开发活动的研究更为广泛。这些工作包括事后调试[15, 22, 29],异常检测[10],功能使用研究[12],以及性能问题根本原因的自动化分析[17]。这类研究突显了高质量日志数据的潜在价值，以及依赖于此的研究和工具开发机会。

6 结论

本文提出了一套日志记录的设计原则，认为日志记录是软件开发和部署生命周期中的一个基本组成部分。通过以这种方式看待日志记录，并思考如何将其与语言和运行时的其余部分紧密耦合，以实现最佳性能和可用性，我们开发出了一种具有多项创新特性的新型日志系统。因此，Log++在性能上优于现有的最新技术水平的日志框架，代表了现代云、移动和物联网开发工作流程中日志技术的重要进步。