深入探究Golang中log標準庫的使用

Posted on 2023-05-07 by WalkonNet

Go 語言標準庫中的 log 包設計簡潔明瞭，易於上手，可以輕松記錄程序運行時的信息、調試錯誤以及跟蹤代碼執行過程中的問題等。使用 log 包無需繁瑣的配置即可直接使用。本文旨在深入探究 log 包的使用和原理，幫助讀者更好地瞭解和掌握它。

使用

先來看一個 log 包的使用示例：

package main
import "log"
func main() {
	log.Print("Print")
	log.Printf("Printf: %s", "print")
	log.Println("Println")
	log.Fatal("Fatal")
	log.Fatalf("Fatalf: %s", "fatal")
	log.Fatalln("Fatalln")
	log.Panic("Panic")
	log.Panicf("Panicf: %s", "panic")
	log.Panicln("Panicln")
}

假設以上代碼存放在 main.go 中，通過 go run main.go 執行代碼將會得到如下輸出：

$ go run main.go
2023/03/08 22:33:22 Print
2023/03/08 22:33:22 Printf: print
2023/03/08 22:33:22 Println
2023/03/08 22:33:22 Fatal
exit status 1

以上示例代碼中使用 log 包提供的 9 個函數分別對日志進行輸出，最終得到 4 條打印日志。我們來分析下每個日志函數的作用，來看看為什麼出現這樣的結果。

log 包提供瞭 3 類共計 9 種方法來輸出日志內容。

函數名	作用	使用示例
Print	打印日志	log.Print("Print")
Printf	打印格式化日志	log.Printf("Printf: %s", "print")
Println	打印日志並換行	log.Println("Println")
Panic	打印日志後執行 panic(s)（s 為日志內容）	log.Panic("Panic")
Panicf	打印格式化日志後執行 panic(s)	log.Panicf("Panicf: %s", "panic")
Panicln	打印日志並換行後執行 panic(s)	log.Panicln("Panicln")
Fatal	打印日志後執行 os.Exit(1)	log.Fatal("Fatal")
Fatalf	打印格式化日志後執行 os.Exit(1)	log.Fatalf("Fatalf: %s", "fatal")
Fatalln	打印日志並換行後執行 os.Exit(1)	log.Panicln("Panicln")

根據以上表格說明，我們可以知道，log 包在執行 log.Fatal("Fatal") 時，程序打印完日志就通過 os.Exit(1) 退出瞭。這也就可以解釋上面的示例程序，為什麼打印瞭 9 次日志，卻隻輸出瞭 4 條日志，並且最後程序退出碼為 1 瞭。

以上是 log 包最基本的使用方式，如果我們想對日志輸出做一些定制，可以使用 log.New 創建一個自定義 logger：

logger := log.New(os.Stdout, "[Debug] - ", log.Lshortfile)

log.New 函數接收三個參數，分別用來指定：日志輸出位置（一個 io.Writer 對象）、日志前綴（字符串，每次打印日志都會跟隨輸出）、日志屬性（定義好的常量，稍後會詳細講解）。

使用示例：

package main

import (
	"log"
	"os"
)

func main() {
	logger := log.New(os.Stdout, "[Debug] - ", log.Lshortfile)
	logger.Println("custom logger")
}

示例輸出：

[Debug] – main.go:10: custom logger

以上示例中，指定日志輸出到 os.Stdout，即標準輸出；日志前綴 [Debug] - 會自動被加入到每行日志的行首；這條日志沒有打印當前時間，而是打印瞭文件名和行號，這是 log.Lshortfile 日志屬性的作用。

日志屬性可選項如下：

屬性	說明
Ldate	當前時區的日期，格式：2009/01/23
Ltime	當前時區的時間，格式：01:23:23
Lmicroseconds	當前時區的時間，格式：01:23:23.123123，精確到微妙
Llongfile	全文件名和行號，格式：/a/b/c/d.go:23
Lshortfile	當前文件名和行號，格式：d.go:23，會覆蓋 Llongfile
LUTC	使用 UTC 而非本地時區，推薦日志全部使用 UTC 時間
Lmsgprefix	將 `prefix` 內容從行首移動到日志內容前面
LstdFlags	標準 logger 對象的初始值（等於：`Ldate\|Ltime`）

