Go标准库之log使用详解和源码解析

简介

log包实现了简单的日志打印功能，支持日志输出到控制台或者日志文件。log包里核心的数据结构只有1个Logger，定义如下

// A Logger represents an active logging object that generates lines of
// output to an io.Writer. Each logging operation makes a single call to
// the Writer's Write method. A Logger can be used simultaneously from
// multiple goroutines; it guarantees to serialize access to the Writer.
type Logger struct {
    mu     sync.Mutex // ensures atomic writes; protects the following fields
    prefix string     // prefix on each line to identify the logger (but see Lmsgprefix)
    flag   int        // properties
    out    io.Writer  // destination for output
    buf    []byte     // for accumulating text to write
}

Logger结构体里的字段，在使用上我们只需要关心prefix，flag和out这3个字段的含义：

• out：表示日志输出的地方。可以是标准输出os.Stdout，os.Stderr或者指定的本地文件
• flag：日志的属性设置。可以控制每行日志最开头打印的内容。取值如下：

// These flags define which text to prefix to each log entry generated by the Logger.
// Bits are or'ed together to control what's printed.
// With the exception of the Lmsgprefix flag, there is no
// control over the order they appear (the order listed here)
// or the format they present (as described in the comments).
// The prefix is followed by a colon only when Llongfile or Lshortfile
// is specified.
// For example, flags Ldate | Ltime (or LstdFlags) produce,
//	2009/01/23 01:23:23 message
// while flags Ldate | Ltime | Lmicroseconds | Llongfile produce,
//	2009/01/23 01:23:23.123123 /a/b/c/d.go:23: message
const (
	Ldate         = 1 << iota     // the date in the local time zone: 2009/01/23
	Ltime                         // the time in the local time zone: 01:23:23
	Lmicroseconds                 // microsecond resolution: 01:23:23.123123.  assumes Ltime.
	Llongfile                     // full file name and line number: /a/b/c/d.go:23
	Lshortfile                    // final file name element and line number: d.go:23. overrides Llongfile
	LUTC                          // if Ldate or Ltime is set, use UTC rather than the local time zone
	Lmsgprefix                    // move the "prefix" from the beginning of the line to before the message
	LstdFlags     = Ldate | Ltime // initial values for the standard logger
)

• prefix：每行日志最开头的日志前缀

注意：如果flag开启了Lmsgprefix，那这个prefix前缀就不是放在每行日志的最开头了，而是在具体被打印的内容的前面。比如prefix如果是"INFO:"

• flag不开启Lmsgprefix的时候，prefix在每行日志最开头，日志输出为：
  INFO:2021/12/01 21:00:34 example1.go:14: your message
• flag开启Lmsgprefix的时候，prefix在要打印的内容"your message"的前面，日志输出为：
  2021/12/01 21:02:20 example1.go:14: INFO:your message

Logger结构体实现了若干指针接收者方法，包括设置日志属性、打印日志等。

同时在log这个包里，自带了一个默认的Logger，源码如下：

var std = New(os.Stderr, "", LstdFlags)

这个自带的std配套有若干辅助函数，用于设置日志属性和打印日志等。

这些辅助函数实际上就是对Logger结构体的方法做了一层封装，在辅助函数里面都是通过std这个Logger指针去调用Logger的方法。所以辅助函数和Logger结构体方法是一一对应的。

log使用方法

要使用log包打印日志，有2种方式，可以根据各自业务场景选择对应方法：

• 方法1：使用log包里自带的std这个Logger指针。通常用于在控制台输出日志。
• 方法2：自定义Logger。通常用于把日志输出到文件里。

方法1和方法2相比，没有本质区别，只是使用场景上有一个偏好。

当然方法1也可以实现输出日志到文件里，方法2也可以实现在控制台打印日志。

下面详细介绍下这两种方式的用法。

方式1：log自带的标准错误输出

talk is cheap, show me the code。我们先看一段代码示例：

// example1.go
package main

import (
    "log"
)

func main() {
    // 通过SetFlags设置Logger结构体里的flag属性
    log.SetFlags(log.Ldate | log.Ltime | log.Lshortfile | log.Lmsgprefix)
    // 通过SetPrefix设置Logger结构体里的prefix属性
    log.SetPrefix("INFO:")
    // 调用辅助函数Println打印日志到标准
    log.Println("your message")
}

上面的示例，使用了log包里自带的std标准输出，先通过SetFlags和SetPrefix这2个log包里的函数设置好std指向的Logger结构体对象里的flag和prefix属性，然后通过log包里定义的Println函数，把日志打印到控制台。程序运行结果如下：

2021/12/01 18:18:53 example3.go:14: INFO:your message

总结方式1的使用流程如下：

1. 通过调用SetFlags，SetPrefix，SetOutput函数设置好日志属性。SetOutPut可以用于设置日志输出的地方，比如终端，文件等。

如果省略这个步骤，会使用std创建时设置的默认属性。我们回顾下std的创建代码：

// New creates a new Logger. The out variable sets the
// destination to which log data will be written.
// The prefix appears at the beginning of each generated log line, or
// after the log header if the Lmsgprefix flag is provided.
// The flag argument defines the logging properties.
func New(out io.Writer, prefix string, flag int) *Logger {
	return &Logger{out: out, prefix: prefix, flag: flag}
}

var std = New(os.Stderr, "", LstdFlags)

从上面的源码可以看出std是默认把日志输出到控制台，默认日志的prefix前缀为空串，默认flag属性是LstdFlags，也就是日志开头会打印日期和时间，比如：2009/01/23 01:23:23

调用SetXXX函数可以修改std的默认属性。

