大幅提升 golang 写日志序列化性能实践

原创
2018/03/27 18:35
阅读数 6.9K

    线上服务,需要记录日志量比较大,便于排查问题,同时,线上要求所有日志需要经过rsyslog 灌到kafka 中去,我们日志需要按规定格式序列化。我们使用的log库是 "github.com/Sirupsen/logrus"。 那么问题来了,golang 的序列化性能真的是一言难尽。

该文章后续仍在不断的更新修改中, 请移步到原文地址http://dmwan.cc

    从网上资料来看,Protocol Buffers  性能好于json, 而使用json 的话,有个很经典的性能对比图,

    

    具体数据不太重要,结论就是 官方的json 最差,滴滴开源的json 库大致是目前市面最好。然后我们就列出了几个方案。

    第一个方案,使用monkey patch ,替换到系统的encoding/json。 第二个方案是直接在log 模块中直接重写json formater 。由于第一种方式会导致调试的时候调用栈错乱,我们重写了json formater。 然而,真的如大家认为的一样,使用jsoniter 性能会有至少一倍以上提升吗?答案是不一定!

    经过我们pprof 分析,我们替代json库后的图像如下:

    

从时间上看,序列化花了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 序列化性能下降的如此厉害,需要从源码角度分析,下次有空再分析。

展开阅读全文
打赏
2
11 收藏
分享
加载中
caucy博主
我测试的时候,当时用的go 版本比较低,go1.8 及其以前的版本官方的json 性能差,但是1.10 以后,其实两个序列化的效果基本没太大区别了
2019/02/28 16:52
回复
举报
在比较性能的时候,我直接采用楼主你的代码,但是跑出的结果是不一样的。显示的是,原生的json效果貌似更快。
encoding/json, using struct 15380099
json-iterator, using struct 15821046
encoding/json,using map 164310037
json-iterator, using map 167692826

而在我采用banckmark的时候,得到的结果是,jsoniter更快,不是很懂为什么。
BenchmarkJsonStruct-4 100 18815895 ns/op 4000771 B/op 200003 allocs/op
BenchmarkJsoniterStruct-4 100 16342666 ns/op 3400887 B/op 200003 allocs/op
BenchmarkJsonMap-4 20 88123650 ns/op 44805954 B/op 1100023 allocs/op
BenchmarkJsoniterMap-4 20 80661203 ns/op 46416087 B/op 1100079 allocs/op
2019/02/28 16:44
回复
举报
更多评论
打赏
2 评论
11 收藏
2
分享
返回顶部
顶部