允许trace方法_Go: Trace包探秘

本文基于Go 1.13。

Go为我们提供了一个工具，可在运行时启用跟踪并获得程序执行的详细视图。借助trace软件包，可以通过测试的标识-trace启用此工具，从pprof进行实时跟踪，或者在我们的代码中的任何地方启用此工具。该工具功可以更强大，因为你可以使用自定义traces对其进行增强。让我们回顾一下它的工作原理。

流程

该工具的流程非常简单。每个事件，例如内存分配；垃圾收集器的所有阶段；Go标准库会静态记录goroutine在运行，暂停等时的状态，并将其格式化以供以后显示。但是，在开始录制之前，Go首先“停止了世界”，并对当前goroutine及其状态进行了快照。

这将使之后Go能够正确构建每个goroutine的生命周期。流程如下：

跟踪之前的初始化阶段

然后，将收集到的事件推送到缓冲区，当达到最大容量时，该缓冲区随后将刷新到完整缓冲区列表。这是此流程的图：

每个P的的跟踪事件收集

跟踪器现在需要一种将这些跟踪事件转存到输出的方法。为此，当跟踪开始时，Go会生成专用于此的goroutine。该goroutine将在数据可用时转存数据并在数据不可用时候停放等待。这是它的表示：

专用goroutine读取并转存跟踪事件

现在流程非常清楚，让我们回顾一下记录的跟踪事件。

跟踪

生成跟踪事件后，可以通过运行命令

go tool trace my-output.out

来完成可视化。让我们以一些跟踪事件为例：

使用go tool 跟踪

其中大多数都很简单。与垃圾收集器相关的跟踪位于蓝色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允许使用标准库自定义和可视化自己的跟踪。

自定义

我们可以定义的跟踪具有两个层次级别：

• 在任务的顶层，有开始和结束。
• 在该区域的子级别上。

这是它们的一个简单示例：

func main() {
  ctx, task := trace.NewTask(context.Background(), "main start")

  var wg sync.WaitGroup
  wg.Add(2)

  go func() {
    defer wg.Done()
    r := trace.StartRegion(ctx, "reading file")
    defer r.End()

    ioutil.ReadFile(`n1.txt`)
  }()

  go func() {
    defer wg.Done()
    r := trace.StartRegion(ctx, "writing file")
    defer r.End()

    ioutil.WriteFile(`n2.txt`, []byte(`42`), 0644)
  }()

  wg.Wait()

  defer task.End()
}

这些新追踪可以通过自定义任务直接从工具中可视化：

自定义任务和区域

可以记录一些日志到任务中：

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）允许在生产中进行持续配置，同时在我们的应用程序上保持少量开销。

本文编译自 Go: Discovery of the Trace Package https:// medium.com/a-journey-wi th-go/go-discovery-of-the-trace-package-e5a821743c3c