這些屬性都是預定義好的常量，不能修改，可以通過 | 運算符組合使用（如：log.Ldate|log.Ltime|log.Lshortfile）。

使用 log.New 函數創建 logger 對象以後，依然可以通過 logger 對象的方法修改其屬性值：

方法	作用
SetOutput	設置日志輸出位置
SetPrefix	設置日志輸出前綴
SetFlags	設置日志屬性

現在我們來看一個更加完整的使用示例：

package main

import (
	"log"
	"os"
)

func main() {
	// 準備日志文件
	logFile, _ := os.Create("demo.log")
	defer func() { _ = logFile.Close() }()

	// 初始化日志對象
	logger := log.New(logFile, "[Debug] - ", log.Lshortfile|log.Lmsgprefix)
	logger.Print("Print")
	logger.Println("Println")

	// 修改日志配置
	logger.SetOutput(os.Stdout)
	logger.SetPrefix("[Info] - ")
	logger.SetFlags(log.Ldate|log.Ltime|log.LUTC)
	logger.Print("Print")
	logger.Println("Println")
}

執行以上代碼，得到 demo.log 日志內容如下：

main.go:15: [Debug] – Print
main.go:16: [Debug] – Println

控制臺輸出內容如下：

[Info] – 2023/03/11 01:24:56 Print
[Info] – 2023/03/11 01:24:56 Println

可以發現，在 demo.log 日志內容中，因為指定瞭 log.Lmsgprefix 屬性，所以日志前綴 [Debug] - 被移動到瞭日志內容前面，而非行首。

因為後續通過 logger.SetXXX 對 logger 對象的屬性進行瞭動態修改，所以最後兩條日志輸出到系統的標準輸出。

以上，基本涵蓋瞭 log 包的所有常用功能。接下來我們就通過走讀源碼的方式來更深入的瞭解 log 包瞭。

源碼

註意：本文以 Go 1.19.4 源碼為例，其他版本可能存在差異。

Go 標準庫的 log 包代碼量非常少，算上註釋也才 400+ 行，非常適合初學者閱讀學習。

在上面介紹的第一個示例中，我們使用 log 包提供的 9 個公開函數對日志進行輸出，並通過表格的形式分別介紹瞭函數的作用和使用示例，那麼現在我們就來看看這幾個函數是如何定義的：

func Print(v ...any) {
	if atomic.LoadInt32(&std.isDiscard) != 0 {
		return
	}
	std.Output(2, fmt.Sprint(v...))
}
func Printf(format string, v ...any) {
	if atomic.LoadInt32(&std.isDiscard) != 0 {
		return
	}
	std.Output(2, fmt.Sprintf(format, v...))
}
func Println(v ...any) {
	if atomic.LoadInt32(&std.isDiscard) != 0 {
		return
	}
	std.Output(2, fmt.Sprintln(v...))
}
func Fatal(v ...any) {
	std.Output(2, fmt.Sprint(v...))
	os.Exit(1)
}
func Fatalf(format string, v ...any) {
	std.Output(2, fmt.Sprintf(format, v...))
	os.Exit(1)
}
func Fatalln(v ...any) {
	std.Output(2, fmt.Sprintln(v...))
	os.Exit(1)
}
func Panic(v ...any) {
	s := fmt.Sprint(v...)
	std.Output(2, s)
	panic(s)
}
func Panicf(format string, v ...any) {
	s := fmt.Sprintf(format, v...)
	std.Output(2, s)
	panic(s)
}
func Panicln(v ...any) {
	s := fmt.Sprintln(v...)
	std.Output(2, s)
	panic(s)
}

