日志库 · golang

# 一、golang日志库 ## 1.1 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上的star数量也有约1.1k。 ## 1.2 golang logrus的GitHub地址 logrus的GitHub地址 [https://github.com/sirupsen/logrus](https://github.com/sirupsen/logrus) lfshook的GitHub地址 [https://github.com/rifflock/lfshook](https://github.com/rifflock/lfshook) file-rotatelogs的GitHub地址 [https://github.com/lestrrat-go/file-rotatelogs](https://github.com/lestrrat-go/file-rotatelogs) pkg/errors的GitHub地址 [https://github.com/pkg/errors](https://github.com/pkg/errors) # 二、logrus特性 logrus具有以下特性： 1. 完全兼容golang标准库日志模块。logrus拥有六种日志级别：debug、info、warn、error、fatal和panic，这是golang标准库日志模块的API的超集。如果你的项目使用标准库日志模块，完全可以用最低的代价迁移到logrus上。 2. 可扩展的Hook机制。允许使用者通过hook方式，将日志分发到任意地方，如本地文件系统、标准输出、logstash、elasticsearch或者mq等，或者通过hook定义日志内容和格式等。 3. 可选的日志输出格式。**logrus内置了两种日志格式，JSONFormatter和TextFormatter。**如果这两个格式不满足需求，可以自己动手实现接口Formatter，来定义自己的日志格式。 4. Field机制。logrus鼓励通过Field机制进行精细化、结构化的日志记录，而不是通过冗长的消息来记录日志。 5. logrus是一个可插拔的、结构化的日志框架。 # 三、logrus的使用 ## 3.1 第一个示例最简单的使用logrus的示例如下： ~~~ package main import ( log "github.com/sirupsen/logrus" ) func main() { log.WithFields(log.Fields{ "animal": "walrus", }).Info("A walrus appears") } ~~~ 上面代码执行后，标准输出上输出如下： ~~~ time="2018-08-11T15:42:22+08:00" level=info msg="A walrus appears" animal=walrus ~~~ logrus与golang标准库日志模块完全兼容，因此，你可以使用`log “github.com/sirupsen/logrus”`替换所有日志导入。 ## 3.2 第二个示例 logrus可以通过简单的配置，来定义输出、格式或者日志级别等。示例如下： ~~~ package main import ( "os" log "github.com/sirupsen/logrus" ) func initLog() { // 设置日志格式为json格式 log.SetFormatter(&log.JSONFormatter{}) // 设置将日志输出到标准输出（默认的输出为stderr，标准错误） // 日志消息输出可以是任意的io.writer类型 log.SetOutput(os.Stdout) // 设置日志级别为warn以上 log.SetLevel(log.WarnLevel) } func main() { initLog() log.WithFields(log.Fields{ "animal": "walrus", "size": 10, "country": "china", }).Info("A group of walrus emerges from the ocean") log.WithFields(log.Fields{ "omg": true, "number": 122, "country": "china", }).Warn("The group's number increased tremendously!") log.WithFields(log.Fields{ "omg": true, "number": 100, "country": "america", }).Fatal("The ice breaks!") } ~~~ 上面代码执行后，标准输出上输出如下： ~~~ {"country":"china","level":"warning","msg":"The group's number increased tremendously!","number":122,"omg":true,"time":"2018-12-12T18:22:20+08:00"} {"country":"america","level":"fatal","msg":"The ice breaks!","number":100,"omg":true,"time":"2018-12-12T18:22:20+08:00"} exit status 1 ~~~ ## 3.3 Logger logger是一种相对高级的用法。对于一个大型项目，往往需要一个全局的logrus实例，即`logger`对象，来记录项目所有的日志。示例如下： ~~~ package main import ( "github.com/sirupsen/logrus" "os" ) // logrus提供了New()函数来创建一个logrus的实例。 // 项目中，可以创建任意数量的logrus实例。 var log = logrus.New() func main() { // 为当前logrus实例设置消息的输出，同样地， // 可以设置logrus实例的输出到任意io.writer log.Out = os.Stdout // 为当前logrus实例设置消息输出格式为json格式。 // 同样地，也可以单独为某个logrus实例设置日志级别和hook，这里不详细叙述。 log.Formatter = &logrus.JSONFormatter{} log.WithFields(logrus.Fields{ "animal": "walrus", "size": 10, }).Info("A group of walrus emerges from the ocean") } ~~~ 执行结果如下所示： ~~~ {"animal":"walrus","level":"info","msg":"A group of walrus emerges from the ocean","size":10,"time":"2018-12-12T18:33:38+08:00"} ~~~ ## 3.4 Fields 前一章提到过，logrus不推荐使用冗长的消息来记录运行信息，它推荐使用`Fields`来进行精细化的、结构化的信息记录。例如下面记录日志的方式： ~~~ log.Fatalf("Failed to send event %s to topic %s with key %d", event, topic, key) ```` 在logrus中不太提倡，logrus鼓励使用以下方式替代之： <div class="se-preview-section-delimiter"></div> ```go log.WithFields(log.Fields{ "event": event, "topic": topic, "key": key, }).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`实例记录日志即可。 ~~~ requestLogger := log.WithFields(log.Fields{"request_id": request_id, "user_ip": user_ip}) requestLogger.Info("something happened on that request") # will log request_id and user_ip requestLogger.Warn("something not great happened") ~~~ # 四、Hook logrus最令人心动的功能，就是其可扩展的HOOK机制了。通过在初始化时为logrus添加hook，logrus可以实现各种扩展功能。 ## 4.1 Hook接口 logrus的hook原理是：在每次写入日志时拦截，修改logrus.Entry。logrus的hook接口定义如下。 ~~~ // logrus在记录Levels()返回的日志级别的消息时，会触发HOOK。 // 然后，按照Fire方法定义的内容，修改logrus.Entry。 type Hook interface { Levels() []Level Fire(*Entry) error } ~~~ 一个简单自定义的hook如下所示。`DefaultFieldHook类型的对象`会在所有级别的日志消息中加入默认字段`appName="myAppName"`。 ~~~ type DefaultFieldHook struct { } func (hook *DefaultFieldHook) Fire(entry *log.Entry) error { entry.Data["appName"] = "MyAppName" return nil } func (hook *DefaultFieldHook) Levels() []log.Level { return log.AllLevels } ~~~ hook的使用也很简单，在初始化前调用`log.AddHook(hook)`添加相应的`hook`即可。 logrus官方仅仅内置了syslog的[hook](https://github.com/sirupsen/logrus/tree/master/hooks/syslog)。但Github上有很多第三方的hook可供使用，文末将提供一些第三方HOOK的链接。 # 五、问题与解决方案尽管logrus有诸多优点，但是为了灵活性和可扩展性，官方也削减了很多实用的功能，例如： * 没有提供行号和文件名的支持 * 输出到本地文件系统时，没有提供日志分割功能 * 官方没有提供输出到ELK等日志处理中心的功能但是，这些功能都可以通过自定义hook来实现。 ## 5.1 记录文件名和行号 logrus一个很致命的问题，就是没有提供文件名和行号，这在大型项目中通过日志定位问题时有诸多不便。Github上的logrus的issue#63：[Log filename and line number](https://github.com/sirupsen/logrus/issues/63)创建于2014年，四年过去了仍是open状态。网上给出的解决方案分位两类，一就是自己实现一个hook；二就是通过装饰器包装`logrus.Entry`。两种方案网上都有很多代码，但是大多无法正常工作。但总体来说，解决问题的思路都是对的：通过标准库的`runtime`模块获取运行时信息，并从中提取文件名、行号和调用函数名。标准库`runtime`模块的`Caller(skip int)`函数可以返回当前goroutine调用栈中的文件名、行号、函数信息等，参数skip表示返回的栈帧的层次，0表示`runtime.Caller`的调用者。返回值包括响应栈帧层次的pc(程序计数器)、文件名和行号信息。为了提高效率，我们通过跟踪调用栈发现，从`runtime.Caller()`的调用者开始，到记录日志的生成代码之间，大概有8到11层左右，所以我们在hook中循环第8到11层调用栈，应该可以找到日志记录的生产代码。 ![这里写图片描述](https://img-blog.csdn.net/20180814170801498?watermark/2/text/aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3dzbHlrNjA2/font/5a6L5L2T/fontsize/400/fill/I0JBQkFCMA==/dissolve/70) 此外，`runtime.FuncForPC(pc uintptr) *Func`可以返回指定`pc`的函数信息。所以，我们要实现的hook也是基于以上原理，使用`runtime.Caller()`依次循环调用栈的第7~11层，过滤掉`sirupsen`包内容，那么第一个非`siupsenr`包就认为是我们的生产代码了，并返回`pc`以便通过`runtime.FuncForPC()`获取函数名称。然后将文件名、行号和函数名组装为`source`字段塞到`logrus.Entry`中即可。 ~~~ time="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()" time="2018-08-11T19:10:17+08:00" level=error msg="!!!msb info not found" source="postgres/postgres_query.go:63:QueryPostgresInfo()" time="2018-08-11T19:10:17+08:00" level=error msg="get postgres instances info failed, scrape metrics failed, error:msb env not found" source="collector/exporter.go:71:Scrape()" ~~~ ## 5.2 日志本地文件分割 logrus本身不带日志本地文件分割功能，但是我们可以通过`file-rotatelogs`进行日志本地文件分割。每次在我们写入日志的时候，logrus都会调用`file-rotatelogs`来判断日志是否要进行切分。关于本地日志文件分割的例子，网上很多，这里不再详细介绍，奉上代码： ~~~ import ( "github.com/lestrrat-go/file-rotatelogs" "github.com/rifflock/lfshook" log "github.com/sirupsen/logrus" "time" ) func newLfsHook(logLevel *string, maxRemainCnt uint) log.Hook { writer, err := rotatelogs.New( logName+".%Y%m%d%H", // WithLinkName 为最新的日志建立软连接，以方便随时找到当前日志文件 rotatelogs.WithLinkName(logName), // WithRotationTime 设置日志分割的时间，这里设置为一小时分割一次 rotatelogs.WithRotationTime(time.Hour), // WithMaxAge和WithRotationCount 二者只能设置一个， // WithMaxAge 设置文件清理前的最长保存时间， // WithRotationCount 设置文件清理前最多保存的个数。 //rotatelogs.WithMaxAge(time.Hour*24), rotatelogs.WithRotationCount(maxRemainCnt), ) if err != nil { log.Errorf("config local file system for logger error: %v", err) } level, ok := logLevels[*logLevel] if ok { log.SetLevel(level) } else { log.SetLevel(log.WarnLevel) } lfsHook := lfshook.NewHook(lfshook.WriterMap{ log.DebugLevel: writer, log.InfoLevel: writer, log.WarnLevel: writer, log.ErrorLevel: writer, log.FatalLevel: writer, log.PanicLevel: writer, }, &log.TextFormatter{DisableColors: true}) return lfsHook } ~~~ 使用上述本地日志文件切割的效果如下： ![这里写图片描述](https://img-blog.csdn.net/20180814170847468?watermark/2/text/aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3dzbHlrNjA2/font/5a6L5L2T/fontsize/400/fill/I0JBQkFCMA==/dissolve/70) ## 5.3 将日志发送到elasticsearch 将日志发送到elasticsearch，是很多日志监控系统的选择。将logrus日志发送到elasticsearch的原理是：在hook的每次fire调用时，使用golang的es客户端将日志信息写到elasticsearch。elasticsearch官方没有提供golang客户端，但是有很多第三方的go语言客户端可供使用，我们选择[elastic](https://github.com/olivere/elastic)。elastic提供了丰富的[文档](https://godoc.org/gopkg.in/olivere/elastic.v5)，以及Java中的流式接口，使用起来非常方便。 ~~~ client, err := elastic.NewClient(elastic.SetURL("http://localhost:9200")) if err != nil { log.Panic(err) } // Index a tweet (using JSON serialization) tweet1 := Tweet{User: "olivere", Message: "Take Five", Retweets: 0} put1, err := client.Index(). Index("twitter"). Type("tweet"). Id("1"). BodyJson(tweet1). Do(context.Background()) ~~~ 考虑到logrus的Fields机制，可以实现如下数据格式： ~~~ msg := struct { Host string Timestamp string `json:"@timestamp"` Message string Data logrus.Fields Level string } ~~~ 其中，`Host`记录产生日志主机信息，在创建hook时指定。对于其他数据，需要从`logrus.Entry`中取得。测试中，我们选择按照此原理实现的第三方HOOK：[elogrus](https://github.com/sohlich/elogrus)。其使用如下： ~~~ import ( "github.com/olivere/elastic" "gopkg.in/sohlich/elogrus" ) func initLog() { client, err := elastic.NewClient(elastic.SetURL("http://localhost:9200")) if err != nil { log.Panic(err) } hook, err := elogrus.NewElasticHook(client, "localhost", log.DebugLevel, "mylog") if err != nil { log.Panic(err) } log.AddHook(hook) } ~~~ 从Elasticsearch查询得到日志存储，效果如下： ~~~ GET http://localhost:9200/mylog/_search HTTP/1.1 200 OK content-type: application/json; charset=UTF-8 transfer-encoding: chunked { "took": 1, "timed_out": false, "_shards": { "total": 5, "successful": 5, "failed": 0 }, "hits": { "total": 2474, "max_score": 1.0, "hits": [ { "_index": "mylog", "_type": "log", "_id": "AWUw13jWnMZReb-jHQup", "_score": 1.0, "_source": { "Host": "localhost", "@timestamp": "2018-08-13T01:12:32.212818666Z", "Message": "!!!msb info not found", "Data": {}, "Level": "ERROR" } }, { "_index": "mylog", "_type": "log", "_id": "AWUw13jgnMZReb-jHQuq", "_score": 1.0, "_source": { "Host": "localhost", "@timestamp": "2018-08-13T01:12:32.223103348Z", "Message": "get postgres instances info failed, scrape metrics failed, error:msb env not found", "Data": { "source": "collector/exporter.go:71:Scrape()" }, "Level": "ERROR" } }, //... { "_index": "mylog", "_type": "log", "_id": "AWUw2f1enMZReb-jHQu_", "_score": 1.0, "_source": { "Host": "localhost", "@timestamp": "2018-08-13T01:15:17.212546892Z", "Message": "!!!msb info not found", "Data": { "source": "collector/exporter.go:71:Scrape()" }, "Level": "ERROR" } }, { "_index": "mylog", "_type": "log", "_id": "AWUw2NhmnMZReb-jHQu1", "_score": 1.0, "_source": { "Host": "localhost", "@timestamp": "2018-08-13T01:14:02.21276903Z", "Message": "!!!msb info not found", "Data": {}, "Level": "ERROR" } } ] } } Response code: 200 (OK); Time: 16ms; Content length: 3039 bytes ~~~ ## 5.4 将日志发送到其他位置将日志发送到日志中心，也是logrus所提倡的。虽然没有提供官方支持，但是目前Github上有很多第三方hook可供使用： * [logrus\_amqp](https://github.com/vladoatanasov/logrus_amqp)：Logrus hook for Activemq * [logrus-logstash-hook](https://github.com/bshuster-repo/logrus-logstash-hook):Logstash hook for logrus * [mgorus](https://github.com/weekface/mgorus):Mongodb Hooks for Logrus * [logrus\_influxdb](https://github.com/abramovic/logrus_influxdb):InfluxDB Hook for Logrus * [logrus-redis-hook](https://github.com/rogierlommers/logrus-redis-hook):Hook for Logrus which enables logging to RELK stack (Redis, Elasticsearch, Logstash and Kibana) 等等。对于上述第三方hook，我这里没有具体验证，大家可以根据需要自行尝试。 ## 5.5 其他注意事项 ### 5.5.1 Fatal处理和很多日志框架一样，logrus的`Fatal`系列函数会执行`os.Exit(1)`。但是，logrus提供“可以注册一个或多个`fatal handler`函数`”`的接口`logrus.RegisterExitHandler(handler func(){})`，让logrus在执行`os.Exit(1)`之前进行相应的处理。`fatal handler`可以在系统异常时调用一些资源释放api等，让应用正确地关闭。 ### 5.5.2 线程安全 **默认情况下，logrus的api都是线程安全的，其内部通过互斥锁来保护并发写**。互斥锁工作于调用hooks或者写日志的时候。如果不需要锁，可以调用`logger.SetNoLock()`来关闭之。可以关闭logrus互斥锁的情形包括： * 没有设置hook，或者所有的hook都是线程安全的实现。 * 写日志到logger.Out已经是线程安全的了。例如，logger.Out已经被锁保护，或者写文件时，文件是以O\_APPEND方式打开的，并且每次写操作都小于4k。尊重别人的劳动成果，原文网址： [https://blog.csdn.net/wslyk606/article/details/81670713](https://blog.csdn.net/wslyk606/article/details/81670713)