深入 Operator 日誌框架，實現一個高性能的 Operator

讓我們用Operator日誌記錄來展開我們的主題。不同於最常見的打印方法fmt.Printf，它不會在消息中打印具體的參數信息，而是單獨在日誌中打印，比如JSON字符串。

{"severity":"INFO","eventTime":"2022-07-09T09:04:55.260Z","logger":"controller.opresource","message":"Deleting OpResource, because it is no longer in scope!","reconciler group":"op.spotify.com","reconciler kind":"OpResource","name":"afs-proxy-0618bce","namespace":"","name":"afs-proxy"}

這是Operator日誌打印的規範方式嗎? 讓我們通過深入研究Operator日誌框架的實現和使用細節來揭示答案。

Log in operator

controller-runtime alias.go提供了一個默認的Log對象，默認情況下由go-logr執行該對象的實現

// Log is the base logger used by controller-runtime.  It delegates
// to another logr.Logger.  You *must* call SetLogger to
// get any actual logging.
Log = log.Log

Go-logr是一個簡單的日誌框架，它本身沒有日誌輸出功能，而是對Dave Cheney提出的Go日誌分類的進一步優化。

一般情況下，一個Go程序只需要兩個級別的日誌:INFO和ERROR; 而其他層次並不重要。對於調試，它提供v級輸出，放棄跟蹤或調試等其他級別。

它的實現包括Logr和LogSink接口，任何外部日誌框架都可以通過實現LogSink來集成Logr。

在默認的controller-runtime中，DelegatingLogSink被實現爲默認的Logr日誌輸出，其中logger使用簡單的NullLogSink。這個默認實現對於大多數場景已經足夠了，並且可以與fmt.Sprintf結合使用。

log.V(10).Info(fmt.Sprintf("Create Resources for User:%s, Project:%s", user, project))

然而， DelegatingLogSink有一個明顯的缺陷：當它被部署爲集羣範圍的控制器並管理數千個資源時，它的低效率是一個性能瓶頸。以下兩個是導致其效率低下的主要原因。

它使用了很多鎖 。DelegatingLogSink使用一個 promisesLock互斥鎖，並且兩者 WithName和 WithValues的方法 loggerPromise需要鎖，甚至 Enable, Info和 Error函數依賴於 RLock，讀鎖。毫無疑問，在具有大量寫入操作的日誌輸出中頻繁鎖定，即使使用讀鎖定，也會導致性能下降。

func (l *DelegatingLogSink) Info(level int, msg string,keysAndValues ...interface{}) {
  l.lock.RLock()
  defer l.lock.RUnlock()
  l.logger.Info(level, msg, keysAndValues...)
}

日誌內容使用的是fmt.Sprintf。我們使用字符串。Join或Buffer操作來替換fmt.Sprintf和+連接字符串，以提高許多Go字符串操作的效率 (閱讀golang中的連接字符串快速基準:+或fmt.Sprintf瞭解更多)。但是在編寫日誌時，我們確實希望從日誌框架中免費獲得這一點，而不是重新創建輪子，這是logr和controller-runtime的默認實現無法提供的。

其他選項

如果我們放棄默認實現，還有其他選項嗎? 如何切換?

Go社區提供了廣泛的日誌包，甚至本地的也可以滿足基本的日誌輸出需求。

在《A Sip of Go Log》中，我們深入挖掘了日誌的基本邏輯，並比較了一些流行的日誌開源包，其中Uber的zap以其性能吸引了我們的眼球。讓我們回顧一下這些驚人的數字，看看zap是否是最好的選擇。

controller-runtime已經有了默認的zapr實現，它已經在內部的很多地方被使用了。但爲什麼不將它用作默認實現呢?

用戶可以通過定製一個Logger來集成zap，以實現某些附加功能，如時間轉換、日誌輸出到外部存儲等，controller-runtime將其封裝爲一個Logger。Logger最終在zap控制器運行時實現。

按照以下四個步驟定義zap Logger。

zap.go實現了console和json兩種編碼器，並提供了zapr標準Logger所需的功能，如WriteTo和Level。

默認情況下，zapr採用consoleEncoder和debugLevel/warnLevelin開發模式，而使用jsonencoder和infollevel /errorLevelin生產。

至於替換這個Operator中的默認Logr，在初始化main方法中的Reconciler 時，我們只需要使用Log: zap.New()，然後我們可以按以下模式在控制器中打印日誌。