可以發現，這些函數代碼主邏輯基本一致，都是通過 std.Output 輸出日志。不同的是，PrintX 輸出日志後程序就執行結束瞭；Fatal 輸出日志後會執行 os.Exit(1)；而 Panic 輸出日志後會執行 panic(s)。

那麼接下來就是要搞清楚這個 std 對象是什麼，以及它的 Output 方法是如何定義的。

我們先來看下 std 是什麼：

var std = New(os.Stderr, "", LstdFlags)
func New(out io.Writer, prefix string, flag int) *Logger {
	l := &Logger{out: out, prefix: prefix, flag: flag}
	if out == io.Discard {
		l.isDiscard = 1
	}
	return l
}

可以看到，std 其實就是使用 New 創建的一個 Logger 對象，日志輸出到標準錯誤輸出，日志前綴為空，日志屬性為 LstdFlags。

這跟我們上面講的自定義日志對象 logger := log.New(os.Stdout, "[Debug] - ", log.Lshortfile) 方式如出一轍。也就是說，當我們通過 log.Print("Print") 打印日志時，其實使用的是 log 包內部已經定義好的 Logger 對象。

Logger 定義如下：

type Logger struct {
	mu        sync.Mutex // 鎖，保證並發情況下對其屬性操作是原子性的
	prefix    string     // 日志前綴，即 Lmsgprefix 參數值
	flag      int        // 日志屬性，用來控制日志輸出格式
	out       io.Writer  // 日志輸出位置，實現瞭 io.Writer 接口即可，如 文件、os.Stderr
	buf       []byte     // 存儲日志輸出內容
	isDiscard int32      // 當 out = io.Discard 是，此值為 1
}

其中，flag 和 isDiscard 這兩個屬性有必要進一步解釋下。

首先是 flag 用來記錄日志屬性，其合法值如下：

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
)

具體含義我就不再一一解釋瞭，前文的表格已經寫的很詳細瞭。

值得註意的是，這裡在定義常量時，巧妙的使用瞭左移運算符 1 << iota，使得常量的值呈現 1、2、4、8… 這樣的遞增效果。其實是為瞭位運算方便，通過對屬性進行位運算，來決定輸出內容，其本質上跟基於位運算的權限管理是一樣的。所以在使用 log.New 新建 Logger 對象時可以支持 log.Ldate|log.Ltime|log.Lshortfile 這種形式設置多個屬性。

std 對象的屬性初始值 LstdFlags 也是在這裡定義的。

其次還有一個屬性 isDiscard，是用來丟棄日志的。在上面介紹 PrintX 函數定義時，在輸出日志前有一個 if atomic.LoadInt32(&std.isDiscard) != 0 的判斷，如果結果為真，則直接 return 不記錄日志。

在 Go 標準庫的 io 包裡，有一個 io.Discard 對象，io.Discard 實現瞭 io.Writer，它執行 Write 操作後不會產生任何實際的效果，是一個用於丟棄數據的對象。比如有時候我們不在意數據內容，但可能存在數據不讀出來就無法關閉連接的情況，這時候就可以使用 io.Copy(io.Discard, io.Reader) 將數據寫入 io.Discard 實現丟棄數據的效果。

使用 New 創建 Logger 對象時，如果 out == io.Discard 則 l.isDiscard 的值會被置為 1，所以使用 PrintX 函數記錄的日志將會被丟棄，而 isDiscard 屬性之所以是 int32 類型而不是 bool，是因為方便原子操作。

現在，我們終於可以來看 std.Output 的實現瞭：

func (l *Logger) Output(calldepth int, s string) error {
	now := time.Now() // 獲取當前時間
	var file string
	var line int
	// 加鎖，保證並發安全
	l.mu.Lock()
	defer l.mu.Unlock()
	// 通過位運算來判斷是否需要獲取文件名和行號
	if l.flag&(Lshortfile|Llongfile) != 0 {
		// 運行 runtime.Caller 獲取文件名和行號比較耗時，所以先釋放鎖
		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]
	// 格式化日志頭信息（如：日期時間、文件名和行號、前綴）並寫入 buf
	l.formatHeader(&l.buf, now, file, line)
	// 追加日志內容到 buf
	l.buf = append(l.buf, s...)
	// 保證輸出日志以 \n 結尾
	if len(s) == 0 || s[len(s)-1] != '\n' {
		l.buf = append(l.buf, '\n')
	}
	// 調用 Logger 對象的 out 屬性的 Write 方法輸出日志
	_, err := l.out.Write(l.buf)
	return err
}

