go

go pprof

性能分析和瑞士军刀go pprof

Posted by Liangjf on December 31, 2019

性能分析和瑞士军刀go pprof

此文是我在公司内部的每月技术分享,在其基础上稍微做了修改。

go的pprof是针对程序的性能分析的,但在介绍go pprof之前,先来看看不借助go pprof的传统性能分析是如何做的。

什么是性能分析

是什么?

在软件中,性能分析也叫profiling,维基百科的定义是通过收集程序运行时的数据信息并加以分析就是性能分析,是一种动态程序分析的方法。分析的是运行时的性能,而不是静态的代码。

性能分析的目标包括但不限于:

  • 应用负载的角度:吞吐量,延时等。
  • 系统资源的角度:cpu负载,内存使用情况,网络带宽,饱和度等。

这两个角度其实可以看做是从顶层到底层看待问题,从底层到顶层的看待问题。

为什么?

为什么软件需要性能分析?这个问题就如同,人为什么需要定期做体检。

试想这场景,写了一大堆接口,急冲冲的上线,几个请求过来,响应延时很大。一查看,cpu打满了。这是没有对程序做性能测试和分析的结果。这时的程序对于我们来说是一个黑盒子,对它的性能指标是一概不知的,这无疑是非常危险的。

如何做?

一句话概括:性能分析,就是找出应用或系统的瓶颈,设法规避或减轻它们,更加高效利用系统资源,让应用能够处理更多的请求。

一般来说,性能分析可以根据以下步骤来实施:

  • 根据用户量,选择合适的指标评估应用程序和系统的性能
  • 为应用程序和系统定下性能预期
  • 进行性能基准测试
  • 性能分析定位瓶颈和排查问题
  • 优化应用程序和系统
  • 性能监控和告警

传统如何性能分析

这里的传统性能分析,是指go的pprof性能分析之外的性能分析方法。主要是指借助linux环境下的一系列工具来定位,分析,排查关于性能问题的方法论。

常见的性能问题有:

  • 1、cpu使用率过高问题
  • 2、io资源占有率异常问题
  • 3、网络io资源异常问题
  • 4、软中断触发频繁
  • ……

常用工具

  • 1.查看平均负载情况(使用工具:uptime、top、htop、atop)
  • 2.cpu利用率(cat /proc/cpuinfo、top、mpstat、perf)
  • 3.查看io使用情况(使用工具:iostat)
  • 4.查看进程占用资源情况(使用工具:ps、pidstat)

需安装工具(ubuntu环境):

  • sudo apt install linux-tools-common
  • sudo apt install perf
  • sudo apt install sysstat

定位分析

cpu使用率异常问题

cpu占有率和平均负载有关。平均负载是单位时间内, 系统处于可运行状态和不可中断状态的平均进程数( 平均活跃进程数 )

其中top、htop、atop三者功能基本一样,只是htop支持图形界面的鼠标操作,支持横向或纵向滚动浏览进程列表,支持不需要输入进程号杀进程。atop拥有多个视图,数据信息更多直观。

top效果图

htop效果图

atop效果图

常用套路:

  • 1、top/htop/atop看cpu使用率和平均负载,定位到对应进程pid;
  • 2、执行命令 perf top -g -p 20368,得到-g打印调用链,-p指定进程pid,动态观看异常进程cpu异常位置
  • 3、修改优化代码

看这个案例:

执行命令 htop

看到 gitlab-cron的cpu使用率达到100%,整整占了一个核,按理说是不应该的,因为这个进程只是一个统计gitlab数据的定时任务。

记下pid,执行命令 sudo perf -g -p pid

看到gitlab-cron进程的动态调用链的cpu使用率,通过键盘上下键,移到cpu最大那行,然后按下enter键,逐层到达最后的调用地方。

通过上面步骤排查问题,定位到代码位置了。

main.go

func main() {
    srv := server.NewServer()
    defer srv.Stop()

    srv.Init()

    ctx, cancel := context.WithCancel(context.TODO())
    defer cancel()

    c := cron.NewCron()
    defer c.Stop()

    dailyCron := cron.NewDailyCron(srv)
    if err := c.AddCronTask(`CRON_TZ=Asia/Shanghai 30 20 * * *`, dailyCron); err != nil {
      log.Fatal(err)
      return
    }

    c.RunCronTask(ctx)

    srv.Run(ctx)
}

定位到此处代码:

func (s *Server) Run(ctx context.Context) {
    for {
        select {
        case <-ctx.Done():
            return
        }
    }
}

这里大意写了个for循环了,本意是想main的context传进来,在main退出时控制整个server退出,修改代码为

func (s *Server) Run(ctx context.Context) {
    select {
    case <-ctx.Done():
        return
    }
}

再次htop,查看cpu使用率,现在cpu使用率正常了。

除了使用 top ps看cpu使用率,还可以使用 pidstat 1 以1秒的间隔动态打印cpu使用率,也是非常直观的。

特别注意的是,有时候top看到cpu使用率很高,但是没有找到cpu使用率高的进程,这时候可以用以下命令来持续观察:

