前言:
碰到死锁是一个很让人糟心的事情 ! 更让人无语的事，在测试环境中压力测试了好久都是ok的, 一点毛病都没有。但一到线上的正式环境居然出现死锁了。 主要现象是 队列中的任务不再被消费了，也没有相关的日志输出。 通过我们业务stats接口是可以看到进程内的状态, 队列确实没人消费。
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 |
# xiaorui.cc { "alert_queue": 0, "input_task_queue": 30000, // 这个 "notify_queue": 30000, // 这个 "pushing_queue": 0, "qps_boss": { "15m": 189, "1m": 2053, "5m": 541, "avg": 4112, "count": 226029 }, "qps_proxy": { "15m": 1, "1m": 22, "5m": 5, "avg": 34, "count": 1919 }, "reporting_queue": 30000, "saver_queue": 0, "timer_heap_len": 30854, .... .... } |
我们知道golang是pmg模型，可能出现goroutine在不同的线程上浮动。 这样很难通过传统的pstack和strace分析出问题。 在其他语言里，你可以使用strace追踪关于mutex锁的调用，或者用pstack看到调用栈的信息。
好在，golang runtime工具集里其实提供了打印所有 goroutine调用栈的工具，但是直接用官方的方法略显麻烦。 我这边简单把golang输出打印goroutine stack的工具封装了一个模块，我们通过外部的kill信号来控制stack的文件输出。
代码已经扔到github里了，没几行代码，只是更加简单易用而已。 https://github.com/rfyiamcool/stack_dump
分析解决问题
通过下面的stack输出，我们看到有在等待拿锁，但是居然等了4分钟，那么这必然是死锁的逻辑了。 进而继续分析，下面这两个不同的模块都等了4分钟的锁，那么冲突的逻辑肯定是他们了。 通过代码显示死锁的原因是出现了 锁的重用，也就说，拿到了锁，但又去拿锁， golang的sync.mutex是不可重入的，所以死锁了 !
解决方法？ 别重入加锁，要么就直接加大锁的粒度。
dump_stack库的使用方法
其实这次主要是给大家分享下 如何通过golang goroutine stack来分析各种问题，不单单是死锁问题，大家可以举一反三来解决更多的bug，比如想知道当前协程在做什么? 这里简单说下 github.com/rfyiamcool/dump_stack 库的使用方法。
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 |
package main //xiaorui.cc import ( "time" "github.com/rfyiamcool/dump_stack" ) func main() { dumpStack.SetupStackTrap() // dumpStack.SetupStackTrap("stack.log") time.Sleep(100 * time.Second) } |
然后我们给该进程发送 -USR1 信号，这样就可以拿到所有协程的函数调用栈. 我们也可以使用awk来统计分析当前stack的调用top.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 |
# xiaorui.cc awk -F '[' '/goroutine \d*/{print "[" $2}' stack.log | sort | uniq -c | sort -k1nr | head -20 5030 [select]: 1910 [semacquire]: 952 [IO wait]: 198 [chan send]: 11 [sleep]: 3 [runnable]: 2 [chan receive, 6 minutes]: 2 [select, 6 minutes]: 1 [chan receive]: 1 [IO wait, 1 minutes]: 1 [running]: 1 [select, 6 minutes, locked to thread]: 1 [syscall]: |
总结:
死锁是个让人郁闷问题，好在及时解决，发现问题到解决上线不到一个小时…. 多亏了golang内置了这么多的优秀debug工具。
有疑问加站长微信联系（非本文作者）
