题记
这是我参与「第五届青训营 」伴学笔记创作活动的第 6天,本文用于记录在青训营的学习笔记和一些心得。
day6 1月20日
性能调优实战
性能调优原则
- 要依靠数据不是猜测
- 要定位最大瓶颈而不是细枝末节
- 不要过早优化
- 不要过度优化
性能分析工具
性能调优的核心是性能瓶颈的分析,对于 Go 应用程序,最方便的就是 pprof 工具
-
pprof 功能说明
- pprof 是用于可视化和分析性能分析数据的工具
- 可以知道应用在什么地方耗费了多少 CPU、memory 等运行指标
cmdline显示运行进程的命令, threadcreate比较复杂, 不适明,trace需要另外的工具解析,暂不涉及 炸弹在CPU,堆内存,goroutine, 锁竞争和阻塞操作上埋了炸弹,可以使用pprof工具进行分析
在终端执行以下命令,
输入top命名(作用是查看占用资源最多的函数)
什么情况下flat==cum,flat==0?
- 1.函数中没有调用其他函数
- 2.函数中只有其他函数的调用
根据上面的top命令,你知道Eat函数占用最多的资源,现在我们使用list命令(作用:根据指定的正则表达式查找代码行)
使用web命令,调用关系可视化。
注释eat的for循环,cpu占用降低。
现在我们来分析堆内存问题,我们使用以下命令进行分析
进入view
top和source就跟pprof里面的top和list命令差不多,这个可视化更直观。根据这个我们找到占用内存最大的语句,注释它。
协程的排查
打开View菜单,切换到Flame Graph视图可以看到,刚才的节点被堆叠了起来 图中,自顶向下展示了各个调用,表示各个函数调用之间的层级关系每一行中,条形越长代表消耗的资源占比越多 显然,那些「又平又长」的节点是占用资源多的节点 可以看到,*Wolf.Drink()这个调用创建了超过90%的goroutine,问题可能在这里火焰图是非常常用的性能分析工具,在程序逻辑复杂的情况下很有用,可以重点熟悉
mutex
修改链接后缀,改成mutex,然后打开网页观察,发现存在1个锁操作同样地,在Graph视图中定位到出问题的函数在*Wolf.Howl()然后在Source视图中定位到县体哪—行发生了锁竞争 在这个函数中,goroutine足足等待了1秒才解锁,在这里阻塞住了,显然不是什么业务需求,注释掉。
block
我们开始排查最后一个阻塞问题。 在程序中,除了锁的竞争会导致阻塞之外,还有很多逻辑(例如读取一个channel)也会导致阻塞,在页面中可以看到阻塞操作还剩两个(强调)。链接地址未尾再换成block。
和刚才一样,Graph到Source的视图切换 可以看到,在*Cat.Pee()函数中读取了一个time.AfterO)生成的channel,这就导致了这个goroutine实际上阻塞了1秒钟,而不是等待了1秒钟。
不过通过上面的分析,我们只定位到—个block的问题 有同学可能会发现。刚刚的计数页面上有两个阻塞操作,但是实际上只有一个,那么另一个为什么没有展示呢?提示,可以关注一下pprof Top视图中表格之外的部分, 从框住的地方可以发现,有4个节点因为cumulative小于1.41秒被drop掉了,这就是另-一个阻塞操做的节点。,但他因为总用时小于总时长的千分之五,所以被省略掉了,这样的过滤策略能够更加有效地突出问题所在,而省略相对没有问题的信息。
如果不作任何过滤全部展示的话,对于一个复杂的程序可能内容就会非常庞大了,不利于我们的问题定位。
我们知道了另一个阻塞是确实存在的,接下来大家可以进一步猜测一下没有展示的这个阻塞操作发生在哪里?需要点击哪个链接查看? 提示:程序除了在跑性能「炸弹」之外,还有什么工作呢?我们是怎样访问它的采样信息的? 尽管占用低的节点不会在pprof工具中展示出来,但实际上他是被记录下来的。我们还可以通过暴露出来的接口地址直接访问它。所以,打开Block指标的页面,可以看到,第二个阻塞操作发生在了http handler中,这个阻塞操作是符合预期的。
至此,我们已经发现了代码中存在的所有「炸弹] 以上我们介绍了五种使用pprof采集的常用性能指标:CPU、堆内存、Goroutine、锁竞争和阻塞;两种展示方式:交互式终端和网页;四种视图:Top、Graph、源码和火焰图。 pprof除了http的获取方式之外,也可以直接在运行时调用runtime/pprof包将指标数据输出到本地文件。视图中还有一个更底层的「反汇编]视图。有兴趣的同学可以尝试一下它们的用法,俗话说,知其然还要知其所以然,接下来我们来看看它们内部的实现。
采样过程与原理
首先来看CPU。CPU采样会记录所有的调用栈和它们的占用时间。 在采样时,进程会每秒暂停一百次,每次会记录当前的调用栈信息。汇总之后,根椐调用栈在采样中出现的次数来排断函数的运行时间.你需要手动地启动和停止采样。每秒100次的暂停频率也不能更改。 这个定时暂停机制在unix或类unix系统上是依赖信号机制实现的。 每次「暂停」都会接收到一个信号,通过系统计时器来保证这个信号是固定频率发送的。接下来看看具体的流程。
—共有三个相关角色:进程本身、操作系统和写缓冲。 启动采样时,进程向OS注册一个定时器,OS会每隔10ms向进程发送一个SIGPROF信号,进程接收到信号后就会对当前的调用栈进行记录。与此同时,进程会启动一个写缓冲的goroutine,它会每隔100ms从进程中读取已经记录的堆栈信息,并写入到输出流。 当采样停止时,进程向OS取消定时器,不再接收信号,写缓冲读取不到新的堆栈时,结束输出。
接下来看看堆内存采样。
提到内存指标的时候说的都是「堆内存」而不是「内存」,这是因为pprof的内存采样是有局限性的。
内存采样在实现上依赖了内存分配器的记录,所以它只能记录在堆上分配,且会参与GC的内存,一些其他的内存分配,你如调用结束就会回收的栈内存、一些更底层使用cgo调用分配的内存,是不会被内存来带记录的。
它的采样率是一个大小,默认每分配512KB内存会采样一次,采样率是可以在运行开头调整的,设为1则为每次分配都会记录。 与CPU和goroutine都不同的是,内存的采样是一个持续的过程,它会记录从程序运行起的所有分配或释放的内存大小和对象数量,并在采样时遍历这些结果进行汇总。 还记得刚才的例子中,堆内存采样的四种指标吗?alloc的两次指标是从程序运行开始的累计指标,而inuse的两项指标是通过累计分配减去累计释放得到的程序当前持有的指标。你也可以通过比较两次alloc的差值来得到某一段时间程序分配的内存【大小和数量】
接下来我们来看看goroutine和系统线程的采样。这两个采样指标在概念上和实现上都比较相似,所以在这里进行对比。 Goroutie采样会记录所有用户发起,也就是入口不是runtime开头的goroutine,以及main函数所在goroutine的信息和创建这些goroutine的调用栈 他们在实现上非常的相似,都是会在STW之后,遍历所有goroutine/所有线程的列表(图中的m就是GMP模型中的m,在golang中和线程——对应)并输出堆栈 最后Start The World继续运行。这个采样是立刻触发的全量记录,你可以通过比较两个时间点的差值来得到某一时间段的指标。
最后是阻塞和锁竞争这两种采样
这两个指标在流程和原理上也非常相似
这两个采样记录的都是对应操作发生的调用栈、次数和耗时,不过这两个指标的采样率含义并不相同。
阻塞操作的采样率是一个「阈值」,消耗超过阈值时间的阻塞操作才会被记录,1为每次操作都会记录。记得炸弹程序的main代码吗?里面设置了rate=1
锁竞争的采样率是一个「比例」,运行时会通过随机数来只记录固定比例的锁操作,1为每次操作都会记录。 它们在实现上也是基本相同的。都是一个「主动上报」的过程。
在阻塞操作或锁操作发生时,会计算出消耗的时间,连同调用栈一起主动上报给采样器,采样器会根据采样率可能会丢弃一些记录。
在采样时,采样器会遍历已经记录的信息,统计出具体操作的次数、调用栈和总耗时。和堆内存一样,你可以对比两个时间点的差值计算出段时间内的操作指标。