性能优化流程
理清待优化代码的常用逻辑与场景
根据实际场景编写压测用例
使用pprof 或者火焰图等工具取得数据
找到热点代码重点优化
Profiling
pprof 是用于可视化和分析性能分析数据的工具。为什么pprof可以帮助我们分析Go程序性能呢?因为它可以采集程序运行时数据:比如说协程栈,这样服务阻塞在哪里是不是一目了然了;比如说内存分配情况包括调用栈,这样哪里耗费内存也清楚了。有两种类型的 profiler :
1.追踪型:任何时候触发提前设定的事件就会做测量,例如:函数调用,函数退出,等等
2.采样型:常规时间间隔做一次测量
Go CPU profiler 是一个采样型的 profiler。也有一个追踪型的 profiler,Go 执行追踪器,用来追踪特定事件像请求锁,GC 相关的事件,等等。
采样型 profiler 通常包含两个主要部分:
采样器:一个在时间间隔触发的回调,一个堆栈信息一般会被收集成 profiling data。不同的 profiler 用不同的策略去触发回调。
数据收集:这个是 profiler 收集数据的地方:它可能是内存占用或者是调用统,基本上跟堆栈追踪相关的数据
在计算机性能调试领域里,profiling 就是对应用的画像,这里画像就是应用使用 CPU 和内存的情况。也就是说应用使用了多少 CPU 资源?都是哪些部分在使用?每个函数使用的比例是多少?有哪些函数在等待 CPU 资源?知道了这些,我们就能对应用进行规划,也能快速定位性能瓶颈。
CPU Profiling 是如何工作的?stack trace + statistics 的模型。当我们准备进行 CPU Profiling 时,通常需要选定某一时间窗口,在该窗口内,CPU Profiler 会向目标程序注册一个定时执行的 hook(有多种手段,譬如 SIGPROF 信号),在这个 hook 内我们每次会获取业务线程此刻的 stack trace。我们将 hook 的执行频率控制在特定的数值,譬如 100hz,这样就做到每 10ms 采集一个业务代码的调用栈样本。当时间窗口结束后,我们将采集到的所有样本进行聚合,最终得到每个函数被采集到的次数,相较于总样本数也就得到了每个函数的相对占比。借助此模型我们可以发现占比较高的函数,进而定位 CPU 热点。
Heap Profiling 也是stack trace + statistics 的模型。数据采集工作并非简单通过定时器开展,而是需要侵入到内存分配路径内,即直接将自己集成在内存分配器内,当应用程序进行内存分配时拿到当前的 stack trace,最终将所有样本聚合在一起,这样我们便能知道每个函数直接或间接地内存分配数量了。由于 Heap Profiling 也是采样的(默认每分配 512k 采样一次),所以展示的内存大小要小于实际分配的内存大小。同 CPU Profiling 一样,这个数值仅仅是用于计算相对占比,进而定位内存分配热点。
如何看懂火焰图(以从下到上为例)
如何看懂火焰图火焰图的调用顺序从下到上,每个方块代表一个函数,它上面一层表示这个函数会调用哪些函数,方块的大小代表了占用 CPU 使用的长短。火焰图的配色并没有特殊的意义,默认的红、黄配色是为了更像火焰而已。
每一列代表一个调用栈,每一个格子代表一个函数
纵轴展示了栈的深度,按照调用关系从下到上排列。最顶上格子代表采样时,正在占用 cpu 的函数。
横轴的意义是指:火焰图将采集的多个调用栈信息,通过按字母横向排序的方式将众多信息聚合在一起。需要注意的是它并不代表时间。
横轴格子的宽度代表其在采样中出现频率,所以一个格子的宽度越大,说明它是瓶颈原因的可能性就越大。
纵向表示调用栈的深度
横向表示消耗的时间
实现cpu采样
采样对象: 函数调用和它们占用的时间
采样率:100次/秒,固定值
采样时间:从手动启动到手动结束
profiler在Linux中,Go runtime 使用setitimer/timer_create/timer_settime API来设置SIGPROF 信号处理器。这个处理器在runtime.SetCPUProfileRate 控制的周期内被触发,默认为100Mz(10ms)。一旦 pprof.StartCPUProfile 被调用,Go runtime 就会在特定的时间间隔产生SIGPROF 信号。内核向应用程序中的一个运行线程发送 SIGPROF 信号。由于 Go 使用非阻塞式 I/O,等待 I/O 的 goroutines 不被计算为运行,Go CPU profiler 不捕获这些。顺便提一下:这是实现 fgprof 的基本原因。fgprof 使用 runtime.GoroutineProfile来获得等待和非等待的 goroutines 的 profile 数据。
一旦一个随机运行的goroutine 收到 SIGPROF 信号,它就会被中断,然后信号处理器的程序开始运行。被中断的 goroutine 的堆栈 在这个信号处理器的上下文中被检索出来,然后和当前的 profiler 标签一起被保存到一个无锁的日志结构中(每个捕获的堆栈追踪都可以和一个自定义的标签相关联,你可以用这些标签在以后做过滤)。这个特殊的无锁结构被命名为 profBuf ,它被定义在 runtime/profbuf.go 中,它是一个单一写、单一读的无锁环形缓冲 结构,与这里发表的结构相似。writer 是 profiler 的信号处理器,reader 是一个 goroutine(profileWriter),定期读取这个缓冲区的数据,并将结果汇总到最终的 hashmap。这个最终的 hashmap 结构被命名为 profMap,并在 runtime/pprof/map.go中定义。PS:goroutine 堆栈信息 ==> sigProfHandler ==write==> profBuf ==read==> profWriter ==> profMap
heap 采样
采样程序通过内存分配器 在堆上分配和释放内存,记录分配/释放的大小和数量
采样率:每分配512KB 记录一次,可在运行开头修改,1为每次分配均记录。
采样时间:从程序运行开始到结束
采样指标:alloc_space,alloc_objects,inuse_space,inuse_objects
计算方式: inuse = alloc - free
goroutine
记录所有用户发起且在运行中的goroutine(即入口非runtime开头的)的调用栈信息
runtime.main 的调用栈信息
采样方式:stop the world ==> 遍历 allg slice ==> 输出创建g的堆栈 ==> start the world ThreadCreate
记录程序创建的所有系统线程信息
采样方式:stop the world ==> 遍历 allm 链表 ==> 输出创建m的堆栈 ==> start the world
block
采样阻塞操作的次数和耗时
采样率:阻塞耗时超过阈值的才会被记录。1 为每次阻塞均记录
采样方式:阻塞操作 ==> Profiler 上报调用栈和消耗时间(时间未到阈值则丢弃) ==> 遍历阻塞记录 ==> 统计阻塞次数和耗时
锁竞争
采样争抢锁的次数和耗时
采样率:只记录固定比例的锁操作,1 为每次加锁均记录
采样方式:阻塞操作 ==> Profiler 上报调用栈和消耗时间(比例未命中则丢弃) ==> 遍历锁记录 ==> 统计锁竞争次数和耗时
trace
虽然CPU分析器做了一件很好的工作,告诉你什么函数占用了最多的CPU时间,但它并不能帮助你确定是什么阻止了goroutine运行。这里可能的原因:被syscall阻塞 、阻塞在共享内存(channel/mutex etc)、阻塞在运行时(如 GC)、甚至有可能是运行时调度器不工作导致的。这种问题使用pprof很难排查。
go tool trace 能够跟踪捕获各种执行中的事件,例如:
Goroutine 的创建/阻塞/解除阻塞。
Syscall 的进入/退出/阻止,GC 事件。
Heap 的大小改变。
Processor 启动/停止等等。
时间线: 显示执行的时间单元 根据时间的纬度不同 可以调整区间
stats 区域
堆,显示执行期间内存的分配和释放情况(折线图)
协程(Goroutine),显示每个时间点哪些Goroutine在运行 哪些goroutine等待调度 ,其包含 GC 等待(GCWaiting)、可运行(Runnable)、运行中(Running)这三种状态。
Threads,显示在执行期间有多少个线程在运行,其包含正在调用 Syscall(InSyscall)、运行中(Running)这两种状态。
proc区域,虚拟处理器Processor:每个虚拟处理器显示一行,虚拟处理器的数量一般默认为系统内核数。数量由环境变量GOMAXPROCS控制。
上一层表示Processor上运行的goroutine的信息,一个P 某个时刻只能运行一个G,选中goroutine 可以查看特定时间点 特定goroutine的执行堆栈信息以及关联的事件信息
下一层表示processor附加的事件比如SysCall 或runtime system events