golang日志库

golang标准库的日志框架非常简单，仅仅提供了print，panic和fatal三个函数对于更精细的日志级别、日志文件分割以及日志分发等方面并没有提供支持。所以催生了很多第三方的日志库，但是在golang的世界里，没有一个日志库像slf4j那样在Java中具有绝对统治地位。golang中，流行的日志框架包括logrus、zap、zerolog、seelog等。
logrus是目前Github上star数量最多的日志库，目前(2018.08，下同)star数量为8119，fork数为1031。logrus功能强大，性能高效，而且具有高度灵活性，提供了自定义插件的功能。很多开源项目，如docker，prometheus等，都是用了logrus来记录其日志。
zap是Uber推出的一个快速、结构化的分级日志库。具有强大的ad-hoc分析功能，并且具有灵活的仪表盘。zap目前在GitHub上的star数量约为4.3k。
seelog提供了灵活的异步调度、格式化和过滤功能。目前在GitHub上也有约1.1k。

logrus特性

logrus具有以下特性：

完全兼容golang标准库日志模块：logrus拥有六种日志级别：debug、info、warn、error、fatal和panic，这是golang标准库日志模块的API的超集。如果您的项目使用标准库日志模块，完全可以以最低的代价迁移到logrus上。
可扩展的Hook机制：允许使用者通过hook的方式将日志分发到任意地方，如本地文件系统、标准输出、logstash、elasticsearch或者mq等，或者通过hook定义日志内容和格式等。
可选的日志输出格式：logrus内置了两种日志格式，JSONFormatter和TextFormatter，如果这两个格式不满足需求，可以自己动手实现接口Formatter，来定义自己的日志格式。
Field机制：logrus鼓励通过Field机制进行精细化的、结构化的日志记录，而不是通过冗长的消息来记录日志。
logrus是一个可插拔的、结构化的日志框架。

logrus的使用

第一个示例

最简单的使用logrus的示例如下：

1package main
2
3import (
4  log "github.com/sirupsen/logrus"
5)
6
7func main() {
8  log.WithFields(log.Fields{
9    "animal": "walrus",
10  }).Info("A walrus appears")
11}

上面代码执行后，标准输出上输出如下：

time="2018-08-11T15:42:22+08:00" level=info msg="A walrus appears" animal=walrus

logrus与golang标准库日志模块完全兼容，因此您可以使用log“github.com/sirupsen/logrus”替换所有日志导入。
logrus可以通过简单的配置，来定义输出、格式或者日志级别等。

1package main
2
3import (
4	"os"
5	log "github.com/sirupsen/logrus"
6)
7
8func init() {
9	// 设置日志格式为json格式
10	log.SetFormatter(&log.JSONFormatter{})
11
12	// 设置将日志输出到标准输出（默认的输出为stderr，标准错误）
13	// 日志消息输出可以是任意的io.writer类型
14	log.SetOutput(os.Stdout)
15
16	// 设置日志级别为warn以上
17	log.SetLevel(log.WarnLevel)
18}
19
20func main() {
21	log.WithFields(log.Fields{
22		"animal": "walrus",
23		"size":   10,
24	}).Info("A group of walrus emerges from the ocean")
25
26	log.WithFields(log.Fields{
27		"omg":    true,
28		"number": 122,
29	}).Warn("The group's number increased tremendously!")
30
31	log.WithFields(log.Fields{
32		"omg":    true,
33		"number": 100,
34	}).Fatal("The ice breaks!")
35}

Logger

logger是一种相对高级的用法, 对于一个大型项目, 往往需要一个全局的logrus实例，即logger对象来记录项目所有的日志。如：

1package main
2
3import (
4	"github.com/sirupsen/logrus"
5	"os"
6)
7
8// logrus提供了New()函数来创建一个logrus的实例。
9// 项目中，可以创建任意数量的logrus实例。
10var log = logrus.New()
11
12func main() {
13    // 为当前logrus实例设置消息的输出，同样地，
14    // 可以设置logrus实例的输出到任意io.writer
15	log.Out = os.Stdout
16
17    // 为当前logrus实例设置消息输出格式为json格式。
18    // 同样地，也可以单独为某个logrus实例设置日志级别和hook，这里不详细叙述。
19    log.Formatter = &logrus.JSONFormatter{}
20
21	log.WithFields(logrus.Fields{
22		"animal": "walrus",
23		"size":   10,
24	}).Info("A group of walrus emerges from the ocean")
25}

Fields

前一章提到过，logrus不推荐使用冗长的消息来记录运行信息，它推荐使用Fields来进行精细化的、结构化的信息记录。
例如下面的记录日志的方式：

