 第16章 日志记录
第16章 日志记录
  # 第16章 日志记录
从程序中打印日志消息是故障排查的重要手段。日志消息能告知你程序在任意时刻的运行情况,在出现问题时提供急需的上下文信息。Go标准库提供了便捷的包,用于生成和管理程序中的日志消息。在这里,我们将学习使用log包(可用于生成文本消息)和slog包(可用于生成结构化日志消息)。
本章包含以下内容:
- 使用标准日志记录器
- 写入日志消息
- 控制格式
- 更改日志输出位置
 
- 使用结构化日志记录器
- 使用全局日志记录器进行日志记录
- 使用不同级别写入结构化日志
- 在运行时更改日志级别
- 使用带有额外属性的日志记录器
- 更改日志输出位置
- 从上下文添加日志信息
 
# 使用标准日志记录器
标准库日志记录器在log包中定义。它是一个简单的日志记录库,可用于打印格式化的日志消息,展示程序的运行过程。在大多数实际应用场景中,标准库日志记录器的功能较为有限,但对于概念验证和小型程序而言,它是一个易于设置的有用工具。对于任何重要项目,建议使用结构化日志记录器log/slog包。
# 写入日志消息
标准日志记录器是一个简单的日志记录实现,用于打印诊断消息。它不提供结构化输出或多个日志级别,但对于面向终端用户或开发者的日志消息而言,它可能会很有用。
# 操作方法……
你可以使用默认日志记录器打印日志消息:
log.Println("This is a log message similar to fmt.Println")
log.Printf("This is a log message similar to fmt.Printf")
2
输出如下:
2024/09/17 23:05:26 This is a log message similar to fmt.Println
2024/09/17 23:05:26 This is a log message similar to fmt.Printf
2
上述函数使用log.Logger的单例实例,可通过log.Default()获取。换句话说,调用log.Println等同于调用log.Default().Println。
你也可以创建一个新的日志记录器,对其进行配置,并在程序中传递使用:
logger := log.New(os.Stderr, "", log.LstdFlags)
logger.Println("This is a log message written to stderr")
2
输出如下:
2024/09/17 23:10:34 This is a log message with a prefix
除了log.Println和log.Printf,你还可以使用log.Fatal或log.Panic来终止程序:
log.Fatal("Fatal error")
这将使程序以退出代码1终止,并输出以下内容:
2024/09/17 23:05:26 Fatal error
使用以下代码,我们也能观察到类似的情况:
log.Panic("Fatal error")
这将引发恐慌,并生成如下输出:
2024/09/17 23:05:26 Fatal error
panic: Fatal error
goroutine 1 [running]:
log.Panic({0xc000104f30?, 0xc00007c060?, 0x556310?})
/usr/local/go-faketime/src/log/log.go:432 +0x5a
main.main()
/tmp/sandbox255937470/prog.go:8 +0x38
2
3
4
5
6
7
# 控制格式
你可以使用位标志(bit flags)控制日志记录器的输出格式。你还可以为后续的日志消息定义一个前缀。
# 操作方法……
你可以按如下方式创建一个带有前缀的新日志记录器:
logger := log.New(log.Writer(), "prefix: ", log.LstdFlags)
logger.Println("This is a log message with a prefix")
2
输出如下:
prefix: 2024/09/17 23:10:34 This is a log message with a prefix
你也可以设置现有日志记录器的前缀:
logger.SetPrefix("newPrefix")
logger.Println("This is a log message with the new prefix")
2
输出如下:
newPrefix: 2024/09/17 23:10:34 This is a log message with the new prefix
输出字段及其打印方式由标志控制。log.LstdFlags告知日志记录器,日志的日期和时间也应被写入。
log.Lshortfile会打印显示日志语句所在位置的文件名和行号:
logger.SetFlags(log.LstdFlags | log.Lshortfile)
logger.Println("This is a log message with a prefix and file name")
2
这将给出如下输出:
prefix: 2024/09/17 23:10:34 main.go:17: This is a log message with a prefix and file name
log.Llongfile会打印完整路径:
logger.SetFlags(log.LstdFlags | log.Llongfile) 
logger.Println("This is a log message with a prefix and long file name")
2
生成的输出如下:
prefix: 2024/09/17 23:10:34 /home/bserdar/github.com/go-recipes-book/src/chp14/stdlogger/main.go:19: This is a log message with a prefix and long file name
你可以使用按位或(|)运算符组合多个标志。log.Lmsgprefix会将前缀字符串(如果存在)从日志行的开头移动到消息的开头:
logger.SetFlags(log.LstdFlags | log.Lshortfile | log.Lmsgprefix)
logger.Println("This is a log message with a prefix moved to the")
2
输出如下:
2024/09/17 23:10:34 main.go:21: prefix: This is a log message with a prefix moved to the beginning of the message
以下标志会以协调世界时(UTC)打印时间和日期,以及短文件名:
logger.SetFlags(log.LstdFlags | log.Lshortfile | log.LUTC)
logger.Println("This is a log message with with UTC time") 
2
输出如下:
prefix: 2024/09/18 05:10:34 main.go:23: This is a log message with with UTC time
# 更改日志输出位置
默认情况下,日志输出到标准错误(os.Stderr),但可以在不影响日志指令的情况下更改输出位置。
# 操作方法……
你可以使用log.New创建一个具有指定输出的日志记录器。以下示例创建一个日志记录器,将其输出打印到标准错误:
logger := log.New(os.Stderr, "", log.LstdFlags)
然后,你可以使用Logger.SetOutput更改日志记录目标:
output, err := os.Create("log.txt")
if err != nil {
    log.Fatal(err)
}
defer output.Close()
logger.SetOutput(output)
logger.Println("This is a log message to log.txt")
logger.SetOutput(os.Stderr)
logger.Println("Message to log.txt was written")
2
3
4
5
6
7
8
9
10
使用io.Discard作为日志输出可停止日志记录:
logger.SetOutput(io.Discard)
logger.Println("This message will not be logged")
2
# 使用结构化日志记录器
由于标准日志记录器在实际应用中的用途有限,社区开发了许多第三方日志记录库。这些库中出现的一些模式强调了结构化日志记录和性能。考虑到这些使用模式,结构化日志记录包被添加到了标准库中。log包对于开发来说仍然是一个有用的工具,因为它为开发者和程序用户提供了一个简单的接口,但log/slog包是一个适用于生产环境的库,它支持自动化日志分析工具,同时提供了一个易于使用且灵活的接口。
# 使用全局日志记录器进行日志记录
与log包类似,通过slog.Default()函数可以访问一个全局结构化日志记录器。你可以简单地配置一个全局日志记录器,并在程序中使用它。
| 提示 对于任何重要项目,建议传递日志记录器实例。不同环境的日志记录需求可能不同,因此使用专用的日志记录器会很有帮助。 | 
|---|
# 操作方法……
使用slog日志记录函数写入日志:
slog.Debug("This is a debug message")
slog.Info("This is an info message with an integer field", "arg", 42)
slog.Info("This is another info message with an integer field", slog.Int("arg",42))
2
3
你无法修改默认日志记录器的设置,但可以创建一个新的日志记录器并将其设置为默认日志记录器。以下示例展示了如何将JSON日志记录器设置为默认日志记录器:
logger := slog.New(slog.NewJSONHandler(os.Stderr, &slog.HandlerOptions{
    Level: slog.LevelDebug,
}))
slog.SetDefault(logger)
2
3
4
| 提示 slog.SetDefault()还会设置log包的默认日志记录器,因此log包的函数会调用slog函数。使用slog.SetLogLoggerLevel设置log包消息的日志级别。 | 
|---|
# 使用不同级别编写结构化日志
结构化日志记录器(structured logger)允许你以不同级别记录消息。例如,你可以在 slog.LevelDebug 级别记录详细消息,在 slog.LevelWarn 级别记录警告消息,在 slog.LevelError 级别记录错误消息,并且可以通过配置或命令行参数设置程序的日志记录级别。
# 操作方法……
- 使用 slog.HandlerOptions.Level设置为所需级别的方式创建一个slog.Handler。以下示例创建一个文本日志处理器(text log handler),它将每条日志消息作为单独的文本行打印出来。它使用os.Stderr作为输出,日志记录级别设置为slog.LevelDebug:
handler := slog.NewTextHandler(os.Stderr, &slog.HandlerOptions{
    Level: slog.LevelDebug,
})
2
3
- 使用该处理器创建一个日志记录器:
logger := slog.New(handler)
- 使用日志记录器创建不同级别的消息。只有那些等于或高于处理器选项所确定级别的消息才会被打印到输出中:
logger.Debug("This is a debug message")
logger.Info("This is an info message with an integer argument",
    "arg", 42)
