用线程转储找出停顿原因
目标
亲手制造“堆还有剩余,服务却停了”,并通过线程转储找出原因——持有锁的线程、排队的线程、死锁,以及通过 tryLock 超时实现的恢复。
为什么重要
进程和端口都还活着、却没有响应时,堆曲线什么都不会告诉你。只有线程转储才能显示“谁在等什么”。重启会让证据消失,所以在卡住的那一刻获取转储的动作要排在前面。材料 Stuck.java 是一个在 127.0.0.1:8085 上以 4 个处理线程(worker-N)运行的 HTTP 服务——/health 不碰数据库,/ 会获取数据库锁并工作 5ms,/poison 则握着锁永远睡下去。如果指定 -Ddb.lock.timeout.ms=<ms>,就会用 ReentrantLock.tryLock 取代 synchronized,在该时间内没能拿到锁就返回 503。
步骤
- 在
/root/jvm/threads中编译 Stuck.java,用nohup java -cp /root/jvm/threads Stuck > /root/jvm/threads/server.log 2>&1 &启动,然后把 pid 写入/root/jvm/threads/server.pid。curl -s http://127.0.0.1:8085/health必须返回 ok。 - 用
jcmd -l > /root/jvm/threads/jcmd.txt留下 JVM 列表。其中 Stuck 必须以 server.pid 中的 pid 显示出来。 - 用
jcmd <pid> Thread.print > /root/jvm/threads/dump-idle.txt留下正常状态的转储。其中必须有Full thread dump和"worker-1"。 - 制造事件:先用
curl -s -m 20 http://127.0.0.1:8085/poison &让它永远持有锁,再用curl -s -m 20 http://127.0.0.1:8085/ &另外发送三次(全部放在后台)。2 秒之后执行jcmd <pid> Thread.print > /root/jvm/threads/dump-stuck.txt。转储中必须有至少 3 行waiting to lock,并有BLOCKED,而且/health也不再响应。 - 在 dump-stuck.txt 中,读出持有
- locked <주소> (a Stuck$Db)(占位符为地址)的线程名称,以及对同一个地址执行waiting to lock的线程数,把它们以holder=<스레드이름>(占位符为线程名称)和blocked=<n>两行写入/root/jvm/threads/diagnosis.txt。评分器会与正在运行的进程的转储进行核对。 - 编译
Deadlock.java,用java -cp /root/jvm/threads Deadlock > /root/jvm/threads/deadlock.log 2>&1 &启动(保持运行不要动),1 秒之后执行jcmd <pid> Thread.print > /root/jvm/threads/dump-deadlock.txt。其中必须有Found 1 deadlock.。 - 恢复:kill 掉 server.pid 对应的进程,加上
-Ddb.lock.timeout.ms=500重新启动,并更新 server.pid。再次在后台发送/poison,然后把curl -s -m 5 -o /dev/null -w '%{http_code}' http://127.0.0.1:8085/的结果保存到/root/jvm/threads/after.txt——现在必须在 5 秒内返回 503。 - 在服务保持运行的状态下,以 2 秒为间隔留下
/root/jvm/threads/dumps/dump-1.txt、dump-2.txt、dump-3.txt。三个文件的时刻行(pid 行之后的第二行)必须互不相同。
参考
- 查找锁地址:
grep -n 'locked <.*Stuck\$Db' dump-stuck.txt和grep -c 'waiting to lock <주소>' dump-stuck.txt(占位符为地址)。线程名称是该行上方离它最近的、以"..."开头的那一行。 - 在同一个端口上启动两次,第二次会因绑定失败而退出。请在第 7 步先 kill。
- 常见错误:只获取一份转储;只统计排队线程的数量,却没有去找持有锁的线程。
启动服务并留下 pid
在 /root/jvm/threads 中编译 Stuck.java,用 nohup 启动后,把 pid 写入 /root/jvm/threads/server.pid。/health 返回 ok。
在 nohup java -cp /root/jvm/threads Stuck > server.log 2>&1 & 之后执行 echo $! > server.pid。如果像 cd … && nohup … & 这样用 && 连在一起,$! 就会变成子 shell 的 pid,所以 cd 要单独执行。启动大约需要 1 秒,所以 curl 之前请稍等片刻。
JVM 列表
用 jcmd -l > /root/jvm/threads/jcmd.txt 留下输出。其中 Stuck 必须以 server.pid 中的 pid 显示出来。
jcmd -l 只会显示以相同用户启动的 JVM。每行是一个 pid 加主类。
正常状态的转储
用 jcmd Thread.print > /root/jvm/threads/dump-idle.txt 留下输出。其中必须有 Full thread dump 和 "worker-1"。
pid 可以用 $(cat /root/jvm/threads/server.pid) 取出来用。必须先留下正常的转储,才能与事件转储做比较。
制造事件并获取转储
在后台发送 /poison,再在后台另外发送三次 /,2 秒之后执行 jcmd Thread.print > /root/jvm/threads/dump-stuck.txt。转储中必须有至少 3 行 waiting to lock,并有 BLOCKED。
先执行 curl -s -m 20 http://127.0.0.1:8085/poison &,再执行三次 curl -s -m 20 http://127.0.0.1:8085/ &。4 个处理线程全部排到锁前面之后,/health 也不会响应——这就是事件。
持有锁的线程与排队的线程
在 dump-stuck.txt 中,读出持有 locked <地址> (a Stuck$Db) 的线程名称,以及对同一个地址执行 waiting to lock 的线程数,以 holder=<名称> 和 blocked= 的形式写入 /root/jvm/threads/diagnosis.txt。
记下 locked 行的地址(<0x...>),那一行上方离它最近的、以双引号开头的行就是线程名称。blocked 是相同地址的 waiting to lock 行的数量。
死锁由 JVM 直接点名
编译 Deadlock.java 并在后台启动(保持运行不要动),然后执行 jcmd Thread.print > /root/jvm/threads/dump-deadlock.txt。其中必须有 Found 1 deadlock.。
java -cp /root/jvm/threads Deadlock > deadlock.log 2>&1 & 之后,pid 就是 $!。两个线程互相等待对方的锁,所以程序不会结束——在评分结束之前不要动它。
把无限等待变成 503
kill 掉 server.pid 对应的进程,加上 -Ddb.lock.timeout.ms=500 重新启动,并更新 server.pid。在后台发送 /poison 之后,把 curl -s -m 5 -o /dev/null -w '%{http_code}' http://127.0.0.1:8085/ 的结果保存到 /root/jvm/threads/after.txt(503)。
系统属性要放在类名之前:java -Ddb.lock.timeout.ms=500 -cp ... Stuck。tryLock 如果 500ms 内没能拿到锁就返回 503,所以服务只是变慢,不会停住。
转储要三份
在服务保持运行的状态下,以 2 秒为间隔留下 /root/jvm/threads/dumps/dump-1.txt、dump-2.txt、dump-3.txt。三个文件的时刻行(pid 行之后的第二行)必须互不相同。
for i in 1 2 3; do jcmd $PID Thread.print > dumps/dump-$i.txt; sleep 2; done。如果同一个线程在三份转储中停在同一个位置,就是真的卡住了。