Output 方法代碼並不多，基本邏輯也比較清晰，首先根據日志屬性來決定是否需要獲取文件名和行號，因為調用 runtime.Caller 是一個耗時操作，開銷比較大，為瞭增加並發性，暫時將鎖釋放，獲取到文件名和行號後再重新加鎖。

接下來就是準備日志輸出內容瞭，首先清空 buf 中保留的上次日志信息，然後通過 formatHeader 方法格式化日志頭信息，接著把日志內容也追加到 buf 中，在這之後有一個保證輸出日志以 \n 結尾的邏輯，來保證輸出的日志都是單獨一行的。不知道你有沒有註意到，在前文的 log 包使用示例中，我們使用 Print 和 Println 兩個方法時，最終日志輸出效果並無差別，使用 Print 打印日志也會換行，其實就是這裡的邏輯決定的。

最後，通過調用 l.out.Write 方法，將 buf 內容輸出。

我們來看下用來格式化日志頭信息的 formatHeader 方法是如何定義：

func (l *Logger) formatHeader(buf *[]byte, t time.Time, file string, line int) {
	// 如果沒有設置 Lmsgprefix 屬性，將日志前綴內容設置到行首
	if l.flag&Lmsgprefix == 0 {
		*buf = append(*buf, l.prefix...)
	}
	// 判斷是否設置瞭日期時間相關的屬性
	if l.flag&(Ldate|Ltime|Lmicroseconds) != 0 {
		// 是否設置 UTC 時間
		if l.flag&LUTC != 0 {
			t = t.UTC()
		}
		// 是否設置日期
		if l.flag&Ldate != 0 {
			year, month, day := t.Date()
			itoa(buf, year, 4)
			*buf = append(*buf, '/')
			itoa(buf, int(month), 2)
			*buf = append(*buf, '/')
			itoa(buf, day, 2)
			*buf = append(*buf, ' ')
		}
		// 是否設置時間
		if l.flag&(Ltime|Lmicroseconds) != 0 {
			hour, min, sec := t.Clock()
			itoa(buf, hour, 2)
			*buf = append(*buf, ':')
			itoa(buf, min, 2)
			*buf = append(*buf, ':')
			itoa(buf, sec, 2)
			if l.flag&Lmicroseconds != 0 {
				*buf = append(*buf, '.')
				itoa(buf, t.Nanosecond()/1e3, 6)
			}
			*buf = append(*buf, ' ')
		}
	}
	// 是否設置文件名和行號
	if l.flag&(Lshortfile|Llongfile) != 0 {
		if l.flag&Lshortfile != 0 {
			short := file
			for i := len(file) - 1; i > 0; i-- {
				if file[i] == '/' {
					short = file[i+1:]
					break
				}
			}
			file = short
		}
		*buf = append(*buf, file...)
		*buf = append(*buf, ':')
		itoa(buf, line, -1)
		*buf = append(*buf, ": "...)
	}
	// 如果設置瞭 Lmsgprefix 屬性，將日志前綴內容放到日志頭信息最後，也就是緊挨著日志內容前面
	if l.flag&Lmsgprefix != 0 {
		*buf = append(*buf, l.prefix...)
	}
}

formatHeader 方法是 log 包裡面代碼量最多的一個方法，主要通過按位與（&）來計算是否設置瞭某個日志屬性，然後根據日志屬性來格式化頭信息。

其中多次調用 itoa 函數，itoa 顧名思義，將 int 轉換成 ASCII 碼，itoa 定義如下：