liangjf@blue:~/test/linux$ sudo perf record -g
[ perf record: Woken up 6 times to write data ]
[ perf record: Captured and wrote 2.529 MB perf.data (12478 samples) ]

liangjf@blue:~/test/linux$ ls
perf.data
liangjf@blue:~/test/linux$ sudo perf report

观看的效果和直接 perf -g -p pid是一样的。

io资源占有率异常问题,网络io资源异常问题,软中断触发频繁软中断触发频繁等问题的分析待续。

go的pprof

go是一门注重性能,工程性非常强的语言,自带了很多实用的工具,其中的pprof是针对性能分析的工具,包括cpu性能分析,内存分析,阻塞分析,goroutine分析,锁分析等。并且使用起来非常优雅,将其称为瑞士军刀可谓名副其实。

瑞士军刀,是含有许多工具在一个刀身上的折叠小刀,在野外非常实用。把pprof比作为go的瑞士军刀,是想表明pprof这个工具在go的一系列小工具中非常实用。

pprof在go中用于可视化和分析定位运行时性能的工具。主要包括以下方面的性能分析:

  • CPU profile。(CPU分析,定位程序消耗CPU的地方)
  • Memory Profile。(内存分析,堆栈跟踪,排查内存泄漏)
  • Block Profiling。(阻塞分析,定位阻塞等待同步或定时器通道的地方)
  • Mutex  Profiling。(互斥锁分析,锁竞争)
  • Goroutine Profiling。(goroutine分析)

如何嵌入到go程序

有两种嵌入方法,一种是针对服务型程序,一种是针对服务型应用(长时间运行),一种是针对工具型应用(运行一遍得到结果)

服务型应用的嵌入方法

1、导入包
import (
    "net/http"
    _ "net/http/pprof"
)

import net/http/pprof 包后,会自动为server加入以下路由方法

  • “/debug/pprof/”, pprof.Index
  • “/debug/pprof/cmdline”, pprof.Cmdline
  • “/debug/pprof/profile”, pprof.Profile
  • “/debug/pprof/symbol”, pprof.Symbol
  • “/debug/pprof/trace”, pprof.Trace
2、demo
package main

import (
	"log"
	"net/http"
	_ "net/http/pprof"
)

func main() {
	log.Println("server start")
	log.Fatal(http.ListenAndServe(":9090", nil))
}
3、web访问pprof

在浏览器访问,http://localhost:9090/debug/pprof/ ,就可以通过web来查看和分析此服务型应用的各方面性能。

web界面如下图:

工具型应用的嵌入方法

1、导入包
import (
    "net/http"
    _ "runtime/pprof"
)
2、添加生成和运行pprof代码

在需要统计和分析性能的地方添加以下代码,程序运行结束会在本地生成test.pprof文件

f, _ := os.Create("./test.pprof")

_ = pprof.StartCPUProfile(f)
defer pprof.StopCPUProfile()
3、demo(go经典并发找素数)
package main

import (
	"os"
	"runtime/pprof"
)

func Generate(ch chan<- int) {
	for i := 2; ; i++ {
		ch <- i
	}
}

func Filter(in <-chan int, out chan<- int, prime int) {
	for {
		i := <-in
		if i%prime != 0 {
			out <- i
		}
	}
}

func cal() {
	ch := make(chan int)
	go Generate(ch)
	for i := 0; i < 100; i++ {
		prime := <-ch
		ch1 := make(chan int)
		go Filter(ch, ch1, prime)
		ch = ch1
	}
}

func main() {
	f, _ := os.Create("test.pprof")

	_ = pprof.StartCPUProfile(f)
	defer pprof.StopCPUProfile()

	for i := 0; i < 1000; i++ {
		go cal()
	}
}
4、打开pprof文件

在项目目录生成test.pprof文件,执行以下命令打开pprof文件:

go tool pprof test.pprof

5、pprof的命令终端模式

此时会进入pprof的命令终端模式

liangjf@blue:~/test/go/pprof$ go tool pprof test.pprof
File: main
Type: cpu
Time: Nov 30, 2019 at 7:49pm (CST)
Duration: 200.52ms, Total samples = 0 
No samples were found with the default sample value type.
Try "sample_index" command to analyze different sample values.
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) 

不熟悉使用pprof的话,可以先help,看看有哪些命令,常用命令有:

  • top(类似linux top工具)
  • png(生成png,调用图)
  • web(打开web分析)
  • list(支持正则匹配top得到的函数名,更加详细查看每行代码的cpu消耗)

注意,如果是用xshell此类工具,在使用pprof终端模式的时候,web后可能会弹窗:

重新web,就会打开浏览器看到下图效果:

gin的gin-pprof

gin是go中一个非常优秀的web微框架, 简单精悍,类似于瑞士军刀。

如何嵌入到gin程序

1、导入包

github.com/DeanThompson/ginpprof

2、添加ginpprof路由

ginpprof.Wrapper(g)

3、demo

package main

import (
	"github.com/DeanThompson/ginpprof"
	"github.com/gin-gonic/gin"
	"log"
	"net/http"
)

