第13节 从 0 编写一个日志包
❤️💕💕During the winter vacation, I followed up and learned two projects: tiktok project and IAM project, and summarized and practiced the CloudNative project and Go language. I learned a lot in the process.Myblog:http://nsddd.top
[TOC]
优秀的开源日志包
在做项目开发时,我们可以从0编写自己的日志包、也可以使用Go语言标准库的log包,还可以使用开源的日志包,但更多的是基于优秀的开源日志包进行二次开发,来实现定制化的日志功能。Go生态中也有一些非常优秀的开源日志包,例如标准库log包、glog、logrus、zap、seelog、zerolog等。用的比较多的是glog
、logrus
和zap
。
标准库log包使用
标准库log包功能非常简单,提供了开箱,仅提供了Print、Panic和Fatal三类函数用于日志输出。因为是标准库自带的,所以不需要我们下载安装,使用起来非常方便。标准库log包只有不到400行的代码量,如果读者想研究如何实现一个日志包,阅读标准库log包是一个不错的开始。Go的标准库大量使用了log包,例如:net/http、net/rpc
等。
log包使用
在使用log包时,需要首先创建一个*log. Logger
类型的log实例,所有的日志输出都是通过该实例提供的方法来完成的。
可以使用log包提供的全局全局变量std
,std
定义如下(位于Go标准包log目录下的log.go文件中):
var std = New(os.Stderr, "", LstdFlags)
也也可以使用log.New函
数创建自己的logger,在创建时,可以指定输出的位置、每行日志的前缀和日志属性,例如:
logger := log.New(logFile, "[Debug]", log.Lshortfile)
有如下几种日志属性可供选择:
- Ldate:当前时区的日期,格式是:2009/01/23。
- Ltime:当前时区的时间,格式是:01:23:23,精确到秒。
- Lmicroseconds:当前时区的时间,格式是:01:23:23.862600,精确到微妙。
- Llongfile:全文件名和行号。
- Lshortfile:当前文件名和行号,会覆盖Llongfile。
- LUTC:使用UTC而非本地时区。
- Lmsgprefix:将“前缀”从行的开头移至消息之前。
- LstdFlags:标准Logger的默认值(Ldate、Ltime)。
除了在执行log.New时配置log.Logger之外,创建之后还可以通过log.Logger提供的3种方法来改变log.Logger的配置:
- SetOutput:指定输出的位置。
- SetPrefix:设置每行日志的前缀。
- SetFlags:设置日志属性。
log.Logger提供了Print、Panic、Fatal函数来记录日志:
- Print:打印日志,例如:log.Print("call Print: line1")
- Panic:打印日志后执行panic(s),s为日志内容。
- Fatal:打印日志后执行os.Exit(1)。
Print、Panic、Fatal函数还提供Println、Printf、Panicln、Panicf、Fatalln、Fatalf来格式化打印日志。Print底层调用fmt.Sprint(v...)
,Println底层调用fmt.Sprintln(v...)
,Printf底层调用了fmt.Sprintf(format, v...)
。
标准库log的使用示例(main.go文件):
package main
import (
"log"
"os"
)
func main() {
// 输出到文件
logFile, err := os.Create("./log.log")
defer logFile.Close()
if err != nil {
log.Fatalln("create file log.log failed")
}
logger := log.New(logFile, "[Debug] ", log.Lshortfile)
logger.SetOutput(os.Stdout)
logger.Print("call Print: line1")
logger.Println("call Println: line2")
// 修改日志配置
logger.SetPrefix("[Info] ")
logger.SetFlags(log.Ldate)
logger.SetOutput(os.Stdout)
logger.Print("Info check stdout")
}
执行如下命令执行上述程序:
$ go run main.go
[Debug] main.go:17: call Print: line1
[Debug] main.go:18: call Println: line2
[Info] 2020/11/28 Info check stdout
glog
glog是Google推出的日志包,跟标准库log包一样,是一个轻量级的日志包,使用简单方便,但要比标准库log包提供更多的功能,glog具有如下特性:
- 支持4种日志级别:INFO、WARNING、ERROR、FATAL。
- 支持命令行选项,例如:
-alsologtostderr
、-log_backtrace_at
、-log_dir
、-logtostderr
、-v
等,每个参数实现某种功能。 - 支持根据文件大小切割日志文件。
- 支持日志按级别分类输出。
- 支持V level,V level特性可以使开发者自定义日志级别。
- 支持vmodule,vmodule可以使开发者对不同的文件使用不同的日志级别。
- 支持traceLocation,traceLocation可以打印出指定位置的栈信息。
kubernetes项目就使用了基于glog封装的klog作为其日志库。
glog使用方法
glog使用非常简单,常见的用法如下。
- 基本用法
glog的最常用的使用方法:
package main
import (
"flag"
"github.com/golang/glog"
)
func main() {
glog.MaxSize = 1024 * 1024 * 1024 // 1G自动分割
flag.Parse()
defer glog.Flush()
glog.Info("This is info message")
glog.Infof("This is info message: %v", 123)
glog.Warning("This is warning message")
glog.Warningf("This is warning message: %v", 123)
glog.Error("This is error message")
glog.Errorf("This is error message: %v", 123)
//glog.Fatal("This is fatal message")
//glog.Fatalf("This is fatal message: %v", 123)
}
glog支持4种日志级别,从低到高依次为:INFO、WARNING、ERROR、FATAL。glog支持命令行参数,在程序中,只需要在使用glog之前调用flag.Parse()即可,支持如下7个命令行参数:
-alsologtostderr
:同时将日志打印到文件和标准错误输出。-log_backtrace_at value
:指定代码运行到指定行时,把该代码的栈信息打印出来。-log_dir
:指定日志存储的文件夹。-logtostderr
:日志打印到标准错误输出,而不是文件中。-stderrthreshold value
:指定大于或者等于该级别的日志才会被输出到标准错误输出,默认为ERROR。-v value
:指定日志级别。-vmodule value
:对不同的文件使用不同的日志级别。
执行上述代码(假设保存在example1.go文件中):
$ mkdir -p log && go run example1.go -log_dir=log -alsologtostderr
I1202 09:43:49.618480 26223 example1.go:14] This is info message
I1202 09:43:49.618781 26223 example1.go:15] This is info message: 123
W1202 09:43:49.618792 26223 example1.go:17] This is warning message
W1202 09:43:49.618830 26223 example1.go:18] This is warning message: 123
E1202 09:43:49.618840 26223 example1.go:20] This is error message
E1202 09:43:49.618877 26223 example1.go:21] This is error message: 123
以上命令会同时将日志打印在log目录和标准错误输出中(-alsologtostderr
),log目录下文件列表为:
main.colin.colin.log.ERROR.20201202-081133.24123
main.colin.colin.log.INFO.20201202-081133.24123
main.colin.colin.log.WARNING.20201202-081133.24123
main.ERROR -> main.colin.colin.log.ERROR.20201202-081133.24123
main.INFO -> main.colin.colin.log.INFO.20201202-081133.24123
main.WARNING -> main.colin.colin.log.WARNING.20201202-081133.24123
main.INFO文件是一个软链接,链接到最新的INFO级别的日志文件,低优先级的日志文件包含高优先级的日志,例如INFO级别的日志文件中包含WARNING、ERROR、FATAL级别的日志。默认情况下,当单个日志文件达到1.8G时,,glog会对日志文件进行转存:关闭当前的文件,新建日志文件,可以通过glog.MaxSize设置转存阈值。
从上面的输出可以发现,glog的日志输出格式为:<header>] <message>
,其中header的格式为:Lmmdd hh:mm:ss.uuuuuu threadid file:line
:
- Lmmdd:L代表了glog的日志级别:I -> INFO、W -> WARNING、E -> ERROR、F -> FATAL。
- hh:mm:ss.uuuuuu:代表了时间信息,例如10:12:32.995956。
- threadid,是进程PID,即os.Getpid()的返回值。
- file:line:指明了打印日志的位置:文件名和行号。
使用glog.Info、glog.Warning等函数记录日志后,为了提高性能,这些日志会暂存在内存的buffer中,而不是直接写入文件中,只有显式的调用glog.Flush(),数据才会被写入文件。glog的init函数中启动了一个goroutine来周期性的调用glog.Flush(),默认的flush间隔为30秒。如果程序退出,自上次glog.Flush()函数执行之后产生的日志,就会被丢失,所以在程序退出时,需要调用glog.Flush()将日志刷新到磁盘文件中。
这里要注意,调用glog.Fatal函数后,glog会打印日志并退出程序,在程序退出前,会将缓存中的所有日志都写入日志,但是对于glog.Info、glog.Warning、glog.Error函数则不会。
- vmodule功能
glog 最常用的就是 V level 的功能,V越小,说明日志级别越高。示例如下:(保存在example2.go文件中):
package main
import (
"flag"
"github.com/golang/glog"
)
func main() {
flag.Parse()
defer glog.Flush()
glog.V(3).Info("LEVEL 3 message") // 使用日志级别 3
glog.V(5).Info("LEVEL 5 message") // 使用日志级别 5
glog.V(7).Info("LEVEL 7 message") // 使用日志级别 7
glog.V(8).Info("LEVEL 8 message") // 使用日志级别 8
}
执行上述代码:
$ go run example2.go -log_dir=log -alsologtostderr
上面的命令不会有任何输出,因为日志级别不够,可以通过-v
设置日志级别:
$ go run example2.go -log_dir=log -alsologtostderr -v=5
I1202 09:52:44.163989 29042 example2.go:13] LEVEL 3 message
I1202 09:52:44.164335 29042 example2.go:14] LEVEL 5 message
此时,日志级别高于或者等于5(V值小于或者等于5)的日志将被打印出来。
glog还支持对不同的文件使用不同的日志级别(-vmodule
),例如:
$ go run main.go foo.go -v=3 -log_dir=log -alsologtostderr -vmodule=foo=5
通过指定-vmodule=foo=5
参数,可以设置对foo.go文件使用5级别,对其它文件使用3级别。-vmodule
的输入参数省去了.go后缀,语法格式为:-vmodule=file1=2,file2=1,fs*=3
。
- traceLocation功能
traceLocation可以打印出指定位置的栈信息(-log_backtrace_at=filename:line_number
),例如有如下代码:
package main
import (
"flag"
"github.com/golang/glog"
)
func main() {
glog.MaxSize = 1024 * 1024 * 1024 // 1G自动分割
flag.Parse()
defer glog.Flush()
glog.Info("This is info message")
}
执行以上代码(保存在example3.go文件中):
$ go run example3.go -log_dir=log -alsologtostderr -log_backtrace_at=example3.go:13
I1202 10:12:41.304582 1340 example3.go:13] This is info message
goroutine 1 [running]:
... 打印backtrace,此处省略 ...
I1202 10:12:41.304779 1340 example3.go:14] This is info message: 123
logrus介绍
logrus是目前Github上star数量最多的日志包,功能强大、性能高效、高度灵活,还提供了自定义插件的功能。很多优秀的开源项目,例如:docker
、prometheus
等都使用了logrus。logrus除了具有日志的基本功能外,还具有如下特性:
- 支持常用的日志级别,logrus支持如下日志级别:Debug、Info、Warn、Error、Fatal和Panic。
- 可扩展,logrus的hook机制允许使用者通过hook的方式将日志分发到任意地方,例如:本地文件、标准输出、elasticsearch、logstash、kafka等。
- 支持自定义日志格式,logrus内置了2种格式:JSONFormatter和TextFormatter。除此之外,logrus允许使用者通过实现Formatter接口,来自定义日志格式。
- 结构化日志记录,logrus的Field机制可以允许使用者自定义日志字段,而不是通过冗长的消息来记录日志。
- 预设日志字段,logrus的Default Fields机制可以给一部分或者全部日志统一添加共同的日志字段,例如给某次HTTP请求的所有日志添加X-Request-ID字段。
- Fatal handlers:logrus允许注册一个或多个handler,当发生fatal级别的日志时调用。当我们的程序需要优雅关闭时,该特性会非常有用。
logrus使用方法如下:
- 基本用法
logrus可以通过简单的配置,来定义输出、格式或者日志级别等,示例如下:
package main
import (
"os"
"github.com/sirupsen/logrus"
)
func main() {
// logrus设置
logrus.SetFormatter(&logrus.JSONFormatter{})
logrus.SetOutput(os.Stdout)
logrus.SetLevel(logrus.WarnLevel)
// logrus使用
logrus.Debug("Useful debugging information.")
logrus.Info("Something noteworthy happened!")
logrus.Warn("You should probably take a look at this.")
logrus.Error("Something failed but I'm not quitting.")
logrus.WithFields(logrus.Fields{
"animal": "walrus",
"size": 10,
}).Info("A group of walrus emerges from the ocean")
logrus.WithFields(logrus.Fields{
"omg": true,
"number": 122,
}).Warn("The group's number increased tremendously!")
}
可以通过logrus.SetFormatter设置输出的日志格式,logrus自带有JSONFormatter和TextFormatter。通过logrus.SetLevel来设置日志级别,通过logrus.SetOutput设置日志输出等。
假设上述代码保存在example1.go文件中,运行代码:
$ go run example1.go
{"level":"warning","msg":"You should probably take a look at this.","time":"2020-12-03T22:35:35+08:00"}
{"level":"error","msg":"Something failed but I'm not quitting.","time":"2020-12-03T22:35:35+08:00"}
{"level":"warning","msg":"The group's number increased tremendously!","number":122,"omg":true,"time":"2020-12-03T22:35:35+08:00"}
- Default Fields
通常,在一个应用中、或者应用的一部分中,始终附带一些固定的记录字段会很有帮助。比如在处理用户HTTP请求时,上下文中所有的日志都会有request_id。为了避免每次记录日志都要使用:
logrus.WithFields(logrus.Fields{"request_id”", request_id})
我们可以创建一个logrus.Entry实例,为这个实例设置默认Fields,把logrus.Entry实例设置到记录器Logger,再记录日志时每次都会附带上这些默认的字段。
logger := log.WithFields(log.Fields{"request_id": request_id})
logger.Info("something happened on that request") // 也会记录request_id
logger.Warn("something not great happened")
- Hook接口
logrus具有hook能力,允许我们自定义一些日志处理逻辑,实现一个hook只需要实现如下接口:
// logrus在记录Levels()返回的日志级别的消息时会触发HOOK,
// 按照Fire方法定义的内容修改logrus.Entry.
type Hook interface {
Levels() []Level
Fire(*Entry) error
}
一个简单自定义hook如下,DefaultFieldHook定义会在所有级别的日志消息中加入默认字段myHook="MyHookTest"
:
type DefaultFieldHook struct {
}
func (hook *DefaultFieldHook) Fire(entry *log.Entry) error {
entry.Data["myHook"] = " MyHookTest "
return nil
}
func (hook *DefaultFieldHook) Levels() []log.Level {
return log.AllLevels
}
实现了hook之后,只需要调用log.AddHook(hook)即可将自定义的hook注册到logrus中。通过hook可以实现很多强大的日志处理功能,比较常见的用法是,当有指定级别的日志产生时,邮件通知或者告警给相关负责人。
zap包介绍
zap是uber开源的日志包,以高性能著称,很多公司的日志包都是基于zap改造而来。zap除了具有日志基本的功能之外,还具有很多强大的特性:
- 支持常用的日志级别,例如:Debug、Info、Warn、Error、DPanic、Panic、Fatal。
- 性能非常高,zap具有非常高的性能,适合对性能要求比较高的场景。
- 像logrus一样,支持结构化的日志记录。
- 支持预设日志字段。
- 支持针对特定的日志级别,输出调用堆栈。
- 支持hook。
zap使用方法
基本用法:
zap使用方法跟其他日志包使用方法比较类似,如下是一个常见的用法:
package main
import (
"time"
"go.uber.org/zap"
)
func main() {
logger, _ := zap.NewProduction()
defer logger.Sync() // flushes buffer, if any
url := "http://marmotedu.com"
logger.Info("failed to fetch URL",
zap.String("url", url),
zap.Int("attempt", 3),
zap.Duration("backoff", time.Second),
)
sugar := logger.Sugar()
sugar.Infow("failed to fetch URL",
"url", url,
"attempt", 3,
"backoff", time.Second,
)
sugar.Infof("Failed to fetch URL: %s", url)
}
将上述代码保存在 example1.go
文件中,运行:
{"level":"info","ts":1607006503.3008754,"caller":"zap/example1.go:13","msg":"failed to fetch URL","url":"http://marmotedu.com","attempt":3,"backoff":1}
{"level":"info","ts":1607006503.3009226,"caller":"zap/example1.go:20","msg":"failed to fetch URL","url":"http://marmotedu.com","attempt":3,"backoff":1}
{"level":"info","ts":1607006503.300958,"caller":"zap/example1.go:25","msg":"Failed to fetch URL: http://marmotedu.com"}
默认的日志输出格式为JSON格式,并记录了文件名和行号。
上述代码通过zap.NewProduction()
创建了一个logger,zap还提供了zap.NewExample()
、zap.NewDevelopment()
来快速创建一个logger,不同方法创建的logger具有不同的设置,Example适合用在测试代码中,Development在开发环境中使用,Production用在生产环境。如果想自定义logger,可以调用zap.New()
方法来创建。logger提供了Debug、Info、Warn、Error、Panic、Fatal等方法,用来记录不同级别的日志。在程序退出时,注意要调用defer logger.Sync()
将缓存中的日志刷新到磁盘文件中。
当我们对日志的性能要求比较高时,可以使用Logger而非SugaredLogger,Logger性能更好,内存分配次数更少。 为了提高性能,Logger没有使用interface
和反射,并且Logger只支持结构化的日志,所以在使用Logger时,需要指定具体的类型和key-value格式的日志字段,例如:
logger.Info("failed to fetch URL",
zap.String("url", url),
zap.Int("attempt", 3),
zap.Duration("backoff", time.Second),
)
如果觉得Logger的日志格式比较繁琐,可以使用更加便捷的SugaredLogger
,调用logger.Sugar()
即可创建SugaredLogger
。SugaredLogger
的使用比Logger
简单,但性能比Logger低 50% 左右,可以用在调用次数不高的函数中,调用方式如下:
sugar := logger.Sugar()
sugar.Infow("failed to fetch URL",
"url", url,
"attempt", 3,
"backoff", time.Second,
)
sugar.Infof("Failed to fetch URL: %s", url)
定制Logger
可以使用NexExample()/NewDevelopment()/NewProduction()
函数创建默认的Logger,每种方法创建的Logger配置不一样,也可以创建一个定制化的Logger,创建方式如下:
package main
import (
"encoding/json"
"go.uber.org/zap"
)
func main() {
rawJSON := []byte(`{
"level":"debug",
"encoding":"json",
"outputPaths": ["stdout", "test.log"],
"errorOutputPaths": ["stderr"],
"initialFields":{"name":"dj"},
"encoderConfig": {
"messageKey": "message",
"levelKey": "level",
"levelEncoder": "lowercase"
}
}`)
var cfg zap.Config
if err := json.Unmarshal(rawJSON, &cfg); err != nil {
panic(err)
}
logger, err := cfg.Build()
if err != nil {
panic(err)
}
defer logger.Sync()
logger.Info("server start work successfully!")
}
以上示例调用zap.Config的Build方法创建了一个输出到标准输出和文件test.log的Logger,将上述代码保存在example2.go
文件中,运行:
$ go run example2.go
{"level":"info","message":"server start work successfully!","name":"dj"}
zap.Config定义如下:
type Config struct {
Level AtomicLevel
Development bool
DisableCaller bool
DisableStacktrace bool
Sampling *SamplingConfig
Encoding string
EncoderConfig zapcore.EncoderConfig
OutputPaths []string
ErrorOutputPaths []string
InitialFields map[string]interface{}
}
Config结构体,各字段说明如下:
- Level:日志级别。
- Development:设置Logger的模式为development模式。
- DisableCaller:禁用调用信息. 该字段值为 true 时, 日志中将不再显示该日志所在的函数调用信息。
- DisableStacktrace:禁用自动堆栈跟踪捕获。
- Sampling:流控配置, 也叫采样. 单位是每秒钟, 作用是限制日志在每秒钟内的输出数量, 以防止CPU和IO被过度占用。
- Encoding:指定日志编码器, 目前仅支持两种编码器:console和json,默认为json。
- EncoderConfig:编码配置。
- OutputPaths:配置日志标准输出,可以配置多个日志输出路径, 一般情况可以仅配置标准输出或输出到文件, 如有需求的话, 也可以两者同时配置。
- ErrorOutputPaths:错误输出路径,可以是多个。
- InitialFields:初始化字段配置, 该配置的字段会以结构化的形式打印在每条日志输出中。
调用zap.Config的Build()方法,可以使用zap.Config配置创建一个Logger。
其中EncoderConfig为编码配置:
type EncoderConfig struct {
MessageKey string `json:"messageKey" yaml:"messageKey"`
LevelKey string `json:"levelKey" yaml:"levelKey"`
TimeKey string `json:"timeKey" yaml:"timeKey"`
NameKey string `json:"nameKey" yaml:"nameKey"`
CallerKey string `json:"callerKey" yaml:"callerKey"`
FunctionKey string `json:"functionKey" yaml:"functionKey"`
StacktraceKey string `json:"stacktraceKey" yaml:"stacktraceKey"`
LineEnding string `json:"lineEnding" yaml:"lineEnding"`
EncodeLevel LevelEncoder `json:"levelEncoder" yaml:"levelEncoder"`
EncodeTime TimeEncoder `json:"timeEncoder" yaml:"timeEncoder"`
EncodeDuration DurationEncoder `json:"durationEncoder" yaml:"durationEncoder"`
EncodeCaller CallerEncoder `json:"callerEncoder" yaml:"callerEncoder"`
EncodeName NameEncoder `json:"nameEncoder" yaml:"nameEncoder"`
ConsoleSeparator string `json:"consoleSeparator" yaml:"consoleSeparator"`
}
常用的设置如下:
- MessageKey:日志中信息的键名,默认为msg。
- LevelKey:日志中级别的键名,默认为level。
- EncodeLevel:日志中级别的格式,默认为小写,如debug/info。
- 选项
zap支持多种选项,选项的使用方式如下:
package main
import "go.uber.org/zap"
func main() {
logger, _ := zap.NewProduction(zap.AddCaller())
defer logger.Sync()
logger.Info("hello world")
}
将上述代码保存在example3.go中,执行:
$ go run example3.go
{"level":"info","ts":1607010625.6718638,"caller":"zap/example3.go:9","msg":"hello world"}
上述日志输出了日志的调用信息(文件名:行号)"caller":"zap/example3.go:9"
。zap提供了多个选项可供选择:
AddStacktrace(lvl zapcore.LevelEnabler)
:用来在指定级别及以上级别输出调用堆栈。zap.WithCaller(enabled bool)
:指定是否在日志输出内容中增加文件名和行号。zap.AddCaller()
:与zap.WithCaller(true)等价,指定在日志输出内容中增加行号和文件名。zap. AddCallerSkip(skip int)
:指定在调用栈中跳过的调用深度,否则通过调用栈获得的行号可能总是日志组件中的行号。zap. IncreaseLevel(lvl zapcore.LevelEnabler)
:提高日志级别,如果传入的lvl比当前logger的级别低,则不会改变日志级别。ErrorOutput(w zapcore.WriteSyncer)
:指定日志组件中出现异常时的输出位置。Fields(fs ...Field)
:添加公共字段。Hooks(hooks ...func(zapcore.Entry) error)
:注册钩子函数,用来在日志打印时同时调用hook方法。WrapCore(f func(zapcore.Core) zapcore.Core)
:替换Logger的zapcore.Core。 -Development()
:将Logger修改为Development模式。
预设日志字段
如果每条日志都期望加一些公共字段,例如requestID,可以在创建Logger时使用Fields(fs ...Field)
选项,如下代码中,添加了requestID、userID公共字段到每条日志中:
package main
import "go.uber.org/zap"
func main() {
logger := zap.NewExample(zap.Fields(
zap.Int("userID", 10),
zap.String("requestID", "fbf54504"),
))
logger.Debug("This is a debug message")
logger.Info("This is a info message")
}
将上述代码保存到preset_field.go
文件中,运行:
$ go run preset_field.go
{"level":"debug","msg":"This is a debug message","userID":10,"requestID":"fbf54504"}
{"level":"info","msg":"This is a info message","userID":10,"requestID":"fbf54504"}
全局Logger:
zap提供了2个全局Logger,可以方便我们调用:
*zap.Logger
:可通过zap.L()获得,提供了Debug()、Info()、Warn()、Error()、Panic()、DPanic()、Fatal()方法来记录日志。*zap.SugaredLogger
:可通过zap.S()获得,提供了Debugf()、Debugw()、Infof()、Infow()、Warnf()、Warnw()、Errorf()、Errorw()、Panicf()、Panicw()、DPanicf()、DPanicw()、Fatalf()、Fatalw()方法来记录日志。
默认的全局Logger不会记录任何日志,它是一个无用的Logger,例如zap.L()返回了名为_globalL
的Logger,_globalL
定义为:
_globalL = NewNop()
func NewNop() *Logger {
return &Logger{
core: zapcore.NewNopCore(),
errorOutput: zapcore.AddSync(ioutil.Discard),
addStack: zapcore.FatalLevel + 1,
}
}
zapcore.NewNopCore()
函数定义为:
type nopCore struct{}
// NewNopCore returns a no-op Core.
func NewNopCore() Core { return nopCore{} }
func (nopCore) Enabled(Level) bool { return false }
func (n nopCore) With([]Field) Core { return n }
func (nopCore) Check(_ Entry, ce *CheckedEntry) *CheckedEntry { return ce }
func (nopCore) Write(Entry, []Field) error { return nil }
func (nopCore) Sync() error { return nil }
// NewCore creates a Core that writes logs to a WriteSyncer.
func NewCore(enc Encoder, ws WriteSyncer, enab LevelEnabler) Core {
return &ioCore{
LevelEnabler: enab,
enc: enc,
out: ws,
}
}
可以看到NewNop()创建一个不记录任何日志、任何内部错误、不执行任何钩子的Logger。可以使用ReplaceGlobals函数将全局Logger替换为我们创建的Logger,例如:
package main
import "go.uber.org/zap"
func main() {
zap.L().Info("default global Logger")
zap.S().Info("default global SugaredLogger")
logger := zap.NewExample()
defer logger.Sync()
zap.ReplaceGlobals(logger)
zap.L().Info("replaced global Logger")
zap.S().Info("replaced global SugaredLogger")
}
假设上述代码保存在global_logger.go
文件中,运行:
$ go run global_logger.go
{"level":"info","msg":"replaced global Logger"}
{"level":"info","msg":"replaced global SugaredLogger"}
可以看到在zap.ReplaceGlobals(logger)
之前的日志,并没有被打印出来。
其它开源包
还有很多其它优秀的开源日志包供我们选择,例如:log15、zerolog、seelog、apex/log、go-logging等。你可以在开发中,都详加调研,选择一个适合自己的日志包。
开源日志包选择
我们介绍了很多日志包,每种日志包使用的场景不同,你可以根据自己的需求结合日志包的特性进行选择:
- 标准库log包: 标准库log包不支持日志级别、日志分割、日志格式等功能,所以在大型项目中很少直接使用,通常用于一些短小的程序,比如:用于生成JWT Token的main.go文件中。标准库日志包也很适合一些简短的代码,用于快速调试和验证。
- glog: glog实现了日志包的基本功能,对于一些对日志功能要求不多的小型项目非常适合。
- logrus: logrus功能强大,不仅实现了日志包的基本功能,还有很多高级特性,适合一些大型项目,尤其是需要结构化日志记录的项目。
- zap: zap提供了很强大的日志功能,性能高,内存分配次数少,适合对日志性能要求很高的项目。另外,zap包中的子包zapcore,提供了很多底层的日志接口,适合用来做二次封装。例如 iam 项目作者 就基于zap和zapcore封装了marmotedu/log日志包,该日志包可以很好的兼容glog,封装背景是因为在做容器云平台开发时,发现kubernetes源码中大量使用了glog,需要日志包能够兼容glog。
接下来,我们来学习如何从零开始开发出一个日志包:
从0编写一个日志包
接下来,我会向你展示如何快速编写一个具备基本功能的日志包,让你通过这个简短的日志包实现掌握日志包的核心设计思路。该日志包主要实现以下几个功能:
- 支持自定义配置。
- 支持文件名和行号。
- 支持日志级别 Debug、Info、Warn、Error、Panic、Fatal。
- 支持输出到本地文件和标准输出。
- 支持JSON和TEXT格式的日志输出,支持自定义日志格式。
- 支持选项模式。
日志包名称为cuslog
,示例项目完整代码存放在 cuslog。
具体实现分为以下四个步骤:
- 定义:定义日志级别和日志选项。
- 创建:创建Logger及各级别日志打印方法。
- 写入:将日志输出到支持的输出中。
- 自定义:自定义日志输出格式。
定义日志级别和日志选项
一个基本的日志包,首先需要定义好日志级别和日志选项。本示例将定义代码保存在options.go文件中。
可以通过如下方式定义日志级别:
type Level uint8
const (
DebugLevel Level = iota
InfoLevel
WarnLevel
ErrorLevel
PanicLevel
FatalLevel
)
var LevelNameMapping = map[Level]string{
DebugLevel: "DEBUG",
InfoLevel: "INFO",
WarnLevel: "WARN",
ErrorLevel: "ERROR",
PanicLevel: "PANIC",
FatalLevel: "FATAL",
}
在日志输出时,要通过对比开关级别和输出级别的大小,来决定是否输出,所以日志级别Level要定义成方便比较的数值类型。几乎所有的日志包都是用常量计数器iota
来定义日志级别。
另外,因为要在日志输出中,输出可读的日志级别(例如输出INFO而不是1),所以需要有Level到Level Name的映射LevelNameMapping,LevelNameMapping会在格式化时用到。
接下来看定义日志选项。日志需要是可配置的,方便开发者根据不同的环境设置不同的日志行为,比较常见的配置选项为:
- 日志级别。
- 输出位置,例如标准输出或者文件。
- 输出格式,例如JSON或者Text。
- 是否开启文件名和行号。
本示例的日志选项定义如下:
type options struct {
output io.Writer
level Level
stdLevel Level
formatter Formatter
disableCaller bool
}
为了灵活地设置日志的选项,你可以通过选项模式,来对日志选项进行设置:
type Option func(*options)
func initOptions(opts ...Option) (o *options) {
o = &options{}
for _, opt := range opts {
opt(o)
}
if o.output == nil {
o.output = os.Stderr
}
if o.formatter == nil {
o.formatter = &TextFormatter{}
}
return
}
func WithLevel(level Level) Option {
return func(o *options) {
o.level = level
}
}
...
func SetOptions(opts ...Option) {
std.SetOptions(opts...)
}
func (l *logger) SetOptions(opts ...Option) {
l.mu.Lock()
defer l.mu.Unlock()
for _, opt := range opts {
opt(l.opt)
}
}
具有选项模式的日志包,可通过以下方式,来动态地修改日志的选项:
cuslog.SetOptions(cuslog.WithLevel(cuslog.DebugLevel))
你可以根据需要,对每一个日志选项创建设置函数 WithXXXX
。这个示例日志包支持如下选项设置函数:
- WithOutput(output io.Writer):设置输出位置。
- WithLevel(level Level):设置输出级别。
- WithFormatter(formatter Formatter):设置输出格式。
- WithDisableCaller(caller bool):设置是否打印文件名和行号。
创建Logger及各级别日志打印方法
为了打印日志,我们需要根据日志配置,创建一个Logger,然后通过调用Logger的日志打印方法,完成各级别日志的输出。本示例将创建代码保存在logger.go文件中。
可以通过如下方式创建Logger
:
var std = New()
type logger struct {
opt *options
mu sync.Mutex
entryPool *sync.Pool
}
func New(opts ...Option) *logger {
logger := &logger{opt: initOptions(opts...)}
logger.entryPool = &sync.Pool{New: func() interface{} { return entry(logger) }}
return logger
}
上述代码中,定义了一个Logger,并实现了创建Logger的New函数。日志包都会有一个默认的全局Logger,本示例通过 var std = New()
创建了一个全局的默认Logger。cuslog.Debug
、cuslog.Info
和cuslog.Warnf
等函数,则是通过调用std Logger
所提供的方法来打印日志的。
定义了一个Logger之后,还需要给该Logger添加最核心的日志打印方法,要提供所有支持级别的日志打印方法。
如果日志级别是Xyz,则通常需要提供两类方法,分别是非格式化方法Xyz(args ...interface{})
和格式化方法Xyzf(format string, args ...interface{})
,例如:
func (l *logger) Debug(args ...interface{}) {
l.entry().write(DebugLevel, FmtEmptySeparate, args...)
}
func (l *logger) Debugf(format string, args ...interface{}) {
l.entry().write(DebugLevel, format, args...)
}
本示例实现了如下方法:Debug、Debugf、Info、Infof、Warn、Warnf、Error、Errorf、Panic、Panicf、Fatal、Fatalf。更详细的实现,你可以参考 cuslog/logger.go。
这里要注意,Panic、Panicf要调用panic()函数,Fatal、Fatalf函数要调用 os.Exit(1)
函数。
将日志输出到支持的输出中
调用日志打印函数之后,还需要将这些日志输出到支持的输出中,所以需要实现write
函数,它的写入逻辑保存在entry.go文件中。实现方式如下:
type Entry struct {
logger *logger
Buffer *bytes.Buffer
Map map[string]interface{}
Level Level
Time time.Time
File string
Line int
Func string
Format string
Args []interface{}
}
func (e *Entry) write(level Level, format string, args ...interface{}) {
if e.logger.opt.level > level {
return
}
e.Time = time.Now()
e.Level = level
e.Format = format
e.Args = args
if !e.logger.opt.disableCaller {
if pc, file, line, ok := runtime.Caller(2); !ok {
e.File = "???"
e.Func = "???"
} else {
e.File, e.Line, e.Func = file, line, runtime.FuncForPC(pc).Name()
e.Func = e.Func[strings.LastIndex(e.Func, "/")+1:]
}
}
e.format()
e.writer()
e.release()
}
func (e *Entry) format() {
_ = e.logger.opt.formatter.Format(e)
}
func (e *Entry) writer() {
e.logger.mu.Lock()
_, _ = e.logger.opt.output.Write(e.Buffer.Bytes())
e.logger.mu.Unlock()
}
func (e *Entry) release() {
e.Args, e.Line, e.File, e.Format, e.Func = nil, 0, "", "", ""
e.Buffer.Reset()
e.logger.entryPool.Put(e)
}
上述代码,首先定义了一个Entry结构体类型,该类型用来保存所有的日志信息,即日志配置和日志内容。写入逻辑都是围绕Entry类型的实例来完成的。
用Entry的write方法来完成日志的写入,在write方法中,会首先判断日志的输出级别和开关级别,如果输出级别小于开关级别,则直接返回,不做任何记录。
在write中,还会判断是否需要记录文件名和行号,如果需要则调用 runtime.Caller()
来获取文件名和行号,调用 runtime.Caller()
时,要注意传入正确的栈深度。
write函数中调用 e.format
来格式化日志,调用 e.writer
来写入日志,在创建Logger传入的日志配置中,指定了输出位置 output io.Writer
,output类型为 io.Writer
,示例如下:
type Writer interface {
Write(p []byte) (n int, err error)
}
io.Writer实现了Write方法可供写入,所以只需要调用e.logger.opt.output.Write(e.Buffer.Bytes())
即可将日志写入到指定的位置中。最后,会调用release()方法来清空缓存和对象池。至此,我们就完成了日志的记录和写入。
自定义日志输出格式
cuslog包支持自定义输出格式,并且内置了JSON和 Text 格式的 Formatter
。Formatter
接口定义为:
type Formatter interface {
Format(entry *Entry) error
}
cuslog内置的Formatter有两个:JSON和TEXT。
测试日志包
cuslog日志包开发完成之后,可以编写测试代码,调用cuslog
包来测试cuslog
包,代码如下:
package main
import (
"log"
"os"
"github.com/marmotedu/gopractise-demo/log/cuslog"
)
func main() {
cuslog.Info("std log")
cuslog.SetOptions(cuslog.WithLevel(cuslog.DebugLevel))
cuslog.Debug("change std log to debug level")
cuslog.SetOptions(cuslog.WithFormatter(&cuslog.JsonFormatter{IgnoreBasicFields: false}))
cuslog.Debug("log in json format")
cuslog.Info("another log in json format")
// 输出到文件
fd, err := os.OpenFile("test.log", os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644)
if err != nil {
log.Fatalln("create file test.log failed")
}
defer fd.Close()
l := cuslog.New(cuslog.WithLevel(cuslog.InfoLevel),
cuslog.WithOutput(fd),
cuslog.WithFormatter(&cuslog.JsonFormatter{IgnoreBasicFields: false}),
)
l.Info("custom log with json formatter")
}
将上述代码保存在main.go文件中,运行:
$ go run example.go
2020-12-04T10:32:12+08:00 INFO example.go:11 std log
2020-12-04T10:32:12+08:00 DEBUG example.go:13 change std log to debug level
{"file":"/home/colin/workspace/golang/src/github.com/marmotedu/gopractise-demo/log/cuslog/example/example.go:15","func":"main.main","message":"log in json format","level":"DEBUG","time":"2020-12-04T10:32:12+08:00"}
{"level":"INFO","time":"2020-12-04T10:32:12+08:00","file":"/home/colin/workspace/golang/src/github.com/marmotedu/gopractise-demo/log/cuslog/example/example.go:16","func":"main.main","message":"another log in json format"}
到这里日志包就开发完成了,完整包见 log/cuslog。
IAM项目日志包设计
这一讲的最后,我们再来看下我们的IAM项目中,日志包是怎么设计的。
先来看一下IAM项目log包的存放位置:pkg/log。放在这个位置,主要有两个原因:
- 第一个,
log
包属于IAM项目,有定制开发的内容; - 第二个,
log
包功能完备、成熟,外部项目也可以使用。
该log包是基于 go.uber.org/zap
包封装而来的,根据需要添加了更丰富的功能。接下来,我们通过log包的Options,来看下log包所实现的功能:
// Options contains configuration items related to log.
type Options struct {
OutputPaths []string `json:"output-paths" mapstructure:"output-paths"`
ErrorOutputPaths []string `json:"error-output-paths" mapstructure:"error-output-paths"`
Level string `json:"level" mapstructure:"level"`
Format string `json:"format" mapstructure:"format"`
DisableCaller bool `json:"disable-caller" mapstructure:"disable-caller"`
DisableStacktrace bool `json:"disable-stacktrace" mapstructure:"disable-stacktrace"`
EnableColor bool `json:"enable-color" mapstructure:"enable-color"`
Development bool `json:"development" mapstructure:"development"`
Name string `json:"name" mapstructure:"name"`
}
Options各配置项含义如下:
- development:是否是开发模式。如果是开发模式,会对DPanicLevel进行堆栈跟踪。
- name:Logger的名字。
- disable-caller:是否开启 caller,如果开启会在日志中显示调用日志所在的文件、函数和行号。
- disable-stacktrace:是否在Panic及以上级别禁止打印堆栈信息。
- enable-color:是否开启颜色输出,true,是;false,否。
- level:日志级别,优先级从低到高依次为:Debug, Info, Warn, Error, Dpanic, Panic, Fatal。
- format:支持的日志输出格式,目前支持Console和JSON两种。Console其实就是Text格式。
- output-paths:支持输出到多个输出,用逗号分开。支持输出到标准输出(stdout)和文件。
- error-output-paths:zap内部(非业务)错误日志输出路径,多个输出,用逗号分开。
log包的Options结构体支持以下3个方法:
- Build方法。Build方法可以根据Options构建一个全局的Logger。
- AddFlags方法。AddFlags方法可以将Options的各个字段追加到传入的pflag.FlagSet变量中。
- String方法。String方法可以将Options的值以JSON格式字符串返回。
log包实现了以下3种日志记录方法:
log.Info("This is a info message", log.Int32("int_key", 10))
log.Infof("This is a formatted %s message", "info")
log.Infow("Message printed with Infow", "X-Request-ID", "fbf54504-64da-4088-9b86-67824a7fb508")
Info
使用指定的 key/value
记录日志。Infof
格式化记录日志。 Infow
也是使用指定的 key/value
记录日志,跟 Info
的区别是:使用 Info
需要指定值的类型,通过指定值的日志类型,日志库底层不需要进行反射操作,所以使用 Info
记录日志性能最高。
log包支持非常丰富的类型,具体你可以参考 types.go。
上述日志输出为:
2021-07-06 14:02:07.070 INFO This is a info message {"int_key": 10}
2021-07-06 14:02:07.071 INFO This is a formatted info message
2021-07-06 14:02:07.071 INFO Message printed with Infow {"X-Request-ID": "fbf54504-64da-4088-9b86-67824a7fb508"}
log包为每种级别的日志都提供了3种日志记录方式,举个例子:假设日志格式为 Xyz
,则分别提供了 Xyz(msg string, fields ...Field)
,Xyzf(format string, v ...interface{})
,Xyzw(msg string, keysAndValues ...interface{})
3种日志记录方法。
另外,log包相较于一般的日志包,还提供了众多记录日志的方法。
第一个方法, log包支持V Level,可以通过整型数值来灵活指定日志级别,数值越大,优先级越低。例如:
⚠️
V Level
是指在glog
日志库中用于控制日志级别的一种机制。glog
是一个 Go 语言的日志库,可以方便地进行日志记录和输出。
V Level
表示 verbose level,即冗长程度。在glog
中,通过设置V Level
的值,可以控制日志的输出级别。V Level
的取值范围是0~~4
,其中0表示只输出普通日志,1~~4
表示输出对应级别的调试信息。
glog
中通过V()
方法来设置V Level
的值,例如:glog.V(1).Info("This is a verbose level 1 log message.")
在这个例子中,通过
glog.V(1)
设置V Level
的值为1,然后调用Info()
方法输出一条日志。由于V Level
的值为1,因此这条日志会被输出。在
glog
中,还可以使用vmodule
选项来控制不同包中的日志输出级别。通过设置vmodule
选项,可以实现更细粒度的日志控制。例如:$ go run main.go -vmodule=module1=2,module2=3
在这个例子中,通过设置
vmodule
选项来控制module1
包中的日志输出级别为2,module2
包中的日志输出级别为3。这样,就可以更加灵活地控制日志的输出级别,以适应不同的应用场景。
// V level使用
log.V(1).Info("This is a V level message")
log.V(1).Infof("This is a %s V level message", "formatted")
log.V(1).Infow("This is a V level message with fields", "X-Request-ID", "7a7b9f24-4cae-4b2a-9464-69088b45b904")
这里要注意,Log.V只支持 Info
、Infof
、Infow
三种日志记录方法。
第二个方法, log包支持WithValues函数,例如:
// WithValues使用
lv := log.WithValues("X-Request-ID", "7a7b9f24-4cae-4b2a-9464-69088b45b904")
lv.Infow("Info message printed with [WithValues] logger")
lv.Infow("Debug message printed with [WithValues] logger")
上述日志输出如下:
2021-07-06 14:15:28.555 INFO Info message printed with [WithValues] logger {"X-Request-ID": "7a7b9f24-4cae-4b2a-9464-69088b45b904"}
2021-07-06 14:15:28.556 INFO Debug message printed with [WithValues] logger {"X-Request-ID": "7a7b9f24-4cae-4b2a-9464-69088b45b904"}
WithValues
可以返回一个携带指定key-value的Logger,供后面使用。
第三个方法, log包提供 WithContext
和 FromContext
用来将指定的Logger添加到某个Context中,以及从某个Context中获取Logger,例如:
// Context使用
ctx := lv.WithContext(context.Background())
lc := log.FromContext(ctx)
lc.Info("Message printed with [WithContext] logger")
WithContext
和FromContext
非常适合用在以context.Context
传递的函数中,例如:
func main() {
...
// WithValues使用
lv := log.WithValues("X-Request-ID", "7a7b9f24-4cae-4b2a-9464-69088b45b904")
// Context使用
lv.Infof("Start to call pirntString")
ctx := lv.WithContext(context.Background())
pirntString(ctx, "World")
}
func pirntString(ctx context.Context, str string) {
lc := log.FromContext(ctx)
lc.Infof("Hello %s", str)
}
上述代码输出如下:
2021-07-06 14:38:02.050 INFO Start to call pirntString {"X-Request-ID": "7a7b9f24-4cae-4b2a-9464-69088b45b904"}
2021-07-06 14:38:02.050 INFO Hello World {"X-Request-ID": "7a7b9f24-4cae-4b2a-9464-69088b45b904"}
将Logger添加到Context中,并通过Context在不同函数间传递,可以使key-value在不同函数间传递。例如上述代码中, X-Request-ID
在main函数、printString函数中的日志输出中均有记录,从而实现了一种调用链的效果。
第四个方法, 可以很方便地从Context中提取出指定的key-value,作为上下文添加到日志输出中,例如 internal/apiserver/api/v1/user/create.go文件中的日志调用:
// Info logs a message at level Info on the compatibleLogger.
log.L(c).Info("user create function called.")
通过调用 Log.L()
函数,实现如下:
// L method output with specified context value.
func L(ctx context.Context) *zapLogger {
return std.L(ctx)
}
func (l *zapLogger) L(ctx context.Context) *zapLogger {
lg := l.clone()
requestID, _ := ctx.Value(KeyRequestID).(string)
username, _ := ctx.Value(KeyUsername).(string)
lg.zapLogger = lg.zapLogger.With(zap.String(KeyRequestID, requestID), zap.String(KeyUsername, username))
return lg
}
L()
方法会从传入的Context中提取出 requestID
和 username
,追加到Logger中,并返回Logger。这时候调用该Logger的Info、Infof、Infow等方法记录日志,输出的日志中均包含 requestID
和 username
字段,例如:
2021-07-06 14:46:00.743 INFO apiserver secret/create.go:23 create secret function called. {"requestID": "73144bed-534d-4f68-8e8d-dc8a8ed48507", "username": "admin"}
通过将Context在函数间传递,很容易就能实现调用链效果,例如:
// Create add new secret key pairs to the storage.
func (s *SecretHandler) Create(c *gin.Context) {
log.L(c).Info("create secret function called.")
...
secrets, err := s.srv.Secrets().List(c, username, metav1.ListOptions{
Offset: pointer.ToInt64(0),
Limit: pointer.ToInt64(-1),
})
...
if err := s.srv.Secrets().Create(c, &r, metav1.CreateOptions{}); err != nil {
core.WriteResponse(c, err, nil)
return
}
core.WriteResponse(c, nil, r)
}
上述代码输出为:
2021-07-06 14:46:00.743 INFO apiserver secret/create.go:23 create secret function called. {"requestID": "73144bed-534d-4f68-8e8d-dc8a8ed48507", "username": "admin"}
2021-07-06 14:46:00.744 INFO apiserver secret/create.go:23 list secret from storage. {"requestID": "73144bed-534d-4f68-8e8d-dc8a8ed48507", "username": "admin"}
2021-07-06 14:46:00.745 INFO apiserver secret/create.go:23 insert secret to storage. {"requestID": "73144bed-534d-4f68-8e8d-dc8a8ed48507", "username": "admin"}
这里要注意, log.L
函数默认会从Context中取 requestID
和 username
键,这跟IAM项目有耦合度,但这不影响log
包供第三方项目使用。这也是我建议你自己封装日志包的原因。
总结
开发一个日志包,我们很多时候需要基于一些业界优秀的开源日志包进行二次开发。当前很多项目的日志包都是基于zap
日志包来封装的,如果你有封装的需要,我建议你优先选择zap日志包。
这一讲中,我先给你介绍了标准库log包、glog、logrus和zap这四种常用的日志包,然后向你展现了开发一个日志包的四个步骤,步骤如下:
- 定义日志级别和日志选项。
- 创建Logger及各级别日志打印方法。
- 将日志输出到支持的输出中。
- 自定义日志输出格式。
最后,我介绍了IAM项目封装的log包的设计和使用方式。log包基于 go.uber.org/zap
封装,并提供了以下强大特性:
- log包支持V Level,可以灵活的通过整型数值来指定日志级别。
- log包支持
WithValues
函数,WithValues
可以返回一个携带指定key-value对的Logger,供后面使用。 - log包提供
WithContext
和FromContext
用来将指定的Logger添加到某个Context中和从某个Context中获取Logger。 - log包提供了
Log.L()
函数,可以很方便的从Context中提取出指定的key-value对,作为上下文添加到日志输出中。
课后练习
- 尝试实现一个新的Formatter,可以使不同日志级别以不同颜色输出(例如:Error级别的日志输出中
Error
字符串用红色字体输出,Info
字符串用白色字体输出)。 - 尝试将runtime.Caller(2)函数调用中的
2
改成1
,看看日志输出是否跟修改前有差异,如果有差异,思考差异产生的原因。
END 链接
✴️版权声明 © :本书所有内容遵循CC-BY-SA 3.0协议(署名-相同方式共享)©