大幅提高 golang 寫日誌序列化性能實踐

時間 2019-11-12

標籤大幅提高 golang 日誌序列性能實踐欄目 Go 简体版

原文原文鏈接

線上服務，須要記錄日誌量比較大，便於排查問題，同時，線上要求全部日誌須要通過rsyslog 灌到kafka 中去，咱們日誌須要按規定格式序列化。咱們使用的log庫是 "github.com/Sirupsen/logrus"。那麼問題來了，golang 的序列化性能真的是一言難盡。git

該文章後續仍在不斷的更新修改中，請移步到原文地址http://dmwan.ccgithub

從網上資料來看，Protocol Buffers 性能好於json，而使用json 的話，有個很經典的性能對比圖，golang

具體數據不過重要，結論就是官方的json 最差，滴滴開源的json 庫大體是目前市面最好。而後咱們就列出了幾個方案。json

第一個方案，使用monkey patch ，替換到系統的encoding/json。第二個方案是直接在log 模塊中直接重寫json formater 。因爲第一種方式會致使調試的時候調用棧錯亂，咱們重寫了json formater。然而，真的如你們認爲的同樣，使用jsoniter 性能會有至少一倍以上提高嗎？答案是不必定！bash

通過咱們pprof 分析，咱們替代json庫後的圖像以下：app

從時間上看，序列化花了9.3s，這時間是不能忍受的。而後，出於疑問，我將原始json formater 的調用棧圖也打出來了，以下：性能

結果很是神奇，原生的encoding/json 打日誌居然比滴滴開源的這個庫還要快？而後開源的庫是有問題的？仍是我本身有問題？帶着疑惑看了下咱們本身實現的json formater 和官方的benchmark。測試

咱們的json formater 以下：優化

package libs

import (
	"fmt"
	"github.com/json-iterator/go"
	"github.com/sirupsen/logrus"
	"strings"
)

type fieldKey string

// FieldMap allows customization of the key names for default fields.
type FieldMap map[fieldKey]string

// Fields type, used to pass to `WithFields`.
type Fields map[string]interface{}

// JSONFormatter formats logs into parsable json
type JSONFormatter struct {
	// TimestampFormat sets the format used for marshaling timestamps.
	TimestampFormat string

	// DisableTimestamp allows disabling automatic timestamps in output
	DisableTimestamp bool

	FieldMap FieldMap

	Service string
}

func NewJSONFormatter(service string) *JSONFormatter {
	format := JSONFormatter{Service: service}
	return &format
}

// Format renders a single log entry
func (f *JSONFormatter) Format(entry *logrus.Entry) ([]byte, error) {
	data := make(Fields, len(entry.Data)+3)
	data["service"] = f.Service
	data["msg"] = entry.Message
	data["task_id"] = ""
	if temp, ok := entry.Data["task_id"]; ok {
		data["task_id"] = temp.(string)
	}
	data["log_date"] = entry.Time.Format("2006-01-02T15:04:05+08:00")

	var json = jsoniter.ConfigCompatibleWithStandardLibrary
	serialized, err := json.Marshal(&data)
	if err != nil {
		return nil, fmt.Errorf("Failed to marshal fields to JSON, %v", err)
	}
	return append(serialized, '\n'), nil
}

這裏的json formater 是沒有問題的和 git 上原生的基本如出一轍。調試

而後，咱們看了下jsoniter 的官方benchmark ，跑了下，的確是比官方json 性能高一倍以上！問題來了，官方使用的是struct，而logrus 使用的是map，這個是不是關鍵？

本身實現了個demo，簡單的測試了下：

package main
import (
    "time"
    "fmt"
    "github.com/json-iterator/go"
    "encoding/json"
)

type Data struct {
    ceshi string
    ceshi1 string
    ceshi2 string
    ceshi3 string
}

var datamap map[string]string