log.Fatalf("Failed to send event %s to topic %s with key %d", event, topic, key)

在logrus中不太提倡，logrus鼓励使用以下方式替代之：

1log.WithFields(log.Fields{
2  "event": event,
3  "topic": topic,
4  "key": key,
5}).Fatal("Failed to send event")

前面的WithFields API可以规范使用者按照其提倡的方式记录日志。但是WithFields依然是可选的，因为某些场景下，使用者确实只需要记录仪一条简单的消息。

通常，在一个应用中、或者应用的一部分中，都有一些固定的Field。比如在处理用户http请求时，上下文中，所有的日志都会有request_id和user_ip。为了避免每次记录日志都要使用log.WithFields(log.Fields{"request_id": request_id, "user_ip": user_ip})，我们可以创建一个logrus.Entry实例，为这个实例设置默认Fields，在上下文中使用这个logrus.Entry实例记录日志即可。

1requestLogger := log.WithFields(log.Fields{"request_id": request_id, "user_ip": user_ip})
2requestLogger.Info("something happened on that request") # will log request_id and user_ip
3requestLogger.Warn("something not great happened")

Hook

logrus最令人心动的功能就是其可扩展的HOOK机制了，通过在初始化时为logrus添加hook，logrus可以实现各种扩展功能。

Hook接口

logrus的hook接口定义如下，其原理是每此写入日志时拦截，修改logrus.Entry。

1// logrus在记录Levels()返回的日志级别的消息时会触发HOOK，
2// 按照Fire方法定义的内容修改logrus.Entry。
3type Hook interface {
4	Levels() []Level
5	Fire(*Entry) error
6}

一个简单自定义hook如下，DefaultFieldHook定义会在所有级别的日志消息中加入默认字段appName="myAppName"。

1type DefaultFieldHook struct {
2}
3
4func (hook *DefaultFieldHook) Fire(entry *log.Entry) error {
5    entry.Data["appName"] = "MyAppName"
6    return nil
7}
8
9func (hook *DefaultFieldHook) Levels() []log.Level {
10    return log.AllLevels
11}

hook的使用也很简单，在初始化前调用log.AddHook(hook)添加相应的hook即可。

logrus官方仅仅内置了syslog的hook。
此外，但Github也有很多第三方的hook可供使用，文末将提供一些第三方HOOK的连接。

记录文件名和行号

logrus的一个很致命的问题就是没有提供文件名和行号，这在大型项目中通过日志定位问题时有诸多不便。Github上的logrus的issue#63：Log filename and line number创建于2014年，四年过去了仍是open状态~~~
网上给出的解决方案分位两类，一就是自己实现一个hook；二就是通过装饰器包装logrus.Entry。两种方案网上都有很多代码，但是大多无法正常工作。但总体来说，解决问题的思路都是对的：通过标准库的runtime模块获取运行时信息，并从中提取文件名，行号和调用函数名。

标准库runtime模块的Caller(skip int)函数可以返回当前goroutine调用栈中的文件名，行号，函数信息等，参数skip表示表示返回的栈帧的层次，0表示runtime.Caller的调用着。返回值包括响应栈帧层次的pc(程序计数器)，文件名和行号信息。为了提高效率，我们先通过跟踪调用栈发现，从runtime.Caller()的调用者开始，到记录日志的生成代码之间，大概有8到11层左右，所有我们在hook中循环第8到11层调用栈应该可以找到日志记录的生产代码。

此外，runtime.FuncForPC(pc uintptr) *Func可以返回指定pc的函数信息。
所有我们要实现的hook也是基于以上原理，使用runtime.Caller()依次循环调用栈的第7~11层，过滤掉sirupsen包内容，那么第一个非siupsenr包就认为是我们的生产代码了，并返回pc以便通过runtime.FuncForPC()获取函数名称。然后将文件名、行号和函数名组装为source字段塞到logrus.Entry中即可。

