理解GoLang特征分析输出
一些背景：
我试图调试一个GoGRPC服务器，一个特定的API调用似乎需要很长时间。这个电话给卡夫卡读了很多书(比方说10-20)，所以我希望它需要一些时间，只是没有那么多。
一个API调用大约需要1-3秒才能完成，但是如果我在一个脚本中调用40个api，则几乎需要30秒才能完成所有调用。但它并没有像我所期望的那样“同时”完成，第一次要花5秒，以后的每秒钟要吐出1秒钟左右。
它需要29秒，并同时对所有40项请求作出响应。这会导致API调用方在请求花费太长时间时超时。
我试图分析CPU，看看我花在哪里的时间。但我对此并不熟悉，go分析器的输出也没有什么意义。
我用go tool pprof生成了图表，但在解释输出时遇到了一些问题。
CPU调用图
- 在这个框中有一个描述时间、类型、buildID等
Duration的框，它描述的是CPU运行的总时间吗？不包括wiat时间 - 有两种类型的边缘，实体线，和虚线。有什么关系？边缘标记的时间意味着什么？
- 箭头的方向是否意味着调用方向？例如，函数A调用B，在图上它将是A -> B？
- 每个顶点在底部有一个时间，例如0.49s中的0.01s(0.93%) (45.79%)，这一次意味着什么？
块剖面
- 和上面的第4条一样，边和顶点都有时间。这是什么意思？
编辑：
我的服务器所做的就是从kafka流中检索一些数据。我已经确定了什么是缓慢的，我已经写了一个脚本，只有卡夫卡调用功能。这是脚本和块剖析图。
每一次对kafka的消耗大约需要50-100毫秒，但是由于大部分时间都花在做IO上，所以我预计API的吞吐量实际上是相当高的，但事实并非如此。如果我打100个电话，大约需要3秒，如果我打400个电话，大约需要10秒。试图了解如何加快API的吞吐量。
func main() {
f, _ := os.Create("cpu.prof")
pprof.StartCPUProfile(f)
defer pprof.StopCPUProfile()
block, _ := os.Create("block.prof")
runtime.SetBlockProfileRate(1)
p := pprof.Lookup("block")
defer p.WriteTo(block, 0)
var wg sync.WaitGroup
wg.Add(messageCount)
for i := 0; i < messageCount; i++ {
go func() {
// consume()
withConsumer()
wg.Done()
}()
}
wg.Wait()
}
var servers = []string{"kafka-1", "kafka-2", "kafka-3"}
var count = 0
var partition = int32(0)
func consume() {
index := count
t := time.Now()
count++
fmt.Println("starting consume", index)
defer func() {
fmt.Println("consume ", index, "took", time.Since(t).String())
}()
consumer, err := sarama.NewConsumer(servers, nil)
if err != nil {
panic(err)
}
var max, min int64
max = 1431401
min = 2
defer func() {
consumer.Close()
}()
pc, err := consumer.ConsumePartition("source-topic", partition, rand.Int63n(max-min)+min)
if err != nil {
panic(err)
}
defer func() {
pc.Close()
}()
signals := make(chan os.Signal, 1)
signal.Notify(signals, os.Interrupt)
select {
case msg := <-pc.Messages():
fmt.Println("msg: ", len(msg.Value))
case <-signals:
return
}
}
谢谢,
回答 1
Stack Overflow用户
发布于 2021-06-09 22:34:19
- 在这个框中有一个描述时间、类型、buildID等时间的框，它描述的是CPU运行的总时间吗？不包括wiat时间
对，是这样。https://golang.org/doc/diagnostics#profiling说：
cpu: CPU配置文件确定程序在使用CPU周期时(而不是在睡觉或等待I/O时)的时间花费在哪里。
- 有两种类型的边缘，实体线，和虚线。有什么关系？边缘标记的时间意味着什么？
https://github.com/google/pprof/issues/493说：“虚线/虚线表示中间的节点已被移除，节点被移除以使图形保持足够小以便于可视化。”
https://gperftools.github.io/gperftools/cpuprofile.html说：“每个边缘都被标记为被调用者代表调用者花费的时间。”
- 箭头的方向是否意味着调用方向？例如，函数A调用B，在图上它将是A -> B？
是。
- 每个顶点在底部有一个时间，例如0.49s中的0.01s(0.93%) (45.79%)，这一次意味着什么？
第一次是当地时间。第二次是累积时间。https://gperftools.github.io/gperftools/cpuprofile.html阐述：
“本地”时间是指用于执行过程中直接包含的指令的时间(以及嵌入到过程中的任何其他过程)。“累积”时间是“本地”时间和在任何呼叫中花费的时间的总和。如果累积时间与本地时间相同，则不打印。
https://stackoverflow.com/questions/48875654
复制相似问题
腾讯云开发者
