图书网页设计网站,宁波网站建设按需定制,科学小制作小发明,动漫设计与制作是什么经过前面的几节对pprof的介绍#xff0c;对pprof统计的原理算是掌握了七八十了#xff0c;我们对memory,block,mutex,trace,goroutine,threadcreate这些维度的统计原理都进行了分析#xff0c;但唯独还没有分析pprof 工具是如何统计cpu使用情况的#xff0c;今天我们来分析…经过前面的几节对pprof的介绍对pprof统计的原理算是掌握了七八十了我们对memory,block,mutex,trace,goroutine,threadcreate这些维度的统计原理都进行了分析但唯独还没有分析pprof 工具是如何统计cpu使用情况的今天我们来分析下这部分。
http 接口暴露的方式
我们启动了一个http服务来暴露各种性能指标信息。让我们再回到当时启动http服务看到的网页图。 当点击上图中profile链接时便会下载一个关于cpu指标信息的二进制文件。这个二进制文件同样可以用go tool pprof 工具去分析同样关于go tool pprof的使用不是本文的重点网上的资料也相当多所以我略去了这部分。
紧接着我们来快速看下如何用程序代码的方式生成cpu的profile文件。
程序代码生成profile
os.Remove(cpu.out)f, _ : os.Create(cpu.out)defer f.Close()pprof.StartCPUProfile(f)defer pprof.StopCPUProfile()// .... do other things代码比较简单pprof.StartCPUProfile 则开始统计 cpu使用情况pprof.StopCPUProfile则停止统计cpu使用情况将程序使用cpu的情况写入cpu.out文件。cpu.out文件我们则可以用go tool pprof去分析了。
好的在快速的看完如何在程序中暴露cpu性能指标后我们来看看golang是如何统计各个函数cpu使用情况的。接下来正戏开始。
cpu 统计原理分析
首先要明白我们究竟要统计的是什么内容我们需要知道cpu的使用情况换言之就是cpu的工作时间花在了哪些函数上最后是不是就是看函数在cpu上的工作时长。
那么函数的在cpu上工作时长应该如何去进行统计
golang还是采用部分采样的方式通过settimmer 系统调用设置了 发送SIGPROF 的定时器当达到runtime.SetCPUProfileRate设置的周期间隔时操作系统就会向进程发送SIGPROF 信号默认情况下是100Mz(10毫秒)。 一旦设置了 发送SIGPROF信号的定时器操作系统便会定期向进程发送SIGPROF信号。 设置定时器的代码便是在我们调用pprof.StartCPUProfile方法开启cpu信息采样的时候。代码如下
// src/runtime/pprof/pprof.go:760
func StartCPUProfile(w io.Writer) error {const hz 100cpu.Lock()defer cpu.Unlock()if cpu.done nil {cpu.done make(chan bool)}// Double-check.if cpu.profiling {return fmt.Errorf(cpu profiling already in use)}cpu.profiling trueruntime.SetCPUProfileRate(hz)go profileWriter(w)return nil
}在倒数第三行的时候调用了设置采样的周期并且紧接着profileWriter 就是用一个协程启动后去不断的读取cpu的采样数据写到文件里。而调用settimer的地方就是在runtime.SetCPUProfileRate里runtime.SetCPUProfileRate最终会调用 setcpuprofilerate方法 setcpuprofilerate 又会去调用setProcessCPUProfiler方法设置settimer 定时器。
// src/runtime/signal_unix.go:269
func setProcessCPUProfiler(hz int32) {.....var it itimervalit.it_interval.tv_sec 0it.it_interval.set_usec(1000000 / hz)it.it_value it.it_intervalsetitimer(_ITIMER_PROF, it, nil)
.... 经过上述步骤后cpu的采样就真正开始了之后就是定时器被触发送SIGPROF信号进程接收到这个信号后会对当前函数的调用堆栈进行记录由于默认的采样周期设置的是100Mz所以你可以理解为每10msgolang就会统计下当前正在运行的是哪个函数在采样的这段时间内哪个函数被统计的次数越多是不是就能说明这个函数在这段时间内占用cpu的工作时长就越多了。
由于golang借助了linux的信号机制去进行cpu执行函数的采样这里有必要额外介绍下linux 进程与信号相关的知识。首先来看下线程处理信号的时机在什么时候。
线程处理信号的时机
线程对信号的处理时机一般 是在由内核态返回到用户态之前也就是说当线程由于系统调用或者中断进入内核态后 当系统调用结束或者中断处理完成后在返回到用户态之前操作系统会检查这个线程是不是有未处理的信号如果有的话那么会先切回到用户态让 线程会首先处理信号信号处理完毕后 又返回内核态内核此时才会将调用栈设置为中断或者系统调用时 用户进程中断的地方 然后切换到用户态后就继续在用户进程之前中断的地方继续执行程序逻辑了。由于进程几乎每时每刻都在进行诸如系统调用的工作可以认为信号的处理是几乎实时的。 如下是线程内核态与用户态切换的过程正式信号处理检查的地方。整个过程可以用下面的示意图表示。 知道了信号是如何被线程处理的还需要了解下内核会如何发送信号给进程。
内核发送信号的方式
内核向进程发信号的方式是对进程中的一个线程发送信号而通过settimmer 系统调用设置定时器 发送SIGPROF 信号的方式就是随机的对进程中的一个运行中线程去进行发送。而运行中线程接收到这个信号后就调用自身的处理函数对这个信号去进行处理对于SIGPROF 信号而言则是将线程中断前的函数栈记录下来用于后续分析函数占用cpu的工作时长。
由于只是随机的向一个运行中的线程发送SIGPROF 信号这里涉及到了两个问题
第一因为同一个进程中只有一个线程在进行采样所以在随机选择运行线程发送SIGPROF信号时要求选择线程时的公平性不然可能会出现A,B两个线程A线程接收到SIGPROF信号的次数远远大于B 线程接收SIGPROF信号的次数这样对A线程进行采样的次数将会变多影响了我们采样的结果。
而golang用settimmer 设置定时器发送SIGPROF 信号 的方式的确被证实在linux上存在线程选择公平性问题(但是mac os上没有这个问题) 关于这个问题的讨论在github上有记录这是链接 这个问题已经在go1.18上得到了解决解决方式我会在下面给出我们先来看随机的向一个运行中的线程发送SIGPROF 信号 引发的第二个问题。
第二 因为是向一个运行中的线程去发送信号所以我们只能统计到采样时间段内在cpu上运行的函数而那些io阻塞的函数将不能被统计到关于这点业内已经有开源库帮助解决GitHub - felixge/fgprof: fgprof is a sampling Go profiler that allows you to analyze On-CPU as well as Off-CPU (e.g. I/O) time together.不过由于这个库进行采样时会stop the world 所以其作者强烈建议如果go协程数量比较多时将go版本升级到1.19再使用。后续有机会再来探讨这个库的实现吧我们先回到如何解决settimer函数在选择线程的公平性问题上。
采样数据的公平性
为了解决公平性问题golang在settimer的系统调用的基础上增加了timer_create系统调用timer_create 可以单独的为每一个线程都创建定时器这样每个运行线程都会采样到自己的函数堆栈了。所以在go1.18版本对pprof.StartCPUProfile内部创建定时器的代码进行了改造。刚才有提到pprof.StartCPUProfile 底层其实是调用setcpuprofilerate 这个方法去设置的定时器所以我们来看看go1.18和go1.17版本在这个方法的实现上主要是哪里不同。
// go1.17 版本 src/runtime/proc.go:4563
func setcpuprofilerate(hz int32) {if hz 0 {hz 0}_g_ : getg()_g_.m.lockssetThreadCPUProfiler(0)for !atomic.Cas(prof.signalLock, 0, 1) {osyield()}if prof.hz ! hz {// 设置进程维度的 SIGPROF 信号发送器setProcessCPUProfiler(hz)prof.hz hz}atomic.Store(prof.signalLock, 0)lock(sched.lock)sched.profilehz hzunlock(sched.lock)if hz ! 0 {// 设置线程维度的SIGPROF 信号定时器setThreadCPUProfiler(hz)}_g_.m.locks--
}上述是go1.17版本的setcpuprofilerate 代码如果你再去看 go1.18版本的代码会发现他们在这个方法上是一模一样的都是调用了setProcessCPUProfiler 和setThreadCPUProfilersetProcessCPUProfiler 设置进程维度的发送SIGPROF信号定时器setThreadCPUProfiler设置线程维度的发送SIGPROF信号的定时器但其实setThreadCPUProfiler 在go1.17的实现上并不完整。
// go 1.17 src/runtime/signal_unix.go:314
func setThreadCPUProfiler(hz int32) {getg().m.profilehz hz
}go1.17版本上仅仅是为协程里代表线程的m变量设置了一个profilehz(采样的频率)并没有真正实现线程维度的采样。
// go 1.18 src/runtime/os_linux.go:605
....
// setThreadCPUProfiler 方法内部 timer_create的代码段
var timerid int32var sevp sigeventsevp.notify _SIGEV_THREAD_IDsevp.signo _SIGPROFsevp.sigev_notify_thread_id int32(mp.procid)ret : timer_create(_CLOCK_THREAD_CPUTIME_ID, sevp, timerid)if ret ! 0 {return}....在go1.18版本上的setThreadCPUProfiler则真正实现了这部分逻辑由于go1.18版本它同时调用了setProcessCPUProfiler以及setThreadCPUProfiler这样在接收SIGPROF信号时就会出现重复计数的问题。
所以go1.18在处理SIGPROF信号的时候也做了去重处理所以在golang信号处理的方法sighandler 内部有这样一段逻辑。
func sighandler(sig uint32, info *siginfo, ctxt unsafe.Pointer, gp *g) {_g_ : getg()c : sigctxt{info, ctxt}if sig _SIGPROF {mp : _g_.m// Some platforms (Linux) have per-thread timers, which we use in// combination with the process-wide timer. Avoid double-counting.if validSIGPROF(mp, c) {sigprof(c.sigpc(), c.sigsp(), c.siglr(), gp, mp)}return}.....如果发现信号是_SIGPROF 那么会通过validSIGPROF 去检测此次的_SIGPROF信号是否应该被统计。validSIGPROF的检测逻辑这里就不展开了。
总结
cpu的统计原理与前面所讲的指标统计的原理稍微复杂点涉及到了linux信号处理相关的内容cpu统计的原理简而言之就是通过设置一个发送SIGPROF信号的定时器然后用户程序通过接收操作系统定时发送的SIGPROF信号来对用户程序正在执行的堆栈函数进行统计。在采样时间内同一个函数被统计的越多说明该函数占用的cpu工作时长就越长。
