Go零消耗debug log技巧
tL;DR, 本文末尾提供零消耗的日志代码，最高性能提升60000%。
看到题目，有人肯定会问，官方的log模块不好么？
Debug Log一般很长，在生产环境还输出的话，也很难找。
再者，log的消耗是比较大的，特别是需要打印行号时。
https://golang.org/src/log/log.go#L158
if l.flag&(Lshortfile|Llongfile) != 0 {
// Release lock while getting caller info - it's expensive.
l.mu.Unlock()
var ok bool
_, file, line, ok = runtime.Caller(calldepth)
if !ok {
file = "???"
line = 0
}
l.mu.Lock()
}
因为需要调用runtime.Caller，这样性能就有较多的损耗。
简单的benchmark，可以发现慢50%。
func BenchmarkWithLine(b *testing.B) {
logger := log.New(ioutil.Discard, "", log.Llongfile|log.LstdFlags)
tf := strings.Repeat("abcde", 1000)
b.ResetTimer()
for i := 0; i < b.N; i++ {
logger.Print(tf)
}
}
// BenchmarkWithLine-4 500000 2806 ns/op
// BenchmarkWithoutLine-4 1000000 1754 ns/op
虽然，log的性能不差，仅需要1us就能进行一次，但如果在代码中有大量的debug日志，这个损耗累积起来，那也是相当惊人的了。
那么，在生产环境，能不能不执行log语句呢？
可以的，例如
const Dev = false
func BenchmarkConst(b *testing.B) {
logger := log.New(ioutil.Discard, "", log.LstdFlags)
tf := strings.Repeat("abcde", 1000)
b.ResetTimer()
for i := 0; i < b.N; i++ {
if Dev {
logger.Print(tf)
}
}
}
// BenchmarkConst-4 2000000000 0.29 ns/op
用go tool objdump查看生成的二进制文件
log_test.go:36 0x4efc32 48890424 MOVQ AX, 0(SP)
log_test.go:36 0x4efc36 e815d4fbff CALL testing.(*B).ResetTimer(SB)
log_test.go:36 0x4efc3b 488b842480000000 MOVQ 0x80(SP), AX
log_test.go:36 0x4efc43 31c9 XORL CX, CX
log_test.go:38 0x4efc45 eb03 JMP 0x4efc4a
log_test.go:38 0x4efc47 48ffc1 INCQ CX
log_test.go:38 0x4efc4a 488b90f0000000 MOVQ 0xf0(AX), DX
log_test.go:38 0x4efc51 4839d1 CMPQ DX, CX
log_test.go:38 0x4efc54 7cf1 JL 0x4efc47
log_test.go:43 0x4efc56 488b6c2470 MOVQ 0x70(SP), BP
log_test.go:43 0x4efc5b 4883c478 ADDQ $0x78, SP
log_test.go:43 0x4efc5f c3 RET
可以看出，ResetTimer之后，仅仅是跑了个空的for循环，这是因为编译器发现if语句永远不成立，所以不编译这一段了（如果Dev是var值，那么还是会对比一下，而不是没有语句生成），不过这个方法需要每次debug时都要改代码。不想改代码可以用go build -ldflags -X方法， 但这个仅仅支持字符串，特别麻烦。
所以有没有更好的解决方案呢？有的，使用build tags
下面是例子，一共三个文件:
log.go
package main
func main() {
Debug("it's expensive")
if Dev {
fmt.Println("we are in develop mode")
}
}
log_debug.go
//+build debug
package main
import (
"fmt"
)
const Dev = true
func Debug(a ...interface{}) {
fmt.Println(a...)
}
log_release.go
//+build !debug
package main
const Dev = false
func Debug(a ...interface{}) {}
debug和release最大的差别就在文件头的//+build !debug， 意思是告诉编译器，如果有debug这个tags，那么编译的时候就略过这个文件。
比如你运行go build -tags "debug" && ./main就会输出，不设定的话，就什么都不输出。
再用go tool objdump 查看生成的可执行文件，跟之前的if Dev效果相同，压根不生成语句。这样就不用每次都改代码了来debug了，是不是很赞啊？
对于Debug函数，由于Go的函数是first class，所以Call function不可避免，不过性能损失基本上为零了。
package main
import "testing"
var a = strings.Repeat("abcde", 1024)
func BenchmarkDebug(b *testing.B) {
for i := 0; i < b.N; i++ {
Debug(a)
}
}
go test -bench=.
BenchmarkDebug-4 500000000 3.27 ns/op
go test -bench=. -tags debug
BenchmarkDebug-4 10000000 146 ns/op
总结一下，如果极度要求性能，尽量使用if Dev这种判断模式，如果要求不高，可以使用Debug函数的方法。