func test(c *gin.Context) {
	c.JSON(http.StatusOK, gin.H{
		"code": 0,
		"msg":  "ok",
	})
}

func router(g *gin.Engine) {
	g.Use(gin.Recovery())
	g.NoRoute(func(c *gin.Context) {
		c.String(http.StatusNotFound, "The incorrect API route.")
	})

	ginpprof.Wrapper(g)
}

func main() {
	g := gin.Default()

	router(g)

	log.Fatal(http.ListenAndServe(":9090", g).Error())
}

自动帮我们注册路由方法:

  • GET /test
  • GET /debug/pprof/
  • GET /debug/pprof/heap
  • GET /debug/pprof/goroutine
  • GET /debug/pprof/allocs
  • GET /debug/pprof/block
  • GET /debug/pprof/threadcreate
  • GET /debug/pprof/cmdline
  • GET /debug/pprof/profile
  • GET /debug/pprof/symbol
  • POST /debug/pprof/symbol
  • GET /debug/pprof/trace
  • GET /debug/pprof/mutex

4、web访问pprof

在浏览器访问,http://localhost:9090/debug/pprof/ ,就可以通过web来查看和分析此服务型应用的各方面性能。

5、ab压测和Go tool pprof常用基本调试基本命令

HTTP场景,参数可选:

  • --text。(go tool pprof后,信息以文本的形式在终端打印)
  • --web。(go tool pprof后,信息以web形式显示)

  • go tool pprof --text http://localhost:9090/debug/pprof/heap
  • go tool pprof --text http://localhost:9090/debug/pprof/profile
  • go tool pprof --text http://localhost:9090/debug/pprof/block

在命令行输入后,默认是定时采集30s。

  • 1、运行上面gin-pprof demo
  • 2、在另一终端执行 go tool pprof --text http://localhost:9090/debug/pprof/profile
  • 3、在另一终端执行多次压测 ab -c 100 -n 1000 http://127.0.0.1:9090/test
  • 4、查看go tool pprof后的结果 go tool pprof /home/liangjf/pprof/pprof.pprof.samples.cpu.003.pb.gz
  • 5、以web形式查看 pprof终端模式中输入 web

可以看到,因为接口太简单了,时间基本是花在系统调用和go的网络框架epoll上。

pprof真实案例

下面看一个真实的例子。

先抛出问题,在测试环境中,go-smartlamp进程占cpu120%,重启,还是将近120%。测试环境只是很少量请求过来的,所以肯定不会达到120%,所以这里肯定有问题。

因为是基于gin的,所以预先就接入gin-pprof,所以我只需要执行 go tool pprof --web http://host/debug/pprof/profile即刻打开web查看profiling。

func Router(g *gin.Engine) {
	...

	if "debug" == viper.GetString("runmode") {
		ginpprof.Wrapper(g)
	}
}

一眼看下去,三个函数很有问题:

  • InitAndroid2BackNsq
  • InitCenter2BackNsq
  • InitPushOfficialMiniNsq

这三个goroutine都是对nsq做初始化工作而已,正常不会占用这么多CPU资源的。再仔细看pprof web图,主要时间是在锁的开销上。不科学啊!!!

不过别怕,既然定位到函数级别了,看看代码就知道什么原因了。

我晕,原来写了个for循环。期初这里只是想初始化nsq,main传入context来控制goroutine的退出。其实是不必要的,因为这里仅仅是初始化nsq,直接函数初始化就行,不惜要创建goroutine并且使用context来控制goroutine的退出。

修改代码后,重新跑,然后top查看go-smartlamp的cpu使用率情况。

ok,现在正常了。

pprof 火焰图

火焰图是一种直观的性能分析图表,因为它的样子近似 🔥而得名。go的pprof profiling 结果也转换成火焰图。

安装工具:go get -u github.com/google/pprof

这是google的开源的一个go pprof工具,非常强大,是基于官方的pprof拓展的。

优点主要是多种view查看方式:graph【图】,flame graph【火焰图】,peek【略看】,source【原始数据】,disassemble【汇编】。

使用pprof的命令修改为:

pprof -http 127.0.0.1:8080 http://localhost:9090/debug/pprof/profile

-http 127.0.0.1:8080 是pprof web访问路径

结语

经过对比传统性能优化和go的pprof性能优化,开源看到不是二选一的问题,有时需要结合linux下的工具来定位进程,线程,然后使用一些常用工具如perf工具等来定位问题,也可以直接使用go的pprof来直观定位问题。

性能优化是一个很大的话题,本文只是简单的介绍。性能优化和问题排查是非常重要的,对它也做了一些总结:

  • 1、定好优化目标,逐个击破。
  • 2、二八原则,并不是所有的性能问题都值得优化,找出最值得优化的地方。
  • 3、性能优化是有成本的,要综合考虑,不要为了优化某个点,而影响了其他点。
  • 4、善于借助开源工具,如linux下的工具,go的pprof,google的pprof等。
  • 5、不要过早优化,过早优化是万恶之源,应该逐步完善,逐步优化提高性能。

参考