frp源碼剖析-frp中的log模塊

前言&引入

一個好的log模塊能夠幫助咱們排錯，分析，統計

通常來講log中須要有時間、棧信息(好比說文件名行號等)，這些東西通常某些底層log模塊已經幫咱們作好了。但在業務中還有不少咱們須要記錄的信息，好比說：在web開發中，若是咱們接收到一條request，咱們可能須要執行不少操做，最基本的：

• 請求數據是要記錄的
• response也是要記錄的

若是僅僅只有這兩條的話咱們其實是能夠將消息放到一行來展現，但更復雜的狀況是也可能還須要記錄某些其餘的信息，好比說咱們在此次請求中將某個消息放入了消息隊列，咱們可能須要將這個消息是否放置成功，內容是什麼，等等記錄下來。若是分行記錄的話當出現問題須要排查的話可能會十分麻煩，由於線上的環境通常是併發的，咱們沒法保證同一個請求中的日誌每行都挨在一塊兒，因此咱們通常須要一個requestId來區分哪些日誌是同一個請求所產生的。因此咱們可能須要這樣的請求處理函數:

func HandleRequest(requestId string, requestData []byte) (response []byte) {
    log.Info(requestId, requestData)
    ...
    log.Info(requestId, "do something: A")
    ...
    log.Info(requestId, "do something: B")
    ...
    log.Info(requestId, response)
    ...
}

但這樣是否是很麻煩!每次打印日誌都須要額外的手動記錄requestId，咱們須要有個通用的東西統一記錄requestId，而後只須要將msg做爲參數放置進去就好了。

那麼咱們可能會想到一個解決辦法：每一個Request都做爲一個結構體，這個結構體包含了一個prefix字段，用來存儲像requestId這樣的須要預置的前綴，那麼這個結構體可能看起來是這樣的：

type Request struct {
    Header []byte
    Body []byte
    Method []byte
    Url []byte
    ...
    prefix string
}

func (r *Request) Info(msg []byte) {
    log.Info(r.prefix, msg)
}

func (r *Request) SetPrefix(prefix string) {
    r.prefix = prefix
}

那麼咱們前面的請求處理函數可能就像這樣：

func HandleRequest(r *Request) (response []byte) {
    r.Info(requestData)
    ...
    r.Info("do something: A")
    ...
    r.Info("do something: B")
    ...
    r.Info(response)
    ...
}

到這裏彷佛大功就告成了，但新的問題來了，由於項目中用到了http2.0，一個鏈接能夠處理多個請求，你的老大但願每一個鏈接都要記錄日誌，且能正確區分不一樣的鏈接。這時候你可能想都沒想就給鏈接結構體Conn加上了prefix字段，而後給Conn加上了Info等記錄方法，但聰明的你突然發現本身彷佛是在作一些重複的工做，爲什麼不把日誌抽離出來？因而就像這樣：

// r.go
type PrefixLog struct {
    prefix string
}

func NewPrefixLog(prefix string) (pl *PrefixLog){
    return $PrefixLog{prefix}
}

func (pl *PrefixLog) Info(msg []byte){
    Log.Info(pl.prefix, msg) // 假設這裏行號是30
}

type Request struct {
    Header []byte
    Body []byte
    Method []byte
    Url []byte
    ...
    *PrefixLog
}

type Conn struct {
    requestCount uint32
    *PrefixLog
}
...

此次基本大功告成！但彷佛新的問題又來了，假如爲了更方便的排錯，咱們在日誌須要保存log的文件名行號信息的話，上面這種形式就有問題了，由於經過這種方式調用的話全部的日誌的文件名和行號都是相同的: file_name: r.go line:30，這該咋辦呢？

正文

frp中的log模塊相對簡單，其封裝了beego的log模塊，主要邏輯寫在utils/log文件中，來分析一下該文件。

全局變量之Log

import (
    "github.com/fatedier/beego/logs"
)

// Log is the under log object
var Log *logs.BeeLogger

這個Log變量是frp中log模塊的核心，幾乎全部(或者說就是全部)的日誌都是由這個Log變量來負責操做的。

初始化之init函數

func init() {
    Log = logs.NewLogger(200)
    Log.EnableFuncCallDepth(true)
    Log.SetLogFuncCallDepth(Log.GetLogFuncCallDepth() + 1)
}

這個init函數則初始化了Log對象，注意Log.SetLogFuncCallDepth(Log.GetLogFuncCallDepth() + 1)這句，大致上就是：咱們的程序能夠說是由一個一個的函數組成，這些函數之間相互調用，每調用一個函數就進行了一次入棧操做，當某個函數執行完就執行了出棧操做，而loggerFuncCallDepth則表示要訪問的棧的位置。

關於calldepth

那這個東西有啥用呢？咱們知道咱們打印日誌的時候有的時候但願可以在日誌中輸出執行log的文件以及行號信息，拿go標準庫log舉個例子:

// main 文件
func a() {
    ...
    b("hell0") // 假如該行行號爲10
    ...
}

func wtf(msg string) {
    ...
    msg = "[WTF!!]: " + msg
    log.Printf(msg) // 假如該行行號爲21
    ...
}

func main() {
    a()
}

// 標準庫log中的Printf方法，注意其內部調用了Output方法，且第一個參數爲2
func Printf(format string, v ...interface{}) {
    std.Output(2, fmt.Sprintf(format, v...))
}

// 這是真正執行了打印的方法
func (l *Logger) Output(calldepth int, s string) error {
    ...
}

這裏函數的調用順序是main -> a -> wtf -> log.Printf -> Output，能夠說這是一個深度爲5的棧，calldepth爲0表示棧頂，也就是Output對應的棧空間，1則表示log.Printf對應的棧空間，2表示wtf對應的棧空間，3表示wtf......以此類推。由於log模塊設置的callpath是2，也就是假如咱們設置了Llongfile或者Lshortfile標識符的時候輸出的文件名是main，行號爲21，假如咱們設置callpath爲3的話，輸出的文件名依然是main但行號則變爲了10。

打印函數

這裏打印函數就拿Info來講明吧

func Info(format string, v ...interface{}) {
    Log.Info(format, v...)
}

能夠看到Info函數實際上就是調用了Log.Info方法，Log.Info作了不少關於併發控制，格式輸出，buffer寫入的操做，但其最主要就是作了「將咱們要打印的文字輸出出來」這個操做。

log文件中惟一的一個結構體: PrefixLogger

type PrefixLogger struct {
    prefix    string
    allPrefix []string
}

func (pl *PrefixLogger) AddLogPrefix(prefix string) {
    if len(prefix) == 0 {
        return
    }

    pl.prefix += "[" + prefix + "] "
    pl.allPrefix = append(pl.allPrefix, prefix)
}

// 一樣，這裏也僅僅列出PrefixLogger的Info方法
func (pl *PrefixLogger) Info(format string, v ...interface{}) {
    Log.Info(pl.prefix+format, v...)
}

PrefixLogger實際上就是一個具備前綴功能的很簡單的結構體。