golang系列—性能评测之pprof+火焰图+trace | 豆包MarsCode AI刷题

用户979530640720
48 阅读6分钟

  1. runtime/pprof

    pprof是golang官方提供的性能测评工具，包含在net/http/pprof和runtime/pprof两个包中，分别用于不同场景。

    runtime/pprof主要用于可结束的代码块，如一次编解码操作等； net/http/pprof是对runtime/pprof的二次封装，主要用于不可结束的代码块，如web应用等。

    首先利用runtime/pprof进行性能测评，下列代码主要实现循环向一个列表中append一个元素，只要导入runtime/pprof并添加2段测评代码就可以实现cpu和mem的性能评测。

    package main
​
import (
    "flag"
    "log"
    "os"
    "runtime/pprof"
    "sync"
)
​
func counter() {
    slice := make([]int, 0)
    c := 1
    for i := 0; i < 100000; i++ {
        c = i + 1 + 2 + 3 + 4 + 5
        slice = append(slice, c)
    }
}
​
func workOnce(wg *sync.WaitGroup) {
    counter()
    wg.Done()
}
​
func main() {
    var cpuProfile = flag.String("cpuprofile", "", "write cpu profile to file")
    var memProfile = flag.String("memprofile", "", "write mem profile to file")
    flag.Parse()
    //采样cpu运行状态
    if *cpuProfile != "" {
        f, err := os.Create(*cpuProfile)
        if err != nil {
            log.Fatal(err)
        }
        pprof.StartCPUProfile(f)
        defer pprof.StopCPUProfile()
    }
​
    var wg sync.WaitGroup
    wg.Add(100)
    for i := 0; i < 100; i++ {
        go workOnce(&wg)
    }
​
    wg.Wait()
    //采样memory状态
    if *memProfile != "" {
        f, err := os.Create(*memProfile)
        if err != nil {
            log.Fatal(err)
        }
        pprof.WriteHeapProfile(f)
        f.Close()
    }
}

    通过编译、执行后获得pprof的采样数据，然后就可以利用相关工具进行分析。

    $:go build main.go
$:./main --cpuprofile=cpu.pprof
$:./main --memprofile=mem.pprof
$:go tool pprof cpu.pprof

    至此就可以获得cpu.pprof和mem.pprof两个采样文件，然后利用go tool pprof工具进行分析。

    • Duration:程序执行时间。在本例中golang自动分配任务给多个核执行程序，总计耗时301.04ms，而采样时间为690ms；也就是说假设有10核执行程序，平均每个核采样69ms的数据。
    • (pprof) ：命令行提示。表示当前在go tool 的pprof工具命令行中，go tool还包括cgo、doc、pprof、test2json、trace等多种命令
    • top：pprof的指令之一，显示pprof文件中的前10项数据，可以通过top 20等方式显示20行数据；当然pprof下有很多指令，例如list，pdf、eog等等
    • flat/flat% ：分别表示在当前层级cpu的占用时间和百分比。例如runtime.memmove在当前层级占用cpu时间380ms，占比本次采集时间的55.07%。
    • cum/cum% ：分别表示截止到当前层级累积的cpu时间和占比。例如main.counter累积占用时间510ms，占本次采集时间的73.91%。
    • sum% ：所有层级的cpu时间累积占用，从小到大一直累积到100%，即690ms。

    当然，也可以使用web指令获得更加直观的信息，MacOS下通过如下命令安装渲染工具。

    brew install graphviz

    安装完成后在pprof的命令行中输入web即可生成一个svg格式的文件。

  2. net/http/pprof

    针对后台服务型应用，服务一般不能停止，我们需要使用net/http/pprof包。类似上述代码，我们编写如下代码：

    package main
