关于fmt包Fprint系列方法的性能问题

作者：水不要鱼

(注：能力有限，如有说错，请指正！)

(原文发表在我的个人网站中：https://www.fishin.com.cn/blog/article.html?articleId=5)

最近在使用 Go 语言实现一个日志库 (logit) 的时候，发现了一个性能问题，经过 Go 的 cpuprofile 检测之后，
问题出在 fmt.Fprintf 中，于是我写了一个简单的测试案例，看看 Fprintf 的性能究竟比直接 writer.Write 差多少：

// 测试使用的 writer，不进行任何输出，避免 I/O 带来的测试波动
type nopWriter struct{}
func (w *nopWriter) Write(p []byte) (n int, err error) {
    return 0, nil
}

// 测试 Fmt.Fprintf 的性能
func BenchmarkFmtFprintf(b *testing.B) {

    w := &nopWriter{}
    for i := 0; i < b.N; i++ {
        fmt.Fprintf(w, "i")
    }
}

// 测试直接 Write 的性能
func BenchmarkWriter(b *testing.B) {

    w := &nopWriter{}
    for i := 0; i < b.N; i++ {
        w.Write([]byte("i"))
    }
}

测试结果如下：

fmtFprintf 的性能检测：

直接 Write 的性能检测：

什么！！！两个居然差了 126 倍。。。好奇心驱使我开始了源码探索：

// Fprintf formats according to a format specifier and writes to w.
// It returns the number of bytes written and any write error encountered.
func Fprintf(w io.Writer, format string, a ...interface{}) (n int, err error) {
	p := newPrinter()
	p.doPrintf(format, a) // 对！就是它！这个方法耗时相当高！点进去一探究竟！
	n, err = w.Write(p.buf)
	p.free()
	return
}

Cpu profile 告诉我，doPrintln 方法耗时相当严重，于是，我继续跟进去看源码，但是这个源码很长，
这里就只贴一个重点的代码，就是 printArg 方法：

func (p *pp) printArg(arg interface{}, verb rune) {
    p.arg = arg
	p.value = reflect.Value{}

	if arg == nil {
		switch verb {
		case 'T', 'v':
			p.fmt.padString(nilAngleString)
		default:
			p.badVerb(verb)
		}
		return
	}

	// Special processing considerations.
	// %T (the value's type) and %p (its address) are special; we always do them first.
	switch verb {
	case 'T':
		p.fmt.fmtS(reflect.TypeOf(arg).String())
		return
	case 'p':
		p.fmtPointer(reflect.ValueOf(arg), 'p')

    // 。。。。省略以下代码，因为答案已经很明显了！
}

上面的代码只看了一小部分就已经知道问题所在了，没错，就是 reflect 反射包的使用。
这个方法短短几行中就存在好几个反射操作，能不慢嘛。。。

不过，仔细一想，也对，fmt 包中的方法，比如 Println，参数都是 interface{} 的，这是为了通用化，
那内部就必然需要判断实际的类型然后做出实际的输出操作。而我的日志库 (logit)
就是输出一个字符串，其实就没必要做这个通用的判断。于是我想起了 io.WriteString 方法，立马测试一番！

// 测试 io.WriteString 性能
func BenchmarkIoWriteString(b *testing.B) {

    w := &nopWriter{}
    for i := 0; i < b.N; i++ {
        io.WriteString(w, "i")
    }
}

io.WriteString 的性能检测：

哈？？？真是让人大跌眼镜，这货的性能居然和 fmt.Fprintf 差不多？莫非又存在反射操作？上源码！

// WriteString writes the contents of the string s to w, which accepts a slice of bytes.
// If w implements StringWriter, its WriteString method is invoked directly.
// Otherwise, w.Write is called exactly once.
func WriteString(w Writer, s string) (n int, err error) {
	if sw, ok := w.(StringWriter); ok {
		return sw.WriteString(s)
	}
	return w.Write([]byte(s))
}

这货的源码很简单，如果是 StringWriter 接口的实现，就使用这个实现的 WriteString 方法，
否则直接 Write。而我的测试用例中，nopWriter 明显没有实现 StringWriter 接口，所以断言失败，
直接调用 Write 方法。那性能不应该这么差啊！莫非是断言导致的？不管三七二十一，测试一番再说！

// 测试断言性能
func BenchmarkAssert(b *testing.B) {

    var w interface{} = &nopWriter{}
    for i := 0; i < b.N; i++ {
        if ww, ok := w.(*nopWriter); ok {
            ww.Write([]byte("i"))
        }
    }
}

断言的性能检测：

从结果来看，好像并不是断言导致的，那究竟是什么原因咧。。。这个我是真不知道，如果有知道的小伙伴，赶紧评论一番告诉我哈，小弟感激不尽！

不过话说回来，实际应用中不可能使用 nopWriter 这样的 IO 设备，更多是文件之类的操作，所以我们来看看如果是实际的文件 IO 的话，性能是怎么样的：

// 测试文件 I/O 的性能
func BenchmarkFileIo(b *testing.B) {

    file, _ := os.Create("Z:/test.txt")

    b.ResetTimer()
    for i := 0; i < b.N; i++ {
        file.Write([]byte("i"))
    }
}