前言:
碰到死锁是一个很让人糟心的事情 ! 更让人无语的事，在测试环境中压力测试了好久都是ok的, 一点毛病都没有。但一到线上的正式环境居然出现死锁了。 主要现象是 队列中的任务不再被消费了，也没有相关的日志输出。 通过我们业务stats接口是可以看到进程内的状态, 队列确实没人消费。
# 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看到调用栈的信息。
该文章后续仍在不断的更新修改中， 请移步到原文地址 http://xiaorui.cc/?p=5160
好在，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 库的使用方法。
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.
# 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工具。
