Go中的块分析

永久链接本文档最后一次更新是针对go1.15.7，但在大多数情况下仍可能适用于旧/新版本。

Go中的阻止配置文件可让您分析程序等待以下阻止操作所花费的时间：

仅当Go必须通过将goroutine停在等待状态来中止执行goroutine的执行时，才会跟踪时间。因此，例如，如果可以立即或通过少量旋转来获取锁，则Mutex.Lock（）操作将不会显示在您的配置文件中。

上面的操作是Go运行时使用的等待状态的子集，即下面的操作不会显示在块配置文件中：

默认情况下，块分析器是禁用的。您可以通过传递速率＆gt;来启用它。 0如下图所示。

速率影响探查器的准确性和开销。在文档中，速率的描述如下：

SetBlockProfileRate控制在阻止配置文件中报告的goroutine阻止事件的比例。探查器的目的是平均每阻塞1纳秒的速率采样一次阻塞事件。

要将每个阻止事件包括在配置文件中，合格率=1。要完全关闭分析，合格率＆lt; = 0。

就我个人而言，我很难解析第二句话，而是更喜欢这样描述速率（aka blockprofilerate）：

比率=＆gt; 2设置采样率（以纳秒为单位）。持续时间＆gt; =速率的每个事件都将被跟踪。对于持续时间＆lt;速率，探查器将随机采样持续时间/速率事件。例如。如果您有一个持续时间为100ns的事件，并且您的速率为1000ns，则块分析器将有10％的机会对其进行跟踪。

块持续时间会在程序的整个生命周期内汇总（启用概要分析时）。要获取导致堆栈事件及其累积持续时间的当前堆栈跟踪的pprof格式快照，可以调用：

另外，为方便起见，您可以使用github.com/pkg/profile或net / http / pprof通过http公开分析，或使用连续分析器在生产中自动收集数据。

最后但并非最不重要的一点是，您可以使用runtime.BlockProfile API以结构化格式获取相同的信息。

tl； dr：块配置率＆gt; = 10000（10µs）对生产应用程序（包括遭受极端竞争的应用程序）的影响应忽略不计。

块分析基本上是在Go运行时内部实现的（有关实际代码，请参见上面的说明中的链接）：