func itoa(buf *[]byte, i int, wid int) {
	// Assemble decimal in reverse order.
	var b [20]byte
	bp := len(b) - 1
	for i >= 10 || wid > 1 {
		wid--
		q := i / 10
		b[bp] = byte('0' + i - q*10)
		bp--
		i = q
	}
	// i < 10
	b[bp] = byte('0' + i)
	*buf = append(*buf, b[bp:]...)
}

這個函數短小精悍，它接收三個參數，buf 用來保存轉換後的內容，i 就是帶轉換的值，比如 year、month 等，wid 表示轉換後 ASCII 碼字符串寬度，如果傳進來的 i 寬度不夠，則前面補零。比如傳入 itoa(&b, 12, 3)，最終輸出字符串為 012。

至此，我們已經理清瞭 log.Print("Print") 是如何打印一條日志的，其函數調用流程如下：

上面我們講解瞭使用 log 包中默認的 std 這個 Logger 對象打印日志的調用流程。當我們使用自定義的 Logger 對象（logger := log.New(os.Stdout, "[Debug] - ", log.Lshortfile)）來打印日志時，調用的 loggger.Print 是一個方法，而不是 log.Print 這個包級別的函數，所以其實 Logger 結構體也實現瞭 9 種輸出日志方法：

func (l *Logger) Print(v ...any) {
	if atomic.LoadInt32(&l.isDiscard) != 0 {
		return
	}
	l.Output(2, fmt.Sprint(v...))
}

func (l *Logger) Printf(format string, v ...any) {
	if atomic.LoadInt32(&l.isDiscard) != 0 {
		return
	}
	l.Output(2, fmt.Sprintf(format, v...))
}

func (l *Logger) Println(v ...any) {
	if atomic.LoadInt32(&l.isDiscard) != 0 {
		return
	}
	l.Output(2, fmt.Sprintln(v...))
}

func (l *Logger) Fatal(v ...any) {
	l.Output(2, fmt.Sprint(v...))
	os.Exit(1)
}

func (l *Logger) Fatalf(format string, v ...any) {
	l.Output(2, fmt.Sprintf(format, v...))
	os.Exit(1)
}

func (l *Logger) Fatalln(v ...any) {
	l.Output(2, fmt.Sprintln(v...))
	os.Exit(1)
}

func (l *Logger) Panic(v ...any) {
	s := fmt.Sprint(v...)
	l.Output(2, s)
	panic(s)
}

func (l *Logger) Panicf(format string, v ...any) {
	s := fmt.Sprintf(format, v...)
	l.Output(2, s)
	panic(s)
}

func (l *Logger) Panicln(v ...any) {
	s := fmt.Sprintln(v...)
	l.Output(2, s)
	panic(s)
}

這 9 個方法跟 log 包級別的函數一一對應，用於自定義 Logger 對象。

有一個值得註意的點，在這些方法內部，調用 l.Output(2, s) 時，第一個參數 calldepth 傳遞的是 2，這跟 runtime.Caller(calldepth) 函數內部實現有關，runtime.Caller 函數簽名如下：

func Caller(skip int) (pc uintptr, file string, line int, ok bool)

runtime.Caller 返回當前 Goroutine 的棧上的函數調用信息（程序計數器、文件信息、行號），其參數 skip 表示當前向上層的棧幀數，0 代表當前函數，也就是調用 runtime.Caller 的函數，1 代表上一層調用者，以此類推。

因為函數調用鏈為 main.go -> log.Print -> std.Output -> runtime.Caller，所以 skip 值即為 2：

0: 表示 std.Output 中調用 runtime.Caller 所在的源碼文件和行號。
1: 表示 log.Print 中調用 std.Output 所在的源碼文件和行號。
2: 表示 main.go 中調用 log.Print 所在的源碼文件和行號。

這樣當代碼出現問題時，就能根據日志中記錄的函數調用棧來找到報錯的源碼位置瞭。

