这是一个创建于 2224 天前的主题，其中的信息可能已经有所发展或是发生改变。
嗯，推断说，某个协程连续执行了大段的时间，导致服务端卡住（其他协成无法得到 CPU 时间）
现在的问题是要怎么找出这个协成，即如何获取某个携程的连续执行时间（不是测量函数执行时间，而是协程连续运行，不让渡 CPU 的持续时间）
第 1 条附言 · 2018-10-23 22:04:35 +08:00
嗯, golang tool trace 这个工具似乎有用, 需要研究下 有什么好的教程呢?
 |
1
keakon 2018-10-23 20:41:42 +08:00
协程的三种写法。。
|
 |
2
helloworld12 OP @keakon #1 ?
|
 |
3
reus 2018-10-24 08:53:37 +08:00
难道不是改代码？
死循环是会触发调度器 bug 的 |
 |
4
yufpga 2018-10-24 09:19:47 +08:00
协程调度的问题可能性不大吧，生成火焰图看一下。工具很多，可以参考： https://github.com/uber/go-torch
|
|
5
helloworld12 OP @yufpga #4 cpu 火焰图，是 cpu 累计时间吧。。。查 latency 应该不是查这个吧？
|
|
6
yufpga 2018-10-24 19:50:55 +08:00  1
@helloworld12 不知道楼主问题解决没有？我不知道楼主得到这个推断的理由是什么，我的想法是这样子的，你说服务端卡住，猜测是某个协程连续执行了大段时间，这里是两个要素，一个大段时间，二是连续执行。如果是连续执行，那么本质上是怀疑 go 的协程调度出现了一些问题， 说实话，这个结果我是不敢相信的。另一个要素是大段时间，这个可以通过火焰图看出来。我没有用过 go tool trace，没办法给出针对性意见。我不知道楼主更具体的情况，所以没有办法肯定一定是 cpu 卡，而不是 io 或是别的什么卡，我的方法可能还是利用 go tool pprof，可以着重看其中的两个指标 block 和 profile， 如果真是 cpu 的问题，profile 指标和火焰图应该能够分析出来。
|
|
7
helloworld12 OP @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 |
Select Language