本文发表于一年多前。旧文章可能包含过时内容。请检查页面中的信息自发布以来是否已变得不正确。

Kubernetes 1.24 中的上下文日志记录

结构化日志工作组在 Kubernetes 1.24 中为日志基础设施添加了新功能。这篇博文解释了开发人员如何利用这些功能使日志输出更有用,以及他们如何参与改进 Kubernetes。

结构化日志

结构化日志的目标是取代 C 风格的格式化和由此产生的不透明日志字符串,代之以具有明确定义的语法来分别存储消息和参数的日志条目,例如作为 JSON 结构。

在使用传统的 klog 文本输出格式进行结构化日志调用时,字符串最初是使用 \n 转义序列打印的,除非嵌入在结构体中。对于结构体,日志条目仍然可以跨越多行,没有简洁的方法将日志流分割成单个条目。

I1112 14:06:35.783529  328441 structured_logging.go:51] "using InfoS" longData={Name:long Data:Multiple
lines
with quite a bit
of text. internal:0}
I1112 14:06:35.783549  328441 structured_logging.go:52] "using InfoS with\nthe message across multiple lines" int=1 stringData="long: Multiple\nlines\nwith quite a bit\nof text." str="another value"

现在,<> 标记以及缩进被用来确保在行首的 klog 标题处进行分割是可靠的,并且产生的输出是人类可读的。

I1126 10:31:50.378204  121736 structured_logging.go:59] "using InfoS" longData=<
	{Name:long Data:Multiple
	lines
	with quite a bit
	of text. internal:0}
 >
I1126 10:31:50.378228  121736 structured_logging.go:60] "using InfoS with\nthe message across multiple lines" int=1 stringData=<
	long: Multiple
	lines
	with quite a bit
	of text.
 > str="another value"

请注意,日志消息本身是带引号打印的。它旨在成为一个固定的字符串,用于识别日志条目,因此应避免在那里使用换行符。

在 Kubernetes 1.24 之前,kube-scheduler 中的一些日志调用仍然使用 klog.Info 处理多行字符串,以避免不可读的输出。现在所有的日志调用都已更新以支持结构化日志。

上下文日志

上下文日志基于 go-logr API。其核心思想是,库从其调用者那里接收一个 logger 实例,并使用该实例进行日志记录,而不是访问全局 logger。由二进制文件决定日志实现,而不是库。go-logr API 围绕结构化日志设计,并支持向 logger 附加额外信息。

这启用了额外的用例

  • 调用者可以向 logger 附加额外信息

    当将此扩展的 logger 传递给一个函数,并且该函数使用它而不是全局 logger 时,额外的信息就会包含在所有日志条目中,而无需修改生成日志条目的代码。这在高并发应用程序中非常有用,因为不同操作的输出会交错在一起,识别某个特定操作的所有日志条目可能会变得困难。

  • 在运行单元测试时,日志输出可以与当前测试相关联。然后,当一个测试失败时,go test 只会显示失败测试的日志输出。该输出也可以默认更详细,因为它不会在成功测试时显示。测试可以并行运行,而不会交错输出。

上下文日志的一个设计决策是允许将 logger 作为值附加到 context.Context。由于 logger 封装了预期日志记录的所有方面,它成为上下文的*一部分*,而不仅仅是*使用*它。一个实际的优势是,许多 API 已经有了一个 ctx 参数,或者添加一个参数还有其他好处,比如可以摆脱函数内部的 context.TODO() 调用。

另一个决定是不破坏与 klog v2 的兼容性

  • 在使用传统 klog 日志调用的库中,如果二进制文件设置了上下文日志记录,这些库仍然可以工作,并通过二进制文件选择的日志后端进行记录。然而,这样的日志输出将不包括附加信息,并且在单元测试中效果不佳,因此应该修改库以支持上下文日志记录。结构化日志的迁移指南已经扩展,也涵盖了上下文日志记录。

  • 当一个库支持上下文日志记录并从其上下文中检索 logger 时,即使在未初始化上下文日志记录的二进制文件中,它仍然可以工作,因为它会得到一个通过 klog 记录的 logger。

在 Kubernetes 1.24 中,上下文日志记录是一个新的 Alpha 特性,其特性门控为 ContextualLogging。当禁用时(默认),新的 klog API 调用(见下文)将成为空操作,以避免性能或功能上的回归。

目前还没有 Kubernetes 组件被转换。Kubernetes 仓库中的一个示例程序演示了如何在二进制文件中启用上下文日志记录,以及输出如何依赖于二进制文件的参数

