日志级别

本指南旨在为库作者提供关于在库中使用哪些 SwiftLog 日志级别是合适的指导,以及在何种情况下使用何种级别。

库需要在各种用例中表现良好,并且不能假定将使用特定的日志后端。配置应用程序的具体细节取决于实施特定应用程序和系统的开发人员,有些人可能选择记录到磁盘,有些人记录到内存,或者有些人可能采用复杂的日志聚合器。在所有这些情况下,库都应该表现“良好”,这意味着它不应该通过记录过多来压倒典型的(“stdout”)日志后端,也不应该通过过度使用 error 级别的日志语句等来发出过多警报。

本文旨在为库作者提供关于在库中使用哪些 SwiftLog 日志级别是合适的指导,以及通用的日志记录风格提示。

库的指南

SwiftLog 通过 Logger.Level 枚举 定义了以下 7 个日志级别,从最不严重到最严重排序:

在这些级别中,只有严重性低于 info 级别(不包括 info 级别)的级别通常可以被库使用:debugtrace

在接下来的章节中,我们将探讨如何在实践中使用它们。

库始终可以安全地在 tracedebug 级别进行日志记录,并且这两个级别应该是任何库进行日志记录的主要级别。

trace 是最精细的日志级别,库的最终用户通常不会使用它,除非调试非常具体的问题。您应该将其视为库开发人员“记录我们可能需要的一切信息来诊断难以重现的错误”的一种方式。在 trace 级别无限制地记录日志可能会对系统性能造成影响,并且开发人员可以假设 trace 级别的日志记录不会在生产部署中使用,除非专门启用以定位某些特定问题。

这与 debug 形成对比,一些用户可能选择在他们的生产系统中启用它。

Debug 级别的日志记录不应该“太”嘈杂。开发人员应该假设某些生产部署可能需要(或想要)启用 debug 级别的日志记录。

Debug 级别的日志记录不应完全破坏生产系统的性能。

因此,debug 日志记录应该为最终用户提供对库中正在发生的事情的高价值理解,使用与领域相关的语言。在 debug 级别进行日志记录不应过于嘈杂或深入内部细节;这正是 trace 的用途。

谨慎使用 warning 级别。在可能的情况下,尽量返回或抛出 Error 给最终用户,这些错误应该具有足够的描述性,以便他们可以检查、记录并找出问题。他们可能会启用 debug 日志记录以了解有关该问题的更多信息。

可以“一次”记录 warning,例如在系统启动时。这可能包括服务器启动时的一些一次性“更安全的配置可用,尝试升级到它!”日志语句。您还可以记录来自后台进程的警告,否则这些进程没有其他方式通知最终用户有关某些问题。

error 级别进行日志记录与警告类似:尽可能避免这样做。相反,通过库的 API 报告错误。例如,从 HTTP 客户端记录“连接失败”不是一个好主意。也许最终用户打算向已知的离线服务器发出此请求以确认它已离线?从他们的角度来看,此连接错误不是“真正的”错误,这只是他们期望的结果——因此,HTTP 客户端应返回或抛出此类错误,但记录它。

还要注意,在您决定记录错误的情况下,请注意错误率。当发生某些网络故障时,是否可能会为每个操作都记录此错误?一些团队和公司已根据系统中记录的错误率设置了警报系统,如果错误率超过某个阈值,则可能会在半夜开始呼叫和寻呼人员。在 error 级别记录日志时,请考虑该问题是否确实应该在晚上吵醒人们。您可能还需要考虑在库中提供配置:“应在哪个日志级别报告此问题?” 这在集群系统中可能很有用,这些系统可能会自行记录网络故障,或者依赖外部系统来检测和报告此故障。

库允许记录 critical 日志,但顾名思义 - 仅在最关键的情况下。通常,这意味着库在发出此类日志后将停止运行。最终用户认为记录的 critical 错误非常重要,并且他们可能已设置其系统在检测到此类日志语句时立即在半夜寻呼人员以调查生产系统。因此,请谨慎记录这些类型的错误。

某些库和情况可能不完全清楚哪个日志级别“最适合”它们。在这种情况下,有时值得允许库的最终用户能够配置特定消息组的级别。您可以在 Soto 库 此处 看到这方面的示例,其中 Options 对象允许最终用户配置记录请求的级别 (options.requestLogLevel),然后将其用作 log.log(self.options.requestLogLevel)

示例

trace 级别的日志记录

debug 级别的日志记录

您可能还需要考虑使用 swift-distributed-tracing 来检测“begin”和“end”事件,因为跟踪可能会为您提供对系统行为的额外见解,而这些见解仅通过手动分析日志语句可能会错过。

