小白学标准库之 log

Posted 2021-09-28 乱舞春秋

---

日常开发中，日志 log 几乎是必不可少。本文旨在介绍 log 的使用和内部实现等。

1. log 使用及实现

package main

import (
	"fmt"
	"log"
)

func init() {
	log.SetPrefix("Trace: ")
	log.SetFlags(log.Ldate | log.Lmicroseconds | log.Llongfile)
}

func main() {
	log.Println("message")

	log.Fatalln("fatal message")

    log.Panicln("panic message")
}

使用 log 需要用到标准库 log 包。init 函数中的 SetPrefix 和 SetFlags 函数定义了 log 的输出格式。以 SetFlags 为例，查看函数原型：

func SetFlags(flag int) {
	std.SetFlags(flag)
}

函数中 std 为 Logger 结构体变量，为指定 Logger 结构体变量，标准库会实例化默认结构体变量：

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

// New 函数
func New(out io.Writer, prefix string, flag int) *Logger {
	return &Logger{out: out, prefix: prefix, flag: flag}
}

// Logger 结构体
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
}

值得一提的是，New 函数接受一个 io.Writer 的接口类型变量，该变量定义了 log 日志的输出路径，默认输出到标准设备 os.Stderr。Stderr 的定义为：

package os

var (
	Stdin  = NewFile(uintptr(syscall.Stdin), "/dev/stdin")
	Stdout = NewFile(uintptr(syscall.Stdout), "/dev/stdout")
	Stderr = NewFile(uintptr(syscall.Stderr), "/dev/stderr")
)

func NewFile(fd uintptr, name string) *File

在包 os 中可以看到三种 File 引用类型的标准输出设备定义 Stdin, Stdout, Stderr。

拉回来我们继续看 std.SetFlags(flag) 这个方法，这个方法很有意思，它接受一个整数值，可是外面传递给 SetFlags 是二进制或类型的值：log.Ldate | log.Lmicroseconds | log.Llongfile。这中间发生了什么呢？

我们在这里找到了答案：

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
)

这里列举了枚举类型常量，且通过特殊常量 iota 实现了不同常量处于不同的二进制位，从而能区分出不同标志位，实现不同的 log 输出信息打印。关于不同标志位的判断是在 formatHeader 方法实现的，这里就不展开介绍了。

l.formatHeader(&l.buf, now, file, line)

在 log 打印这里，调用 Println, Fatalln, Panicln 函数实现不同类型日志打印。Println 输出写到标准输出设备中，Fatalln 输出在调用 Println 方法后调用 os.Exit(1) 退出程序执行，Panicln 在调用 Println 方法后继续调用 panic()。

其中的核心是 Output 方法如下：

func (l *Logger) Output(calldepth int, s string) error {
	now := time.Now() // get this early.
	var file string
	var line int
	l.mu.Lock()
	defer l.mu.Unlock()
	if l.flag&(Lshortfile|Llongfile) != 0 {
		// Release lock while getting caller info - it\'s expensive.
		l.mu.Unlock()
		var ok bool
		_, file, line, ok = runtime.Caller(calldepth)
		if !ok {
			file = "???"
			line = 0
		}
		l.mu.Lock()
	}
	l.buf = l.buf[:0]
	l.formatHeader(&l.buf, now, file, line)
	l.buf = append(l.buf, s...)
	if len(s) == 0 || s[len(s)-1] != \'\\n\' {
		l.buf = append(l.buf, \'\\n\')
	}
	_, err := l.out.Write(l.buf)
	return err
}

简要介绍该方法：

• 使用同步锁防止 goroutine 之间的写入竞争状态。
• formatHeader 将输入的格式按顺序排列。
• 结构体 l 的 out io.Write 接口变量调用 Write 方法实现日志信息写入。

2. 自定义 log

上节使用的是默认 Logger 类型，也可以根据不同 Logger 类型定义不同日志记录器：

var (
	Trace   *log.Logger
	Info    *log.Logger
	Warning *log.Logger
	Error   *log.Logger
)

这里定义了四种 Logger 类型的日志记录器，分别记录 Trace，Info，Warning 和 Error 类型的日志。

完整代码如下：

var (
	Trace   *log.Logger
	Info    *log.Logger
	Warning *log.Logger
	Error   *log.Logger
)

func init() {
	file, err := os.OpenFile("C:/Data/chunqiu/Software/errors.txt", os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0666)
	if err != nil {
		log.Fatalln("Failed to open error log file: ", err)
	}

	Trace = log.New(ioutil.Discard, "Trace: ", log.Ldate|log.Lmicroseconds|log.Llongfile)
	Info = log.New(os.Stdout, "Info: ", log.Ldate|log.Lmicroseconds|log.Llongfile)
	Warning = log.New(os.Stdout, "WARNING: ", log.Ldate|log.Lmicroseconds|log.Llongfile)
	Error = log.New(io.MultiWriter(file, os.Stderr), "ERROR: ", log.Ldate|log.Lmicroseconds|log.Llongfile)
}

func main() {
	Trace.Println("I have a dream")
	Info.Println("I have a dream too")
	Warning.Println("No, you haven\'t")
	Error.Println("Yes, Warning is right")
}

这里需要注意的是：

1. 调用 os 的 OpenFile 函数定义了输出文件信息，输出到指定目录的 errors.txt 文件中，且文件权限为 666。在 Error 日志记录器中，将该文件作为 Write 接口变量闯入 New 函数中。
2. Trace 日志记录器调用 ioutil 的 Discard 变量，该变量是一个实现了 Write 接口的 Discard 结构体变量，Dirscard 什么都没定义。实现的效果是禁用这种类型的日志输出。
3. Info 和 Warning 的日志将写入到标准输出设备 Stdout 中。
4. MultiWriter 是一个接受可变参数的函数，该函数将多个可变参数组合在切片中，赋值给 multiWriter 结构体，该结构体实现了 Writer 接口类型详细定义如下：

   func MultiWriter(writers ...Writer) Writer {
    allWriters := make([]Writer, 0, len(writers))
    for _, w := range writers {
    	if mw, ok := w.(*multiWriter); ok {
    		allWriters = append(allWriters, mw.writers...)
    	} else {
    		allWriters = append(allWriters, w)
    	}
    }
    return &multiWriter{allWriters}
    }
    不展开细讲，最终的表现形式是日志可以写入到外部传入的多个输出设备中，这里输出到 file 和 os.Stderr 中。
   

最后检查输出打印和 errors.txt 信息如下：

C:\\Users\\chunqiu\\go>go run "c:\\Users\\chunqiu\\go\\src\\goinaction\\lib\\log\\customized_log.go"
Info: 2021/09/28 00:59:17.648348 c:/Users/chunqiu/go/src/goinaction/lib/log/customized_log.go:31: I have a dream too
WARNING: 2021/09/28 00:59:17.648887 c:/Users/chunqiu/go/src/goinaction/lib/log/customized_log.go:32: No, you haven\'t    
ERROR: 2021/09/28 00:59:17.648887 c:/Users/chunqiu/go/src/goinaction/lib/log/customized_log.go:33: Yes, Warning is right

// errors.txt
ERROR: 2021/09/27 23:36:08.177438 c:/Users/chunqiu/go/src/goinaction/lib/log/customized_log.go:33: Yes, Warning is right

芝兰生于空谷，不以无人而不芳。