func chansend（...）{如果blockprofilerate＆gt;则为var t0 int64； 0 {t0 = cputicks（）} // ...在阻塞状态下将goroutine停在等待状态...如果blockprofilerate＆gt; 0 {周期：= cputicks（）-如果blocksampled（周期）{saveblockevent（周期）}}}

这意味着除非启用块分析，否则由于CPU分支预测，开销应实际上为零。

启用块分析后，每个阻止操作将支付两次cputicks（）调用的开销。在amd64上，这是通过使用RDTSC指令进行优化的汇编来完成的，并且在我的计算机上的耗费约为10ns / op。在其他平台上，使用了各种替代时钟源，这些时钟源可能具有更高的开销和更低的精度。

根据配置的块轮廓速率（“精度”部分中的更多信息），块事件可能最终会被保存。这意味着收集的堆栈跟踪在我的机器上大约需要1µs（堆栈深度= 16）。然后，通过增加相应的blockRecord计数和周期，将堆栈用作更新内部哈希图的键。

更新哈希图的成本可能与收集堆栈跟踪信息相似，但是我尚未对其进行测量。

无论如何，这对于您的应用程序的开销而言意味着什么？通常，这意味着块分析的开销很低。除非您的应用程序由于争用而在字面上全部花费时间来停泊和取消goroutine，否则即使对每个块事件进行采样，您也将无法看到可测量的影响。

话虽这么说，下面的基准测试结果（请参阅方法论）应该使您对开销块分析可能具有的理论上最坏情况有所了解。图表chan（cap = 0）显示，在完全包含通过无缓冲通道发送微小消息的工作负载上，将blockprofilerate从1设置为1000会大大降低吞吐量。使用图chan（cap = 128）中的缓冲通道可以极大地减少问题，以至于对于不花所有时间在通道通信开销上的实际应用来说，这可能无关紧要。

还要有趣的是，我看不到基于互斥量的工作负载的大量开销。我认为这是由于存在争用时互斥锁在存放goroutine之前先使用了自旋锁。如果有人对在Go中表现出高非旋转互斥锁争用的工作负载有个好主意，请告诉我！

无论如何，请记住，下图显示了专门设计用来触发您可以想象的最坏的数据块分析开销的工作负载。实际的应用程序通常不会看到明显的开销，特别是在使用块配置率> == 10000（10µs）时。

块分析利用共享哈希图，即使空间为空，它也使用1.4 MiB的内存。除非您在应用程序中明确禁用堆分析，否则无论是否使用块分析器，都将分配此映射。

另外，每个唯一的堆栈跟踪都将占用一些额外的内存。 runtime.MemStats的BuckHashSys字段允许您在运行时检查此用法。将来，我可能会尝试提供有关此方面的其他信息以及现实世界的数据。

第一次调用runtime.SetBlockProfileRate（）需要100毫秒，因为它试图测量挂钟和TSC时钟之间的速度比。但是，有关异步抢占的最新更改已破坏了此代码，因此该调用现在仅需要10毫秒。

tl; dr：将采样率设置得太高会使您的结果偏向于不经常发生的长事件而不是频繁发生的短事件。

func blocksampled（循环int64）bool {如果速率＆lt; = 0 ||，则速率== int64（原子。Load64（＆amp; blockprofilerate））。 （比率＆gt;周期＆amp;＆amp; int64（fastrand（））％比率＆gt;周期）{return false} return true}

这意味着，如果将配置率设置得足够低，您将获得非常准确的结果。但是，如果您的速率高于您要采样的某些事件的持续时间，则采样过程将出现偏向，即偏向于具有较高持续时间的偶发事件而不是具有较低持续时间的频繁事件，即使它们可能对相同数量的总体阻止起作用程序的持续时间。

在这种情况下，可以保证blockprofiler在配置文件中捕获并准确报告事件A为100ns。对于事件B，最有可能的结果是，事件探查器将仅捕获单个事件（10个事件中的10％），并将B报告为事件10ns。因此，您可能会发现自己认为事件A导致的阻塞比事件B多10倍，这是不正确的。

为了获得更好的直觉，请考虑下面的模拟示例。在这里，我们从3种阻塞事件中收集了所有持续时间的直方图。如您所见，它们都具有不同的平均持续时间（1000ns，2000ns，3000ns），并且它们以不同的频率发生，且count（a）数（b）＆gt;计数（c）。更难看到的是这些事件的累积持续时间是相同的，即sum（a）= sum（b）= sum（c），但是您可以相信我：)。

因此，假设您的应用程序可能会产生这样的事件，那么当您尝试不同的blockprofilerate值时，它们将如何显示在您的区块文件中？如下所示，一切正常，直到达到1000ns的块轮廓速率为止。每个事件在配置文件中以相同的总持续时间显示（红色和绿色的点隐藏在蓝色的下面）。但是，从1000ns开始，您会看到事件a开始从我们的配置文件中消失，而在2000ns，您已经认为事件b和c造成的阻塞时间是事件a的两倍。

所以，我们能做些什么？在使用块轮廓时，是否总是需要担心偏见吗？没有！如果您的工作负载开销允许的话，最简单的解决方案是使用足够低的块概要速率来捕获大多数阻塞事件。

但是也许还有更好的方法。我认为我们可以通过在持续时间＆lt;＆lt;＆lt;率。但是，发生这种情况时，我们可以像这样简单地乘以采样持续时间：

持续时间=持续时间*（速率/持续时间）＃注意：以上表达式可以简化为“持续时间=速率”

可以使用go运行时的普通补丁来做到这一点，下面的图片显示了模拟它的结果。因此，从我的角度来看，应该有可能消除Go的未来版本中的这种偏见，并且我计划在该版本上与Go项目一起工作。