func log(ctx context.Context) {
  log.FromContext(ctx).Info("message", "param1", param1, "param2", param2 ...)
  log.FromContext(ctx).Error(err, "message", "param1", param1, "param2", param2 ...)
}

爲什麼 zap 這麼快

zap採取的5個步驟 (每個步驟都反映了優化) 主要使用Go的兩個特性，這兩個特性決定了zap的效率。

使用同步。池，以避免輸出日誌時的內存開銷。

日誌。Check是打印的第一步，在Check方法中進行了兩項性能優化。

避免不必要的操作，如跳過不必要的日誌級別，直接返回不需要打印的日誌。例如，如果我們的日誌級別是Info，那麼一旦出現調試級別日誌，它就直接返回。重用Entry對象。zap構造一個真正打印的Entry對象，它將被Checked，以便在同步保存的對象中重用它。池，降低高頻日誌對象的創建和消除頻率，最終減少GC。

func getCheckedEntry() *CheckedEntry {
  ce := _cePool.Get().(*CheckedEntry)
  ce.reset()
  return ce
}

每次寫後更新池

func (ce *CheckedEntry) Write(fields ...Field) {
  //…
  putCheckedEntry(ce)
}

在輸出日誌時，我們還使用同步。內存優化池。默認的consoleEncoder和jsonEncoder都將打印的信息存儲在buffer中，buffer使用sync構建的bufferPool。池中獲取一個對象，並通過下面的拼接獲得最終的輸出日誌。

// console_encoder.go
func (c consoleEncoder) EncodeEntry(ent Entry, fields []Field) (*buffer.Buffer, error) {5 years ago • Akshay Shah [Fix allocation when returning []byte to pool …]
 line := bufferpool.Get()
  // ... 
}

// json_encoder.go
func (enc *jsonEncoder) clone() *jsonEncoder {
 clone := getJSONEncoder()
 clone.EncoderConfig = enc.EncoderConfig
 clone.spaced = enc.spaced
 clone.openNamespaces = enc.openNamespaces
 clone.buf = bufferpool.Get()
 return clone
}

func (enc *jsonEncoder) EncodeEntry(ent Entry, fields []Field) (*buffer.Buffer, error) {5 years ago • Akshay Shah [Fix allocation when returning []byte to pool …]
 final := enc.clone()
  //...
}

// buffer.Pool
type Pool struct {
 p *sync.Pool
}

// NewPool constructs a new Pool.
func NewPool() Pool {
 return Pool{p: &sync.Pool{
  New: func() interface{} {
   return &Buffer{bs: make([]byte, 0, _size)}
  },
 }}
}

