日志级别
本指南旨在为库作者提供关于在库中使用哪些 SwiftLog 日志级别是合适的指导,以及在何种情况下使用何种级别。
库需要在各种用例中表现良好,并且不能假定将使用特定的日志后端。配置应用程序的具体细节取决于实施特定应用程序和系统的开发人员,有些人可能选择记录到磁盘,有些人记录到内存,或者有些人可能采用复杂的日志聚合器。在所有这些情况下,库都应该表现“良好”,这意味着它不应该通过记录过多来压倒典型的(“stdout”)日志后端,也不应该通过过度使用 error
级别的日志语句等来发出过多警报。
本文旨在为库作者提供关于在库中使用哪些 SwiftLog 日志级别是合适的指导,以及通用的日志记录风格提示。
库的指南
SwiftLog 通过 Logger.Level
枚举 定义了以下 7 个日志级别,从最不严重到最严重排序:
trace
debug
info
notice
warning
error
critical
在这些级别中,只有严重性低于 info
级别(不包括 info 级别)的级别通常可以被库使用:debug
和 trace
。
在接下来的章节中,我们将探讨如何在实践中使用它们。
推荐的日志级别
库始终可以安全地在 trace
和 debug
级别进行日志记录,并且这两个级别应该是任何库进行日志记录的主要级别。
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
级别的日志记录
- 可以包括用于打开连接、接受请求等的单个日志语句。
- 它可以包括操作中控制流的高级概述。例如:“开始工作,处理步骤 X,做出 X 决策,完成工作 X,结果代码 200”。此概述可能包含高基数结构化数据。
您可能还需要考虑使用 swift-distributed-tracing 来检测“begin”和“end”事件,因为跟踪可能会为您提供对系统行为的额外见解,而这些见解仅通过手动分析日志语句可能会错过。
要避免的日志级别
所有这些规则都只是通用指南,因此可能有例外情况。请考虑以下示例以及库为何不希望使用严重日志级别的理由。
对于服务客户端(例如,http 客户端)在请求失败时记录 error
通常是不可接受的。最终用户可能会使用客户端来探测端点是否响应,而无法响应可能是预期的行为。记录错误只会混淆和污染他们的日志。
相反,库应该 throw
或返回一个 Error
值,库的用户将有足够的知识来判断他们是否应该记录或忽略它。
库在比 debug
更严重的日志级别记录任何成功的操作甚至更不可接受。这会导致服务器端系统泛滥,特别是如果,例如,有人要记录每个成功处理的请求。在服务器端应用程序中,当部署到生产环境时,当许多最终用户连接到同一服务器时,这很容易使日志记录系统泛滥和不堪重负。此类问题在开发时很少发现,因为只有一个对等方从被测服务请求内容。
示例(要避免的事项)
避免对以下情况使用 info
或任何更严重的日志级别:
- 库的“正常操作”,无需在 info 级别记录“已接受请求”,因为这是 Web 服务的正常操作。
避免使用 error
或 warning
- 报告库的最终用户有能力自行记录的错误。例如,如果数据库驱动程序未能获取查询的所有行,则不应记录错误或警告,而应在提供返回值的流(或函数、异步函数,甚至异步序列)上返回或抛出错误。
- 由于最终用户正在使用这些值,并且有报告(或忽略)此错误的方法,因此库不应代表他们记录任何内容。
- 永远不要将仅仅是信息的内容报告为警告。例如,“检测到奇怪的标头”乍一看可能是一个好主意,可以将其记录为警告,但是如果“奇怪的标头”仅仅是配置错误的客户端(或只是“奇怪的浏览器”),您可能会意外地用这些“奇怪的标头”警告完全淹没最终用户的日志(!)。
- 仅记录有关最终用户可以采取措施的可操作事项的警告。以“检测到奇怪的标头”日志语句为例:将其记录为警告不是一个好的选择,因为服务器开发人员无法修复其服务的用户以停止发送奇怪的标头,因此服务器不应将此信息记录为警告。但是,在
debug
级别记录它可能仍然是合适的。
- 仅记录有关最终用户可以采取措施的可操作事项的警告。以“检测到奇怪的标头”日志语句为例:将其记录为警告不是一个好的选择,因为服务器开发人员无法修复其服务的用户以停止发送奇怪的标头,因此服务器不应将此信息记录为警告。但是,在
- 对于每个请求的样式情况,可能几乎重要到足以成为警告,但不应在之后重复记录,因此可能会很想实现“仅记录一次警告”技术。作者可能会想到一些聪明的技术,例如,对于每个“发现的奇怪标头”仅记录一次警告,然后在不同的级别(例如 trace)记录相同的问题……此类技术会导致令人困惑且难以调试的日志,当系统的开发人员不了解日志记录的有状态性质时,在尝试重现问题时会感到困惑。
- 例如,如果开发人员在生产系统中发现此类警告,他们可能会尝试重现它——认为它仅发生在生产环境中。但是,如果日志记录系统的日志级别选择是有状态的,则他们实际上可能正在成功重现该问题,但永远不会看到它显现出来。为此,以及相关的性能原因(因为实现“每个 X 仅一次”意味着增加存储和每个请求的额外检查要求),不建议应用此模式。
“避免记录警告”规则的例外情况
- “后台进程”,例如在定期计时器上计划的任务,除了通过日志记录之外,可能没有任何其他方式向库的最终用户传达失败或警告。
- 考虑提供一个 API,该 API 将在运行时收集错误,然后您可以避免手动记录错误。这通常可以采用可自定义的“发生错误时”挂钩的形式,库在构造计划作业时接受该挂钩。如果未自定义处理程序,我们可以记录错误,但如果已自定义,则仍由库的最终用户决定如何处理它们。
- “仅记录一次警告”规则的例外情况是,当事情不经常发生时。例如,如果库在其初始化期间警告有关过时的许可证或类似内容,这不一定是坏主意。毕竟,我们宁愿在初始化期间看到一次此警告,而不是在向库发出的每个请求期间看到此警告。使用您的最佳判断力,并在设计记录此类信息的频率和位置时考虑使用您的库的开发人员。
避免更改日志级别或日志处理程序
库代码应发出信息丰富的日志,并让当前 Logger
的 LogHandler
处理过滤并将日志实际导出到后端系统。链接库的可执行目标负责配置 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 条信息:
- 我们接受了一个连接。
- 这是它的字符串表示形式。
- 它来自此对等方。
- 我们当前有
connections.count
个活动连接。
虽然此日志语句包含我们旨在传达给最终用户的所有有用信息,但很难直观地和机械地解析它包含的详细信息。例如,如果我们知道连接在并发连接总数达到 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-tracing 的 LoggingContext
结合使用非常有用,后者会自动使用任何存在的跟踪信息填充元数据。因此,响应某些特定请求而生成的所有日志将自动携带相同的 TraceID。
您可以在以下页面上查看更多结构化日志记录的示例以及示例实现:
- https://tersesystems.com/blog/2020/05/26/why-i-wrote-a-logging-library/
- https://cloud.google.com/logging/docs/structured-logging
- https://stackify.com/what-is-structured-logging-and-why-developers-need-it/
- https://kubernetes.ac.cn/blog/2020/09/04/kubernetes-1-19-introducing-structured-logs/
使用关联 ID / 追踪 ID 进行日志记录
一种非常常见的模式是使用“关联 ID”记录消息。一般来说,最好的方法是使用来自 swift-distributed-tracing 的 LoggingContext
,这样您的库就可以被追踪,并且可以与关联上下文一起使用,而无需考虑最终用户正在使用哪种追踪系统(例如 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 请求时都记录警告是不可接受的。然而,如果库有一种很好的方法来做到这一点,例如在配置时一次记录这样的警告,可能是可以接受的。
某些库可能会实现“仅记录此警告一次”、“仅在启动时记录此警告”、“每小时仅记录此错误一次”或类似的技巧,以保持低噪声水平,但仍然足够信息丰富,不会被遗漏。然而,这通常是为有状态的长时间运行的库保留的模式,而不是数据库和相关持久性存储的客户端。