我是 Go 的新手，最近有一些事情让我很困惑。

我有一段代码(下面发布的简化版本)，我试图测量它的性能。我用两种方式做到了这一点:1) 带有测试包的基准 2) 手动记录时间

运行基准测试输出结果

30000 55603 ns/op

这很好，但是...当我对同一函数执行 30k 次运行并记录每次迭代的时间时，我得到如下输出:

测试耗时 0 ns 测试耗时 0 ns ... ~10 条记录都一样 测试耗时 1000100 ns 测试耗时 0 ns 测试耗时 0 ns ...又是很多零 测试耗时 0 ns 测试耗时 1000000 ns 测试耗时 0 ns ...

计算表明平均值确实是 55603 ns/op，正如基准所声称的那样。

好吧，我说过，我在优化性能方面不是那么擅长，在所有硬核编译器的东西中也不擅长，但我猜这可能是随机垃圾收集？所以我打开 gc 日志，确保它显示一些输出，然后关闭 gc 以保持良好的 aaand...没有垃圾收集，但我看到了相同的图片 - 有些迭代需要一百万倍的时间(？)。

我对所有这一切的理解有 99% 是错误的，也许有人能给我指明正确的方向，或者也许有人确切地知道到底发生了什么？ :)

附言此外，对我来说，不到一纳秒 (0 ns) 有点令人惊讶，这似乎太快了，但程序确实提供了计算结果，所以我不知道该想些什么了。 T_T

编辑 1:回答 Kenny Grant 的问题:我使用 goroutines 来实现某种值生成器以具有惰性，现在我删除了它们并简化了代码。这个问题现在不那么频繁了，但它仍然可以重现。 Playground 链接:https://play.golang.org/p/UQMgtT4Jrf 有趣的是，这不会发生在 Playground 上，但仍然会发生在我的机器上。

编辑 2:我在 win7 x64 上运行 Go 1.9

编辑 3:感谢回复，我现在知道这段代码不可能在 Playground 上正常工作。我将在此处重新发布代码片段，以免我们丢失它。 :)

type PrefType string
var types []PrefType = []PrefType{
    "TYPE1", "TYPE2", "TYPE3", "TYPE4", "TYPE5", "TYPE6",
}

func GetKeys(key string) []string {
    var result []string
    for _, t := range types {
        rr := doCalculations(t)
        for _, k := range rr {
            result = append(result, key + "." + k)
        }
    }
    return result
}

func doCalculations(prefType PrefType) []string {
    return []string{ string(prefType) + "something", string(prefType) + "else" }
}

func test() {
    start := time.Now()
    keysPrioritized := GetKeys("spec_key")
    for _, k := range keysPrioritized {
        _ = fmt.Sprint(k)
    }
    fmt.Printf("test took %v ns\n", time.Since(start).Nanoseconds())
}

func main() {
    for i := 0; i < 30000; i++  {
        test()
    }
}

这是我机器上的输出:

编辑 4:我在装有 Ubuntu 17.04 的笔记本电脑上进行了同样的尝试，输出是合理的，没有零和数百万。似乎是编译器/运行时库中特定于 Windows 的问题。如果有人可以在他们的机器上验证这一点(Win 7/8/10)，那就太好了。

最佳答案

在 Windows 上，对于如此短的持续时间，您没有足够精确的时间戳。 Linux 有更精确的时间戳。根据设计，Go 基准测试至少运行一秒钟。 Go1.9+使用单调(m)值来计算持续时间。

在 Windows 上:

timedur.go:

package main

import (
    "fmt"
    "os"
    "time"
)

type PrefType string

var types []PrefType = []PrefType{
    "TYPE1", "TYPE2", "TYPE3", "TYPE4", "TYPE5", "TYPE6",
}

func GetKeys(key string) []string {
    var result []string
    for _, t := range types {
        rr := doCalculations(t)
        for _, k := range rr {
            result = append(result, key+"."+k)
        }
    }
    return result
}

func doCalculations(prefType PrefType) []string {
    return []string{string(prefType) + "something", string(prefType) + "else"}
}

func test() {
    start := time.Now()
    keysPrioritized := GetKeys("spec_key")
    for _, k := range keysPrioritized {
        _ = fmt.Sprint(k)
    }
    end := time.Now()
    fmt.Printf("test took %v ns\n", time.Since(start).Nanoseconds())
    fmt.Println(start)
    fmt.Println(end)
    if end.Sub(start) < time.Microsecond {
        os.Exit(1)
    }
}

func main() {
    for i := 0; i < 30000; i++ {
        test()
    }
}

输出:

>go run timedur.go
test took 1026000 ns
2017-09-02 14:21:58.1488675 -0700 PDT m=+0.010003700
2017-09-02 14:21:58.1498935 -0700 PDT m=+0.011029700
test took 0 ns
2017-09-02 14:21:58.1538658 -0700 PDT m=+0.015002000
2017-09-02 14:21:58.1538658 -0700 PDT m=+0.015002000
exit status 1
>

在 Linux 上:

输出:

$ go run timedur.go
test took 113641 ns
2017-09-02 14:52:02.917175333 +0000 UTC m=+0.001041249
2017-09-02 14:52:02.917287569 +0000 UTC m=+0.001153717
test took 23614 ns
2017-09-02 14:52:02.917600301 +0000 UTC m=+0.001466208
2017-09-02 14:52:02.917623585 +0000 UTC m=+0.001489354
test took 22814 ns
2017-09-02 14:52:02.917726364 +0000 UTC m=+0.001592236
2017-09-02 14:52:02.917748805 +0000 UTC m=+0.001614575
test took 21139 ns
2017-09-02 14:52:02.917818409 +0000 UTC m=+0.001684292
2017-09-02 14:52:02.917839184 +0000 UTC m=+0.001704954
test took 21478 ns
2017-09-02 14:52:02.917911899 +0000 UTC m=+0.001777712
2017-09-02 14:52:02.917932944 +0000 UTC m=+0.001798712
test took 31032 ns
<SNIP>

结果具有可比性。它们在同一台机器上运行，Windows 10 和 Ubuntu 16.04 双启动。

关于windows - 性能随机下降，我们在Stack Overflow上找到一个类似的问题： https://stackoverflow.com/questions/46012094/