func (p Pool) Get() *Buffer {5 years ago • Akshay Shah [Expose Buffer pools to third-party encoders (…]
 buf := p.p.Get().(*Buffer)
 buf.Reset()
 buf.pool = p
 return buf
}

避免使用interface{}設計api和優化JSON序列化。通過強類型設計和零內存開銷實現JSON序列化。

在zap的日誌輸出中，JSON格式是最終統一的輸出格式，甚至console_encoder也最終調用json_encoder來打印字段。Fields結構設計顯著提高了日誌打印的速度，並用於定義每個輸入參數的類型信息，以快速將類型轉換爲字符串。並且在Field的AddTo方法中定義了所有可能的類型和字符串之間的轉換，避免了zap的類型推斷和反射，大大提高了輸出效率。

// zap console_encoder.go
func (c consoleEncoder) writeContext(line *buffer.Buffer, extra []Field) {
 context := c.jsonEncoder.Clone().(*jsonEncoder)
 defer func() {
  // putJSONEncoder assumes the buffer is still used, but we write out the buffer so
  // we can free it.
  context.buf.Free()
  putJSONEncoder(context)
 }()

 addFields(context, extra)
  // ...
}

func addFields(enc ObjectEncoder, fields []Field) {
 for i := range fields {
  fields[i].AddTo(enc)
 }
}

// Field.go
type Field struct {
 Key       string
 Type      FieldType
 Integer   int64
 String    string
 Interface interface{}
}

// AddTo exports a field through the ObjectEncoder interface. It's primarily
// useful to library authors, and shouldn't be necessary in most applications.
func (f Field) AddTo(enc ObjectEncoder) {
 var err error

 switch f.Type {
 case ArrayMarshalerType:
  err = enc.AddArray(f.Key, f.Interface.(ArrayMarshaler))
 case ObjectMarshalerType:
  err = enc.AddObject(f.Key, f.Interface.(ObjectMarshaler))
 case InlineMarshalerType:
  err = f.Interface.(ObjectMarshaler).MarshalLogObject(enc)
 case BinaryType:
  enc.AddBinary(f.Key, f.Interface.([]byte))
 case BoolType:
  enc.AddBool(f.Key, f.Integer == 1)
 case ByteStringType:
  enc.AddByteString(f.Key, f.Interface.([]byte))
  // more type convert func
}

當然，不要忘記釋放在bufferPool中獲得的對象!

性能測試

讓一個基準測試來驗證zap的出色性能。

import (
 "fmt"
 "testing"

 "github.com/go-logr/logr"
 "github.com/go-logr/logr/funcr"
 "sigs.k8s.io/controller-runtime/pkg/log"
 "sigs.k8s.io/controller-runtime/pkg/log/zap"
)

//go:noinline
func doInfoOneArg(b *testing.B, log logr.Logger) {
 for i := 0; i < b.N; i++ {
  log.Info("this is", "a", "string")
 }
}

//go:noinline
func doInfoSeveralArgs(b *testing.B, log logr.Logger) {
 for i := 0; i < b.N; i++ {
  log.Info("multi",
   "bool", true, "string", "str", "int", 42,
   "float", 3.14, "struct", struct{ X, Y int }{93, 76})
 }
}

// Default Logr
func BenchmarkDiscardLogInfoOneArg(b *testing.B) {
 var log logr.Logger = logr.Discard()
 doInfoOneArg(b, log)
}

// DKL: Default Kubernetes controllerruntime Logr
func BenchmarkDiscardLogInfoOneArgDKL(b *testing.B) {
 var log logr.Logger = log.Log
 doInfoOneArg(b, log)
}

// KLZ: Kubernetes controllerruntime ZapLogr
func BenchmarkDiscardLogInfoOneArgKLZ(b *testing.B) {
 var log logr.Logger = zap.New()
 doInfoOneArg(b, log)
}

func BenchmarkDiscardLogInfoSeveralArgs(b *testing.B) {
 var log logr.Logger = logr.Discard()
 doInfoSeveralArgs(b, log)
}

func BenchmarkDiscardLogInfoSeveralArgsDKL(b *testing.B) {
 var log logr.Logger = log.Log
 doInfoSeveralArgs(b, log)
}

func BenchmarkDiscardLogInfoSeveralArgsKLZ(b *testing.B) {
 var log logr.Logger = zap.New()
 doInfoSeveralArgs(b, log)
}

// output:
BenchmarkDiscardLogInfoOneArg-16               34606057         34.10 ns/op       32 B/op        1 allocs/op
BenchmarkDiscardLogInfoOneArgDKL-16            23754621         47.12 ns/op       32 B/op        1 allocs/op
BenchmarkDiscardLogInfoOneArgKLZ-16             4568048           284.3 ns/op       32 B/op        1 allocs/op
BenchmarkDiscardLogInfoSeveralArgs-16          14577048         102.1 ns/op      176 B/op        2 allocs/op
BenchmarkDiscardLogInfoSeveralArgsDKL-16       12127125         90.31 ns/op      176 B/op        2 allocs/op
BenchmarkDiscardLogInfoSeveralArgsKLZ-16        3421066           386.2 ns/op      180 B/op        2 allocs/op

通過比較這三個日誌包在無參數和多參數場景中的性能，我可以 “自豪地” 宣佈zap是最好的:zap Logr比controller-runtime中的默認Logr快大約 7 倍。

很容易得出這樣的結論: 如果我們想實現一個高性能的Operator，就必須替換默認的Log實現。但是需要注意的是，如果您仍然使用v1，則可能需要將kubebuilder升級到最新的v3版本，這涉及到從klog遷移到logr，請參考結構化和上下文日誌遷移說明以獲得指導。

結構化和上下文日誌遷移: https://github.com/kubernetes/community/blob/HEAD/contributors/devel/sig-instrumentation/migration-to-structured-logging.md#structured-and-contextual-logging-migration-instructions

本文由 Readfog 進行 AMP 轉碼，版權歸原作者所有。
來源：https://mp.weixin.qq.com/s/40Gm8IDBo8qVcjWcaLaXMg