ℹ️ 本文基于Go 1.13。
Go为我们提供了一个工具,可在运行时启用跟踪并获得程序执行的详细视图。 借助trace软件包,可以通过测试的标识-trace启用此工具,从pprof进行实时跟踪,或者在我们的代码中的任何地方启用此工具。 该工具功可以更强大,因为你可以使用自定义traces对其进行增强。 让我们回顾一下它的工作原理。
流程
该工具的流程非常简单。 每个事件,例如内存分配; 垃圾收集器的所有阶段; Go标准库会静态记录goroutine在运行,暂停等时的状态,并将其格式化以供以后显示。 但是,在开始录制之前,Go首先“停止了世界”,并对当前goroutine及其状态进行了快照。
这将使之后Go能够正确构建每个goroutine的生命周期。 流程如下:
然后,将收集到的事件推送到缓冲区,当达到最大容量时,该缓冲区随后将刷新到完整缓冲区列表。 这是此流程的图:
跟踪器现在需要一种将这些跟踪事件转存到输出的方法。 为此,当跟踪开始时,Go会生成专用于此的goroutine。 该goroutine将在数据可用时转存数据并在数据不可用时候停放等待。 这是它的表示:
现在流程非常清楚,让我们回顾一下记录的跟踪事件。
跟踪
生成跟踪事件后,可以通过运行命令go tool trace my-output.out来完成可视化。 让我们以一些跟踪事件为例:
其中大多数都很简单。 与垃圾收集器相关的跟踪位于蓝色GC线下:
快速回顾:
- STW是垃圾收集器中的两个“停止世界”阶段。 在这两个阶段中,goroutine会停止。
- GC(idle)是在没有工作时标记内存的goroutine。
- MARK ASSIST是在分配过程中帮助标记内存的goroutine。
- 一旦垃圾收集器完成,GXX runtime.bgsweep是内存扫描阶段。
- GXX runtime.gcBgMarkWorker是帮助标记内存的专用后台goroutine。
但是,有些跟踪不容易理解。 让我们对其进行回顾,以更好地理解它们:
- 当处理器与线程相关联时,将调用proc start。 当启动新线程或从系统调用恢复时,就会发生这种情况。
- 当线程与当前处理器解除关联时,将调用proc stop。 当线程在系统调用中被阻塞或线程退出时,会发生这种情况。
- 在goroutine进行系统调用时会调用syscall:
- 当goroutine从syscall中被取消阻塞时,显示标签(sysexit):
Go允许使用标准库自定义和可视化自己的跟踪。
自定义
我们可以定义的跟踪具有两个层次级别:
- 在任务的顶层,有开始和结束。
- 在该区域的子级别上。
这是它们的一个简单示例:
这些新追踪可以通过自定义任务直接从工具中可视化:
可以记录一些日志到任务中:
ctx, task := trace.NewTask(context.Background(), "main start") trace.Log(ctx, "category", "I/O file") trace.Log(ctx, "goroutine", "2")
这些日志将在设置任务的goroutine下找到:
通过派生父任务的上下文等,这些任务也可以嵌入其他任务中。
但是,由于pprof的缘故,跟踪生产中的所有这些事件可能会在收集它们时稍微降低性能。
性能影响
一个简单的基准可以帮助理解跟踪的影响。 一个将带有标识-trace运行,而另一个不带标识。 以下是带有ioutil.ReadFile()函数的基准测试的结果,该函数会生成很多事件:
name time/op ReadFiles-8 48.1µs ± 0% name time/op ReadFiles-8 63.5µs ± 0% // with tracing
在这种情况下,影响约为35%,并且可能会因应用程序而异。 但是,某些工具(例如StackDriver)允许在生产中进行持续配置,同时在我们的应用程序上保持少量开销。