logger.Warn("This is a warning message with a string argument",
    "arg", "foo")
2
3
4
5
- 如果担心日志记录性能问题,可以检查特定的日志记录级别是否启用:
// Checking if logging is enabled for a specific level
if logger.Enabled(context.Background(), slog.LevelError) {
    logger.Error("This is an error message", slog.String("arg",
        "foo"))
}
2
3
4
5
# 在运行时更改日志级别
大多数应用程序在应用程序启动时通过命令行选项或配置文件设置日志记录器,并且在运行时不会更改日志记录。然而,在运行时设置日志级别的能力对于识别生产环境中的问题来说是一个非常有用的工具。你可以将正在运行的服务器的调试级别设置为 slog.LevelDebug,记录日志以找出问题行为,然后再将其设置回原始级别。本方法展示了如何实现这一点。
# 操作方法……
- 使用 slog.LevelVar包装日志级别值(这被称为对变量装箱):
level := new(slog.LevelVar)
- 设置初始日志级别:
level.Set(slog.LevelError)
- 使用装箱后的级别创建一个处理器:
handler := slog.NewTextHandler(os.Stderr, &slog.HandlerOptions{
    Level: level,
})
2
3
- 使用该处理器创建一个日志记录器:
logger := slog.New(handler)
- 通过更改 level来控制日志级别:
level.Set(slog.LevelDebug)
// Now all loggers will start printing debug level messages
2
# 使用带有额外属性的日志记录器
假设你有一个服务器,在处理请求时使用的函数会在多个请求处理程序之间共享。当接收到请求时,你可以记录正在运行的处理程序,但当你将该日志记录器传递给这些公共函数时,它们会丢失该信息。它们不知道是哪个请求处理程序调用的。与其将这些信息传递给这些公共函数(毕竟它们并不真正需要这些信息),你可以用这些信息装饰(decorate)一个日志记录器,然后传递这个日志记录器。
# 操作方法……
- 使用 Logger.With创建一个新的日志记录器,并附加额外属性:
func HandlerA(w http.ResponseWriter, req *http.Request) {
    reqId := getRequestIdFromRequest(req)
    // Create a new logger with additional attributes
    logger := slog.With(slog.String("handler", "a"), slog.
        String("reqId", reqId))
    logger.Debug("Start handling request")
    defer logger.Debug("Completed request")
}
2
3
4
5
6
7
8
- 使用这个日志记录器记录消息:
HandleRequest(logger, w, req)
这将输出如下的日志消息:
{"time":"2024-09-19T14:49:42.064787730-06:00","level":"DEBUG","msg":"Start handling request","handler":"a","reqId":"123"}
{"time":"2024-09-19T14:49:42.308187758-06:00","level":"DEBUG","msg":"This is a debug message","handler":"a","reqId":"123","key":"value"}
{"time":"2024-09-19T14:49:42.945674637-06:00","level":"DEBUG","msg":"Completed request","handler":"a","reqId":"123"}
2
3
# 更改日志记录位置
默认的日志记录器将日志写入 os.Stderr,与 log 包类似,在创建日志记录器时可以更改这个设置。
# 操作方法……
日志记录器的输出由 slog.Handler 决定。以下示例创建一个将输出打印到标准错误的日志记录器:
logger := slog.New(slog.NewTextHandler(os.Stderr, &slog.
    HandlerOptions{
        Level: slog.LevelDebug,
    }))
