運維大神如何使用 Golang 日誌監控應用程序

你是如何使用 Golang 日誌監控你的應用程序的呢？Golang 沒有異常，只有錯誤。所以你的第一印象可能就是開發 Golang 日誌策略並非一件簡單的事情。不>支持異常事實上並非什麼問題，異常在不少編程語言中已經失去了其異常性：它>們過於被濫用以致於它們的做用都被忽視了。
-- Nils

本文導航
一、Golang 日誌基礎

• 使用 Golang 「log」 庫

二、爲你 Golang 日誌統一格式

• JSON 格式的結構優點
• 標準化 Golang 日誌

三、Golang 日誌上下文的力量

四、 Golang 日誌對性能的影響

• 不要在 Goroutine 中使用日誌
• 使用異步庫
• 使用嚴重等級管理 Golang 日誌

五、集中化 Golang 日誌

六、但願你享受你的 Golang 日誌之旅

你是否厭煩了那些使用複雜語言編寫的、難以部署的、老是在不停構建的解決方案？Golang 是解決這些問題的好方法，它和 C 語言同樣快，又和 Python 同樣簡單。

可是你是如何使用 Golang 日誌監控你的應用程序的呢？Golang 沒有異常，只有錯誤。所以你的第一印象可能就是開發 Golang 日誌策略並非一件簡單的事情。不支持異常事實上並非什麼問題，異常在不少編程語言中已經失去了其異常性：它們過於被濫用以致於它們的做用都被忽視了。

在進一步深刻以前，咱們首先會介紹 Golang 日誌的基礎，並討論 Golang 日誌標準、元數據意義、以及最小化 Golang 日誌對性能的影響。經過日誌，你能夠追蹤用戶在你應用中的活動，快速識別你項目中失效的組件，並監控整體性能以及用戶體驗。

 Golang 日誌基礎

1) 使用 Golang 「log」 庫

Golang 給你提供了一個稱爲 「log」 的原生日誌庫[1] 。它的日誌器完美適用於追蹤簡單的活動，例如經過使用可用的選項[2]在錯誤信息以前添加一個時間戳。

下面是一個 Golang 中如何記錄錯誤日誌的簡單例子：

package main

import (

    "log"

    "errors"

    "fmt"

    )

func main() {

   /* 定義局部變量 */

  ...

   /* 除法函數，除以 0 的時候會返回錯誤 */

   ret,err = div(a, b)

if err != nil {

 log.Fatal(err)

    }

    fmt.Println(ret)

}

若是你嘗試除以 0，你就會獲得相似下面的結果：

2020/02/24 16:13:30 division by zero

你能夠在這裏[4]找到 Golang 日誌的完整指南，以及 「log」 庫[5]內可用函數的完整列表。

如今你就能夠記錄它們的錯誤以及根本緣由啦。

另外，日誌也能夠幫你將活動流拼接在一塊兒，查找須要修復的錯誤上下文，或者調查在你的系統中單個請求如何影響其它應用層和 API。

爲了得到更好的日誌效果，你首先須要在你的項目中使用盡量多的上下文豐富你的 Golang 日誌，並標準化你使用的格式。這就是 Golang 原生庫能達到的極限。使用最普遍的庫是 glog[6] 和 logrus[7]。必須認可還有不少好的庫可使用。若是你已經在使用支持 JSON 格式的庫，你就不須要再換其它庫了，後面咱們會解釋。

爲你 Golang 日誌統一格式

1) JSON 格式的結構優點

在一個項目或者多個微服務中結構化你的 Golang 日誌多是最困難的事情，但一旦完成就很輕鬆了。結構化你的日誌能使機器可讀（參考咱們 收集日誌的最佳實踐博文[8]）。靈活性和層級是 JSON 格式的核心，所以信息可以輕易被人類和機器解析以及處理。

下面是一個使用 Logrus/Logmatic.io[9] 如何用 JSON 格式記錄日誌的例子：

package main

import (

        "log"

        "os"

)

func main() {

        // 按照所需讀寫權限建立文件

        f, err := os.OpenFile("filename", os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0644)

        if err != nil {

                log.Fatal(err)

        }   

        // 完成後延遲關閉，而不是習慣!

        defer f.Close()

        //設置日誌輸出到 f

        log.SetOutput(f)

        //測試用例

        log.Println("check to make sure it works")

}

會輸出結果：

package main

import (

  log "github.com/Sirupsen/logrus"

  "github.com/logmatic/logmatic-go"

)

func main() {

    // 使用 JSONFormatter

    log.SetFormatter(&logmatic.JSONFormatter{})

        // 使用 logrus 像往常那樣記錄事件

    log.WithFields(log.Fields{"string": "foo", "int": 1, "float": 1.1 }).Info("My first ssl event from golang")

}

2) 標準化 Golang 日誌

同一個錯誤出如今你代碼的不一樣部分，卻以不一樣形式被記錄下來是一件可恥的事情。下面是一個因爲一個變量錯誤致使沒法肯定 web 頁面加載狀態的例子。一個開發者日誌格式是：

