Go語言之log日志

在我們開發程序后，如果有一些問題需要對程序進行調試的時候，日志是必不可少的，這是我們分析程序問題常用的手段。

日志使用

日志分析，就是根據輸出的日志信息，分析挖掘可能的問題，我們使用fmt.Println系列函數也可以達到目的，因為它們也可以把我們需要的信息輸出到終端或者其他文件中。不過fmt.Println系列函數輸出的系統比較簡單，比如沒有時間，也沒有源代碼的行數等，對于我們排查問題，缺少了很多信息。

對此，Go語言為我們提供了標準的log包，來跟蹤日志的記錄。下面我們看看日志包log的使用。

func main() {
    log.Println("飛雪無情的博客:","http://www.flysnow.org")
    log.Printf("飛雪無情的微信公眾號：%s\\n","flysnow_org")}

使用非常簡單，函數名字和用法也和fmt包很相似，但是它的輸出默認帶了時間戳。

2017/04/29 13:18:44 飛雪無情的博客: http://www.flysnow.org
2017/04/29 13:18:44 飛雪無情的微信公眾號：flysnow_org

這樣我們很清晰的就知道了，記錄這些日志的時間，這對我們排查問題，非常有用。

有了時間了，我們還想要更多的信息，必然發生的源代碼行號等，對此日志包log為我們提供了可定制化的配制，讓我們可以自己定制日志的抬頭信息。

func init(){
    log.SetFlags(log.Ldate|log.Lshortfile)}

我們使用init函數，這個函數在main函數執行之前就可以初始化，可以幫我們做一些配置，這里我們自定義日志的抬頭信息為時間+文件名+源代碼所在行號。也就是log.Ldate|log.Lshortfile，中間是一個位運算符|，然后通過函數log.SetFlags進行設置。現在我們再運行下看看輸出的日志。

2017/04/29main.go:10: 飛雪無情的博客:http://www.flysnow.org
2017/04/29 main.go:11: 飛雪無情的微信公眾號：flysnow_org

比著上一個例子，多了源文件以及行號，但是少了時間，這就是我們自定義出來的結果。現在我們看看log包為我們提供了那些可以定義的選項常量。

const (
    Ldate         = 1 << iota     //日期示例： 2009/01/23
    Ltime                         //時間示例: 01:23:23
    Lmicroseconds                 //毫秒示例: 01:23:23.123123.
    Llongfile                     //絕對路徑和行號: /a/b/c/d.go:23
    Lshortfile                    //文件和行號: d.go:23.
    LUTC                          //日期時間轉為0時區的
    LstdFlags     = Ldate | Ltime //Go提供的標準抬頭信息)

這是log包定義的一些抬頭信息，有日期、時間、毫秒時間、絕對路徑和行號、文件名和行號等，在上面都有注釋說明，這里需要注意的是：如果設置了Lmicroseconds，那么Ltime就不生效了；設置了Lshortfile，Llongfile也不會生效，大家自己可以測試一下。

LUTC比較特殊，如果我們配置了時間標簽，那么如果設置了LUTC的話，就會把輸出的日期時間轉為0時區的日期時間顯示。

log.SetFlags(log.Ldate|log.Ltime |log.LUTC)

那么對我們東八區的時間來說，就會減去 8 個小時，我們看輸出：

2017/04/29 05:46:29 飛雪無情的博客: http://www.flysnow.org
2017/04/29 05:46:29 飛雪無情的微信公眾號：flysnow_org

最后一個LstdFlags表示標準的日志抬頭信息，也就是默認的，包含日期和具體時間。

我們大部分情況下，都有很多業務，每個業務都需要記錄日志，那么有沒有辦法，能區分這些業務呢？這樣我們在查找日志的時候，就方便多了。

對于這種情況，Go語言也幫我們考慮到了，這就是設置日志的前綴，比如一個用戶中心系統的日志，我們可以這么設置。

func init(){

    log.SetPrefix("【UserCenter】")

    log.SetFlags(log.LstdFlags |log.Lshortfile |log.LUTC)
}

通過log.SetPrefix可以指定輸出日志的前綴，這里我們指定為【UserCenter】，然后就可以看到日志的打印輸出已經清晰的標記出我們的這些日志是屬于哪些業務的啦。

【UserCenter】2017/04/29 05:53:26 main.go:11: 飛雪無情的博客:http://www.flysnow.org
【UserCenter】2017/04/29 05:53:26main.go:12: 飛雪無情的微信公眾號：flysnow_org

log包除了有Print系列的函數，還有Fatal以及Panic系列的函數，其中Fatal表示程序遇到了致命的錯誤，需要退出，這時候使用Fatal記錄日志后，然后程序退出，也就是說Fatal相當于先調用Print打印日志，然后再調用os.Exit(1)退出程序。

同理Panic系列的函數也一樣，表示先使用Print記錄日志，然后調用panic()函數拋出一個恐慌，這時候除非使用recover()函數，否則程序就會打印錯誤堆棧信息，然后程序終止。

這里貼下這幾個系列函數的源代碼，更好理解。

func Println(v...interface{}) {

    std.Output(2, fmt.Sprintln(v...))
}
func Fatalln(v ...interface{}) {

    std.Output(2, fmt.Sprintln(v...))

    os.Exit(1)
}
func Panicln(v ...interface{}) {

    s := fmt.Sprintln(v...)

    std.Output(2, s)   panic(s)
}

實現原理

通過上面的源代碼，我們發現，日志包log的這些函數都是類似的，關鍵的輸出日志就在于std.Output方法。

func New(out io.Writer, prefixstring, flag int) *Logger {

    return &Logger{out: out,prefix: prefix, flag: flag}
}
var std = New(os.Stderr, "", LstdFlags)

從以上源代碼可以看出，變量std其實是一個*Logger，通過log.New函數創建，默認輸出到os.Stderr設備，前綴為空，日志抬頭信息為標準抬頭LstdFlags。

os.Stderr對應的是UNIX里的標準錯誤警告信息的輸出設備，同時被作為默認的日志輸出目的地。初次之外，還有標準輸出設備os.Stdout以及標準輸入設備os.Stdin。

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

以上就是定義的UNIX的標準的三種設備，分別用于輸入、輸出和警告錯誤信息。理解了os.Stderr，現在我們看下Logger這個結構體，日志的信息和操作，都是通過這個Logger操作的。

type Logger struct {

    mu     sync.Mutex //ensures atomic writes; protects the following fields

    prefix string     //prefix to write at beginning of each line

    flag   int       // properties

    out    io.Writer // destination for output

    buf    []byte    // for accumulating text to write
}

·        字段mu是一個互斥鎖，主要是是保證這個日志記錄器Logger在多goroutine下也是安全的。

·        字段prefix是每一行日志的前綴。

·        字段flag是日志抬頭信息。

·        字段out是日志輸出的目的地，默認情況下是os.Stderr。

·        字段buf是一次日志輸出文本緩沖，最終會被寫到out里。

了解了結構體Logger的字段，現在就可以看下它最重要的方法Output了，這個方法會輸出格式化好的日志信息。

func (l *Logger) Output(calldepth int, s string) error {
    now := time.Now() // get this early.
    var file string
    var line int
    //加鎖，保證多goroutine下的安全
    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]
    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')
    }    
    //輸出拼接好的緩沖buf里的日志信息到目的地
    _, err := l.out.Write(l.buf)    
    return err
}

