• Jstack定位生产环境线程阻塞问题解决


    转载请注明出处:

    一、问题现象

    告警现象:

    • 有一个异步处理的任务日志没有往后继续打印了

    • 这个任务对应的队列存在消息积压

    • 系统日志无任何ERROR堆栈,服务既不崩溃也不恢复

      第一反应: 服务没挂但卡住了,极大概率是线程阻塞问题

    二、初步诊断:jstack第一眼看到什么

    2.1 获取Java进程PID

    # 找到拓扑服务的进程ID
    ps aux | grep topology | grep -v grep
    # 结果:PID=23456
    

    2.2 生成第一次线程堆栈

    jstack -l 23456 > thread_dump_1.log
    

    2.3 统计线程状态分布(快速判断问题类型)

    grep "java.lang.Thread.State" thread_dump_1.log | sort | uniq -c
    

    结果:

       87   java.lang.Thread.State: RUNNABLE
       23   java.lang.Thread.State: TIMED_WAITING
       15   java.lang.Thread.State: WAITING   ← 异常!有15个线程在无限期等待
        2   java.lang.Thread.State: BLOCKED
    

    初步判断: 15个WAITING状态的线程不正常,需要深入分析。

    三、核心排查:逐层分析问题线程

    3.1 查找所有WAITING状态的线程

    grep -B 5 "WAITING" thread_dump_1.log | grep "PE_EVT" -A 10
    

    发现目标线程:

    "PE_EVT1-1" #63 prio=5 tid=0x00007feffa0e7800 nid=0x68 waiting on condition
       java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000006cc4cb2f8> (a java.util.concurrent.locks.StampedLock)
        at java.util.concurrent.locks.StampedLock.acquireWrite(StampedLock.java:1119)
        at java.util.concurrent.locks.StampedLock.writeLock(StampedLock.java:354)
        at com.tethrnet.terra.service.sr.topology.lib.api.model.NetworkGraph.addVertex(NetworkGraph.java:27)
        at com.tethrnet.terra.service.sr.server.topology.service.TopologyManager.updateNode(TopologyManager.java:553)
        at com.tethrnet.terra.service.sr.server.topology.service.TopologyManager.removePeInfos(TopologyManager.java:1929)
        at com.tethrnet.terra.service.sr.server.topology.service.ProdTopologyManager.process(ProdTopologyManager.java:294)
        at com.tethrnet.terra.service.sr.server.topology.service.ProdTopologyManager.processPeEvent(ProdTopologyManager.java:151)
    

    3.2 解读这个堆栈的关键信息

    第一层:线程状态

    • WAITING (parking):线程被挂起了,在等某个条件被满足才能继续

      第二层:在等什么

    • parking to wait for <0x00000006cc4cb2f8> (StampedLock):在等一把读写锁

    • StampedLock.writeLock():具体是在等写锁

      第三层:业务在做什么

    • TopologyManager.removePeInfos:在处理PE设备删除操作

    • NetworkGraph.addVertex:正在向内存拓扑图中添加顶点

      疑问来了: 删除PE信息,为啥在添加顶点?这需要看代码逻辑,但暂时先不管,继续追锁问题。

    3.3 找到锁的占用者(关键一步)

    在完整的堆栈文件中搜索这把锁:

    grep -B 15 -A 30 "0x00000006cc4cb2f8" thread_dump_1.log
    

    找到占用线程:

    "Topology-Processor-5" #120 prio=5 tid=0x00007feffa123800 nid=0x90 runnable
       java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.read(SocketInputStream.java:129)
        at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3123)
        at com.mysql.jdbc.MysqlIO.nextRow(MysqlIO.java:2248)
        at com.mysql.jdbc.ResultSetImpl.next(ResultSetImpl.java:474)
        - locked <0x00000006cc4cb2f8> (a java.util.concurrent.locks.StampedLock)
        at com.tethrnet.terra.service.sr.topology.lib.api.model.NetworkGraph.rebuildIndex(NetworkGraph.java:89)
        at com.tethrnet.terra.service.sr.topology.lib.api.model.NetworkGraph.syncFromDB(NetworkGraph.java:156)
        at com.tethrnet.terra.service.sr.server.topology.service.TopologyManager.initGraph(TopologyManager.java:201)
    

    真相大白!

    • 持有锁的线程在RUNNABLE状态
    • 它在执行数据库查询MysqlIO.readFully
    • 问题很明确:在持有写锁的情况下,执行了耗时的数据库操作

    四、确认问题持续时长:连续采样

    4.1 多次采样判断是否是瞬时问题

    for i in 1 2 3; do
        echo "=== 第${i}次采样 ==="
        jstack -l 23456 > thread_dump_${i}.log
        sleep 10
    done
    

    4.2 对比三次结果

    # 检查PE_EVT1-1线程在三次采样中的状态
    for i in 1 2 3; do
        echo "=== dump_${i} ==="
        grep -A 2 "PE_EVT1-1" thread_dump_${i}.log | grep "WAITING"
    done
    

    结果:

    === dump_1 ===
       java.lang.Thread.State: WAITING (parking)
    === dump_2 ===
       java.lang.Thread.State: WAITING (parking)
    === dump_3 ===
       java.lang.Thread.State: WAITING (parking)
    

    结论: 至少30秒内线程状态没有任何变化,确认是持续阻塞,不是瞬时抖动。

    五、根因定位:代码层面分析

    5.1 问题代码定位

    通过堆栈信息锁定到具体代码行:

    • NetworkGraph.addVertex 第27行

    • NetworkGraph.rebuildIndex 第89行

      查看代码发现问题:

    // 问题代码:NetworkGraph.java
    public void addVertex(Vertex v) {
        long stamp = lock.writeLock();  // 第27行,获取写锁
        try {
            validateVertex(v);
            persistToDatabase(v);        // ← 数据库操作在锁内!
            vertexMap.put(v.getId(), v);
        } finally {
            lock.unlockWrite(stamp);
        }
    }
    
    public void rebuildIndex() {
        long stamp = lock.writeLock();   // 同样的问题
        try {
            syncFromDB();                // ← 数据库同步在锁内
            rebuildInvertedIndex();
        } finally {
            lock.unlockWrite(stamp);
        }
    }
    

    根因确认:

    • 写锁保护了内存操作,但错误地包裹了数据库IO操作
    • 当数据库响应慢时,锁被长时间占用
    • 其他所有需要写锁的线程(包括PE事件处理)全部被阻塞

    六、解决方案与验证

    6.1 代码修复

    // 修复后的代码
    public void addVertex(Vertex v) {
        // 1. 耗时操作移到锁外
        validateVertex(v);
        persistToDatabase(v);        // ← 移出锁保护范围
        
        // 2. 只在必要时加锁
        long stamp = lock.writeLock();
        try {
            vertexMap.put(v.getId(), v);
        } finally {
            lock.unlockWrite(stamp);
        }
    }
    
    // 或者更好的方案:使用并发容器
    private final ConcurrentHashMap vertexMap = new ConcurrentHashMap<>();
    
    public void addVertex(Vertex v) {
        validateVertex(v);
        persistToDatabase(v);
        vertexMap.put(v.getId(), v);  // ConcurrentHashMap内部处理并发
    }
    

    6.2 修复后验证

    # 部署修复版本后,再次观察线程状态
    jstack -l 45678 > thread_dump_fixed.log
    grep "java.lang.Thread.State" thread_dump_fixed.log | sort | uniq -c
    

    修复后结果:

      105   java.lang.Thread.State: RUNNABLE
       18   java.lang.Thread.State: TIMED_WAITING
        0   java.lang.Thread.State: WAITING   ← WAITING线程消失!
        0   java.lang.Thread.State: BLOCKED
    

    七、经验总结:线程阻塞问题定位方法论

    7.1 完整排查流程图

    【现象】服务响应慢/假死
            ↓
    1. 统计线程状态分布
       grep "Thread.State" dump.log | sort | uniq -c
       → 大量WAITING/BLOCKED = 锁竞争问题
            ↓
    2. 定位问题线程
       grep -B 5 "WAITING" dump.log | grep "业务关键字"
       → 找到卡住的业务线程
            ↓
    3. 分析线程堆栈
       - 看状态:WAITING/BLOCKED/RUNNABLE
       - 看锁对象:waiting to lock <地址>
       - 看业务代码:定位到具体行号
            ↓
    4. 找到锁占用者
       grep -A 30 "锁地址" dump.log
       → 找到持有锁的线程
            ↓
    5. 确认问题持续时长
       连续采样3次,间隔10秒
       → 对比线程状态是否变化
            ↓
    6. 定位代码并修复
       - 缩小锁范围
       - 耗时操作移出锁外
       - 使用并发容器替代手动锁
    

    7.2 核心排查技巧

    问题特征 排查方向 典型堆栈特征
    大量WAITING线程 锁竞争,找锁占用者 waiting to lock <地址>
    两个线程相互等待 死锁,jstack会明确提示 Found one Java-level deadlock
    线程RUNNABLE但不动 可能是死循环 堆栈反复出现在同一行
    线程WAITING,锁占用者是RUNNABLE 锁内执行耗时操作 锁占用者的堆栈中有IO/DB调用

    7.3 一次成功定位的关键点

    1. 第一时间做线程dump:问题出现时立即保存现场,错过了可能就再也复现不了
    2. 连续采样:单次dump只能看到"此时此刻",多次才能判断"持续多久"
    3. 寻找锁地址:把waiting to lock的地址复制出来,全文搜索找占用者
    4. 关注业务代码:不要只看框架堆栈,一定要追到自己的业务代码行

    7.4 防止类似问题的编码原则

    // ❌ 错误:锁内包含耗时操作
    synchronized(lock) {
        databaseCall();      // 网络IO
        httpRequest();       // 网络IO
        fileWrite();         // 磁盘IO
        complexCalcuation(); // 大量计算
    }
    
    // ✅ 正确:只锁必要的最小范围
    Object result = expensiveOperation();  // 锁外执行
    synchronized(lock) {
        sharedState.update(result);        // 只锁状态修改
    }
    

    八、写在最后

    这次排查让我深刻体会到:

    1. jstack是Java开发者最锋利的瑞士军刀,掌握它就能应对80%的线程问题

    2. 不要被表象迷惑:WAITING状态本身不是bug,谁持有锁才是关键

    3. 代码审查的盲区:锁的范围往往是code review容易忽略的地方

    4. 监控的重要性:如果有线程dump的自动化采集,问题可以早发现1小时

    最后记住:

    看到WAITING/BLOCKED不可怕,可怕的是你不知道谁在占用资源。jstack就是那盏照亮黑暗的手电筒。


  • 相关阅读:
    网络——ARP、DHCP、ICMP协议
    TCN代码详解-Torch (误导纠正)
    【PHP实现微信公众平台开发—基础篇】第2章 微信公众账号及申请流程详解
    浅谈AVL树,红黑树,B树,B+树原理及应用
    波奇学Linux:日志
    vue.draggable拖拽,项目中三个表格互相拖拽的实例操作,前端分页等更多小技巧~
    Java项目利用Redisson实现真正生产可用高并发秒杀功能 支持分布式高并发秒杀
    Mysql5.7(Docker环境)实现主从复制
    DevOps工具链整合:打造高效的自动化工作流
    读书笔记-《ON JAVA 中文版》-摘要3
  • 原文地址:https://www.cnblogs.com/zjdxr-up/p/20064548