1import (
2	"fmt"
3	log "github.com/sirupsen/logrus"
4	"runtime"
5	"strings"
6)
7
8// line number hook for log the call context,
9type lineHook struct {
10    Field  string
11    // skip为遍历调用栈开始的索引位置
12	Skip   int
13	levels []log.Level
14}
15
16// Levels implement levels
17func (hook lineHook) Levels() []log.Level {
18	return log.AllLevels
19}
20
21// Fire implement fire
22func (hook lineHook) Fire(entry *log.Entry) error {
23	entry.Data[hook.Field] = findCaller(hook.Skip)
24	return nil
25}
26
27func findCaller(skip int) string {
28	file := ""
29	line := 0
30	var pc uintptr
31    // 遍历调用栈的最大索引为第11层.
32	for i := 0; i < 11; i++ {
33        file, line, pc = getCaller(skip + i)
34        // 过滤掉所有logrus包，即可得到生成代码信息
35		if !strings.HasPrefix(file, "logrus") {
36			break
37		}
38	}
39
40	fullFnName := runtime.FuncForPC(pc)
41
42	fnName := ""
43	if fullFnName != nil {
44		fnNameStr := fullFnName.Name()
45        // 取得函数名
46		parts := strings.Split(fnNameStr, ".")
47		fnName = parts[len(parts)-1]
48	}
49
50	return fmt.Sprintf("%s:%d:%s()", file, line, fnName)
51}
52
53func getCaller(skip int) (string, int, uintptr) {
54	pc, file, line, ok := runtime.Caller(skip)
55	if !ok {
56		return "", 0, pc
57	}
58	n := 0
59
60    // 获取包名
61	for i := len(file) - 1; i > 0; i-- {
62		if file[i] == '/' {
63			n++
64			if n >= 2 {
65				file = file[i+1:]
66				break
67			}
68		}
69	}
70	return file, line, pc
71}

效果如下：

1time="2018-08-11T19:10:15+08:00" level=warning msg="postgres_exporter is ready for scraping on 0.0.0.0:9295..." source="postgres_exporter/main.go:60:main()"
2time="2018-08-11T19:10:17+08:00" level=error msg="!!!msb info not found" source="postgres/postgres_query.go:63:QueryPostgresInfo()"

日志本地文件分割

logrus本身不带日志本地文件分割功能，但是我们可以通过file-rotatelogs进行日志本地文件分割。每次当我们写入日志的时候，logrus都会调用file-rotatelogs来判断日志是否要进行切分。关于本地日志文件分割的例子网上很多，这里不再详细介绍，奉上代码：

1import (
2	"github.com/lestrrat-go/file-rotatelogs"
3	"github.com/rifflock/lfshook"
4	log "github.com/sirupsen/logrus"
5	"time"
6)
7
8func newLfsHook(logLevel *string, maxRemainCnt uint) log.Hook {
9	writer, err := rotatelogs.New(
10        logName+".%Y%m%d%H",
11        // WithLinkName为最新的日志建立软连接，以方便随着找到当前日志文件
12        rotatelogs.WithLinkName(logName),
13        
14        // WithRotationTime设置日志分割的时间，这里设置为一小时分割一次
15        rotatelogs.WithRotationTime(time.Hour),
16        
17        // WithMaxAge和WithRotationCount二者只能设置一个，
18        // WithMaxAge设置文件清理前的最长保存时间，
19        // WithRotationCount设置文件清理前最多保存的个数。
20		//rotatelogs.WithMaxAge(time.Hour*24),
21		rotatelogs.WithRotationCount(maxRemainCnt),
22	)
23
24	if err != nil {
25		log.Errorf("config local file system for logger error: %v", err)
26	}
27
28	level, ok := logLevels[*logLevel]
29
30	if ok {
31		log.SetLevel(level)
32	} else {
33		log.SetLevel(log.WarnLevel)
34	}
35
36	lfsHook := lfshook.NewHook(lfshook.WriterMap{
37		log.DebugLevel: writer,
38		log.InfoLevel:  writer,
39		log.WarnLevel:  writer,
40		log.ErrorLevel: writer,
41		log.FatalLevel: writer,
42		log.PanicLevel: writer,
43	}, &log.TextFormatter{DisableColors: true})
44
45	return lfsHook
46}

使用上述本地日志文件切割的效果如下：

将日志发送到elasticsearch

将日志发送到elasticsearch是很多日志监控系统的选择，将logrus日志发送到elasticsearch的原理是在hook的每次fire调用时，使用golang的es客户端将日志信息写到elasticsearch。elasticsearch官方没有提供golang客户端，但是有很多第三方的go语言客户端可供使用，我们选择elastic。elastic提供了丰富的文档，以及Java中的流式接口，使用起来非常方便。

1client, err := elastic.NewClient(elastic.SetURL("http://localhost:9200"))
2	if err != nil {
3		log.Panic(err)
4    }
5
6// Index a tweet (using JSON serialization)
7tweet1 := Tweet{User: "olivere", Message: "Take Five", Retweets: 0}
8put1, err := client.Index().
9    Index("twitter").
10    Type("tweet").
11    Id("1").
12    BodyJson(tweet1).
13    Do(context.Background())

考虑到logrus的Fields机制，可以实现如下数据格式：

1msg := struct {
2	Host      string
3	Timestamp string `json:"@timestamp"`
4	Message   string
5	Data      logrus.Fields
6	Level     string
7}

