无法让 golang pprof 正常工作

Question

我曾尝试对一些Golang应用程序进行性能分析，但无法使其正常工作。我已经按照以下两个教程进行了操作：

• http://blog.golang.org/profiling-go-programs
• http://saml.rilspace.org/profiling-and-creating-call-graphs-for-go-programs-with-go-tool-pprof

两个说法都表示在添加一些代码行到应用程序后，你必须执行你的应用程序，我做到了并且屏幕上显示了以下消息：

2015/06/16 12:04:00 profile: cpu profiling enabled, /var/folders/kg/4fxym1sn0bx02zl_2sdbmrhr9wjvqt/T/profile680799962/cpu.pprof

所以，我理解正在执行分析，将信息发送到文件中。

但是，当我查看任何测试程序中的文件大小时，它总是64字节。

当我尝试使用pprof打开cpu.pprof文件并执行“top10”命令时，我发现文件中没有东西：

（“./fact”是我的应用程序）

go tool pprof ./fact /var/folders/kg/4fxym1sn0bx02zl_2sdbmrhr9wjvqt/T/profile680799962/cpu.pprof top10 --> (pprof) top10 0 of 0 total ( 0%) flat flat% sum% cum cum%

所以，当我在进行性能分析时，似乎什么都没有发生。

我已经在Mac（这个例子）和Ubuntu上测试过了，使用了三个不同的程序。

您知道我做错了什么吗？

这个示例程序非常简单，这是代码（一个非常简单的阶乘程序，我从互联网上找到的）：

import "fmt"
import "github.com/davecheney/profile"

func fact(n int) int {
      if n == 0 {
        return 1
      }
      return n * fact(n-1)
}

func main() {
      defer profile.Start(profile.CPUProfile).Stop()
      fmt.Println(fact(30))
}

谢谢，Fer

- Fersca

---

首先，您使用的是哪个操作系统？其次，“pprof”是一种“采样分析器”，而您没有执行任何可以进行采样的操作。您的应用程序需要持续执行一些可感知时间的指令，以累积足够的样本（在使用net/http/pprof时，默认的采样时间为30秒）。 - JimB

我正在使用OSX 10.10.2（Yosemite）进行工作。我现在正在尝试让配置文件长时间运行，并且现在我发现文件有更多信息:) 谢谢！ - Fersca

你还需要阅读这个链接：http://godoc.org/rsc.io/pprof_mac_fix - JimB

官方文档可能会有帮助：https://pkg.go.dev/runtime/pprof - guettli

Answer 1

正如inf已经提到的，您的代码执行得太快了。原因是pprof通过在程序执行期间反复停止您的程序，查看那个时刻正在运行的函数并将其记录下来(以及整个函数调用堆栈)。Pprof每秒采样100次。这在runtime/pprof/pprof.go中是硬编码的，您可以轻松地检查(请参见https://golang.org/src/runtime/pprof/pprof.go第575行及其上面的注释):

func StartCPUProfile(w io.Writer) error {
// The runtime routines allow a variable profiling rate,
// but in practice operating systems cannot trigger signals
// at more than about 500 Hz, and our processing of the
// signal is not cheap (mostly getting the stack trace).
// 100 Hz is a reasonable choice: it is frequent enough to
// produce useful data, rare enough not to bog down the
// system, and a nice round number to make it easy to
// convert sample counts to seconds.  Instead of requiring
// each client to specify the frequency, we hard code it.
const hz = 100

// Avoid queueing behind StopCPUProfile.
// Could use TryLock instead if we had it.
if cpu.profiling {
    return fmt.Errorf("cpu profiling already in use")
}

cpu.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 = true
runtime.SetCPUProfileRate(hz)
go profileWriter(w)
return nil

}

程序运行时间越长，可以生成的样本越多，也越有可能对短时间运行的函数进行采样。如果程序在第一次采样之前就结束了，则生成的cpu.pprof文件将为空。

从上面的代码中可以看出，采样率是通过设置来确定的

runtime.SetCPUProfileRate(..)

如果在调用StartCPUProfile()之前使用另一个值调用runtime.SetCPUProfileRate()，则可以覆盖采样率。在程序执行期间，您将收到警告消息“runtime: cannot set cpu profile rate until previous profile has finished.”，但您可以忽略它。这是因为pprof.go再次调用SetCPUProfileRate()。由于您已经设置了该值，因此pprof中的值将被忽略。

此外，Dave Cheney发布了他的新版本性能分析工具，您可以在此处找到它：https://github.com/pkg/profile。在那里，您可以指定写入cpu.pprof的路径，还有其他更改。

defer profile.Start(profile.CPUProfile, profile.ProfilePath(".")).Stop()

你可以在这里阅读相关内容：http://dave.cheney.net/2014/10/22/simple-profiling-package-moved-updated 顺便提一下，即使您将int64作为参数和返回值，您的fact()函数也会很快溢出。30!大约是2*10^32，而int64仅存储值高达2^63-1，大约为9*10^18。

- alex

Answer 2

问题在于你的函数运行速度过快，导致pprof无法对其进行采样。尝试在fact调用周围添加一个循环，并将结果相加以人为地延长程序时间。

- Stephan Dollberg

---

谢谢，我会尝试并告诉你结果!! :) - Fersca

我现在明白了，在添加了一个for{;;}和一个sleep之后，文件有更多的信息。谢谢 :) - Fersca

Answer 3

我曾经苦于空的pprof文件，直到我意识到我遵循了过时的博客文章。

上游文档很好：https://pkg.go.dev/runtime/pprof

编写一个你想要分析的测试，然后：

go test -cpuprofile cpu.prof -memprofile mem.prof -bench .

这将创建 cpu.prof 和 mem.prof。

您可以按照以下方式进行分析：

go tool pprof cpu.prof

这将为您提供一个命令行界面。 "top"和"web"命令经常被使用。

内存也是一样：

go tool pprof mem.prof

- guettli