话虽这么说，我没有接受过统计学方面的培训，所以我在这里的分析可能会被误导🙃。

recording记录下来之后，可能可以减少块轮廓中的偏差。我已经对此进行了概念验证，但是尚不清楚这在实践中是否能很好地工作。

amd64和其他平台使用TSC来实现cputicks（）函数。过去，此技术一直受到频率缩放和其他类型的CPU电源转换问题的挑战。现代CPU应该提供不变的TSC，但是至少某些Go用户仍在报告问题。我无法确定原因是由于硬件损坏还是与多路插座系统有关的问题，但希望将来对此做更多的研究。

另请注意“初始化时间”部分中的错误描述，这可能会影响将cputicks转换为墙上时钟时间的准确性。

块概要文件的最大堆栈深度为32。在较深的堆栈深度处发生的块事件仍将包含在概要文件中，但是生成的数据可能更难处理。

如前所述，有争议的Go互斥锁将首先尝试旋转一下，然后屈服于调度程序。如果旋转成功，则不会跟踪任何块事件。这在块剖析器中对持续时间较长的事件提出了另一个细微的偏差。

section这部分需要做更多的研究，作为互斥量分析器注释的一部分。

阻塞时间不受挂钟时间限制。多个goroutine可以同时花费时间进行阻塞，这意味着可以查看累积的块持续时间超过程序运行时间的配置文件。

Go中的互斥锁分析功能与块分析重叠。似乎两者都可以用来理解互斥争用。使用互斥量探查器时，它将报告Unlock（）调用站点，而不是块探查器报告的Lock（）调用站点。互斥锁探查器还使用了一种更简单且可能无偏的采样机制，这应该使其更加准确。但是，互斥锁探查器不涵盖通道争用，因此块探查器更加灵活。启用互斥量和块分析器后，跟踪重复的争用事件可能会浪费一些开销。

section这部分需要做更多的研究，作为互斥量分析器注释的一部分。

块探查器目前不支持探查器标签，但似乎将来可能很容易实现。

下面是以pprof的protobuf格式编码的块配置文件的示例。有两种值类型：

$ go工具pprof -raw block.pb.gz PeriodType：争用计数周期：1时间：2021-02-08 14：53：53.243777 +0100 CETS样本：争用/计数延迟/纳秒22820 867549417：1 2 3 4 22748 453510869：1 2 5 4位置1：0x10453af M = 1运行时.selectgo /usr/local/Cellar/go/1.15.6/libexec/src/runtime/select.go:511 s = 0 2：0x10d082b M = 1 main.simulateBlockEvents / Users /felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/block-sample/main.go:71 s = 0 3：0x10d0b72 M = 1 main.eventB /Users/felix.geisendoerfer /go/src/github.com/felixge/go-profiler-notes/examples/block-sample/main.go:57 s = 0 main.run.func2 /Users/felix.geisendoerfer/go/src/github.com /felixge/go-profiler-notes/examples/block-sample/main.go:33 s = 0 4：0x10d01b8 M = 1 golang.org/x/sync/errgroup.(*Group).Go.func1 / Users / felix.geisendoerfer/go/pkg/mod/golang.org/x/[email protected]/errgroup/errgroup.go：57 s = 0 5：0x10d0b12 M = 1 main.eventA / Users / felix。 geisendoerfer / go / src / github.com / felixge / go-profile r-notes / examples / block-sample / main.go：53 s = 0 main.run.func1 /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/block- sample / main.go：30 s = 0Mappings1：0x0 / 0x0 / 0x0 [FN]

区块剖析由Dmitry Vyukov实现，并首次出现在go1.1版本（2013-05-13）中。

我在Datadog上进行Go的连续分析。你应该检查一下。我们也正在招聘：）。

该页面上的信息被认为是正确的，但不提供任何保修。欢迎反馈！