func main() {

    data := Data{
        ceshi: "ceshi111111111111111111111111111111111111111",
        ceshi1: "ceshi111111111111111111111111111111111111111",
        ceshi2: "ceshi111111111111111111111111111111111111111",
        ceshi3: "ceshi111111111111111111111111111111111111111",
    }
    t1 := time.Now()
    for i:=0; i<100000; i++{
        json.Marshal(&data)
    }
    cost := time.Since(t1).Nanoseconds()
    fmt.Printf("encoding/json, using struct %v\n", cost)

    var jsoner = jsoniter.ConfigCompatibleWithStandardLibrary
    t2 := time.Now()
    for i:=0; i<100000; i++{
        jsoner.Marshal(&data)
    }
    cost = time.Since(t2).Nanoseconds()
    fmt.Printf("json-iterator, using struct %v\n", cost)

    data1 := map[string]string{}
    data1["ceshi"] = "ceshi111111111111111111111111111111111111111"
    data1["ceshi1"] = "ceshi111111111111111111111111111111111111111"
    data1["cesh2"] = "ceshi111111111111111111111111111111111111111"
    data1["ceshi3"] = "ceshi111111111111111111111111111111111111111"

    t3 := time.Now()
    for i:=0; i<100000; i++{
          json.Marshal(&data1)
    }
    cost = time.Since(t3).Nanoseconds()
    fmt.Printf("encoding/json,using map %v\n", cost)

    t4 := time.Now()
    for i:=0; i<100000; i++{
        jsoner.Marshal(&data1)
    }
    cost = time.Since(t4).Nanoseconds()
    fmt.Printf("json-iterator, using map %v\n", cost)
}

輸出結果以下：

encoding/json, using struct 20051594
json-iterator, using struct 15108556
encoding/json,using map 224949830
json-iterator, using map 195824204

結果是使用struct 序列化，性能比使用map 好一個數量級，無論是使用標準庫仍是iterator，在一樣對struct marshl的狀況下，json-iterator 性能好於encoding/json。

由此，關鍵點就很是明確了，當咱們事先json formater 的時候，不能照着官方源碼抄，或者直接使用官方的json formater,這都是有極大問題的。想下其實也能理解，咱們寫日誌的時候key 是不定的，因此只能使用map。

下面是咱們修改的json formater:

package logging

import (
	"fmt"
	"github.com/json-iterator/go"
	"github.com/Sirupsen/logrus"
)

type fieldKey string

// FieldMap allows customization of the key names for default fields.
type FieldMap map[fieldKey]string

// Fields type, used to pass to `WithFields`.
type Fields map[string]interface{}

// JSONFormatter formats logs into parsable json
type JSONFormatter struct {
	// TimestampFormat sets the format used for marshaling timestamps.
	TimestampFormat string

	// DisableTimestamp allows disabling automatic timestamps in output
	DisableTimestamp bool

	FieldMap FieldMap

	Service string
}

func NewJSONFormatter(service string) *JSONFormatter {
	format := JSONFormatter{Service: service}
	return &format
}

//根據須要，將結構體的key 設置成本身須要的
type Data struct {
	Service string	`json:"service"`
	Msg		string	`json:"msg"`
	TaskId	string	`json:"task_id"`
	LogData	string	`json:"log_date"`
}

// Format renders a single log entry
func (f *JSONFormatter) Format(entry *logrus.Entry) ([]byte, error) {
	data := Data{
		Service: f.Service,
		Msg: entry.Message,
		TaskId: "",
	}
	if temp, ok := entry.Data["task_id"]; ok {
		data.TaskId = temp.(string)
	}
	data.LogData = entry.Time.Format("2006-01-02T15:04:05+08:00")

	var json = jsoniter.ConfigCompatibleWithStandardLibrary
	serialized, err := json.Marshal(&data)
	if err != nil {
		return nil, fmt.Errorf("Failed to marshal fields to JSON, %v", err)
	}
	return append(serialized, '\n'), nil
}

經過以上優化，序列化時間縮短到不到3s：

總結，golang 須要頻繁寫日誌的時候，要麼使用text format ，要麼json format 的時候，特別主要下序列化的對象。具體，爲何json-iterator 對map 序列化性能降低的如此厲害，須要從源碼角度分析，下次有空再分析。