Go编程快闪之logrus日志库

golang中常见的日志包是logrus， 根据logrus的胚子和我们的生产要求，给出一个生产可用的logrus实践姿势。

logrus是一个结构化的、可插拔的、兼容golang标准log api的日志库。

快速过一下能力

• 支持对output=TTY增加关键字颜色
• 内置JSONFormatter和TextFormatter(默认)两种Formatter
• 支持输出logger所在的函数行位置 log.SetReportCaller(true)
• 可以兼容golang内置的标准log库, 建议无脑替换
• 鼓励输出可解析的日志字段，而不是大段的无法结构化的文本日志

log.WithFields(log.Fields{
 "event": event,
 "topic": topic,
 "key": key,
}).Fatal("Failed to send event")

基于现状，凑了6个钱包上生产，下面给出一些自己的生产实践。

1. logrus不支持滚动日志

好马配好鞍 https://github.com/lestrrat-go/file-rotatelogs 让你下雨天不再哭泣。

它会根据配置自动按照时间切分日志，并滚动清理日志(不用配磁盘报警，不用担心磁盘满故障)。

	logf, err := rotatelogs.New(
  	cfg.Log.LogDir+logName+".%Y%m%d%H%M",
  	rotatelogs.WithLinkName(cfg.Log.LogDir+logName),
  	rotatelogs.WithMaxAge(24*time.Hour),
  	rotatelogs.WithRotationTime(time.Hour),
  )
  if err != nil {
  	stdLog.Printf("failed to create rotatelogs: %s", err)
  	return
  }

2. 日志格式化

java生态默认日志输出格式：

11:44:44.827 WARN [93ef3E0120160803114444] [main] [ClassPathXmlApplicationContext] Exception encountered during context initialization - cancelling refresh attempt

在公司中javaer占据主流，故java的默认格式就成了公司集中式日志的"标准"格式。

很明显，logrus默认的两种Formatter都不匹配。

github.com/antonfisher/nested-logrus-formatter 让你柳暗花明。

log.SetFormatter(&nested.Formatter{ // 嵌套日志兼容skynet日志格式
		HideKeys:        true,
		FieldsOrder:     []string{"region", "node", "topic"},
		TimestampFormat: "2006-01-02 15:04:05.000", // 显示ms
	})

3. 自定义Hook用法：输出固定字段

写本文的时候，发现logrus官方本身支持输出默认日志字段。

requestLogger := log.WithFields(log.Fields{"request_id": request_id, "user_ip": user_ip})
requestLogger.Warn("something not great happened")

Hook: 通常 钩子函数用于在触发某种事件时附带一些动作。

logrus的Hook定义:logEntry满足指定的logLevel日志时， 你想要做的动作。
(你甚至可以不设置output直接在hook输出日志，这就是内置write hook的实现)。

type Hook interface {
	Levels() []Level
	Fire(*Entry) error
}

示例代码为logLevel>=info的logEntry，固定了2个日志字段。

type FixedFieldHook struct {
	LogLevels  []logrus.Level
	FixedField map[string]string
}

// Fire will be called when some logging function is called with current hook
// It will format log entry to string and write it to appropriate writer
func (hook *FixedFieldHook) Fire(entry *logrus.Entry) error {
	for k, v := range hook.FixedField {
		entry.Data[k] = v
	}
	return nil
}

log.AddHook(&FixedFieldHook{ // Set fixed field
		FixedField: map[string]string{"region": cfg.LocalRegion, "node": ip},
		LogLevels: []logrus.Level{
			logrus.InfoLevel,
			logrus.ErrorLevel,
			logrus.WarnLevel,
			logrus.FatalLevel,
		},
	})

抛砖引玉，战术卧倒。

使用时是这样：

func initLog(cfg config, logName string, log *logrus.Logger) {
	_, err := os.Stat(cfg.Log.LogDir)
	if os.IsNotExist(err) {
		// stdLod.Debug("folder does not  exists.")
		os.MkdirAll(cfg.Log.LogDir, os.ModeDir)
	}
	logf, err := rotatelogs.New(                             // 基于file形成时间滚动日志
		cfg.Log.LogDir+logName+".%Y%m%d%H%M",
		rotatelogs.WithLinkName(cfg.Log.LogDir+logName), // 让你始终在一个位置查看文件，即使文件已经滚动切分
		rotatelogs.WithMaxAge(24*time.Hour),
		rotatelogs.WithRotationTime(time.Hour),
	)
	if err != nil {
		stdLog.Printf("failed to create rotatelogs: %s", err)
		return
	}
	log.SetFormatter(&nested.Formatter{    // 设置nested日志格式
		HideKeys:        true,
		FieldsOrder:     []string{"region", "node", "topic"},
		TimestampFormat: "2006-01-02 15:04:05.000", // 显示ms
		NoColors:        true,
	})
	log.ReportCaller = true
	log.AddHook(&FixedFieldHook{           // 设置默认字段
		FixedField: map[string]string{"region": cfg.LocalRegion, "node": ip},
		LogLevels: []logrus.Level{
			logrus.InfoLevel,
			logrus.ErrorLevel,
			logrus.WarnLevel,
			logrus.FatalLevel,
		},
	})
	if !cfg.Log.Debug {
		log.SetOutput(logf)
		log.SetLevel(logrus.InfoLevel)
	} else {
		fileAndStdoutWriter := io.MultiWriter(logf, os.Stdout)
		log.SetOutput(fileAndStdoutWriter)
		log.SetLevel(logrus.DebugLevel)
	}
}

4. 带缓冲区的logrus日志Hook： 解决logrus默认同步写日志带来的性能问题

上面说到logrus Hook 甚至可以替代logrus默认的output，已知logrus是同步写日志，通过Hook机制我们可以自定义一个异步的output Writer（用缓存区的方式实现），
logrus-async-hook， 能有效解决logrus默认不支持异步日志带来的写性能问题，欢迎试用，期待你的star。

bufio 包实现缓冲 I/O,它包装一个 io.Reader 或 io.Writer 对象，创建另一个对象（Reader 或 Writer），该对象也实现该接口，为文本 I/O 提供缓冲和一些帮助。

使用如下：

func ExampleHook_default() {
	l := logrus.New()
	l.SetLevel(logrus.InfoLevel)
	l.SetFormatter(&logrus.TextFormatter{
		DisableTimestamp: true,
	})

	l.SetOutput(io.Discard)       // Send all logs to nowhere by default， Hook中已经指定了output Writer

	ws := &BufferedWriterHook{Writer: os.Stdout}
	l.ExitFunc = func(code int) {
		ws.Stop()
	}
	l.AddHook(ws)

	l.Info("test2")
	l.Warn("test3")
	l.Error("test4")

	// Output:
	// level=info msg=test2
	// level=warning msg=test3
	// level=error msg=test4
}

下面是相比同步写日志的基准测试结果：大致是原同步写日志的10+倍性能。

-8表示8个CPU线程执行；64819表示总共执行了64819次；19755ns/op，表示每次执行耗时19755纳秒；496/op表示每次执行分配了496字节内存；15 allocs/op表示每次执行分配了15次对象。