2
3
4
与 log 包不同,在创建日志记录器之后,除非编写自己的处理器,否则无法更改日志记录位置。
# 从上下文(context)添加日志记录信息
通常,你需要记录的信息在上下文中是可用的。每个 slog 日志记录函数都有两个变体,一个带上下文,一个不带。如果你使用带上下文的变体,你可以编写一个处理器,从包含调用站点信息的上下文中提取信息。
# 操作方法……
创建一个新的处理器,可能会包装一个现有的处理器。以下代码片段展示了一个通过包装 slog.Handler 从上下文中提取 id 的处理器:
type ContextIDHandler struct {
    slog.Handler
}
2
3
定义 Handle 方法。从上下文中提取信息,修改日志记录,并将其传递给被包装的处理器:
func (h ContextIDHandler) Handle(ctx context.Context, r slog.Record) error {
    // If the context has a string id, retrieve it and add it to the
    // record
    if id, ok := ctx.Value("id").(string); ok {
        r.Add(slog.String("id", id))
    }
    return h.Handler.Handle(ctx, r)
}
2
3
4
5
6
7
8
使用接受 context.Context 的日志记录函数:
func Handler(w http.ResponseWriter, req *http.Request) {
    logger.Debug(req.Context(), "Handler started")
   ...
}
2
3
4
如果请求上下文中有 id,这将把它添加到日志消息中:
{"time":"2024-09-19T15:02:12.163787730-06:00","level":"DEBUG","msg":"Handler started","id":"123"}
