代码分析示例

Go 支持 CPU 分析 和 内存 分析 两种分析方式。不推荐同时对一个应用做俩种类型的分析，因为这俩种不同的分析方式不能相互工作的很好。然而，profileMe.go 应用是一个例外，因为它被用来说明这个两种技术。

用于分析的 Go 代码保存再 profileMe.go，并分为五部分来介绍。profileMe.go 的第一部分 Go 代码如下：

package main
import (
    "fmt"
    "math"
    "os"
    "runtime"
    "runtime/pprof"
    "time"
)
func fibo1(n int) int64 {
    if n == 0 || n == 1 {
        return int64(n)
    }
    time.Sleep(time.Millisecond)
    return int64(fibo2(n-1)) + int64(fibo2(n-2))
}

注意给您的程序创建分析数据必须直接或间接引入 runtime/pprof 包。在 fibo1() 函数调用 time.Sleep() 是为了使它慢一点。在这节尾声您将明白为什么。

profileMe.go 的第二段代码如下：

func fibo2(n int) int {
    fn := make(map[int]int)
    for i:= 0; i <= n; i++ {
        var f int
        if i <= 2 {
            f = 1
        } else {
            f = fn[i-1] + fn[i-2]
        }
        fn[i] = f
    }
    time.Sleep(50 * time.Millisecond)
    return fn[n]
}

上面这段代码包含另个 Go 函数的实现，使用另一个算法计算斐波那契数列。

profileMe.go 的第三部分代码如下：

func N1(n int) bool {
    k := math.Floor(float64(n/2 + 1))
    for i := 2; i < int(k); i++ {
        if (n % i) == 0 {
            return false
        }
    }
    return true
}

func N2(n int) bool {
    for i := 2 ; i < n; i++ {
        if (n % i) == 0 {
            return false
        }
    }
    return true
}

N1() 和 N2() 函数都是用来找出给定整数是否是素数。第一个函数已被优化，因为它的 for 循环迭代大约超过第二个函数的 for 循环使用的数字的一半。因为它们运行的都相当慢，所以没必要在此调用 time.Sleep()。

profileMe.go 的第四部分如下：

func main() {
    cpuFile, err := os.Create("/tmp/cpuProfile.out")
    if err != nil {
        fmt.Println(err)
        return
    }
    pprof.StartCPUProfile(cpuFile)
    defer pprof.StopCPUProfile()
    total := 0
    for i := 2; i < 100000; i++ {
        n := N1(i)
        if n {
            total = total + 1
        }
    }
    fmt.Println("Total primes:", total)
    total = 0
    for i := 2; i < 100000; i++ {
        n := N2(i)
        if n {
            total = total + 1
        }
    }
    fmt.Println("Total primes:", total)
    for i := 1; i < 90; i++ {
        n := fibo1(i)
        fmt.Println(n, " ")
    }
    fmt.Println()
    for i := 1; i < 90; i++ {
        n := fibo2(i)
        fmt.Println(n, " ")
    }
    fmt.Println()
    runtime.GC()

调用 os.Create() 创建一个文件用于写分析数据。调用 pprof.StartCPUProfile() 开始程序的 CPU 分析，然后调用 ppprof.StopCPUProfile() 停止。

profileMe.go 的最后部分如下：

    // Memory profiling!
    memory, err := os.Create("/tmp/memoryProfile.out")
    if err != nil {
        fmt.Println(err)
        return
    }
    defer memory.Close()
    for i := 0; i < 10; i++ {
        s := make([]byte, 50000000)
        if s == nil {
            fmt.Println("Operation failed!")
        }
        time.Sleep(50 * time.Millisecond)
    }
    err = pprof.WriteHeapProfile(memory)
    if err != nil {
        fmt.Println(err)
        return
    }
}

最后这部分，您可以看到 内存分析 技术是如何工作的。它与 CPU 分析很相似， 您再次需要一个文件来写分析数据。

执行 profileMe.go 将产生如下输出：

除了输出外，程序也搜集分析数据到俩个文件：

$ cd /tmp
$ ls -l *Profile*
-rw-r--r-- 1 mtsouk wheel 1965 Mar 8 16:53 cpuProfile.out
-rw-r--r-- 1 mtsouk wheel 484 Mar 8 16:53 memoryProfile.out

只有在收集了分析数据后，您才能开始检查它。

因此，您现在可以启动命令行分析器来检查 CPU 数据，如下所示：

$ go tool pprof /tmp/cpuProfile.out
Main binary filename not availabe.
Type: cpu
Time: Mar 8, 2018 at 4:53pm (EET)
Duration: 19.12s, Total samples = 4.18s (21.86%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof)

在分析器 shell 中输入 help 将产生如下输出：

top 命令以文本形式返回前10个条目:

输出的第一行，显示函数占程序总执行时间的 98.56%。 main.N2 函数显著的占程序执行时间的 46.65%。

top10 --cum 命令返回每个函数执行的累计时间：

如果您想找出一个特定函数到底发生了什么的话，您可以使用 list 命令，后跟函数名（和包名组合），您将获得该函数执行的更多详细信息：

这个输出显示了 main.N1 的 for 循环几乎占用了整个函数的执行时间。特别是 if (n % i) == 0 表达式占了整个函数执行时间的 910ms 中的 850ms。

您也可以使用 pdf 命令从 Go 分析器的shell 创建一个分析数据的 PDF 输出：

(pprof) pdf
Generating report in prfile001.pdf

注意您需要 Graphviz 为了使生成的 PDF 文件能被您喜爱的 PDF 阅读器浏览。

最后，一个警告：如果您的程序执行太快，那么分析器将没有足够的时间获取样本，从而当您加载数据文件时，可能看到 Total samples = 0 的输出。如果那样的话，您将不能从分析过程中获得任何有用的信息。这就是为什么在 profileMe.go 的部分函数中使用 time.Sleep() 函数的原因：