要避免的日志级别

所有这些规则都只是通用指南,因此可能有例外情况。请考虑以下示例以及库为何不希望使用严重日志级别的理由。

对于服务客户端(例如,http 客户端)在请求失败时记录 error 通常是不可接受的。最终用户可能会使用客户端来探测端点是否响应,而无法响应可能是预期的行为。记录错误只会混淆和污染他们的日志。

相反,库应该 throw 或返回一个 Error 值,库的用户将有足够的知识来判断他们是否应该记录或忽略它。

库在比 debug 更严重的日志级别记录任何成功的操作甚至更不可接受。这会导致服务器端系统泛滥,特别是如果,例如,有人要记录每个成功处理的请求。在服务器端应用程序中,当部署到生产环境时,当许多最终用户连接到同一服务器时,这很容易使日志记录系统泛滥和不堪重负。此类问题在开发时很少发现,因为只有一个对等方从被测服务请求内容。

示例(要避免的事项)

避免对以下情况使用 info 或任何更严重的日志级别:

避免使用 errorwarning

“避免记录警告”规则的例外情况

避免更改日志级别或日志处理程序

库代码应发出信息丰富的日志,并让当前 LoggerLogHandler 处理过滤并将日志实际导出到后端系统。链接库的可执行目标负责配置 LogHandler 和日志级别。

库更改 Logger 的日志级别或 LogHandler 是一种反模式,因此请避免如下代码:

// ⚠️ Avoid mutating log levels in libraries
var localLogger = logger
localLogger.logLevel = .warning
// ...

以及如下代码:

// ⚠️ Avoid creating loggers with a log handler factory in libraries
let localLogger = Logger(label: "Local", factory: ...)
// ...

任何此类代码都应包含在可执行目标中。

建议的日志记录风格

虽然库可以自由选择他们喜欢的任何日志消息风格,但如果您希望库的用户喜欢您的库生成的日志,以下是一些最佳实践。