其中Host记录产生日志主机信息，在创建hook是指定。其他数据需要从logrus.Entry中取得。测试过程我们选择按照此原理实现的第三方HOOK：elogrus。其使用如下：

1import (
2    "github.com/olivere/elastic"
3	"gopkg.in/sohlich/elogrus"
4)
5
6func initLog() {
7    client, err := elastic.NewClient(elastic.SetURL("http://localhost:9200"))
8    if err != nil {
9        log.Panic(err)
10    }
11    hook, err := elogrus.NewElasticHook(client, "localhost", log.DebugLevel, "mylog")
12    if err != nil {
13        log.Panic(err)
14    }
15    log.AddHook(hook)
16}

从Elasticsearch查询得到日志存储，效果如下：

1GET http://localhost:9200/mylog/_search
2
3HTTP/1.1 200 OK
4content-type: application/json; charset=UTF-8
5transfer-encoding: chunked
6
7{
8  "took": 1,
9  "timed_out": false,
10  "_shards": {
11    "total": 5,
12    "successful": 5,
13    "failed": 0
14  },
15  "hits": {
16    "total": 2474,
17    "max_score": 1.0,
18    "hits": [
19      {
20        "_index": "mylog",
21        "_type": "log",
22        "_id": "AWUw13jWnMZReb-jHQup",
23        "_score": 1.0,
24        "_source": {
25          "Host": "localhost",
26          "@timestamp": "2018-08-13T01:12:32.212818666Z",
27          "Message": "!!!msb info not found",
28          "Data": {},
29          "Level": "ERROR"
30        }
31      },
32      {
33        "_index": "mylog",
34        "_type": "log",
35        "_id": "AWUw13jgnMZReb-jHQuq",
36        "_score": 1.0,
37        "_source": {
38          "Host": "localhost",
39          "@timestamp": "2018-08-13T01:12:32.223103348Z",
40          "Message": "get postgres instances info failed, scrape metrics failed, error:msb env not found",
41          "Data": {
42            "source": "collector/exporter.go:71:Scrape()"
43          },
44          "Level": "ERROR"
45        }
46      },
47      //...
48      {
49        "_index": "mylog",
50        "_type": "log",
51        "_id": "AWUw2f1enMZReb-jHQu_",
52        "_score": 1.0,
53        "_source": {
54          "Host": "localhost",
55          "@timestamp": "2018-08-13T01:15:17.212546892Z",
56          "Message": "!!!msb info not found",
57          "Data": {
58            "source": "collector/exporter.go:71:Scrape()"
59          },
60          "Level": "ERROR"
61        }
62      },
63      {
64        "_index": "mylog",
65        "_type": "log",
66        "_id": "AWUw2NhmnMZReb-jHQu1",
67        "_score": 1.0,
68        "_source": {
69          "Host": "localhost",
70          "@timestamp": "2018-08-13T01:14:02.21276903Z",
71          "Message": "!!!msb info not found",
72          "Data": {},
73          "Level": "ERROR"
74        }
75      }
76    ]
77  }
78}
79
80Response code: 200 (OK); Time: 16ms; Content length: 3039 bytes

将日志发送到其他位置

将日志发送到日志中心也是logrus所提倡的，虽然没有提供官方支持，但是目前Github上有很多第三方hook可供使用：

logrus_amqp：Logrus hook for Activemq。
logrus-logstash-hook:Logstash hook for logrus。
mgorus:Mongodb Hooks for Logrus。
logrus_influxdb:InfluxDB Hook for Logrus。
logrus-redis-hook:Hook for Logrus which enables logging to RELK stack (Redis, Elasticsearch, Logstash and Kibana)。

等等，上述第三方hook我这里没有具体验证，大家可以根据需要自行尝试。

其他注意事项

Fatal处理

和很多日志框架一样，logrus的Fatal系列函数会执行os.Exit(1)。但是logrus提供可以注册一个或多个fatal handler函数的接口logrus.RegisterExitHandler(handler func() {} )，让logrus在执行os.Exit(1)之前进行相应的处理。fatal handler可以在系统异常时调用一些资源释放api等，让应用正确的关闭。

线程安全

默认情况下，logrus的api都是线程安全的，其内部通过互斥锁来保护并发写。互斥锁工作于调用hooks或者写日志的时候，如果不需要锁，可以调用logger.SetNoLock()来关闭之。可以关闭logrus互斥锁的情形包括：

没有设置hook，或者所有的hook都是线程安全的实现。
写日志到logger.Out已经是线程安全的了，如logger.Out已经被锁保护，或者写文件时，文件是以O_APPEND方式打开的，并且每次写操作都小于4k。

Golang日志框架之logrus