golang日志框架之logrus的使用

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的示例如下：

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”替换所有日志导入。
logrus可以通过简单的配置，来定义输出、格式或者日志级别等。

package main

import (
  "os"
  log "github.com/sirupsen/logrus"
)

func init() {
  // 设置日志格式为json格式
  log.setformatter(&log.jsonformatter{})

  // 设置将日志输出到标准输出（默认的输出为stderr，标准错误）
  // 日志消息输出可以是任意的io.writer类型
  log.setoutput(os.stdout)

  // 设置日志级别为warn以上
  log.setlevel(log.warnlevel)
}

func main() {
  log.withfields(log.fields{
    "animal": "walrus",
    "size":  10,
  }).info("a group of walrus emerges from the ocean")

  log.withfields(log.fields{
    "omg":  true,
    "number": 122,
  }).warn("the group's number increased tremendously!")

  log.withfields(log.fields{
    "omg":  true,
    "number": 100,
  }).fatal("the ice breaks!")
}

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")
}

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可以实现各种扩展功能。

hook接口

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

// 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的。

此外，但github也有很多第三方的hook可供使用，文末将提供一些第三方hook的连接。

问题与解决方案

尽管logrus有诸多优点，但是为了灵活性和可扩展性，官方也削减了很多实用的功能，例如：

• 没有提供行号和文件名的支持
• 输出到本地文件系统没有提供日志分割功能
• 官方没有提供输出到elk等日志处理中心的功能

但是这些功能都可以通过自定义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中即可。

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()"

日志本地文件分割

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
}

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

将日志发送到elasticsearch

将日志发送到elasticsearch是很多日志监控系统的选择，将logrus日志发送到elasticsearch的原理是在hook的每次fire调用时，使用golang的es客户端将日志信息写到elasticsearch。elasticsearch官方没有提供golang客户端，但是有很多第三方的go语言客户端可供使用，我们选择。elastic提供了丰富的，以及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：。其使用如下：

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"
    }
   }
  ]
 }
}

将日志发送到其他位置

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

：logrus hook for activemq。

:logstash hook for logrus。

:mongodb hooks for logrus。

:influxdb hook for logrus。

: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。

以上就是本文的全部内容，希望对大家的学习有所帮助，也希望大家多多支持。