首页 > 后端开发 > Golang > golang性能诊断看这篇就够了

golang性能诊断看这篇就够了

发布: 2023-07-24 16:18:33
转载
1787 人浏览过
我们日常接触性能诊断问题,一般分为两种情况,一是线上应用真的出现性能问题;二是我们需要对准备上线的系统进行性能预估;后者需要压力测试辅助进行,此处不表。
针对GO应用,性能诊断工具主要分为两层:OS层面和GO应用层面(go tool pprof /trace /gc)


OS诊断


系统诊断,我们一般主要关注三个方面: CPU 、Memory、I/O

1.1 CPU

CPU诊断主要关注平均负载(Load Average),CPU使用率,上下文切换(Context Switch)。常用top命令查看cpu使用率以及服务器负载情况。

golang性能诊断看这篇就够了

平均负载:0.14 0.07 0.06 分别表示过去1分钟、5分钟、15分钟的机器负载的平均值,根据经验,若负载数值小于0.7*CPU个数则正常,超过或者达到CPU核数的四五倍,则系统的负载就明显偏高。

CPU的上下文切换情况可通过vmstat命令可以查看,上下文切换发生的场景有如下几种:

  1. 时间片用完,CPU正常调度下一个任务

  2. 被其他优先级更高的任务抢占

  3. 执行任务碰到I/O阻塞,挂起当前任务,切换到下一个任务

  4. 用户代码主动挂起当前任务让出CPU

  5. 多任务抢占资源,因没抢到而被挂起

  6. 硬件中断

1.2  Memory

从操作系统角度,内存关注应用进程是否足够,可以使用 free –m 命令查看内存的使用情况。

通过 top 命令可以查看进程使用的虚拟内存 VIRT 和物理内存 RES,根据公式 VIRT = SWAP + RES 可以推算出具体应用使用的交换分区(Swap)情况,使用交换分区过大会影响 应用性能,可以将 swappiness 值调到尽可能小。


1.3 I/O

I/O 包括磁盘 I/O 和网络 I/O,一般情况下磁盘更容易出现 I/O 瓶颈。通过iostat可以查看磁盘的读写情况,通过 CPU 的 I/O wait 可以看出磁盘 I/O 是否正常。

如果磁盘 I/O 一直处于很高的状态,说明磁盘太慢或故障,成为了性能瓶颈,需要进行应用优化或者磁盘更换。

除了常用的 top、 ps、vmstat、iostat 等命令,还有其他 Linux 工具可以诊断系统问题,如 mpstat、tcpdump、netstat、pidstat、sar 等 更多Linux性能诊断工具如下图:

golang性能诊断看这篇就够了

GO应用诊断


go生态已经为我们提供了大量的API和诊断工具帮助我们解决go应用的性能问题。我们常用的大致可以分为两类:
  • Profiling 收集程序执行过程中的具体事件,并抽样统计 方便精确定位问题

  • Tracing 一种检测代码的方法,用于分析调用或用户请求整个生命周期中的延迟,且可以跨多个Go进程。


2.1 profiling

profile一般被称为性能分析,对程序而言,就是程序运行时的各种概况信息,包括cpu占用情况、内存情况、线程情况等。方便分析昂贵或频繁调用的程序场景。
如何使用?

1.首先profiling代码埋入

import _ "net/http/pprof"


func main() {
    go func() {
        log.Println(http.ListenAndServe("0.0.0.0:9090", nil))
    }()
    ...
}
登录后复制


2.保存特定时间点的profile,例如保存heap信息

curl http://localhost:6060/debug/pprof/heap --output heap.tar.gz
登录后复制

3.使用go tool pprof 分析保存的profile快照,如分析上述heap信息

go tool pprof heap.tar.gz
登录后复制


2.1.1  CPU Profiling

pprof可以帮忙我们分析出函数执行缓慢问题  CPU占用过高问题

go tool pprof http://localhost:6060/debug/pprof/profile?second=10
登录后复制

命令行方式: 常用命令 top  list traces