message: 'unknown error: cannot determine loading status from unknown error: missing or invalid arg value client'</span>

另外一我的的格式倒是：

unknown error: cannot determine loading status - invalid client</span>

強制日誌標準化的一個好的解決辦法是在你的代碼和日誌庫之間建立一個接口。這個標準化接口會包括全部你想添加到你日誌中的可能行爲的預約義日誌消息。這麼作能夠防止出現不符合你想要的標準格式的自定義日誌信息。這麼作也便於日誌調查。

 

因爲日誌格式都被統一處理，使它們保持更新也變得更加簡單。若是出現了一種新的錯誤類型，它只須要被添加到一個接口，這樣每一個組員都會使用徹底相同的信息。

最常使用的簡單例子就是在 Golang 日誌信息前面添加日誌器名稱和 id。你的代碼而後就會發送 「事件」 到你的標準化接口，它會繼續講它們轉化爲 Golang 日誌消息。

// 主要部分，咱們會在這裏定義全部消息。

// Event 結構體很簡單。爲了當全部信息都被記錄時能檢索它們，

// 咱們維護了一個 Id

var (

    invalidArgMessage = Event{1, "Invalid arg: %s"}

    invalidArgValueMessage = Event{2, "Invalid arg value: %s => %v"}

    missingArgMessage = Event{3, "Missing arg: %s"}

)

// 在咱們應用程序中可使用的全部日誌事件

func (l *Logger)InvalidArg(name string) {

    l.entry.Errorf(invalidArgMessage.toString(), name)

}

func (l *Logger)InvalidArgValue(name string, value interface{}) {

    l.entry.WithField("arg." + name, value).Errorf(invalidArgValueMessage.toString(), name, value)

}

func (l *Logger)MissingArg(name string) {

    l.entry.Errorf(missingArgMessage.toString(), name)

}

所以若是咱們使用前面例子中無效的參數值，咱們就會獲得類似的日誌信息：

time="2017-02-24T23:12:31+01:00" level=error msg="LoadPageLogger00003 - Missing arg: client - cannot determine loading status" arg.client=<nil> logger.name=LoadPageLogger

JSON 格式以下：

{"arg.client":null,"level":"error","logger.name":"LoadPageLogger","msg":"LoadPageLogger00003 - Missing arg: client - cannot determine loading status", "time":"2017-02-24T23:14:28+01:00"}

Golang 日誌上下文的力量

如今 Golang 日誌已經按照特定結構和標準格式記錄，時間會決定須要添加哪些上下文以及相關信息。爲了能從你的日誌中抽取信息，例如追蹤一個用戶活動或者工做流，上下文和元數據的順序很是重要。

例如在 logrus 庫中能夠按照下面這樣使用 JSON 格式添加 hostname、appname 和 session 參數：

// 對於元數據，一般作法是經過複用來重用日誌語句中的字段。

  contextualizedLog := log.WithFields(log.Fields{

    "hostname": "staging-1",

    "appname": "foo-app",

    "session": "1ce3f6v"

  })

contextualizedLog.Info("Simple event with global metadata")

元數據能夠視爲 javascript 片斷。爲了更好地說明它們有多麼重要，讓咱們看看幾個 Golang 微服務中元數據的使用。你會清楚地看到是怎麼在你的應用程序中跟蹤用戶的。這是由於你不只須要知道一個錯誤發生了，還要知道是哪一個實例以及什麼模式致使了錯誤。假設咱們有兩個按順序調用的微服務。上下文信息保存在頭部（header）中傳輸：

