如何 检测 golang 协成的连续执行时间？

[helloworld12]

嗯，推断说，某个协程连续执行了大段的时间，导致服务端卡住（其他协成无法得到 CPU 时间）

现在的问题是要怎么找出这个协成，即如何获取某个携程的连续执行时间（不是测量函数执行时间，而是协程连续运行，不让渡 CPU 的持续时间）

[keakon]

协程的三种写法。。

[helloworld12]

@keakon #1 ?

[reus]

难道不是改代码？
死循环是会触发调度器 bug 的

[yufpga]

协程调度的问题可能性不大吧，生成火焰图看一下。工具很多，可以参考： https://github.com/uber/go-torch

[helloworld12]

@yufpga #4 cpu 火焰图，是 cpu 累计时间吧。。。查 latency 应该不是查这个吧？

[yufpga]

@helloworld12 不知道楼主问题解决没有？我不知道楼主得到这个推断的理由是什么，我的想法是这样子的，你说服务端卡住，猜测是某个协程连续执行了大段时间，这里是两个要素，一个大段时间，二是连续执行。如果是连续执行，那么本质上是怀疑 go 的协程调度出现了一些问题， 说实话，这个结果我是不敢相信的。另一个要素是大段时间，这个可以通过火焰图看出来。我没有用过 go tool trace，没办法给出针对性意见。我不知道楼主更具体的情况，所以没有办法肯定一定是 cpu 卡，而不是 io 或是别的什么卡，我的方法可能还是利用 go tool pprof，可以着重看其中的两个指标 block 和 profile， 如果真是 cpu 的问题，profile 指标和火焰图应该能够分析出来。

[helloworld12]

@yufpga #6 嗯,谢谢, 应该是 block 问题

50 多个连接, 负载不是很大, 占了 15%~20% 的 CPU

查了下, profile,
970ms 21.85% 21.85% 970ms 21.85% runtime.futex

[futex 好像是 linux 的用户空间的快速锁]( https://zh.wikipedia.org/wiki/Futex)

应该是 cas 的模式吧...然后怀疑 futex 是 spinlock, 接着查询到 [futex 是支持 futex_wait 和 futex_wake 就是支持唤醒机制]( http://blog.sina.com.cn/s/blog_e59371cc0102v29b.html)

既然 futex 支持唤醒机制,为什么会这么耗 CPU, 在锁上耗 CPU,不是因为不断的尝试获取锁吗?

(pprof) tree
Showing nodes accounting for 3.53s, 79.50% of 4.44s total
Dropped 281 nodes (cum <= 0.02s)
Showing top 80 nodes out of 240
----------------------------------------------------------+-------------
flat flat% sum% cum cum% calls calls% + context
----------------------------------------------------------+-------------
0.41s 42.27% | runtime.futexsleep
0.31s 31.96% | runtime.systemstack
0.24s 24.74% | runtime.startm
0.01s 1.03% | runtime.unlock
0.97s 21.85% 21.85% 0.97s 21.85% | runtime.futex
----------------------------------------------------------+-------------
0.24s 55.81% | syscall.Write
0.19s 44.19% | internal/poll.(*FD).Read
0.33s 7.43% 29.28% 0.43s 9.68% | syscall.Syscall
0.09s 20.93% | runtime.reentersyscall
0.01s 2.33% | runtime.exitsyscall