线上服务，需要记录日志量比较大，便于排查问题，同时，线上要求所有日志需要经过rsyslog 灌到kafka 中去，我们日志需要按规定格式序列化。我们使用的log库是 "github.com/Sirupsen/logrus"。 那么问题来了，golang 的序列化性能真的是一言难尽。
从网上资料来看，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 序列化性能下降的如此厉害，需要从源码角度分析，下次有空再分析。
有疑问加站长微信联系（非本文作者）
