Go 語言日誌指南

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

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

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

I. Golang 日誌基礎

1) 使用 Golang 「log」 庫

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

下面是一個 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，你就會得到類似下面的結果：

為了快速測試一個 Golang 函數，你可以使用 go playground。

為了確保你的日誌總是能輕易訪問，我們建議你把它們寫到一個文件：

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")
}

你可以在這裡找到 Golang 日誌的完整指南，以及 「log」 庫內可用函數的完整列表。

現在你就可以記錄它們的錯誤以及根本原因啦。

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

為了獲得更好的日誌效果，你首先需要在你的項目中使用儘可能多的上下文豐富你的 Golang 日誌，並標準化你使用的格式。這就是 Golang 原生庫能達到的極限。使用最廣泛的庫是 glog 和 logrus。必須承認還有很多好的庫可以使用。如果你已經在使用支持 JSON 格式的庫，你就不需要再換其它庫了，後面我們會解釋。

II. 為你 Golang 日誌統一格式

1) JSON 格式的結構優勢

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

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

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")
}

會輸出結果：

{   
    "date":"2016-05-09T10:56:00+02:00",
    "float":1.1,
    "int":1,
    "level":"info",
    "message":"My first ssl event from golang",
    "String":"foo"
}

2) 標準化 Golang 日誌

同一個錯誤出現在你代碼的不同部分，卻以不同形式被記錄下來是一件可恥的事情。下面是一個由於一個變數錯誤導致無法確定 web 頁面載入狀態的例子。一個開發者日誌格式是：

message: &apos;unknown error: cannot determine loading status from unknown error: missing or invalid arg value client&apos;</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"}

III. 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。這個庫提供了一種簡單的方式在或複雜或簡單的架構中添加追蹤的實現。它通過不同步驟允許你追蹤用戶的查詢，就像下面這樣：

IV. Golang 日誌對性能的影響

1) 不要在 Goroutine 中使用日誌

在每個 goroutine 中創建一個新的日誌器看起來很誘人。但最好別這麼做。Goroutine 是一個輕量級線程管理器，它用於完成一個 「簡單的」 任務。因此它不應該負責日誌。它可能導致並發問題，因為在每個 goroutine 中使用 log.New() 會重複介面，所有日誌器會並發嘗試訪問同一個 io.Writer。

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

2) 使用非同步庫

儘管有很多可用的 Golang 日誌庫，要注意它們中的大部分都是同步的（事實上是偽非同步）。原因很可能是到現在為止它們中沒有一個會由於日誌嚴重影響性能。

但正如 Kjell Hedström 在他的實驗中展示的，使用多個線程創建成千上萬日誌，即便是在最壞情況下，非同步 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 日誌可能開銷很大。開發人員應該抵制記錄幾乎所有事情的誘惑 - 儘管它非常有趣！如果日誌的目的是為了獲取儘可能多的信息，為了避免包含無用元素的日誌的白噪音，必須正確使用日誌。

V. 集中化 Golang 日誌

如果你的應用程序是部署在多台伺服器上的，這樣可以避免為了調查一個現象需要連接到每一台伺服器的麻煩。日誌集中確實有用。

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

這裡甚至有一個 Golang syslog 軟體包 幫你將 Golang 日誌發送到 syslog 守護進程。

希望你享受你的 Golang 日誌之旅

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

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

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

如果你有想閱讀的特定編程語言，在 Twitter @logmatic 上告訴我們吧。

via: https://logmatic.io/blog/our-guide-to-a-golang-logs-world/

作者：Nils 譯者：ictlyh 校對：wxy

本文由 LCTT 原創編譯，Linux中國 榮譽推出

本文轉載來自 Linux 中國: https://github.com/Linux-CN/archive