整個代碼比較簡潔，為了多goroutine安全互斥鎖也用上了，但是在獲取調用堆棧信息的時候，又要先解鎖，因為這個過程比較重。獲取到文件、行號等信息后，繼續加互斥鎖保證安全。

后面的就比較簡單了，formatHeader方法主要是格式化日志抬頭信息，然后存儲在buf這個緩沖中，最后再把我們自己的日志信息拼接到緩沖buf的后面，然后為一次log日志輸出追加一個換行符，這樣每次日志輸出都是一行一行的。

有了最終的日志信息buf，然后把它寫到輸出的目的地out里就可以了，這是一個實現了io.Writer接口的類型，只要實現了這個接口，都可以當作輸出目的地。

func (l *Logger) SetOutput(wio.Writer) {

    l.mu.Lock()    

    defer l.mu.Unlock()

    l.out = w
}

log包的SetOutput函數，可以設置輸出目的地。這里稍微簡單介紹下runtime.Caller，它可以獲取運行時方法的調用信息。

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

參數skip表示跳過棧幀數，0 表示不跳過，也就是runtime.Caller的調用者。1 的話就是再向上一層，表示調用者的調用者。

log日志包里使用的是 2 ，也就是表示我們在源代碼中調用log.Print、log.Fatal和log.Panic這些函數的調用者。

以main函數調用log.Println為例，是main->log.Println->*Logger.Output->runtime.Caller這么一個方法調用棧，所以這時候，skip的值分別代表：

·        0 表示*Logger.Output中調用runtime.Caller的源代碼文件和行號。

·        1 表示log.Println中調用*Logger.Output的源代碼文件和行號。

·        2 表示main中調用log.Println的源代碼文件和行號。

所以這也是log包里的這個skip的值為什么一直是 2 的原因。

定制自己的日志

通過上面的源碼分析，我們知道日志記錄的根本就在于一個日志記錄器Logger，所以我們定制自己的日志，其實就是創建不同的Logger。

var (
    Info *log.Logger
    Warning *log.Logger
    Error * log.Logger)func init(){
    errFile,err:=os.OpenFile("errors.log",os.O_CREATE|os.O_WRONLY|os.O_APPEND,0666)
    if err!=nil{
        log.Fatalln("打開日志文件失敗：",err)
    }

    Info = log.New(os.Stdout,"Info:",log.Ldate | log.Ltime | log.Lshortfile)
    Warning = log.New(os.Stdout,"Warning:",log.Ldate | log.Ltime | log.Lshortfile)
    Error = log.New(io.MultiWriter(os.Stderr,errFile),"Error:",log.Ldate | log.Ltime | log.Lshortfile)}func main() {
    Info.Println("飛雪無情的博客:","http://www.flysnow.org")
    Warning.Printf("飛雪無情的微信公眾號：%s\\n","flysnow_org")
    Error.Println("歡迎關注留言")
}

我們根據日志級別定義了三種不同的Logger，分別為Info，Warning，Error，用于不同級別日志的輸出。這三種日志記錄器都是使用log.New函數進行創建。

這里創建Logger的時候，Info和Warning都比較正常，Error這里采用了多個目的地輸出，這里可以同時把錯誤日志輸出到os.Stderr以及我們創建的errors.log文件中。

io.MultiWriter函數可以包裝多個io.Writer為一個io.Writer，這樣我們就可以達到同時對多個io.Writer輸出日志的目的。

io.MultiWriter的實現也很簡單，定義一個類型實現io.Writer，然后在實現的Write方法里循環調用要包裝的多個Writer接口的Write方法即可。

func (t *multiWriter) Write(p []byte) (n int, err error) {
    for _, w := range t.writers {
        n, err = w.Write(p)
        if err != nil {
                    return
        } 
        if n != len(p) {
            err = ErrShortWrite            
            return
        }
    }    
    return len(p), nil
}

這里我們通過定義了多個Logger來區分不同的日志級別，使用比較麻煩，針對這種情況，可以使用第三方的log框架，也可以自定包裝定義，直接通過不同級別的方法來記錄不同級別的日志，還可以設置記錄日志的級別等。