（转）跟我一起学Go系列：日志系统从入门到晋级
原文：https://zhuanlan.zhihu.com/p/361930459
日志模块在如今的应用中地位是如日中天，开发者没有日志就相当于双目失明，对程序的运行状态无法判断。Go 也不例外提供了基础的日志调用模块：log 模块。log 模块主要提供了 3 类接口，分别是 “Print 、Panic 、Fatal ”，下面一起看看基础日志包的使用。
Go log 包简单使用
三类接口基本使用：
- log.Print：打印日志，和 fmt 包没什么区别，只是加上了上面的日志格式。
- log.Fatal ：会先将日志内容打印到标准输出，接着调用系统的 os.exit(1) 接口，退出程序并返回状态 1 。但是有一点需要注意，由于是直接调用系统接口退出，defer 函数不会被调用。
- log.Panic：该函数把日志内容刷到标准错误后调用 panic 函数。
Go 原生 log 结构的定义如下：
type Logger struct {
mu sync.Mutex // ensures atomic writes; protects the following fields
prefix string // prefix to write at beginning of each line
flag int // properties
out io.Writer // destination for output
buf []byte // for accumulating text to write
}
可见在结构体中有 sync.Mutex 类型字段，所以 log 中所有的操作都是支持并发的。
下面看一下这三种 log 打印的用法：
package main
import (
"log"
)
func main() {
log.Print("我就是一条日志")
log.Printf("%s,","我是带格式的日志")
log.Panic("哈哈，我好痛")
}
输出：
2021/03/29 17:31:03 我是带格式的日志,
2021/03/29 17:31:03 哈哈，我好痛
panic: 哈哈，我好痛
goroutine 1 [running]:
log.Panic(0xc0002dff68, 0x1, 0x1)
/usr/local/go/src/log/log.go:351 +0xae
main.main()
/Users/yangyue/go/src/go-web-demo/main.go:24 +0xfa
使用非常简单，可以看到 log 的默认输出带了时间，非常的方便。Panic方法在输出后调用了Panic方法，所以抛出了异常信息。上面的示例中没有演示Fatal方法，你可以试着把log.Fatal()放在程序的第一行，你会发现下面的代码都不会执行。因为上面说过，它在打印完日志之后会调用os.exit(1)方法，所以系统就退出了。
定制打印参数
上面说到 log 打印的时候默认是自带时间的，那如果除了时间以外，我们还想要别的信息呢，当然 log 也是支持的。
SetFlags(flag int)方法提供了设置打印默认信息的能力，下面的字段是 log 中自带的支持的打印类型：
Ldate = 1 << iota // the date in the local time zone: 2009/01/23
Ltime // the time in the local time zone: 01:23:23
Lmicroseconds // microsecond resolution: 01:23:23.123123. assumes Ltime.
Llongfile // full file name and line number: /a/b/c/d.go:23
Lshortfile // final file name element and line number: d.go:23. overrides Llongfile
LUTC // if Ldate or Ltime is set, use UTC rather than the local time zone
LstdFlags = Ldate | Ltime // initial values for the standard logger
这是 log 包定义的一些抬头信息，有日期、时间、毫秒时间、绝对路径和行号、文件名和行号等，在上面都有注释说明，这里需要注意的是：如果设置了Lmicroseconds，那么Ltime就不生效了；设置了Lshortfile， Llongfile也不会生效，大家自己可以测试一下。
LUTC比较特殊，如果我们配置了时间标签，那么如果设置了LUTC的话，就会把输出的日期时间转为 0 时区的日期时间显示。
最后一个LstdFlags表示标准的日志抬头信息，也就是默认的，包含日期和具体时间。
使用方法：
func init(){
log.SetFlags(log.Ldate|log.Lshortfile)
}
使用 init 方法，可以在 main 函数执行之前初始化代码。另外，虽然参数是 int 类型，但是上例中使用位运算符传递了多个常量为什么会被识别到底传了啥进去了呢。这是因为源码中去做解析的时候，也是根据不同的常量组合的位运算去判断你传了啥的。所以先看源码，你就可以大胆的传了。
package main
import (
"log"
)
func main() {
log.SetFlags(log.Ldate|log.Lshortfile)
log.Print("我就是一条日志")
log.Printf("%s,","谁说我是日志了，我是错误")
}
输出：
2021/03/29 main.go:23: 我就是一条日志
2021/03/29 main.go:24: 谁说我是日志了，我是错误,
如何传自定义参数进日志
在 Java 开发中我们会有这样的日志需求：为了查日志更方便，我们需要在一个 http 请求或者 rpc 请求进来到结束的作用链中用一个唯一 id 将所有的日志串起来，这样可以在日志中搜索这个唯一 id 就能拿到这次请求的所有日志记录。
所以现在的任务是如何在 Go 的日志中去定义这样的一个 id。Go 中提供了这样的一个方法：SetPrefix(prefix string),通过log.SetPrefix可以指定输出日志的前缀。
package main
import (
uuid "github.com/satori/go.uuid"
"log"
)
func main() {
uuids, _ := uuid.NewV1()
log.SetPrefix(uuids.String() +" ")
log.SetFlags(log.Ldate|log.Lshortfile)
log.Print("我就是一条日志")
log.Printf("%s,","谁说我是日志了，我是错误")
}
输出：
e12ae2a4-9071-11eb-9c8f-acde48001122 2021/03/29 main.go:26: 我就是一条日志
e12ae2a4-9071-11eb-9c8f-acde48001122 2021/03/29 main.go:27: 谁说我是日志了，我是错误,
log 输出的底层实现
从源码中我们可以看到，无论是 Print，Panic，还是 Fatal 他们都是使用std.Output(calldepth int, s string)方法。std 的定义如下：
func New(out io.Writer, prefix string, flag int) *Logger {
return &Logger{out: out, prefix: prefix, flag: flag}
}
var std = New(os.Stderr, "", LstdFlags)
即每一次调用 log 的时候都会去创建一个 Logger 对象。另外 New 中传入的第一个参数是os.Stderr，os.Stderr对应的是UNIX里的标准错误警告信息的输出设备，同时被作为默认的日志输出目的地。初次之外，还有标准输出设备os.Stdout以及标准输入设备os.Stdin。
var (
Stdin = NewFile(uintptr(syscall.Stdin), "/dev/stdin")
Stdout = NewFile(uintptr(syscall.Stdout), "/dev/stdout")
Stderr = NewFile(uintptr(syscall.Stderr), "/dev/stderr")
)
前两种分别用于输入、输出和警告错误信息。所有的输出都会调用的方法：std.Output(calldepth int, s string)：
func (l *Logger) Output(calldepth int, s string) error {
now := time.Now()
var file string
var line int
//加锁，保证多goroutine下的安全
l.mu.Lock()
defer l.mu.Unlock()
//如果配置了获取文件和行号的话
if l.flag&(Lshortfile|Llongfile) != 0 {
//因为runtime.Caller代价比较大，先不加锁
l.mu.Unlock()
var ok bool
_, file, line, ok = runtime.Caller(calldepth)
if !ok {
file = "???"
line = 0
}
//获取到行号等信息后，再加锁，保证安全
l.mu.Lock()
}
//把我们的日志信息和设置的日志抬头进行拼接
l.buf = l.buf[:0]
l.formatHeader(&l.buf, now, file, line)
l.buf = append(l.buf, s...)
if len(s) == 0 || s[len(s)-1] != '\n' {
l.buf = append(l.buf, '\n')
}
//输出拼接好的缓冲buf里的日志信息到目的地
_, err := l.out.Write(l.buf)
return err
}
formatHeader方法主要是格式化日志抬头信息，就是我们上面提到设置的日志打印格式，解析完之后存储在buf这个缓冲中，最后再把我们自己的日志信息拼接到缓冲buf的后面，然后为一次 log 日志输出追加一个换行符，这样每次日志输出都是一行一行的。
上面我们提到过runtime.Caller(calldepth)这个方法，runtime 包非常有意思，它提供了一个运行时环境，可以在运行时去管理内存分配，垃圾回收，时间片切换等等，类似于 Java 中虚拟机做的活。（是不是很疑惑为什么在 Go 中竟然可以去做Java中虚拟机能做的事情，其实想想协程的概念，再对比线程的概念，就不会疑惑为啥会给你提供这么个包）。
Caller方法的解释是：
Caller 方法查询有关函数调用的文件和行号信息，通过调用 Goroutine 的堆栈。参数 skip 是堆栈帧框架升序方式排列的数字值，0 标识 Caller 方法的调用。（出于历史原因，Skip 的含义在调用者和调用者之间有所不同。）
返回值报告程序计数器、文件名和相应文件中行号的查询。如果无法恢复信息，则 Boolean OK为 fasle。
Caller方法的定义：
func Caller(skip int) (pc uintptr, file string, line int, ok bool) {
}
参数skip表示跳过栈帧数，0表示不跳过，也就是runtime.Caller的调用者。1的话就是再向上一层，表示调用者的调用者。
log 日志包里使用的是2，也就是表示我们在源代码中调用log.Print、log.Fatal和log.Panic这些函数的调用者。
以main函数调用log.Println为例，main->log.Println->*Logger.Output->runtime.Caller这么一个方法调用栈，所以这时候，skip 的值分别代表：
0表示*Logger.Output中调用runtime.Caller的源代码文件和行号；1表示log.Println中调用*Logger.Output的源代码文件和行号；2表示main中调用log.Println的源代码文件和行号；
所以这也是log包里的这个skip的值为什么一直是2的原因。
如何自定义自己的日志框架
通过上面的学习，你其实知道了，日志的实现是通过 New() 函数构造了 Logger 对象来处理的。那我们只用构造不同的 Logger 对象来处理不同类型的日记即可。下面是一个简单的实现：
package main
import (
"io"
"log"
"os"
)
var (
Info *log.Logger
Warning *log.Logger
Error * log.Logger
)
func init(){
infoFile,err:=os.OpenFile("/data/service_logs/info.log",os.O_CREATE|os.O_WRONLY|os.O_APPEND,0666)
warnFile,err:=os.OpenFile("/data/service_logs/warn.log",os.O_CREATE|os.O_WRONLY|os.O_APPEND,0666)
errFile,err:=os.OpenFile("/data/service_logs/errors.log",os.O_CREATE|os.O_WRONLY|os.O_APPEND,0666)
if infoFile!=nil || warnFile != nil || err!=nil{
log.Fatalln("打开日志文件失败：",err)
}
Info = log.New(os.Stdout,"Info:",log.Ldate | log.Ltime | log.Lshortfile)
Warning = log.New(os.Stdout,"Warning:",log.Ldate | log.Ltime | log.Lshortfile)
Error = log.New(io.MultiWriter(os.Stderr,errFile),"Error:",log.Ldate | log.Ltime | log.Lshortfile)
Info = log.New(io.MultiWriter(os.Stderr,infoFile),"Info:",log.Ldate | log.Ltime | log.Lshortfile)
Warning = log.New(io.MultiWriter(os