func helloMicroService1(w http.ResponseWriter, r *http.Request) {

client := &http.Client{}

// 該服務負責接收全部到來的用戶請求

// 咱們會檢查是不是一個新的會話仍是已有會話的另外一次調用

session := r.Header.Get("x-session")

if ( session == "") {

session = generateSessionId()

// 爲新會話記錄日誌

}

// 每一個請求的 Track Id 都是惟一的，所以咱們會爲每一個會話生成一個

track := generateTrackId()

// 調用你的第二個微服務，添加 session/track

reqService2, _ := http.NewRequest("GET", "http://localhost:8082/", nil)

reqService2.Header.Add("x-session", session)

reqService2.Header.Add("x-track", track)

resService2, _ := client.Do(reqService2)

….

當調用第二個服務時：

func helloMicroService2(w http.ResponseWriter, r *http.Request) {

// 相似以前的微服務，咱們檢查會話並生成新的 track

session := r.Header.Get("x-session")

track := generateTrackId()

// 這一次，咱們檢查請求中是否已經設置了一個 track id，

// 若是是，它變爲父 track

parent := r.Header.Get("x-track")

if (session == "") {

w.Header().Set("x-parent", parent)

}

// 爲響應添加 meta 信息

w.Header().Set("x-session", session)

w.Header().Set("x-track", track)

if (parent == "") {

w.Header().Set("x-parent", track)

}

// 填充響應

w.WriteHeader(http.StatusOK)

io.WriteString(w, fmt.Sprintf(aResponseMessage, 2, session, track, parent))

}

如今第二個微服務中已經有和初始查詢相關的上下文和信息，一個 JSON 格式的日誌消息看起來相似以下。

在第一個微服務：

{"appname":"go-logging","level":"debug","msg":"hello from ms 1","session":"eUBrVfdw","time":"2017-03-02T15:29:26+01:00","track":"UzWHRihF"}

在第二個微服務：

{"appname":"go-logging","level":"debug","msg":"hello from ms 2","parent":"UzWHRihF","session":"eUBrVfdw","time":"2017-03-02T15:29:26+01:00","track":"DPRHBMuE

若是在第二個微服務中出現了錯誤，多虧了 Golang 日誌中保存的上下文信息，如今咱們就能夠肯定它是怎樣被調用的以及什麼模式致使了這個錯誤。

若是你想進一步深挖 Golang 的追蹤能力，這裏還有一些庫提供了追蹤功能，例如 Opentracing[10]。這個庫提供了一種簡單的方式在或複雜或簡單的架構中添加追蹤的實現。它經過不一樣步驟容許你追蹤用戶的查詢，就像下面這樣：

 

Golang 日誌對性能的影響

1) 不要在 Goroutine 中使用日誌

在每一個 goroutine 中建立一個新的日誌器看起來很誘人。但最好別這麼作。Goroutine 是一個輕量級線程管理器，它用於完成一個 「簡單的」 任務。所以它不該該負責日誌。它可能致使併發問題，由於在每一個 goroutine 中使用 log.New()會重複接口，全部日誌器會併發嘗試訪問同一個 io.Writer。

爲了限制對性能的影響以及避免併發調用 io.Writer，庫一般使用一個特定的 goroutine 用於日誌輸出。

2) 使用異步庫

儘管有不少可用的 Golang 日誌庫，要注意它們中的大部分都是同步的（事實上是僞異步）。緣由極可能是到如今爲止它們中沒有一個會因爲日誌嚴重影響性能。

但正如 Kjell Hedström 在他的實驗[11]中展現的，使用多個線程建立成千上萬日誌，即使是在最壞狀況下，異步 Golang 日誌也會有 40% 的性能提高。所以日誌是有開銷的，也會對你的應用程序性能產生影響。若是你並不須要處理大量的日誌，使用僞異步 Golang 日誌庫可能就足夠了。但若是你須要處理大量的日誌，或者很關注性能，Kjell Hedström 的異步解決方案就頗有趣（儘管事實上你可能須要進一步開發，由於它只包括了最小的功能需求）。

3）使用嚴重等級管理 Golang 日誌

一些日誌庫容許你啓用或停用特定的日誌器，這可能會派上用場。例如在生產環境中你可能不須要一些特定等級的日誌。下面是一個如何在 glog 庫中停用日誌器的例子，其中日誌器被定義爲布爾值：

type Log bool

func (l Log) Println(args ...interface{}) {

    fmt.Println(args...)

}

var debug Log = false

if debug {

    debug.Println("DEBUGGING")

}

而後你就能夠在配置文件中定義這些布爾參數來啓用或者停用日誌器。

沒有一個好的 Golang 日誌策略，Golang 日誌可能開銷很大。開發人員應該抵制記錄幾乎全部事情的誘惑 - 儘管它很是有趣！若是日誌的目的是爲了獲取儘量多的信息，爲了不包含無用元素的日誌的白噪音，必須正確使用日誌。

集中化 Golang 日誌

 

若是你的應用程序是部署在多臺服務器上的，這樣能夠避免爲了調查一個現象須要鏈接到每一臺服務器的麻煩。日誌集中確實有用。

使用日誌裝箱工具，例如 windows 中的 Nxlog，linux 中的 Rsyslog（默認安裝了的）、Logstash 和 FluentD 是最好的實現方式。日誌裝箱工具的惟一目的就是發送日誌，所以它們可以處理鏈接失效以及其它你極可能會遇到的問題。

這裏甚至有一個 Golang syslog 軟件包[12] 幫你將 Golang 日誌發送到 syslog 守護進程。

但願你享受你的 Golang 日誌之旅

在你項目一開始就考慮你的 Golang 日誌策略很是重要。若是在你代碼的任意地方均可以得到全部的上下文，追蹤用戶就會變得很簡單。從不一樣服務中閱讀沒有標準化的日誌是已經很痛苦的事情。一開始就計劃在多個微服務中擴展相同用戶或請求 id，後面就會容許你比較容易地過濾信息並在你的系統中跟蹤活動。

你是在構架一個很大的 Golang 項目仍是幾個微服務也會影響你的日誌策略。一個大項目的主要組件應該有按照它們功能命名的特定 Golang 日誌器。這使你能夠當即判斷出日誌來自你的哪一部分代碼。然而對於微服務或者小的 Golang 項目，只有較少的核心組件須要它們本身的日誌器。但在每種情形中，日誌器的數目都應該保持低於核心功能的數目。

你如今已經可使用 Golang 日誌量化決定你的性能或者用戶滿意度啦！

今晚爲你詳細講解直播，添加小助手wechat：17812796384 獲取直播連接