爱上开源之golang入门至实战第三章goroutine分析

爱上开源之golang入门至实战第三章goroutine分析

爱上开源之golang入门至实战第三章 - goroutine分析

Goroutine

Pprof中的Goroutine是对当前时间点的goroutine(协程)数据的采样，我们经常使用pprof对可能发送goroutine(协程)泄漏的可能点进行分析；goroutine(协程)泄漏是goroutine启动之后没有退出导致goroutine的数量不会减少，或者是在实际应用中goroutine占用了很长时间才退出导致在一段时间内goroutine的数量急剧上升； 虽然goroutine(协程)相对于线程的开销来说更加的轻量级，但是对于一个高并发的对性能要求比较高的系统，一样会由于协程的持续无谓的开销而导致整体性能的降低；甚至更严重的由于协程不断的增加，最后由于资源不够充足而无法进行分配，导致整个系统宕机。

我们还是先一起来看看；pprof提供出来的goroutine是怎样的采样数据； 如下图所示：

如果了解以上的采样数据和数据格式表示的什么信息； 我们可以查看​​runtime/pprof/pprof.go​​的源代码

​​runtime/pprof/pprof.go​​源代码Line 709是Goroutine的pprof采样数据的输出入口

func writeRuntimeProfile(w io.Writer, debug int, name string, fetch func([]runtime.StackRecord, []unsafe.Pointer) (int, bool)) error { // Find out how many records there are (fetch(nil)), // allocate that many records, and get the data. // There's a race—more records might be added between // the two calls—so allocate a few extra records for safety // and also try again if we're very unlucky. // The loop should only execute one iteration in the common case. var p []runtime.StackRecord var labels []unsafe.Pointer n, ok := fetch(nil, nil) for { // Allocate room for a slightly bigger profile, // in case a few more entries have been added // since the call to ThreadProfile. p = make([]runtime.StackRecord, n+10) labels = make([]unsafe.Pointer, n+10) n, ok = fetch(p, labels) if ok { p = p[0:n] break } // Profile grew; try again. } return printCountProfile(w, debug, name, &runtimeProfile{p, labels})}

在​​printCountProfile​​函数Line 435 可以找到goroutine的具体输出内容； 入口函数如下

if debug > 0 { // Print debug profile in legacy format tw := tabwriter.NewWriter(w, 1, 8, 1, '\t', 0) fmt.Fprintf(tw, "%s profile: total %d\n", name, p.Len()) for _, k := range keys { fmt.Fprintf(tw, "%d %s\n", count[k], k) printStackRecord(tw, p.Stack(index[k]), false) } return tw.Flush() }

​​技巧​​

选择一个好的IDE对于语言的学习非常的有作用；golang的IDE，笔者首选intellij公司出品的Idea；Idea功能强大；体验感非常的强；用idea来研究golang的源代码非常的高效

下图为Idea里的源代码片段

​​技巧​​

下面来看看goroutine pprof中使用

goroutine: Stack traces of all current goroutines

所以首先要明确的就是； goroutine pprof是程序栈里当前的所有协程； 这里强调的当前的；即这个也是一个快照量；反映的是当前采集时间点上的协程状况

Goroutine的手工埋点

在很多的文档和网上资料里， 往往只介绍了如何通过net/Profiling和Heap的埋点方式，其他的埋点方式网上和文档都没有介绍，在pprof包里可以export的方法也只有​​StartCPUProfile​​​和​​WriteHeapProfile​​两个，其他都没有提供export的方法，笔者通过pprof的源代码找到了其他的埋点方法，goroutine的埋点方法如下：

routineProfile := pprof.Lookup("goroutine") if err := routineProfile.WriteTo(f2, 0); err != nil { panic("could not start goroutine-1 profile: ") }

通过在这段代码，就可以把当前程序栈中的协程采样数据记录到指定的文件里；然后通过​​go tool pprof goroutine-prof-1​​ 命令；就可以进行goroutine的pprof分析了。

下面通过一个实例，来演示一下goroutine pprof分析； 演示程序在主协程里启动多个协程，协程在收到指定的通道信号后，退出协程；没有收到通道的退出信号前；协程处于阻塞状态；然后在主协程里，进行goroutine采样； 采样结束后；往指定的通道发送退出信号；子协程全部退出后，在主协程再次进行goroutine采样；

代码如下

func TestGoroutinePprof(t *testing.T) { var profileEnd = "goroutine-prof-1" // 指定保存的文件路径，当前目录的goroutine-prof-1文件 var profileEnd2 = "goroutine-prof-2" // 指定保存的文件路径，当前目录的goroutine-prof-2文件 f2, err := os.Create(profileEnd) if err != nil { panic(err) } defer f2.Close() f3, err := os.Create(profileEnd2) if err != nil { panic(err) } defer f3.Close() var goroutine = 100 var wg sync.WaitGroup wg.Add(goroutine) var exit = make(chan bool) for idx := 1; idx <= goroutine; idx++ { func(i int) { go func() { <-exit fmt.Printf("No %d exit\n", i) wg.Done() }() }(idx) } time.Sleep(500 * time.Millisecond) //var profileEnd3 = "heap-prof-3" // 指定保存的文件路径，当前目录的test-prof文件 routineProfile := pprof.Lookup("goroutine") if err := routineProfile.WriteTo(f2, 0); err != nil { panic("could not start goroutine-1 profile: ") } close(exit) wg.Wait() if err := routineProfile.WriteTo(f3, 0); err != nil { panic("could not start goroutine-2 profile: ") } fmt.Printf("sum=%d\n", goroutine)}

​​技巧​​

golang具有多并发编程的良好基因， 通过上面的go func(){}的方式，就可以非常方便的启动一个比线程轻量很多的routine； 同时通过chan的实现； 进行不同routine里的消息通信；通过WaitGroup的方式实现主子协程同步的操作

执行上面的代码，产生​​goroutine-prof-1​​​和​​goroutine-prof-2​​​两个goroutine的采样数据； ​​goroutine-prof-1​​​对应的是启动了所欲的子协程以后的goroutine的采样数据，​​goroutine-prof-2​​对应的是所有子协程收到退出信号后；子协程全部都确保退出后以后的goroutine采样数据。

通过pprof对采样数据进行分析

PS E:\WORK\PROJECT\git\go\go-in-practice\code\charpter-01> go tool pprof goroutine-prof-1warning: GOPATH set to GOROOT (E:\WORK\SOFT\go1.18.windows-amd64\go) has no effectType: goroutine Time: Jul 6, 2022 at 8:43am (CST)Entering interactive mode (type "help" for commands, "o" for options)

执行Top命令

(pprof) top Showing nodes accounting for 102, 100% of 102 total Showing top 10 nodes out of 16 flat flat% sum% cum cum% 101 99.02% 99.02% 101 99.02% runtime.gopark 1 0.98% 100% 1 0.98% runtime/pprof.runtime_goroutineProfileWithLabels 0 0% 100% 1 0.98% go-in-practice/code/charpter-01.TestGoroutinePprof 0 0% 100% 100 98.04% go-in-practice/code/charpter-01.TestGoroutinePprof.func1.1 0 0% 100% 1 0.98% main.main 0 0% 100% 101 99.02% runtime.chanrecv 0 0% 100% 101 99.02% runtime.chanrecv1 0 0% 100% 1 0.98% runtime.main 0 0% 100% 1 0.98% runtime/pprof.(*Profile).WriteTo 0 0% 100% 1 0.98% runtime/pprof.writeGoroutine

​​Showing nodes accounting for 102, 100% of 102 total​​

此时共有102个协程

其中

101 99.02% 99.02% 101 99.02% runtime.gopark 1 0.98% 100% 1 0.98% runtime/pprof.runtime_goroutineProfileWithLabels

查看第一行的101个协程的具体调用栈信息

(pprof) traces goparkType: goroutine Time: Jul 6, 2022 at 8:43am (CST) -----------+------------------------------------------------------- 100 runtime.gopark runtime.chanrecv runtime.chanrecv1 go-in-practice/code/charpter-01.TestGoroutinePprof.func1.1-----------+------------------------------------------------------- 1 runtime.gopark runtime.chanrecv runtime.chanrecv1 testing.(*T).Run testing.runTests.func1 testing.tRunner testing.runTests testing.(*M).Run main.main runtime.main-----------+-------------------------------------------------------

通过这里大致可以看到101分为两个部分 100 来着于​​charpter-01.TestGoroutinePprof.func1.1​​​ 和 1来自于 ​​runtime.main​​主协程(本演示案例使用go test进行运行的，所有主协程即为testing.(*M).Run)

具体查看100个协程的相关源头

(pprof) list func1.1Total: 102ROUTINE ======================== go-in-practice/code/charpter-01.TestGoroutinePprof.func1.1 in E:\WORK\PROJECT\git\go\go-in-practice\code\charpter-01\lesson02_test.go 0 100 (flat, cum) 98.04% of Total . . 232: var exit = make(chan bool) . . 233: . . 234: for idx := 1; idx <= goroutine; idx++ { . . 235: func(i int) { . . 236: go func() { . 100 237: <-exit . . 238: wg.Done() . . 239: fmt.Printf("No %d exit\n", i) . . 240: }() . . 241: }(idx) . . 242: }

在第一个分析段落里，我们共看到了102个协程，以上由我们的测试代码已经找到了101个协程的来历； 还有一个在哪里呢？

继续分析；找到第一个分析段落里的1个协程的

1 0.98% 100% 1 0.98% runtime/pprof.runtime_goroutineProfileWithLabels

在pprof交互命令行里执行​​traces runtime_goroutineProfileWithLabels​​

(pprof) traces runtime_goroutineProfileWithLabelsType: goroutineTime: Jul 6, 2022 at 8:43am (CST)-----------+------------------------------------------------------- 1 runtime/pprof.runtime_goroutineProfileWithLabels runtime/pprof.writeRuntimeProfile runtime/pprof.writeGoroutine runtime/pprof.(*Profile).WriteTo go-in-practice/code/charpter-01.TestGoroutinePprof testing.tRunner-----------+-------------------------------------------------------

通过这里可以看到，是在我们执行routine采样的代码，产生了一个新的协程

在pprof交互命令行里执行​​list runtime_goroutineProfileWithLabels​​查看源码调用

(pprof) list runtime_goroutineProfileWithLabels Total: 102ROUTINE ======================== runtime/pprof.runtime_goroutineProfileWithLabels in E:\WORK\SOFT\go1.18.windows-amd64\go\src\runtime\mprof.go 1 1 (flat, cum) 0.98% of Total . . 748: return . . 749:} . . 750: . . 751://go:linkname runtime_goroutineProfileWithLabels runtime/pprof.runtime_goroutineProfileWithLabels . . 752:func runtime_goroutineProfileWithLabels(p []StackRecord, labels []unsafe.Pointer) (n int, ok bool) { 1 1 753: return goroutineProfileWithLabels(p, labels) . . 754:} . . 755: . . 756:// labels may be nil. If labels is non-nil, it must have the same length as p. . . 757:func goroutineProfileWithLabels(p []StackRecord, labels []unsafe.Pointer) (n int, ok bool) { . . 758: if labels != nil && len(labels) != len(p) {

在这里启动了新的协程；

以上是对第一个采样点的分析；第一个分析点，是在退出信号没有发出的时候，进行采样的，我们创建的100个协程都没有退出； 下面来看看第二个分析点，第二个分析点，是在主协程已经给所有的子协程发出退出信号后，并且等待并确保所有100子协程都全部退出后，在主协程里进行goroutine采样；

通过pprof对第二个采样数据进行分析

PS E:\WORK\PROJECT\git\go\go-in-practice\code\charpter-01> go tool pprof goroutine-prof-2warning: GOPATH set to GOROOT (E:\WORK\SOFT\go1.18.windows-amd64\go) has no effectType: goroutine Time: Jul 6, 2022 at 8:43am (CST)Entering interactive mode (type "help" for commands, "o" for options)

执行Top命令

(pprof) top Showing nodes accounting for 2, 100% of 2 total Showing top 10 nodes out of 15 flat flat% sum% cum cum% 1 50.00% 50.00% 1 50.00% runtime.gopark 1 50.00% 100% 1 50.00% runtime/pprof.runtime_goroutineProfileWithLabels 0 0% 100% 1 50.00% go-in-practice/code/charpter-01.TestGoroutinePprof 0 0% 100% 1 50.00% main.main 0 0% 100% 1 50.00% runtime.chanrecv 0 0% 100% 1 50.00% runtime.chanrecv1 0 0% 100% 1 50.00% runtime.main 0 0% 100% 1 50.00% runtime/pprof.(*Profile).WriteTo 0 0% 100% 1 50.00% runtime/pprof.writeGoroutine 0 0% 100% 1 50.00% runtime/pprof.writeRuntimeProfile

​​Showing nodes accounting for 2, 100% of 2 total​​

此时共有2个协程

其中

1 50.00% 50.00% 1 50.00% runtime.gopark 1 50.00% 100% 1 50.00% runtime/pprof.runtime_goroutineProfileWithLabels

按照第一轮的分析方法；我们可以看到一个是主协程，一个是采样数据的新启动的协程

使用图形化web命令进行分析

在pprof的交互模式里输入web命令

下图为第一次采样点对应的图形化

下图为第二次采样点对应的图形化

图形化的结果很直观，和trace的结果是一致的； 在无法安装图形化的情况下；可以通过traces来查看类似图形调用树的结果

使用traces命令查看采样数据

(pprof) traces goparkType: goroutineTime: Jul 6, 2022 at 10:35am (CST)-----------+------------------------------------------------------- 1 runtime.gopark runtime.chanrecv runtime.chanrecv1 testing.(*T).Run testing.runTests.func1 testing.tRunner testing.runTests testing.(*M).Run main.main runtime.main-----------+-------------------------------------------------------

通过pprof我们进行goroutine的分析；本文中的例子；仅仅是笔者用来演示分析过程只用， 在项目过程中，都是通过压力测试的场景下，查看goroutine的资源情况，然后采样，在进行分析数据； 用以上的分析过程，同样的适用于这样的场景。

版权声明：本文内容由网络用户投稿，版权归原作者所有，本站不拥有其著作权，亦不承担相应法律责任。如果您发现本站中有涉嫌抄袭或描述失实的内容，请联系我们jiasou666@gmail.com 处理，核实后本网站将在24小时内删除侵权内容。