另外，前文介紹過三個設置 Logger 對象屬性的方法，分別是 SetOutput、SetPrefix、SetFlags，其實這三個方法各自還有與之對應的獲取相應屬性的方法，定義如下：

func (l *Logger) Flags() int {
	l.mu.Lock()
	defer l.mu.Unlock()
	return l.flag
}

func (l *Logger) SetFlags(flag int) {
	l.mu.Lock()
	defer l.mu.Unlock()
	l.flag = flag
}

func (l *Logger) Prefix() string {
	l.mu.Lock()
	defer l.mu.Unlock()
	return l.prefix
}

func (l *Logger) SetPrefix(prefix string) {
	l.mu.Lock()
	defer l.mu.Unlock()
	l.prefix = prefix
}

func (l *Logger) Writer() io.Writer {
	l.mu.Lock()
	defer l.mu.Unlock()
	return l.out
}

func (l *Logger) SetOutput(w io.Writer) {
	l.mu.Lock()
	defer l.mu.Unlock()
	l.out = w
	isDiscard := int32(0)
	if w == io.Discard {
		isDiscard = 1
	}
	atomic.StoreInt32(&l.isDiscard, isDiscard)
}

其實就是針對每個私有屬性，定義瞭 getter、setter 方法，並且每個方法內部為瞭保證並發安全，都進行瞭加鎖操作。

當然，log 包級別的函數，也少不瞭這幾個功能：

func Default() *Logger { return std }

func SetOutput(w io.Writer) {
	std.SetOutput(w)
}

func Flags() int {
	return std.Flags()
}

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

func Prefix() string {
	return std.Prefix()
}

func SetPrefix(prefix string) {
	std.SetPrefix(prefix)
}

func Writer() io.Writer {
	return std.Writer()
}

func Output(calldepth int, s string) error {
	return std.Output(calldepth+1, s) // +1 for this frame.
}

至此，log 包的全部代碼我們就一起走讀完成瞭。

總結一下：log 包主要設計瞭 Logger 對象和其方法，並且為瞭開箱即用，在包級別又對外提供瞭默認的 Logger 對象 std 和一些包級別的對外函數。Logger 對象的方法，和包級別的函數基本上是一一對應的，簽名一樣，這樣就大大降低瞭使用難度。

使用建議

關於 log 包的使用，我還有幾條建議分享給你：

log 默認不支持 Debug、Info、Warn 等更細粒度級別的日志輸出方法，不過我們可以通過創建多個 Logger 對象的方式來實現，隻需要給每個 Logger 對象指定不同的日志前綴即可：

loggerDebug = log.New(os.Stdout, "[Debug]", log.LstdFlags)
loggerInfo = log.New(os.Stdout, "[Info]", log.LstdFlags)
loggerWarn = log.New(os.Stdout, "[Warn]", log.LstdFlags)
loggerError = log.New(os.Stdout, "[Error]", log.LstdFlags)

僅在 main.go 文件中使用 log.Panic、log.Fatal，下層程序遇到錯誤時先記錄日志，然後將錯誤向上一層層拋出，直到調用棧頂層才決定要不要使用 log.Panic、log.Fatal。
log 包作為 Go 標準庫，僅支持日志的基本功能，不支持記錄結構化日志、日志切割、Hook 等高級功能，所以更適合小型項目使用，比如一個單文件的腳本。對於中大型項目，則推薦使用一些主流的第三方日志庫，如 logrus、zap、glog 等。
另外，如果你對 Go 標準日志庫有所期待，Go 官方還打造瞭另一個日志庫 slog 現已進入實驗階段，如果項目發展順利，將可能成為 log 包的替代品。

以上就是深入探究Golang中log標準庫的使用的詳細內容，更多關於Golang log標準庫的資料請關註WalkonNet其它相關文章！

深入探究Golang中log標準庫的使用

目錄

使用

源碼

使用建議

推薦閱讀：

發佈留言取消回覆

近期文章

目錄

使用

源碼

使用建議

推薦閱讀：

發佈留言 取消回覆

近期文章

標籤

發佈留言取消回覆