go语言记log:glog剖析

log的一个典型应用场景就是实现log分级,比如线上环境不需要记录DEBUG的log信息。今天介绍一下glog。先看一个glog的简单例子。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
//file name: glog.go
package main

import (
"flag"
"github.com/golang/glog"
)

func main() {
flag.Parse() // 1

glog.Info("This is a Info log") // 2
glog.Warning("This is a Warning log")
glog.Error("This is a Error log")

glog.V(1).Infoln("level 1") // 3
glog.V(2).Infoln("level 2")

glog.Flush() // 4
}

如果你之前没有用过glog,需要使用go get安装一下,你需要像下面这样执行这个go程序。上面标注的几个地方可以先注意一下,等文章读完就理解了。

1
2
3
$ go get
$ go build glog.go
$ ./glog -log_dir="./"

这时候不出意外的话,会在同级目录下生成下面几个类似的log文件。

1
2
3
glog.kltao-mac.kltao.log.ERROR.20160312-173205.22052
glog.kltao-mac.kltao.log.INFO.20160312-173205.22052
glog.kltao-mac.kltao.log.WARNING.20160312-173205.22052

这就是产生的log文件,打开第一个ERROR的log文件,文件内容如下。前面4行是文件响应信息,最后一行就是上面第14行代码记录的log内容。

1
2
3
4
5
Log file created at: 2016/03/12 17:32:05
Running on machine: kltao-mac
Binary: Built with gc go1.4.2 for darwin/amd64
Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu threadid file:line] msg
E0312 17:32:05.568597 22052 glog.go:15] This is a Error log

这个时候如果你打开另外两个INFO和WARNING的log文件,会发现WARNING日志文件中除了WARNING信息还记录了Error信息(This is a Error log),而INFO日志文件中则记录了所有的log信息(This is a Info/Warning/Error log)。很容易理解,这些log是有等级的(ERROR>WARNING>INFO),高等级的日志内容会同时会被记录到低等级的日志文件中去。那么glog提供了一个等级呢?答案是4个,除了上面提出的3个,还有一个FALTAL。
这时候又有一个问题来了,为什么第3处的日志信息没有记录下来呢?不急,这个时候如下重新执行一下。就可以在新的INFO日志文件中找到了对应的信息了。

1
./glog -log_dir="./" -v=3

对,就是这个-v参数。再说V之前,先说一下glog的命令行解析,对应代码就是标注的第1处。那么glog有多少种参数呢?

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
// By default, all log statements write to files in a temporary directory.
// This package provides several flags that modify this behavior.
// As a result, flag.Parse must be called before any logging is done.
//
// -logtostderr=false
// Logs are written to standard error instead of to files.
// -alsologtostderr=false
// Logs are written to standard error as well as to files.
// -stderrthreshold=ERROR
// Log events at or above this severity are logged to standard
// error as well as to files.
// -log_dir=""
// Log files will be written to this directory instead of the
// default temporary directory.
//
// Other flags provide aids to debugging.
//
// -log_backtrace_at=""
// When set to a file and line number holding a logging statement,
// such as
// -log_backtrace_at=gopherflakes.go:234
// a stack trace will be written to the Info log whenever execution
// hits that statement. (Unlike with -vmodule, the ".go" must be
// present.)
// -v=0
// Enable V-leveled logging at the specified level.
// -vmodule=""
// The syntax of the argument is a comma-separated list of pattern=N,
// where pattern is a literal file name (minus the ".go" suffix) or
// "glob" pattern and N is a V level. For instance,
// -vmodule=gopher*=3
// sets the V level to 3 in all Go files whose names begin "gopher".

glog.V(1).Infoln("level 1")这行代码表示设置的-v参数大于V()里面的参数才执行后面的Infoln。如果不加-v参数,默认等级为0,所以第三处的代码没有执行。具体实现不妨看一下源码实现,一目了然。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
type Verbose bool

func V(level Level) Verbose {
// This function tries hard to be cheap unless there's work to do.
// The fast path is two atomic loads and compares.

// Here is a cheap but safe test to see if V logging is enabled globally.
if logging.verbosity.get() >= level {
return Verbose(true)
}

// It's off globally but it vmodule may still be set.
// Here is another cheap but safe test to see if vmodule is enabled.
if atomic.LoadInt32(&logging.filterLength) > 0 {
// Now we need a proper lock to use the logging structure. The pcs field
// is shared so we must lock before accessing it. This is fairly expensive,
// but if V logging is enabled we're slow anyway.
logging.mu.Lock()
defer logging.mu.Unlock()
if runtime.Callers(2, logging.pcs[:]) == 0 {
return Verbose(false)
}
v, ok := logging.vmap[logging.pcs[0]]
if !ok {
v = logging.setV(logging.pcs[0])
}
return Verbose(v >= level)
}
return Verbose(false)
}

func (v Verbose) Info(args ...interface{}) {
if v {
logging.print(infoLog, args...)
}
}

func (v Verbose) Infoln(args ...interface{}) {
if v {
logging.println(infoLog, args...)
}
}

func (v Verbose) Infof(format string, args ...interface{}) {
if v {
logging.printf(infoLog, format, args...)
}
}

程序中标注的4个地方,除了第4个地方,其他都说了,Flush的作用清空缓冲区,就是把日志写到文件。golog初始化的时候,起了一个Flush的守护进程,然后定期去执行I/O操作,所以退出的时候需要显示清除一下缓冲区。glog启动的初始化代码如下。

1
2
3
4
func init() {
...
go logging.flushDaemon()
}

上面应该是glog的大部分使用方法了,更详细的信息可以参考github.com/golang/glog