$ cd $GOPATH/src/k8s.io/kubernetes/staging/src/k8s.io/component-base/logs/example/cmd/
$ go run . --help
...
      --feature-gates mapStringBool  A set of key=value pairs that describe feature gates for alpha/experimental features. Options are:
                                     AllAlpha=true|false (ALPHA - default=false)
                                     AllBeta=true|false (BETA - default=false)
                                     ContextualLogging=true|false (ALPHA - default=false)
$ go run . --feature-gates ContextualLogging=true
...
I0404 18:00:02.916429  451895 logger.go:94] "example/myname: runtime" foo="bar" duration="1m0s"
I0404 18:00:02.916447  451895 logger.go:95] "example: another runtime" foo="bar" duration="1m0s"

example 前缀和 foo="bar" 是由调用函数的调用者添加的,该函数记录了 runtime 消息和 duration="1m0s" 值。

klog 的示例代码包括一个带有每个测试输出的单元测试示例

klog 增强

上下文日志 API

以下调用管理 logger 的查找

FromContext
从一个 context 参数中获取,并回退到全局 logger
背景
全局回退,无意支持上下文日志
TODO
全局回退,但仅作为临时解决方案,直到函数扩展为通过其参数接受 logger
SetLoggerWithOptions
更改回退 logger;当使用 ContextualLogger(true) 调用时,logger 可以直接被调用,此时日志记录将不经过 klog

为了支持 Kubernetes 中的特性门控机制,klog 为相应的 go-logr 调用提供了包装器调用,并有一个全局布尔值控制它们的行为

在 Kubernetes 代码中使用这些函数是通过一个 linter 检查强制执行的。klog 对于上下文日志的默认设置是启用该功能,因为它在 klog 中被认为是稳定的。只有在 Kubernetes 二进制文件中,该默认值才会被覆盖,并且(在某些二进制文件中)通过 --feature-gate 参数进行控制。

ktesting logger

新的 ktesting 包实现了通过 testing.T 使用 klog 的文本输出格式进行日志记录。它有一个用于配置测试用例的单一 API 调用,并支持命令行标志

klogr

klog/klogr 继续被支持,其默认行为不变:它使用自己的自定义格式格式化结构化日志条目,并通过 klog 打印结果。

然而,不鼓励这种用法,因为该格式既不是机器可读的(与 zapr(Kubernetes 使用的 go-logr 实现)产生的真正 JSON 输出相反),也不是人类友好的(与 klog 文本格式相反)。

相反,应该使用 WithFormat(FormatKlog) 创建 klogr 实例,它会选择 klog 文本格式。一个新的 klog.NewKlogr 是一个更简单的构造方法,结果相同。这是 klog 在没有其他配置时作为回退返回的 logger。

可重用的输出测试

许多 go-logr 实现都有非常相似的单元测试,它们检查某些日志调用的结果。如果开发人员不知道某些注意事项,例如一个在调用时会恐慌的 String 函数,那么很可能处理这些注意事项的代码和单元测试都缺失了。

klog.test 是一组可重用的测试用例,可以应用于 go-logr 实现。

输出刷新

klog 过去在 init 期间无条件地启动一个 goroutine,该 goroutine 以硬编码的间隔刷新缓冲数据。现在,该 goroutine 仅在需要时(即写入带缓冲的文件时)启动,并且可以通过 StopFlushDaemonStartFlushDaemon 进行控制。

当 go-logr 实现缓冲数据时,可以通过使用 FlushLogger 选项注册 logger,将刷新该数据集成到 klog.Flush 中。

其他各种变化

有关所有其他增强功能的描述,请参见发布说明

logcheck

logcheck 工具最初设计为结构化日志调用的 linter,现已增强以支持上下文日志和传统的 klog 日志调用。这些增强的检查已经在 Kubernetes 中发现了错误,例如使用格式化字符串和参数调用 klog.Info 而不是 klog.Infof

它可以作为插件包含在 golangci-lint 调用中,Kubernetes 现在就是这样使用它的,也可以独立调用。

我们正在将该工具迁移到一个新的仓库,因为它与 klog 并无真正关联,其发布应该得到正确的跟踪和标记。

后续步骤

结构化日志工作组一直在寻找新的贡献者。现在,从 C 风格日志记录的迁移将一步到位地转向结构化的、上下文相关的日志记录,以减少整体的代码变动和 PR 数量。更改日志调用是对 Kubernetes 的一个很好的首次贡献,也是一个了解不同领域代码的机会。