top: 查看按照占用内存或cpu多少排序的前10的函数信息

  • flat:当前函数占用的CPU时长(不包含其调用的其他函数

  • flat%:当前函数使用CPU占总CPU时长的百分比

  • sum%:前面每一行flat百分比的和

  • cum: 累计量,当前函数及其子函数占用CPU时长 

  • cum%:累计量占总量的百分比

cum>=flat

list: 查看某个函数的代码 以及该函数每行代码的指标信息

traces:打印所有函数调用栈 以及调用栈的指标信息

golang性能诊断看这篇就够了

UI界面方式:从服务器download下生成的sample文件

go tool pprof -http=:8080 pprof.xxx.samples.cpu.001.pb.gz
登录后复制

golang性能诊断看这篇就够了


golang性能诊断看这篇就够了

Flame graph很清晰得可以看到当前CPU被哪些函数执行栈占用


1.2 Heap Profiling

go tool pprof http://localhost:6060/debug/pprof/heap?second=10
登录后复制

命令行 UI查看方式 同理

golang性能诊断看这篇就够了


golang性能诊断看这篇就够了



graph中方框越大 占用内存越多 火焰图 宽度越大 占用内存越多

SAMPLE->inuse_objects可以查看当前的对象数量 这个参数对于分析gc线程占用较高cpu时很有用处 它侧重查看对象数量

inuse_space图可以查看具体的内存占用

毕竟对于10个100m的对象和1亿个10字节的对象占用内存几乎一样大,但是回收起来一亿个小对象肯定比10个大对象要慢很多。

go tool pprof -inuse_space http://localhost:6060/debug/pprof/heap : 分析应用程序的常驻内存占用情况 (默认)
go tool pprof -alloc_objects http://localhost:6060/debug/pprof/heap: 分析应用程序的内存临时分配情况
登录后复制


1.3 并发请求问题 查看方式跟上面类似。

go tool pprof http://localhost:6060/debug/pprof/goroutine
go tool pprof http://localhost:6060/debug/pprof/block
go tool pprof http://localhost:6060/debug/pprof/mutex
登录后复制


2.2 tracing

trace并不是万能的,它更侧重于记录分析 采样时间内运行时系统具体干了什么。

收集trace数据的三种方式:

1. 使用runtime/trace包 调用trace.Start()和trace.Stop()

2. 使用go test -trace=测试标识

3. 使用debug/pprof/trace handler 获取运行时系统最好的方法

例如,通过

go tool pprof http://localhost:6060/debug/pprof/trace?seconds=20 > trace.out
登录后复制

获取运行时服务的trace信息,使用

go tool trace trace.out
登录后复制

会自动打开浏览器展示出UI界面

golang性能诊断看这篇就够了

其中trace view 只能使用chrome浏览器查看,这里go截止1.14版本存在一个 bug,解决办法如下:

go tool trace trace.out 无法查看trace view
go bug:https://github.com/golang/go/issues/25151
mac 解决版本:安装gotip
go get golang.org/dl/gotip
gotip download
then  使用 gotip tool trace trace.out即可
登录后复制

获取的trace.out 二进制文件也可以转化为pprof格式的文件

go tool trace -pprof=TYPE trace.out > TYPE.pprof
Tips:生成的profile文件 支持 network profiling、synchronization profiling、syscall profiling、scheduler profiling
go tool pprof TYPE.pprof
登录后复制


使用gotip tool trace trace.out可以查看到trace view的丰富操作界面:

操作技巧:

ctrl + 1 选择信息

ctrl + 2 移动选区

ctrl + 3 放大选区

ctrl + 4 指定选区区间

shift + ? 帮助信息

AWSD跟游戏快捷键类似 玩起来跟顺手

整体的控制台信息 如下图:

golang性能诊断看这篇就够了


  • 时间线: 显示执行的时间单元 根据时间的纬度不同 可以调整区间

  • 堆: 显示执行期间内存的分配和释放情况

  • 协程(Goroutine): 显示每个时间点哪些Goroutine在运行 哪些goroutine等待调度 ,其包含 GC 等待(GCWaiting)、可运行(Runnable)、运行中(Running)这三种状态。

goroutine区域选中时间区间

golang性能诊断看这篇就够了

OS线程(Machine): 显示在执行期间有多少个线程在运行,其包含正在调用 Syscall(InSyscall)、运行中(Running)这两种状态。

golang性能诊断看这篇就够了

  • 虚拟处理器Processor: 每个虚拟处理器显示一行,虚拟处理器的数量一般默认为系统内核数。数量由环境变量GOMAXPROCS控制

  • 协程和事件: 显示在每个虚拟处理器上有什么 Goroutine 正在运行,而连线行为代表事件关联。

每个Processor分两层,上一层表示Processor上运行的goroutine的信息,下一层表示processor附加的事件比如SysCall 或runtime system events

golang性能诊断看这篇就够了

ctrl+3 放大选区,选中goroutine 可以查看,特定时间点 特定goroutine的执行堆栈信息以及关联的事件信息

golang性能诊断看这篇就够了

goroutine analysis

golang性能诊断看这篇就够了

点击goroutine的id 可以跳到trace view 详细查看goroutine具体干了什么

名称
含义
Execution执行时间
Network wait网络等待时间
Sync Block同步阻塞时间
Blocking syscall系统调用阻塞时间
Scheduler wait调度等待时间
GC SweepingGC清扫时间
GC PauseGC暂停时间


实践 一个延迟问题诊断

当我们一个执行关键任务的协程从运行中被阻塞。这里可能的原因:被syscall阻塞 、阻塞在共享内存(channel/mutex etc)、阻塞在运行时(如 GC)、甚至有可能是运行时调度器不工作导致的。这种问题使用pprof很难排查,

使用trace只要我们确定了时间范围就可以在proc区域很容易找到问题的源头

golang性能诊断看这篇就够了

上图可见,GC 的MARK阶段阻塞了主协程的运行



2.3 GC

golang的gc算法是根据标记清除改进的三色标记法,大概流程:

初始所有对象都是白色

  1. Stack scan阶段:从root出发扫描所有可达对象,标记为灰色并放入待处理队列;root包括全局指针和goroutine栈上的指针

  2. Mark阶段:1.从待处理队列取出灰色对象,将其引用的对象标记为灰色并放入队列,自身标记为黑色 2. re-scan全局指针和栈,因为mark和用户程序并行运行,故过程1的时候可能会有新的对象分配,这时需要通过写屏障(write barrier)记录下来;re-scan再完成检查;

  3. 重复步骤Mark阶段,直到灰色对象队列为空,执行清扫工作(白色即为垃圾对象)

go的三色标记法也存在STW(Stop The World),大致有两个场景
  1. GC即将开始时,需要STW 做一些准备工作, 如enable write barrier

  2. re-scan也需要STW,否则上面Mark阶段的re-scan无法终止

通过GODEBUG=gctrace=1可以开启gc日志,查看gc的结果信息

$ GODEBUG=gctrace=1 go run main.go   
gc 1 @0.001s 19%: 0.014+3.7+0.015 ms clock, 0.11+2.8/5.7/3.2+0.12 ms cpu, 5->6->6 MB, 6 MB goal, 8 P
gc 2 @0.024s 6%: 0.004+3.4+0.010 ms clock, 0.032+1.4/4.5/5.3+0.085 ms cpu, 13->14->13 MB, 14 MB goal, 8 P
gc 3 @0.093s 3%: 0.004+6.1+0.027 ms clock, 0.032+0.19/11/15+0.22 ms cpu, 24->25->22 MB, 26 MB goal, 8 P
scvg: 0 MB released
scvg: inuse: 4, idle: 58, sys: 63, released: 58, consumed: 4 (MB)
scvg: 0 MB released
scvg: inuse: 4, idle: 58, sys: 63, released: 58, consumed: 4 (MB)
scvg: 0 MB released
scvg: inuse: 4, idle: 58, sys: 63, released: 58, consumed: 4 (MB)
scvg: 0 MB released
scvg: inuse: 4, idle: 58, sys: 63, released: 58, consumed: 4 (MB)
登录后复制


格式

gc # @#s #%: #+#+# ms clock, #+#/#/#+# ms cpu, #->#-># MB, # MB goal, # P

含义

gc#:GC 执行次数的编号,每次叠加。

@#s:自程序启动后到当前的具体秒数。

#%:自程序启动以来在GC中花费的时间百分比。

#+...+#:GC 的标记工作共使用的 CPU 时间占总 CPU 时间的百分比。

#->#-># MB:分别表示 GC 启动时, GC 结束时, GC 活动时的堆大小.

#MB goal:下一次触发 GC 的内存占用阈值。

#P:当前使用的处理器 P 的数量。



拓展


当我们的程序陷入CPU 和IO混和负载过高时,我们使用pprof profile只能检测出CPU耗时的函数,但是屏蔽了IO等待过长的函数。

https://github.com/felixge/fgprof 给出了一个解决方案:

具体做法是:用一个后台协程在采样时间区间内每秒99次调用runtime.GoruntineProfile,返回的结果忽略了协程当时消耗CPU还是非消耗CPU的区别 进行统计,保存在内存中的map中,可导出转化为pprof

具体用法:

package main
 
import(
    _ "net/http/pprof"
    "github.com/felixge/fgprof"
)
 
func main() {
    http.DefaultServeMux.Handle("/debug/fgprof", fgprof.Handler())
    go func() {
        log.Println(http.ListenAndServe(":6060", nil))
    }()
 
    // <code to profile>
}
 
git clone https://github.com/brendangregg/FlameGraph
cd FlameGraph
curl -s &#39;localhost:6060/debug/fgprof?seconds=3&#39; > fgprof.fold
./flamegraph.pl fgprof.fold > fgprof.svg
登录后复制

如果遇到这种CPU消耗型和非CPU消耗型混合的情况下 可以试试排查下。

以上是golang性能诊断看这篇就够了的详细内容。更多信息请关注PHP中文网其他相关文章!

相关标签:
来源:Go语言进阶学习
本站声明
本文内容由网友自发贡献,版权归原作者所有,本站不承担相应法律责任。如您发现有涉嫌抄袭侵权的内容,请联系admin@php.cn
最新问题
热门教程
更多>
最新下载
更多>
网站特效
网站源码
网站素材
前端模板