首先,重要的是要记住,日志语句的消息以及 swift-log 中的元数据都是 自动闭包,只有在记录器的日志级别设置为必须为给定的消息发出消息时才会被调用。因此,除非实际需要,否则在 trace 级别记录的消息不会“物化”其字符串和元数据表示形式。

    public func debug(_ message: @autoclosure () -> Logger.Message,
                      metadata: @autoclosure () -> Logger.Metadata? = nil,
                      source: @autoclosure () -> String? = nil,
                      file: String = #file, function: String = #function, line: UInt = #line) {

还有一个小而重要的提示:避免在日志语句中插入换行符和其他控制字符(!)。许多日志聚合系统都假定记录输出中的单行专门是“一个日志语句”,如果我们记录未经清理的、可能多行的字符串,则可能会意外中断。这并非所有日志后端都存在问题。例如,有些日志后端会自动清理并形成一个 JSON 有效负载,其中包含 {message: "..."},然后再将其发送到收集日志的后端服务,但普通的旧流(或文件)记录器通常假定一行等于一个日志语句。这也使 grep 搜索日志更加可靠。

结构化日志记录(语义日志记录)

库可能希望采用结构化日志记录风格,该风格以 半结构化数据格式 呈现日志。

这是一种绝妙的模式,使自动化代码更容易、更可靠地处理记录的信息。

考虑以下“非结构化”日志语句:

// NOT structured logging style
log.info("Accepted connection \(connection.id) from \(connection.peer), total: \(connections.count)")

它包含 4 条信息:

虽然此日志语句包含我们旨在传达给最终用户的所有有用信息,但很难直观地和机械地解析它包含的详细信息。例如,如果我们知道连接在并发连接总数达到 100 左右时开始失败,则很难找到我们达到此数字的特定日志语句。例如,我们必须 grep 'total: 100',但是,我们所有日志系统中可能存在许多其他 "total: " 字符串。

相反,我们可以使用结构化日志记录模式来表达相同的信息,如下所示:

log.info("Accepted connection", metadata: [
  "connection.id": "\(connection.id)",
  "connection.peer": "\(connection.peer)",
  "connections.total": "\(connections.count)"
])

// example output:
// <date> info [connection.id:?,connection.peer:?, connections.total:?] Accepted connection

根据日志记录后端,此结构化日志可以在各种系统上以略微不同的方式格式化。即使在这种日志的简单字符串表示形式中,我们也能够 grep 搜索 connections.total: 100,而不必猜测正确的字符串。

此外,由于消息现在不包含那么多“人类可读的措辞”,因此它不太可能从“Accepted”随机更改为“We have accepted”或反之亦然。这种更改可能会破坏设置为解析特定日志消息并发出警报的警报系统。

结构化日志与 swift-distributed-tracingLoggingContext 结合使用非常有用,后者会自动使用任何存在的跟踪信息填充元数据。因此,响应某些特定请求而生成的所有日志将自动携带相同的 TraceID。

您可以在以下页面上查看更多结构化日志记录的示例以及示例实现:

使用关联 ID / 追踪 ID 进行日志记录

一种非常常见的模式是使用“关联 ID”记录消息。一般来说,最好的方法是使用来自 swift-distributed-tracingLoggingContext,这样您的库就可以被追踪,并且可以与关联上下文一起使用,而无需考虑最终用户正在使用哪种追踪系统(例如 OpenTelemetry、Zipkin、Xray 和其他追踪系统)。不过,这个概念可以通过手动记录 requestID 来很好地解释,我们将在下面解释。

以 HTTP 客户端为例,它作为一个库,拥有关于某些请求的大量元数据,可能类似于这样:

log.trace("Received response", metadata: [
   "id": "...",
   "peer.host": "...",
   "payload.size": "...",
   "headers": "...",
   "responseCode": "...",
   "responseCode.text": "...",
])

确切的元数据并不重要,它们只是本例中的一些占位符。重要的是“有很多”元数据。

关于元数据键的旁注:虽然没有一种绝对正确的方法来构建元数据键,但我们建议将它们视为 JSON 键:驼峰式命名法和 . 分隔的标识符。这允许许多日志分析后端将它们视为这样的嵌套结构。

现在,我们希望避免在每个日志语句中记录所有这些信息。相反,我们只需重复记录 "id" 元数据,就像这样:

// ...
log.trace("Something something...", metadata: ["id": "..."])
log.trace("Finished streaming response", metadata: ["id": "..."]) // good, the same ID is propagated

由于关联 ID(或追踪提供的 ID,在这种情况下,我们将记录为 context.log.trace("..."),因为 ID 是自动传播的),在初始日志语句之后的每个后续日志语句中,我们都能够关联所有这些日志语句。然后我们就知道这条 "Finished streaming response" 消息是关于一个响应的,我们可以从 "Received response" 日志消息中查找该响应的 responseCode

这种模式在某种程度上是高级的,可能并不总是正确的方法,但在高性能代码中,重复记录相同的信息可能会过于昂贵,请考虑使用它。

使用关联 ID 日志记录时要避免的事项

当使用关联上下文进行日志记录时,请确保永远不要“丢弃 ID”。当使用分布式追踪的 LoggingContext 时,最容易做到这一点,因为传播它可确保标识符的携带,但这同样适用于任何类型的关联标识符。

具体来说,避免以下情况:

debug: connection established [connection-id: 7]
debug: connection closed unexpectedly [error: foobar] // BAD, the connection-id was dropped

在第二行中,我们不知道哪个连接出现错误,因为 connection-id 被丢弃了。请务必审核您的日志记录代码,以确保所有相关的日志语句都带有必要的关联标识符。

规则的例外情况

这些只是一般准则,总会有例外情况,并且在其他情况下,这些建议会被打破,这是有充分理由的。请使用您最佳的判断力,并始终考虑系统的最终用户,以及他们将如何与您的库交互,并根据具体情况和手头的库和情况,逐个案例地决定如何处理每种情况。

以下是一些示例,说明在相对较高的级别记录消息对于库来说仍然是可以容忍的情况。

对于库来说,在进程崩溃之前,记录 critical 级别的日志是可以接受的,作为告知日志收集系统或最终用户有关崩溃原因的附加信息的最后手段。这应该是来自 fatalError 的消息的补充,并且可以为最终用户带来改进的诊断/调试体验。

有时,库可能能够检测到库的有害错误配置。例如,选择已弃用的协议版本。在这种情况下,通过发出 warning 来通知生产环境中的用户可能很有用。但是,您应确保警告不会重复记录!例如,HTTP 客户端在每次使用客户端的某些错误配置的 http 请求时都记录警告是不可接受的。然而,如果库有一种很好的方法来做到这一点,例如在配置时一次记录这样的警告,可能是可以接受的。

某些库可能会实现“仅记录此警告一次”、“仅在启动时记录此警告”、“每小时仅记录此错误一次”或类似的技巧,以保持低噪声水平,但仍然足够信息丰富,不会被遗漏。然而,这通常是为有状态的长时间运行的库保留的模式,而不是数据库和相关持久性存储的客户端。