2. 调用log包里的辅助函数Print[f|ln]，Fatal[f|ln]，Panic[f|ln]打印日志

• Fatal[f|ln]打印日志后会调用os.Exit(1)
• Panic[f|ln]打印日志后会调用panic

上面的例子example1.go是使用log包自带的std这个Logger指针把日志输出到控制台，我们也可以使用std把日志输出到指定文件，调用SetOutput设置日志输出的参数即可。参见如下代码示例：

// example2.go
package main

import (
    "fmt"
    "log"
    "os"
    "time"
)

func main() {
    // 日志文件名
    fileName := fmt.Sprintf("app_%s.log", time.Now().Format("20060102"))
    // 创建文件
    f, err := os.OpenFile(fileName, os.O_RDWR | os.O_CREATE | os.O_APPEND, 0666)
    if err != nil {
        log.Fatalf("open file error: %v", err)
    }
    // main退出之前，关闭文件
    defer f.Close()
    // 调用SetOutput设置日志输出的地方
    log.SetOutput(f)
    //log.SetOutput(io.MultiWriter(os.Stdout, f))
    // 通过SetFlags设置Logger结构体里的flag属性
    log.SetFlags(log.Ldate | log.Ltime | log.Lshortfile | log.Lmsgprefix)
    // 通过SetPrefix设置Logger结构体里的prefix属性
    log.SetPrefix("INFO:")
    // 调用辅助函数Println打印日志到指定文件
    log.Println("your message")
}

上面的代码会在当前目录下生成一个app_YYYYMMDD.log文件，log.Println里打印的内容会输出到这个文件里。细心的同学，可能看到了上面被注释的一行代码：

log.SetOutput(io.MultiWriter(os.Stdout, f))

这个表示的含义是同时把打印内容输出到标准输出(控制台)和指定文件里。

方式2：自定义Logger

方式1只建议打印到控制台的时候使用，对于打印到日志文件的场景，建议使用自定义Logger，参考如下代码：

// example3.go
package main

import (
    "fmt"
    "log"
    "os"
    "time"
)

func main() {
    // 打开文件
    fileName := fmt.Sprintf("app_%s.log", time.Now().Format("20060102"))
    f, err := os.OpenFile(fileName, os.O_RDWR | os.O_APPEND | os.O_CREATE, 0666)
    if err != nil {
        log.Fatalf("open file error: %v", err)
    }
    // 通过New方法自定义Logger，New的参数对应的是Logger结构体的output, prefix和flag字段
    logger := log.New(f, "[INFO] ", log.LstdFlags | log.Lshortfile | log.Lmsgprefix)
    // 调用Logger的方法Println打印日志到指定文件
    logger.Println("your message")
}

上面的代码会在当前目录下生成一个app_YYYYMMDD.log文件，logger.Println里打印的内容会输出到这个文件里。

注意：New函数返回的是Logger指针，Logger结构体的方法都是指针接受者。

总结方式2的使用流程如下：

1. 通过log.New创建一个新的Logger指针，在New函数里指定好output, prefix和flag等日志属性
2. 调用log包里的辅助函数Print[f|ln]，Fatal[f|ln]，Panic[f|ln]打印日志

• Fatal[f|ln]打印日志后会调用os.Exit(1)
• Panic[f|ln]打印日志后会调用panic

自定义Logger的方式，还可以实现打印日志到控制台，也可以实现同时打印日志到日志文件和控制台，只需要给New函数的第一个参数传递对应的io.Writer类型参数即可。

• 如果要打印到控制台，参数可以用os.Stdout或者os.Stderr
• 如果要同时打印到控制台和日志文件，参数可以用io.MultiWriter(os.Stdout, f)，参考上面的example2.go。

生产应用

生产系统中打印日志就比上面的要复杂多了，需要考虑至少以下几个方面：

• 日志路径设置：支持配置日志文件路径，将日志打印到指定路径的文件里。
• 日志级别控制：支持Debug, Info, Warn, Error, Fatal等不同日志级别。
• 日志切割：可以按照日期和日志大小进行自动切割。
• 性能：在大量日志打印的时候不能对应用程序性能造成明显影响。

Go生态中，目前比较流行的是Uber开发的zap，在GitHub上的开源地址：https://github.com/uber-go/zap

注意事项

• Lmsgprefix属性：不开启该属性时，Logger结构体里的prefix属性就会在每行日志最开头。开启该属性后，prefix就会在被打印的具体内容之前，而不是在每行最开头。
• LUTC属性：对于Logger结构体里的flag属性，如果开启了LUTC属性，那打印的日志里显示的时间就不是本地时间了，而是UTC标准时间。比如中国在东八区，中国时间减去8小时就是UTC时间。
• Fatal[f|ln]：打印日志后，会调用os.Exit(1)。如果defer关键字和Fatal[f|ln]一起使用要小心，因为如果在函数里执行了defer，但是最后是由于调用了os.Exit而退出的函数，那被defer的函数和方法是不会执行的。具体可以参考我之前写的文章Go语言里被defer的函数一定会执行么？
• Panic[f|ln]：打印日志后会调用panic，应用程序要考虑是否要通过recover来捕获panic，避免程序退出。
• log打印的日志一定会换行。所以即使调用的是log包里的Print函数或方法，打印的日志也会换行。因此使用log包里的Print和Println没有区别了。

开源地址

代码开源地址：https://github.com/jincheng9/go-tutorial

也欢迎关注微信公众号：coding进阶，学习更多Go、微服务和云原生架构相关知识。

References

• https://pkg.go.dev/log
• https://www.flysnow.org/2017/05/06/go-in-action-go-log.html