​
import (
    "time"
    "net/http"
    _ "net/http/pprof"
)
​
func counter() {
    slice := make([]int, 0)
    c := 1
    for i := 0; i < 100000; i++ {
        c = i + 1 + 2 + 3 + 4 + 5
        slice = append(slice, c)
    }
}
​
func workForever() {
    for {
        go counter()
        time.Sleep(1 * time.Second)
    }
}
​
func httpGet(w http.ResponseWriter, r *http.Request) {
    counter()
}
​
func main() {
    go workForever()
    http.HandleFunc("/get", httpGet)
    http.ListenAndServe("localhost:8000", nil)
}

    首先导入net/http/pprof包，注意该包利用下划线"_"导入，意味着我们只需要该包运行其init()函数即可，如此该包将自动完成信息采集并保存在内存中。所以在服务上线时需要将net/http/pprof包移除，其不仅影响服务的性能，更重要的是会造成内存的不断上涨。

    通过编译、运行，我们便可以访问：http://localhost:8000/debug/pprof/查看服务的运行情况。

    当然我们也可以利用web形式查看，现在以查看memory为例，在服务程序运行时，执行下列命令采集内存信息。

    go tool pprof main http://localhost:8000/debug/pprof/heap

    采集完成后利用web指令得到svg文件

    上述方法在工具型应用中可以使用，然而在服务型应用时，仅仅只是采样了部分代码段；而只有当有大量请求时才能看到应用服务的主要优化信息，同时Uber开源的火焰图工具go-torch能够辅助我们直观的完成测评。要想实现火焰图的效果，需要安装如下3个工具：

    go get -v github.com/uber/go-torch
git clone https://github.com/brendangregg/FlameGraph.git
git clone https://github.com/wg/wrk

    其中下载FlameGraph和wrk后需要进行编译，如果需要长期使用，需要将二者的可执行文件路径放到系统环境变量中。FlameGraph是画图需要的工具，而wrk是模拟并发访问的工具。通过如下命令进行模拟并发操作：500个线程并发，每秒保持2000个连接，持续时间30s。

    ./wrk -t500 -c2000 -d30s http://localhost:8000/get

    同时开启go-torch工具对http://localhost:8000采集30s信息，采集完毕后会生成svg的文件，用浏览器打开就是火焰图。

    go-torch -u http://localhost:8000 -t 30

    火焰图形似火焰，故此得名，其横轴是CPU占用时间，纵轴是调用顺序。由上图可以看出main.counter占用将近50%的CPU时间。通过wrk的压测后，我们可以再查看内存等信息。

    go tool pprof main http://localhost:8000/debug/pprof/heap //采集内存信息
go tool pprof main http://localhost:8000/debug/pprof/profile //采集cpu信息

    利用web指令看到内存的使用情况如下。其中counter函数占用67.20%，且包含2部分，因为我们的代码中有2处调用counter函数。如果大家觉得web框图更加清晰，完全可以摒弃火焰图，直接使用go tool pprof工具。

  3. trace

    trace工具也是golang支持的go tool工具之一，能够辅助我们跟踪程序的执行情况，进一步方便我们排查问题，往往配合pprof使用。trace的使用和pprof类似，为了简化分析，我们首先利用下列代码进行讲解，只是用1核运行程序：

    package main
​
import (
    "os"
    "runtime"
    "runtime/trace"
    "sync"
    "flag"
    "log"
)
​
func counter(wg *sync.WaitGroup) {
    wg.Done()
    slice := []int{0}
    c := 1
    for i := 0; i < 100000; i++ {
        c = i + 1 + 2 + 3 + 4 + 5
        slice = append(slice, c)
    }
}
​
func main(){
    runtime.GOMAXPROCS(1)
    var traceProfile = flag.String("traceprofile", "", "write trace profile to file")
    flag.Parse()
​
    if *traceProfile != "" {
        f, err := os.Create(*traceProfile)
        if err != nil {
            log.Fatal(err)
        }
        trace.Start(f)
        defer f.Close()
        defer trace.Stop()
    }
​
  var wg sync.WaitGroup
    wg.Add(3)
    for i := 0; i < 3; i ++ {
        go counter(&wg)
    }
    wg.Wait()
}

    同样，通过编译、执行和如下指令得到trace图：

    go tool trace -http=127.0.0.1:8000 trace.pprof

    字段讲解：

    1. Goroutines：运行中的协程数量；通过点击图中颜色标识可查看相关信息，可以看到在大部分情况下可执行的协程会很多，但是运行中的只有0个或1个，因为我们只用了1核。
    2. Heap：运行中使用的总堆内存；因为此段代码是有内存分配缺陷的，所以heap字段的颜色标识显示堆内存在不断增长中。
    3. Threads：运行中系统进程数量；很显然只有1个。
    4. GC：系统垃圾回收；在程序的末端开始回收资源。
    5. syscalls：系统调用；由上图看到在GC开始只有很微少的一段。
    6. Proc0：系统进程，与使用的处理器的核数有关，1个。
avatar
文章
阅读
粉丝