原文:https://www.jianshu.com/p/d634316a9487
---------------------------------------------
在我們開發程序后,如果有一些問題需要對程序進行調試的時候,日志是必不可少的,這是我們分析程序問題常用的手段。
日志使用
日志分析,就是根據輸出的日志信息,分析挖掘可能的問題,我們使用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/29 main.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:26 main.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, prefix string, 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(w io.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框架,也可以自定包裝定義,直接通過不同級別的方法來記錄不同級別的日志,還可以設置記錄日志的級別等。
每個golang包只需要一篇最好文章 系列
http://www.nextblockchain.top/books/golangpackage/summary
作者:豆瓣奶茶
鏈接:https://www.jianshu.com/p/d634316a9487
來源:簡書
著作權歸作者所有。商業轉載請聯系作者獲得授權,非商業轉載請注明出處。
在我們開發程序后,如果有一些問題需要對程序進行調試的時候,日志是必不可少的,這是我們分析程序問題常用的手段。
日志使用
日志分析,就是根據輸出的日志信息,分析挖掘可能的問題,我們使用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/29 main.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:26 main.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, prefix string, 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(w io.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框架,也可以自定包裝定義,直接通過不同級別的方法來記錄不同級別的日志,還可以設置記錄日志的級別等。
每個golang包只需要一篇最好文章 系列
http://www.nextblockchain.top/books/golangpackage/summary