go语言记log: glog剖析

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

//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程序。上面标注的几个地方可以先注意一下，等文章读完就理解了。

$ go get
$ go build glog.go
$ ./glog -log_dir="./"

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

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内容。

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日志文件中找到了对应的信息了。

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

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

// 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，所以第三处的代码没有执行。具体实现不妨看一下源码实现，一目了然。

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启动的初始化代码如下。

func init() {
    ...
    go logging.flushDaemon()
}

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