京公网安备11010502063487号slog 把日志从“一行字符串”变成“带键值的记录”,由 Handler 决定输出格式。这篇看两种内置 Handler 的输出,验证被过滤的日志是不是真的几乎免费、AddSource 的代价、和标准库 log 的差距,以及并发写入会不会把日志行撕裂。
TextHandler:
level=INFO msg=请求完成 method=GET path="/a b" status=200 dur=1.5ms
level=INFO msg=请求完成 req_id=7 http.status=200
JSONHandler:
{"level":"INFO","msg":"请求完成","method":"GET","path":"/a b","status":200,"dur":1500000}
{"level":"INFO","msg":"请求完成","req_id":7,"http":{"status":200}}
{"level":"INFO","msg":"缺值","!BADKEY":"orphan"}
(上一行:key 后面没有配对的值,会变成 !BADKEY)同一条日志,Text 是 key=value,分组变成 http.status=200;JSON 里分组是嵌套对象,time.Duration 被输出成纳秒整数 1500000。参数个数不配对时,孤零零的 key 变成 !BADKEY——静默地出现在日志里;不过 go vet 能在编译前发现(我另外试了 slog.Info("x", "orphan"),vet 报 call to slog.Info missing a final value,另一种把非字符串当 key 的写法也会被报)。
Level=Info 时调用 Debug,带一个 LogValuer 参数:LogValue 被调用了 0 次(被过滤的日志不会计算它) 调用 Info:LogValue 被调用了 1 次 被过滤的 Debug:l.Debug(…,key,value 形式)0 次分配;l.LogAttrs(…,slog.Attr 形式)0 次分配 输出到 io.Discard 的 Info:l.Info 形式 0 次分配;LogAttrs 形式 0 次分配
被级别过滤的日志:LogValuer 的 LogValue 一次都没被调用,这就是“昂贵的值只在真的要输出时才计算”。被过滤的 Info 只要约 5 ns。
slog JSONHandler.Info(msg, k, s) 471 ns/次 0 次分配 slog TextHandler.Info(msg, k, s) 505 ns/次 0 次分配 slog JSONHandler + AddSource 931 ns/次 6 次分配 slog JSONHandler.LogAttrs 448 ns/次 0 次分配 slog 被级别过滤的 Info 5 ns/次 0 次分配 标准库 log.Printf 145 ns/次 0 次分配 fmt.Fprintf(nopW) 55 ns/次 0 次分配 标准库 log.Printf(写到 io.Discard) 3 ns/次 0 次分配
写到空 writer,JSONHandler 一条日志 471 ns、0 次分配,TextHandler 505 ns;标准库 log.Printf 是 145 ns——结构化和时间格式化让 slog 约慢 3 倍。AddSource 要多取调用栈,耗时翻倍(931 ns)并多 6 次分配。需要源码位置再开。注意:标准库 log 写到 io.Discard 时会短路(3 ns),拿它做基准会得到误导性的数字,我一开始就用 io.Discard 测,所以后来换成了一个不会被短路的 writer。
8 个 goroutine 各写 2000 条 JSON 日志:共 16000 行,每行都是完整合法 JSON 的有 16000 行(损坏 0 行)
8 个 goroutine 共 16000 条 JSON 日志,每行都是完整合法的 JSON,没有撕裂。本实验里我给 writer 加了一把锁,所以它验证的是“每条日志一次 Write”,而不是 Handler 自己的锁;我没有试过去掉这把锁。
message, a severity level, and various other attributes expressed as key-value pairs. It defines a type, Logger, which provides several methods (such as Logger.Info and Logger.Error) for reporting events of interest. Each Logger is associated with a Handler. A Logger output method creates a
slog 的模型很简单:一条记录=消息+级别+键值属性,Logger 把它交给 Handler。想换格式或输出目的地,就换 Handler。