深入探究 Go log 標準庫

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 種方法來輸出日誌內容。

根據以上表格說明，我們可以知道，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 日誌屬性的作用。

日誌屬性可選項如下：

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

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

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

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 包的替代品。

總結

本文我與讀者一起深入探究了 Go log 標準庫，首先向大家介紹了 log 包如何使用，接着又帶領大家一起走讀了 log 包的源碼，最後我也給出了一些自己對 log 包的使用建議。

聯繫我

微信：jianghushinian

郵箱：jianghushinian007@outlook.com

博客地址：https://jianghushinian.cn

本文由 Readfog 進行 AMP 轉碼，版權歸原作者所有。
來源：https://mp.weixin.qq.com/s/nWS6uQqekikgvXQ2ORc4Og

猜你喜歡