关于线程:如何利用线程堆栈定位问题

7次阅读

共计 42007 个字符,预计需要花费 106 分钟才能阅读完成。

01 背景

针对在一些服务中会呈现的 cpu 飙高、死锁、线程假死等问题,总结和提炼排查问题的思路和解决方案十分重要。上述问题会波及到线程堆栈,本文将结合实际案例来论述一下线程堆栈的性能。

02 基本知识

2.1 什么是线程堆栈

线程堆栈是零碎过后某个时刻的线程运行状态(即霎时快照)。

线程堆栈的信息蕴含

  • 线程的名字、ID、线程的数量
  • 线程的运行状态、锁的状态(锁被那个线程持有,哪个线程再期待锁)

<!—->

  • 调用堆栈(即函数的调用档次关系)。调用堆栈蕴含残缺的类名,所执行的办法,源代码的行数

2.2 线程堆栈能剖析问题类型

线程堆栈定位问题只能定位在以后线程上留下痕迹的问题

2.3 线程堆栈不能剖析的问题

线程堆栈不能定位在线程堆栈上不留痕迹的问题:

  • 并发 bug 导致的数据凌乱,这种问题在线程堆栈中没有任何航迹,所以这种问题线程堆栈无奈提供任何帮忙。
  • 数据库锁表的问题,表被锁,往往因为某个事务没有提交 / 回滚,但这些信息无奈在堆栈中体现呈现

在线程上不留痕迹的问题只能通过其余伎俩来进行定位。在理论的零碎中,零碎的问题分为几种类型:

  • 在堆栈中可能体现出问题的,应用线程堆栈进行定位
  • 无奈在线程中留下痕迹的问题定位,须要依赖于一个好的日志设计
  • 十分荫蔽的问题,只能依赖于丰盛的代码教训,如多线程导致的数据凌乱,以及前面提到的幽灵代码

2.4 如何输入线程堆栈

kill -3 pid 命令只能打印那一瞬间 java 过程的堆栈信息,适宜在服务器响应慢,cpu、内存疾速飙升等异常情况下应用,能够不便地定位到导致异样产生的 java 类,解决如死锁、连贯超时等起因导致的零碎异样问题。该 命令不会杀死过程。

备注:

将屏幕输入写入到文件中,重写文件内容

将屏幕输入增加到文件开端

Linux 常用命令

命令 形容
ps 查找过程的 pid
pstack 打印过程或者线程的栈信息
strace 统计每一步零碎调用破费的工夫

2.5 剖析线程堆栈 - 线程状态的剖析

2.5.1 概述

2.5.2 Runnable

从虚拟机的角度来看,线程处于正在运行的状态。

那么处于 RUNNABLE 的线程是不是肯定耗费 CPU 呢? 实际上不肯定。上面的线程堆栈示意该线程正在从网络读取数据,只管上面这个线程显示为 RUNNABLE 状态,但实际上网 络 IO, 线程绝大多数工夫是被挂起,只有当数据达到之后,线程才被从新唤醒。挂起产生在本 地代码 (Native) 中,虚拟机基本不晓得,不像显式调用了 Java 的 sleep()或者 wait()等办法,虚构 机能晓得线程的真正状态,但对于本地代码中的挂起,虚拟机无奈真正地晓得线程状态,因 此它一律显示为 RUNNABLE。像这种 socket IO 操作不会耗费大量的 CPU, 因为大多工夫在期待,只有数据到来之后,才耗费一点点 CPU.

Thread-39" daemon prio=1 tid=0x08646590 nid=0x666d runnable [5beb7000..5beb88b8]
      java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.read(SocketInputStream.java:129)
        at java.io.BufferedInputStream.fill(BufferedInputStream.java:183)
        at java.io.BufferedInputStream.read(BufferedInputStream.java:201)
        - locked <0x47bfb940> (a java.io.BufferedInputStream)
        at org.postgresql.PG_Stream.ReceiveChar(PG_Stream.java:141)
        at org.postgresql.core.QueryExecutor.execute(QueryExecutor.java:68)
        - locked <0x47bfb758> (a org.postgresql.PG_Stream)
        at org.postgresql.Connection.ExecSQL(Connection.java:398)

上面的线程正在执行纯 Java 代码指令,实实在在是耗费 CPU 的线程。

"Thread-444" prio=1 tid=0xa4853568 nid=0x7ade runnable [0xafcf7000..0xafcf8680]
      java.lang.Thread.State: RUNNABLE
// 实实在在再对应 CPU 运算指令
at org.apache.commons.collections.ReferenceMap.getEntry(Unknown Source) at org.apache.commons.collections.ReferenceMap.get(Unknown Source)
at org.hibernate.util.SoftLimitMRUCache.get(SoftLimitMRUCache.java:51) at org.hibernate.engine.query.QueryPlanCache.getNativeSQLQueryPlan()
at org.hibernate.impl.AbstractSessionImpl.getNativeSQLQueryPlan()
at org.hibernate.impl.AbstractSessionImpl.list()
at org.hibernate.impl.SQLQueryImpl.list(SQLQueryImpl.java:164)
at com.mogoko.struts.logic.user.LeaveMesManager.getCommentByShopId()
at com.mogoko.struts.action.shop.ShopIndexBaseInfoAction.execute() ......

上面的线程正在进行 JNI 本地办法调用,具体是否耗费 CPU,要看 TcpRecvExt 的实现,如 果 TcpRecvExt 是纯运算代码,那么是实实在在耗费 CPU, 如果 TcpRecvExt()中存在挂起的代 码,那么该线程只管显示为 RUNNABLE, 但实际上也是不耗费 CPU 的。

 "ClientReceiveThread" daemon prio=1 tid=0x99dbacf8 nid=0x7988 runnable [...]
      java.lang.Thread.State: RUNNABLE
        at com.pangu.network.icdcomm.htcpapijni.TcpRecvExt(Native Method)
        at com.pangu.network.icdcomm.IcdComm.receive(IcdComm.java:60)
        at com.msp.client.MspFactory$ClientReceiveThread.task(MspFactory.java:333)
        at com.msp.system.TaskThread.run(TaskThread.java:94)

2.5.3 TIMED_WAITING(on object monitor)

示意以后线程被挂起一段时间, 阐明该线程正在 执行 obj.wait(int time)办法.

上面的线程堆栈示意以后线程正处于 TIMED_WAITING 状态,以后正在被挂起,时长为 参数中指定的时长,如 obj.wait(2000)。因而该线程以后不耗费 CPU。

 "JMX server" daemon prio=6 tid=0x0ad2c800 nid=0xdec in Object.wait() [...]
      java.lang.Thread.State: TIMED_WAITING (on  object  monitor)
       at java.lang.Object.wait(Native Method)
       - waiting on <0x03129da0> (a [I)
       at com.sun.jmx.remote.internal.ServerComm$Timeout.run(ServerComm.java:150)
       - locked <0x03129da0> (a [I)
       at java.lang.Thread.run(Thread.java:620)

2.5.4 TIMED_WAITING(sleeping)

示意以后线程被挂起一段时间, 即正在执行 Thread.sleep(int time)办法.

上面的线程正处于 TIMED_WAITING 状态,示意以后被挂起一段时间,时长为参数中指 定的时长,如 Thread.sleep(100000)。因而该线程以后不耗费 CPU。

 "Comm thread" daemon prio=10 tid=0x00002aaad4107400 nid=0x649f waiting on condition
    [0x000000004133b000..0x000000004133ba00]
       java.lang.Thread.State: TIMED_WAITING (sleeping)
            at java.lang.Thread.sleep(Native Method)
            at org.apache.hadoop.mapred.Task$1.run(Task.java:282)
            at java.lang.Thread.run(Thread.java:619)

2.5.5 TIMED_WAITING(parking)

以后线程被挂起一段时间, 即正在执行 Thread.sleep(int time)方 法.

上面的线程正处于 TIMED_WAITING 状态,示意以后被挂起一段时间,时长为参数中指 定的时长,如 LockSupport.parkNanos(blocker, l10000)。因而该线程以后不耗费 CPU。

"RMI TCP" daemon prio=6 tid=0x0ae3b800 nid=0x958 waiting on condition [0x17eff000..0x17effa94]
 java.lang.Thread.State: TIMED_WAITING (parking)
       at sun.misc.Unsafe.park(Native Method)
       - parking to wait for  <0x02f49f58> (a java.util.concurrent.SynchronousQueue$TransferStack)
       at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:179)
       at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:424)
       at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:323)
       at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:871)
       at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:495)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:693)
       at java.lang.Thread.run(Thread.java:620)

2.5.6 WAINTING(on object monitor)

以后线程被挂起,即正在执行 obj.wait()办法 (无参数的 wait() 方 法).

上面的线程正处于 WAITING 状态,示意以后线程被挂起,如 obj.wait()(只能通过 notify()唤 醒)。因而该线程以后不耗费 CPU。

 "IPC Client" daemon prio=10 tid=0x00002aaad4129800 nid=0x649d in Object.wait() [0x039000..0x039d00]
       java.lang.Thread.State: WAITING (on object monitor)
            at java.lang.Object.wait(Native Method)
            - waiting on <0x00002aaab3acad18>; (aorg.apache.hadoop.ipc.Client$Connection)
            at java.lang.Object.wait(Object.java:485)
            at org.apache.hadoop.ipc.Client$Connection.waitForWork(Client.java:234)
            - locked <0x00002aaab3acad18> (aorg.apache.hadoop.ipc.Client$Connection)
            at org.apache.hadoop.ipc.Client$Connection.run(Client.java:273)

2.5.7 总结

处于 TIMED_WAITING、WAITING 状态的线程肯定不耗费 CPU,处于 Runable 的线程,要联合以后线程代码的性质判断,是否耗费 CPU。

  • 如果纯 java 运算代码,则耗费 CPU
  • 如果是网络 IO,很少耗费 CPU
  • 如果是本地代码,联合本地代码的性质判断(能够通过 pstack/gstack 获取本地线程堆栈),如果是纯运算代码,则耗费 CPU,如果被挂起,则不耗费 CPU,如果是 IO,则不怎么耗费 CPU。

03 CPU 飙高

3.1 概述

零碎的 CPU 的飙高的起因有很多,上面列举一下一些常见的场景:

3.2 死循环导致 CPU 飙高

死循环并不一定会导致 CPU 的 100% 利用率,如果死循环中的代码不是 CPU 密集型,而是像 Socket 或者数据库 IO 操作,这些操作是不怎么耗费 CPU 的。但如果循环代码中是 CPU 密集型操作,那这就是导致 CPU 利用率 100% 的可能起因。

定位问题的办法是:通过屡次打印线程堆栈

次要流程如下:

  1. 获取第一次堆栈信息
  2. 期待肯定的工夫,再获取第二次堆栈信息。
  3. 预处理两次堆栈信息,首先去掉处于 sleeping 或者 waiting 状态的线程,因为这种线程是不耗费 CPU 的
  4. 比拟第一次堆栈和第二次堆栈预处理后的线程,找出这段时间始终沉闷的线程,如果两次堆栈中同一个线程处于同样的调用上下文,那么就应该列为重点怀疑对象。具体情况须要联合代码详细分析。导致这种状况的可能起因猜想是:

猜想一:查看该线程的执行高低所对应的代码是否属于长期运行的代码。

猜想二:如果不属于长期运行的代码,那么这个线程为什么长期执行不完那段代码,可能的起因是代码呈现死循环了。

导致死循环呈现的起因:

  • 多线程:for,while 循环中的退出条件永远不满足导致的死循环。
  • 多线程:链表等数据结构首尾相接,导致遍历永远无奈进行
  • 其问题

3.3 非死循环导致 CPU 飙高

导致 CPU 飙高的可能起因:

  • 纯 java 代码导致的 CPU 过高,具体情况能够参考博客:【稳定性平台】一次性能优化教训分享
  • java 代码中调用的 JNI 代码导致的 CPU 过高
  • 虚拟机本身的代码导致的 CPU 过高,比方 GC 的 bug 等

定位问题的办法是:通过打印线程堆栈

次要流程如下:

第一步:获取指标过程 id(pid),应用命令能够获取过程 ID,jps -l 或 ps -ef |grep java

第二步:通过 top -Hp pid 获取该过程下最耗费 CPU 的本地线程 ID。

第三步:打印线程堆栈,应用如下命令,jstack -l pid

第四步:将十进制的本地线程 ID 换算成 16 进制,采纳如下命令:printf “0x%x\n” 53841(本地线程 ID), 输入 Oxd251。

第五步:在 java 线程堆栈中查找 nid=< 第一步获取的最耗 CPU 工夫的线程 ID(十进制换算成的十六进制的本地线程 ID)>,具体分析如下

  • 如果在 java 线程堆栈中找到了对应的线程 ID,并且该线程正在执行纯 java 代码,阐明是该 java 代码导致的 CPU 过高的。
  • 如果在 java 线程堆栈中找到了对应的线程 ID,并且该线程正在执行 native code 代码,阐明是导致的 CPU 过高的问题代码在 JNI 调用中。
  • 如果在 java 线程堆栈中找不到了对应的线程 ID,有如下两种可能:
    • JNI 调用中从新创立的线程来执行,那么在 java 线程堆栈中就不存在该线程的信息。
    • 虚拟机本身代码导致的 CPU 过高,如堆内存枯竭导致的频繁 Full GC,或者虚拟机 bug 等
    • 此时同样能够通过 pstack pid 命令获取所有的本地线程堆栈,依据之前获取的最耗时 CPU 工夫的线程 ID,在本地线程堆栈中找到对应的线程,即为高耗费 CPU 的线程。借助本地线程堆栈信息,能够间接定位到本地代码找出问题。

04 零碎假死

4.1 概述

零碎假死只是一个表面现象。零碎假死,从外表上看,是零碎不解决响应。对于 web 零碎来说,http 申请无数据返回。总之来说,零碎像死了一样。导致系统假死的起因很多,具体的问题须要在特定的场景下进行剖析,但总的归纳起因有如下几种:

备注:非凡状况,零碎假死,当一个服务即对外提供 http 和 rpc 服务时,两者应用的不同的线程池,即便其中一个线程池中的线程产生死锁,另外一个线程池依然能够提供服务

4.2 线程死锁

4.2.1 死锁和定位办法

什么死锁

当两个线程或多个线程正在期待被对方占有的锁,死锁就会产生。死锁会导致两个线程无奈持续运行,被永远挂起。

定位问题的办法是:打印线程堆栈。如呈现死锁时,在打印线程堆栈时虚构机会主动给出死锁的提醒。

4.2.2 背景

在 2021.12.13 11:15 refund-interfaces 服务上这台机器 10.240.49.153 操作命令挂载沙箱,在 11:32:19 分在流量回放平台操作录制,此时返回操作失败,对录制失败进行问题排查,在 11:34 分,order 服务有接口报服务超时,然而从 refund-interface 监控上看,这台 10.240.49.153 的监控不存在,其余都是失常的,11:59 才发现这台机器依然在 dubbo 的注册核心,过后状况没有比拟好伎俩保留现场,只能将机器重启,破会了现场。预先初步猜想是在高并发的状况下,操作平台的录制性能导致产生死锁。而产生死锁时,要想复原零碎,长期也是惟一躲避的方法就是将零碎重启。

为保障服务的可用性,在产生异常情况下,降级计划和问题排查思路

通常的降级计划是:

【计划一】保留现场法 - 摘除流量法,目前我司该计划并不欠缺

1. 对于 http,须要从网关摘除流量,即是 consul

2. 对于 rpc,须要从 dubbo 的注册核心摘除流量,即是 nacos

3. 对于 mq,服务接入 MQ 的生产端摘除流量

【计划二】万能法 - 机器重启

通常的问题排查思路是:尽量保留现场,便于预先问题排查!!!!

备注:对于死锁的产生,如没有保留现场,须要对其发现的伎俩是通过压测的形式。因为代码如有产生死锁的潜在可能并不象征照死锁每次都产生,它只产生该产生的时候,当死锁呈现的时候,往往是遇到了最可怜的时候 - 在高负载的生产环境之下

4.2.3 通过压测形式来复现死锁

4.2.3.1 景象

在 2021-12-27 11:58:15 没有监控,压测是存在,服务过程是存在的,在 12:02 dump 线程堆栈进行察看,如上

4.2.3.2 dump 线程堆栈

Found one Java-level deadlock:
=============================
"DubboServerHandler-10.246.144.236:20888-thread-200":
  waiting to lock monitor 0x00007faa6c00c128 (object 0x00000006bd2a0000, a com.pandora.jvm.sandbox.repeater.module.classloader.PluginClassLoader),
  which is held by "com.alibaba.nacos.client.naming.updater"
"com.alibaba.nacos.client.naming.updater":
  waiting to lock monitor 0x00007fa91c0568b8 (object 0x00000006bcf0de00, a com.alibaba.jvm.sandbox.core.classloader.ModuleJarClassLoader),
  which is held by "XNIO-1 task-44"
"XNIO-1 task-44":
  waiting to lock monitor 0x00007fa904004848 (object 0x0000000722c10c48, a java.lang.Object),
  which is held by "com.alibaba.nacos.client.naming.updater"

Java stack information for the threads listed above:
===================================================
"DubboServerHandler-10.246.144.236:20888-thread-200":
    at com.pandora.jvm.sandbox.repeater.plugin.dubbo.DubboProviderInvocationProcessor.assembleIdentity(DubboProviderInvocationProcessor.java:39)
    at com.pandora.jvm.sandbox.repeater.plugin.core.impl.api.DefaultEventListener.sample(DefaultEventListener.java:194)
    at com.pandora.jvm.sandbox.repeater.plugin.core.impl.api.DefaultEventListener.onEvent(DefaultEventListener.java:89)
    at com.alibaba.jvm.sandbox.core.enhance.weaver.EventListenerHandler.handleEvent(EventListenerHandler.java:117)
    at com.alibaba.jvm.sandbox.core.enhance.weaver.EventListenerHandler.handleOnBefore(EventListenerHandler.java:353)
    at java.com.alibaba.jvm.sandbox.spy.Spy.spyMethodOnBefore(Spy.java:164)
    at org.apache.dubbo.rpc.filter.ContextFilter.invoke(ContextFilter.java)
    at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:81)
    at org.apache.dubbo.rpc.filter.GenericFilter.invoke(GenericFilter.java:147)
    at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:81)
    at org.apache.dubbo.rpc.filter.ClassLoaderFilter.invoke(ClassLoaderFilter.java:38)
    at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:81)
    at org.apache.dubbo.rpc.filter.EchoFilter.invoke(EchoFilter.java:41)
    at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:81)
    at org.apache.dubbo.rpc.protocol.dubbo.DubboProtocol$1.reply(DubboProtocol.java:145)
    at org.apache.dubbo.remoting.exchange.support.header.HeaderExchangeHandler.handleRequest(HeaderExchangeHandler.java:100)
    at org.apache.dubbo.remoting.exchange.support.header.HeaderExchangeHandler.received(HeaderExchangeHandler.java:175)
    at org.apache.dubbo.remoting.transport.DecodeHandler.received(DecodeHandler.java:51)
    at org.apache.dubbo.remoting.transport.dispatcher.ChannelEventRunnable.run(ChannelEventRunnable.java:57)
    at com.alibaba.ttl.TtlRunnable.run(TtlRunnable.java:51)
    at com.alibaba.ttl.TtlRunnable.run(TtlRunnable.java:55)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:775)
"com.alibaba.nacos.client.naming.updater":
    at java.lang.ClassLoader.checkCerts(ClassLoader.java:881)
    - waiting to lock <0x00000006bcf0de00> (a com.alibaba.jvm.sandbox.core.classloader.ModuleJarClassLoader)
    at java.lang.ClassLoader.preDefineClass(ClassLoader.java:662)
    at java.lang.ClassLoader.defineClass(ClassLoader.java:755)
    at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142)
    at java.net.URLClassLoader.defineClass(URLClassLoader.java:468)
    at java.net.URLClassLoader.access$100(URLClassLoader.java:74)
    at java.net.URLClassLoader$1.run(URLClassLoader.java:369)
    at java.net.URLClassLoader$1.run(URLClassLoader.java:363)
    at java.security.AccessController.doPrivileged(Native Method)
    at java.net.URLClassLoader.findClass(URLClassLoader.java:362)
    at com.alibaba.jvm.sandbox.core.classloader.RoutingURLClassLoader.access$400(RoutingURLClassLoader.java:22)
    at com.alibaba.jvm.sandbox.core.classloader.RoutingURLClassLoader$1.loadClass(RoutingURLClassLoader.java:91)
    at com.alibaba.jvm.sandbox.core.classloader.ClassLoadingLock.loadingInLock(ClassLoadingLock.java:55)
    - locked <0x0000000722c10c48> (a java.lang.Object)
    at com.alibaba.jvm.sandbox.core.classloader.RoutingURLClassLoader.loadClass(RoutingURLClassLoader.java:64)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:406)
    - locked <0x00000006bd2a0000> (a com.pandora.jvm.sandbox.repeater.module.classloader.PluginClassLoader)
    at com.pandora.jvm.sandbox.repeater.module.classloader.PluginClassLoader.loadClass(PluginClassLoader.java:47)
    - locked <0x00000006bd2a0000> (a com.pandora.jvm.sandbox.repeater.module.classloader.PluginClassLoader)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:352)
    at com.pandora.jvm.sandbox.repeater.plugin.exception.ExceptionEventListener.sample(ExceptionEventListener.java:34)
    at com.pandora.jvm.sandbox.repeater.plugin.core.impl.api.DefaultEventListener.onEvent(DefaultEventListener.java:89)
    at com.alibaba.jvm.sandbox.core.enhance.weaver.EventListenerHandler.handleEvent(EventListenerHandler.java:117)
    at com.alibaba.jvm.sandbox.core.enhance.weaver.EventListenerHandler.handleOnBefore(EventListenerHandler.java:353)
    at java.com.alibaba.jvm.sandbox.spy.Spy.spyMethodOnBefore(Spy.java:164)
    at java.lang.RuntimeException.<init>(RuntimeException.java:62)
    at java.lang.IllegalArgumentException.<init>(IllegalArgumentException.java:52)
    at java.lang.NumberFormatException.<init>(NumberFormatException.java:55)
    at java.lang.Long.parseLong(Long.java:552)
    at java.lang.Long.parseLong(Long.java:631)
    at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1845)
    - locked <0x0000000722cc9928> (a sun.net.www.protocol.http.HttpURLConnection)
    at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1498)
    - locked <0x0000000722cc9928> (a sun.net.www.protocol.http.HttpURLConnection)
    at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:480)
    at com.alibaba.nacos.common.http.client.response.JdkHttpClientResponse.getStatusCode(JdkHttpClientResponse.java:75)
    at com.alibaba.nacos.common.http.client.handler.AbstractResponseHandler.handle(AbstractResponseHandler.java:43)
    at com.alibaba.nacos.common.http.client.NacosRestTemplate.execute(NacosRestTemplate.java:483)
    at com.alibaba.nacos.common.http.client.NacosRestTemplate.exchangeForm(NacosRestTemplate.java:427)
    at com.alibaba.nacos.client.naming.net.NamingProxy.callServer(NamingProxy.java:599)
    at com.alibaba.nacos.client.naming.net.NamingProxy.reqApi(NamingProxy.java:524)
    at com.alibaba.nacos.client.naming.net.NamingProxy.reqApi(NamingProxy.java:491)
    at com.alibaba.nacos.client.naming.net.NamingProxy.reqApi(NamingProxy.java:486)
    at com.alibaba.nacos.client.naming.net.NamingProxy.queryList(NamingProxy.java:400)
    at com.alibaba.nacos.client.naming.core.HostReactor.updateService(HostReactor.java:339)
    at com.alibaba.nacos.client.naming.core.HostReactor$UpdateTask.run(HostReactor.java:420)
    at com.alibaba.ttl.TtlRunnable.run(TtlRunnable.java:51)
    at com.alibaba.ttl.TtlRunnable.run(TtlRunnable.java:55)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:775)
"XNIO-1 task-44":
    at com.alibaba.jvm.sandbox.core.classloader.ClassLoadingLock.loadingInLock(ClassLoadingLock.java:53)
    - waiting to lock <0x0000000722c10c48> (a java.lang.Object)
    at com.alibaba.jvm.sandbox.core.classloader.RoutingURLClassLoader.loadClass(RoutingURLClassLoader.java:64)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:352)
    at com.pandora.jvm.sandbox.repeater.plugin.core.impl.dewuext.TraceExtension.dewuTrace(TraceExtension.java:51)
    at com.pandora.jvm.sandbox.repeater.plugin.core.impl.api.DefaultEventListener.onEvent(DefaultEventListener.java:76)
    at com.alibaba.jvm.sandbox.core.enhance.weaver.EventListenerHandler.handleEvent(EventListenerHandler.java:117)
    at com.alibaba.jvm.sandbox.core.enhance.weaver.EventListenerHandler.handleOnBefore(EventListenerHandler.java:353)
    at java.com.alibaba.jvm.sandbox.spy.Spy.spyMethodOnBefore(Spy.java:164)
    at io.jaegertracing.internal.JaegerSpan.finish(JaegerSpan.java)
    at com.poizon.fusion.monitor.instrument.jdbc.MonitorPreparedStatement.execute(MonitorPreparedStatement.java:97)
    at io.shardingsphere.shardingjdbc.jdbc.core.statement.MasterSlavePreparedStatement$3.executeSQL(MasterSlavePreparedStatement.java:152)
    at io.shardingsphere.shardingjdbc.jdbc.core.statement.MasterSlavePreparedStatement$3.executeSQL(MasterSlavePreparedStatement.java:149)
    at io.shardingsphere.spi.executor.MasterSlaveSQLExecuteCallback.execute0(MasterSlaveSQLExecuteCallback.java:17)
    at io.shardingsphere.shardingjdbc.jdbc.core.statement.MasterSlavePreparedStatement.execute(MasterSlavePreparedStatement.java:155)
    at com.poizon.fusion.monitor.instrument.jdbc.MonitorPreparedStatement.execute(MonitorPreparedStatement.java:89)
    at org.apache.ibatis.executor.statement.PreparedStatementHandler.query(PreparedStatementHandler.java:64)
    at org.apache.ibatis.executor.statement.RoutingStatementHandler.query(RoutingStatementHandler.java:79)
    at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:63)
    at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:324)
    at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:156)
    at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:109)
    at com.github.pagehelper.PageInterceptor.intercept(PageInterceptor.java:108)
    at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:61)
    at com.sun.proxy.$Proxy419.query(Unknown Source)
    at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:147)
    at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:140)
    at sun.reflect.GeneratedMethodAccessor490.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:426)
    at com.sun.proxy.$Proxy192.selectList(Unknown Source)
    at org.mybatis.spring.SqlSessionTemplate.selectList(SqlSessionTemplate.java:223)
    at org.apache.ibatis.binding.MapperMethod.executeForMany(MapperMethod.java:147)
    at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:80)
    at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:93)
    at com.sun.proxy.$Proxy193.selectByExample(Unknown Source)
    at com.shizhuang.duapp.refund.infrastructure.db.dao.RefundOrderDao.getReturnBySubOrderNoList(RefundOrderDao.java:1049)
    at com.shizhuang.duapp.refund.infrastructure.db.dao.RefundOrderDao$$FastClassBySpringCGLIB$$41f7ca21.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:750)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
    at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:139)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
    at org.springframework.aop.framework.adapter.MethodBeforeAdviceInterceptor.invoke(MethodBeforeAdviceInterceptor.java:56)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:93)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:689)
    at com.shizhuang.duapp.refund.infrastructure.db.dao.RefundOrderDao$$EnhancerBySpringCGLIB$$28f9b058.getReturnBySubOrderNoList(<generated>)
    at com.shizhuang.duapp.refund.application.service.refund.app.impl.QueryRefundDetailInBuyerOrderDetailService.hasRefund(QueryRefundDetailInBuyerOrderDetailService.java:147)
    at com.shizhuang.duapp.refund.interfaces.facade.refund.app.RefundOrderDesc2OldOrderDetailController.hasRefund(RefundOrderDesc2OldOrderDetailController.java:150)
    at com.shizhuang.duapp.refund.interfaces.facade.refund.app.RefundOrderDesc2OldOrderDetailController$$FastClassBySpringCGLIB$$da692b9e.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:750)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
    at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:88)
    at com.poizon.fusion.monitor.instrument.openfeign.aspect.FeignClientAspect.invoke(FeignClientAspect.java:109)
    at sun.reflect.GeneratedMethodAccessor486.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:644)
    at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:633)
    at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:93)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:689)
    at com.shizhuang.duapp.refund.interfaces.facade.refund.app.RefundOrderDesc2OldOrderDetailController$$EnhancerBySpringCGLIB$$25d2f6d1.hasRefund(<generated>)
    at sun.reflect.GeneratedMethodAccessor497.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190)
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138)
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:105)
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:893)
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:798)
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
    at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:909)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:665)
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:750)
    at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129)
    at com.shizhuang.duapp.dubbo.environment.ServletEnvironmentFilter.doFilter(ServletEnvironmentFilter.java:28)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at com.alibaba.druid.support.http.WebStatFilter.doFilter(WebStatFilter.java:124)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at org.springframework.boot.actuate.web.trace.servlet.HttpTraceFilter.doFilterInternal(HttpTraceFilter.java:88)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at com.shizhuang.duapp.sentinel.client.servlet.SentinelServletFilter.doFilter(SentinelServletFilter.java:90)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:94)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at com.poizon.fusion.webmvc.logging.AccessLoggingFilter.doFilterInternal(AccessLoggingFilter.java:63)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.filterAndRecordMetrics(WebMvcMetricsFilter.java:114)
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:104)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at com.poizon.fusion.monitor.instrument.spring.web.server.servlet.MonitorServletFilter.doFilter(MonitorServletFilter.java:170)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
    at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
    at io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:68)
    at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
    at io.undertow.servlet.handlers.RedirectDirHandler.handleRequest(RedirectDirHandler.java:68)
    at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:132)
    at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
    at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
    at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
    at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
    at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
    at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
    at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:269)
    at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:78)
    at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:133)
    at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:130)
    at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
    at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
    at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:249)
    at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:78)
    at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:99)
    at io.undertow.server.Connectors.executeRootHandler(Connectors.java:376)
    at io.uXNIO-1 task-44":
    at com.alibaba.jvm.sandbox.core.classloader.ClassLoadingLock.loadingInLock(ClassLoadingLock.java:53)
    - waiting to lock <0x0000000722c10c48> (a java.lang.Object)
    at com.alibaba.jvm.sandbox.core.classloader.RoutingURLClassLoader.loadClass(RoutingURLClassLoader.java:64)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:352)
    at com.pandora.jvm.sandbox.repeater.plugin.core.impl.dewuext.TraceExtension.dewuTrace(TraceExtension.java:51)ndertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
    at com.alibaba.ttl.TtlRunnable.run(TtlRunnable.java:51)
    at com.alibaba.ttl.TtlRunnable.run(TtlRunnable.java:55)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:775)

Found 1 deadlock.

备注:

有一些令人头疼的死锁场景,比方类加载过程产生的死锁,尤其是在框架大量应用自定义类加载时,因为往往不是在利用自身的代码库中,jstack 等工具也不见得可能显示全副锁信息。

4.2.3.3 dump 文件剖析

线程 XNIO-1

XNIO-1 task-44":
    at com.alibaba.jvm.sandbox.core.classloader.ClassLoadingLock.loadingInLock(ClassLoadingLock.java:53)
    - waiting to lock <0x0000000722c10c48> (a java.lang.Object)
    at com.alibaba.jvm.sandbox.core.classloader.RoutingURLClassLoader.loadClass(RoutingURLClassLoader.java:64)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:352)
    at com.pandora.jvm.sandbox.repeater.plugin.core.impl.dewuext.TraceExtension.dewuTrace(TraceExtension.java:51)

线程 com.alibaba.nacos.client.naming.updater

"com.alibaba.nacos.client.naming.updater":
    at java.lang.ClassLoader.checkCerts(ClassLoader.java:881)
    - waiting to lock <0x00000006bcf0de00> (a com.alibaba.jvm.sandbox.core.classloader.ModuleJarClassLoader)
    at java.lang.ClassLoader.preDefineClass(ClassLoader.java:662)
    at java.lang.ClassLoader.defineClass(ClassLoader.java:755)
    at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142)
    at java.net.URLClassLoader.defineClass(URLClassLoader.java:468)
    at java.net.URLClassLoader.access$100(URLClassLoader.java:74)
    at java.net.URLClassLoader$1.run(URLClassLoader.java:369)
    at java.net.URLClassLoader$1.run(URLClassLoader.java:363)
    at java.security.AccessController.doPrivileged(Native Method)
    at java.net.URLClassLoader.findClass(URLClassLoader.java:362)
    at com.alibaba.jvm.sandbox.core.classloader.RoutingURLClassLoader.access$400(RoutingURLClassLoader.java:22)
    at com.alibaba.jvm.sandbox.core.classloader.RoutingURLClassLoader$1.loadClass(RoutingURLClassLoader.java:91)
    at com.alibaba.jvm.sandbox.core.classloader.ClassLoadingLock.loadingInLock(ClassLoadingLock.java:55)
    - locked <0x0000000722c10c48> (a java.lang.Object)
    at com.alibaba.jvm.sandbox.core.classloader.RoutingURLClassLoader.loadClass(RoutingURLClassLoader.java:64)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:406)
    - locked <0x00000006bd2a0000> (a com.pandora.jvm.sandbox.repeater.module.classloader.PluginClassLoader)
    at com.pandora.jvm.sandbox.repeater.module.classloader.PluginClassLoader.loadClass(PluginClassLoader.java:47)
    - locked <0x00000006bd2a0000> (a com.pandora.jvm.sandbox.repeater.module.classloader.PluginClassLoader)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:352)
    at com.pandora.jvm.sandbox.repeater.plugin.exception.ExceptionEventListener.sample(ExceptionEventListener.java:34)

联合代码剖析

线程 XNIO-1

线程 com.alibaba.nacos.client.naming.updater

4.2.3.4 论断

在高并发状况,类加载加锁导致死锁的

4.2.3.5 解决方案

提前加载 RepeatCache 和 Tracer 类

4.3 线程假死

线程假死是线程始终处于运行中,不退出。

定位问题的办法是:打印线程堆栈

业务中须要应用 spark 进行数据处理,因而将 spark 工作上传到服务器执行,然而 main 线程始终 hang 住。通过打印线程堆栈,摘出其中的局部线程堆栈,如下:

"main" #1 prio=5 os_prio=0 tid=0x00007f0d98009800 nid=0x6240b runnable [0x00007f0d9ec49000]
   java.lang.Thread.State: RUNNABLE
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
    at java.net.SocketInputStream.read(SocketInputStream.java:171)
    at java.net.SocketInputStream.read(SocketInputStream.java:141)
    at com.mysql.cj.protocol.ReadAheadInputStream.fill(ReadAheadInputStream.java:107)
    at com.mysql.cj.protocol.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:150)
    at com.mysql.cj.protocol.ReadAheadInputStream.read(ReadAheadInputStream.java:180)
    - locked <0x000000072028a7b8> (a com.mysql.cj.protocol.ReadAheadInputStream)
    at java.io.FilterInputStream.read(FilterInputStream.java:133)
    at com.mysql.cj.protocol.FullReadInputStream.readFully(FullReadInputStream.java:64)
    at com.mysql.cj.protocol.a.SimplePacketReader.readHeaderLocal(SimplePacketReader.java:81)
    at com.mysql.cj.protocol.a.SimplePacketReader.readHeader(SimplePacketReader.java:63)
    at com.mysql.cj.protocol.a.SimplePacketReader.readHeader(SimplePacketReader.java:45)
    at com.mysql.cj.protocol.a.NativeProtocol.readMessage(NativeProtocol.java:514)
    at com.mysql.cj.protocol.a.NativeProtocol.readServerCapabilities(NativeProtocol.java:475)
    at com.mysql.cj.protocol.a.NativeProtocol.beforeHandshake(NativeProtocol.java:362)
    at com.mysql.cj.protocol.a.NativeProtocol.connect(NativeProtocol.java:1367)
    at com.mysql.cj.NativeSession.connect(NativeSession.java:133)
    at com.mysql.cj.jdbc.ConnectionImpl.connectWithRetries(ConnectionImpl.java:842)
    at com.mysql.cj.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:823)
    - locked <0x0000000722c7fc40> (a com.mysql.cj.jdbc.ConnectionImpl)
    at com.mysql.cj.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:448)
    at com.mysql.cj.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:241)
    at com.mysql.cj.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:198)
    at org.apache.spark.sql.execution.datasources.jdbc.connection.BasicConnectionProvider.getConnection(BasicConnectionProvider.scala:49)
    at org.apache.spark.sql.execution.datasources.jdbc.connection.ConnectionProvider$.create(ConnectionProvider.scala:68)
    - locked <0x0000000722c7fe18> (a org.apache.spark.security.SecurityConfigurationLock$)
    at org.apache.spark.sql.execution.datasources.jdbc.JdbcUtils$.$anonfun$createConnectionFactory$1(JdbcUtils.scala:62)
    at org.apache.spark.sql.execution.datasources.jdbc.JdbcUtils$$$Lambda$1606/936828380.apply(Unknown Source)
    at org.apache.spark.sql.execution.datasources.jdbc.JdbcRelationProvider.createRelation(JdbcRelationProvider.scala:48)
    at org.apache.spark.sql.execution.datasources.SaveIntoDataSourceCommand.run(SaveIntoDataSourceCommand.scala:46)
    at org.apache.spark.sql.execution.command.ExecutedCommandExec.sideEffectResult$lzycompute(commands.scala:70)
    - locked <0x0000000722c96c18> (a org.apache.spark.sql.execution.command.ExecutedCommandExec)
    at org.apache.spark.sql.execution.command.ExecutedCommandExec.sideEffectResult(commands.scala:68)
    at org.apache.spark.sql.execution.command.ExecutedCommandExec.doExecute(commands.scala:90)
    at org.apache.spark.sql.execution.SparkPlan.$anonfun$execute$1(SparkPlan.scala:180)
    at org.apache.spark.sql.execution.SparkPlan$$Lambda$1492/203829039.apply(Unknown Source)
    at org.apache.spark.sql.execution.SparkPlan.$anonfun$executeQuery$1(SparkPlan.scala:218)
    at org.apache.spark.sql.execution.SparkPlan$$Lambda$1516/376234567.apply(Unknown Source)
    at org.apache.spark.rdd.RDDOperationScope$.withScope(RDDOperationScope.scala:151)
    at org.apache.spark.sql.execution.SparkPlan.executeQuery(SparkPlan.scala:215)
    at org.apache.spark.sql.execution.SparkPlan.execute(SparkPlan.scala:176)
    at org.apache.spark.sql.execution.QueryExecution.toRdd$lzycompute(QueryExecution.scala:132)
    - locked <0x0000000722ca3c78> (a org.apache.spark.sql.execution.QueryExecution)
    at org.apache.spark.sql.execution.QueryExecution.toRdd(QueryExecution.scala:131)
    at org.apache.spark.sql.DataFrameWriter.$anonfun$runCommand$1(DataFrameWriter.scala:989)
    at org.apache.spark.sql.DataFrameWriter$$Lambda$1379/456240898.apply(Unknown Source)
    at org.apache.spark.sql.execution.SQLExecution$.$anonfun$withNewExecutionId$5(SQLExecution.scala:103)
    at org.apache.spark.sql.execution.SQLExecution$$$Lambda$1387/862090614.apply(Unknown Source)
    at org.apache.spark.sql.execution.SQLExecution$.withSQLConfPropagated(SQLExecution.scala:163)
    at org.apache.spark.sql.execution.SQLExecution$.$anonfun$withNewExecutionId$1(SQLExecution.scala:90)
    at org.apache.spark.sql.execution.SQLExecution$$$Lambda$1380/1008095885.apply(Unknown Source)
    at org.apache.spark.sql.SparkSession.withActive(SparkSession.scala:775)
    at org.apache.spark.sql.execution.SQLExecution$.withNewExecutionId(SQLExecution.scala:64)
    at org.apache.spark.sql.DataFrameWriter.runCommand(DataFrameWriter.scala:989)
    at org.apache.spark.sql.DataFrameWriter.saveToV1Source(DataFrameWriter.scala:438)
    at org.apache.spark.sql.DataFrameWriter.saveInternal(DataFrameWriter.scala:415)
    at org.apache.spark.sql.DataFrameWriter.save(DataFrameWriter.scala:301)
    at org.apache.spark.sql.DataFrameWriter.jdbc(DataFrameWriter.scala:817)
    at com.pandora.spark.task.job.EsSparkSqlRecordDataHandle.main(EsSparkSqlRecordDataHandle.java:111)

   Locked ownable synchronizers:
    - None

通过对下面的堆栈剖析能够发现 main 线程的状态为:RUNNABLE,且阻塞在办法

ReadAheadInputStream.fill(ReadAheadInputStream.java:107),通过查看配置发现没有配置相干 connectTimeout 和 socketTimeout 等参数,通过配置下面超时参数之后,就呈现其它的报错。

05 零碎运行越来越慢

5.1 概述

零碎迟缓个别是因为如下几个起因造成的:

  1. 堆内存透露造成的内存不足,导致系统越来越慢,直到进行。
  2. Xmx 设置太小造成的堆内存不足,导致系统越来越慢,直到进行。
  3. 零碎呈现死循环,耗费了过多的 CPU。参考上一节的内容
  4. 资源有余导致性零碎运行越来越慢。

5.2 内存透露

5.2.1 定位形式

判断零碎是否存在内存透露的根据是:如果零碎存在内存透露,那么在实现垃圾回收之后的内存值应该持续上升。如果在现场能察看到这个景象,阐明零碎存在内存透露。当狐疑 一个零碎存在内存透露的时候,首先应用 FULL GC 信息对内存透露进行一个初步确认,确认零碎是否存在内存透露。只查看齐全垃圾回收后的可用内存值是否始终再增大,步骤如下:

  • 首先截取零碎稳固运行当前的 GC 信息(如初始化曾经实现),这个十分重要,非稳固运行 期的信息无剖析价值,因为你无奈确认内存的增长是失常的增长还是因为内存透露导致 的非正常增长。
  • 过滤出 FULL GC 的行。只有 FULL GC 的行才有剖析价值。因为实现 GC 后的内存是以后 Java 对象真正应用的内存数量。个别零碎会有两种可能:
    • 如果实现垃圾回收后的内存持续增长,大有始终增长到 Xmx 设定值的趋势,那么这 个时候基本上就能够判定零碎存在内存透露。
    • 如果以后实现垃圾回收后内存增长到一个值之后,又能回落,总体上处于一个动静 均衡,那么内存透露根本能够排除。

通过如上内存应用趋势剖析之后,基本上就能确定零碎是否存在堆内存透露。当然这 种 GC 信息剖析只能通知你零碎是否存在堆内存透露,但具体哪里透露,它是无奈通知你的。内存透露的的精确定位,是要找到内存透露的具体位置,须要通过 dump 内存堆栈,通过其内存堆栈剖析工具能力找到真正导致内存透露的类或者对象。

5.2.2 案例

jvm 监控:

内存堆栈剖析:

通过内存堆栈,定位到如下代码

起因猜想:

1. 通过 jvm 的内存监控上看,这个透露几天,而且透露的速度是一条直线(近似匀速),如果是业务调用导致内存透露应该会有起伏,猜想可能是定时工作调用 dubbo 的逻辑。

验证

5.3 资源有余

5.3.1 特点和定位办法

特点:如资源有余,那么会存在大量的线程在期待资源,打印的线程堆栈如果具备这个特色,那么就阐明该系统资源是瓶颈。对于资源有余导致性能降落,打印出的线程堆栈中会存在大量的线程停在同样的调用上下文中。

资源有余或者资源应用不失当,体现进去往往是一个性能问题。零碎越来越慢,并最终进行响应。遇到零碎变慢等问题,定位问题的办法是打印线程堆栈。

5.3.2 可能的起因

5.3.3 案例

备注:过后没有对服务打印线程堆栈。

从监控上看,数据库的连接池曾经打满 (连接池过后配置的 60)。从客户端角度来看,过后客户端单机的 cpu、memory 都没有应用满,从服务端(mysql) 来看,db 没有任何异样。因而能够看出瓶颈卡在数据库连贯上。

从具体的业务场景来剖析,该问题有两种解决方案:

计划一:资源隔离法。因为从该业务上看,只有流量上报和回放上报的接口的 qps 高,而平台的其余接口 qps 低,并且都是平台后盾的基本操作的办法。将流量上报和回放上报应用一个数据库连接池,平台的其余接口应用另外一个连接池。

计划二:进步数据库的连接池,该形式有点毛病是会影响后盾的页面操作, 呈现页面卡顿的状况。

06 性能剖析

6.1 概述

线程堆栈进行性能剖析应用场景:多线程场合下的性能瓶颈定位。特地是锁的使用不当,导致的性能瓶颈。

改善性能意味着用更少的资源做更多的事。当线程的运行因某个特定资源碰壁时,称之为受限该资源:受限数据库、受限对端的解决能力。

性能调优的终极目标是零碎的 CPU 利用率靠近 100%。如果零碎的 CPU 没有被充分利用,那么可能存在如下问题:施加的压力有余,可能被测试的零碎没有被退出到足够的压力(负载),这时候能够通过减少压力,检测零碎的响应工夫、服务失败率和 CPU 使用率状况。如果减少压力,零碎开始呈现局部服务失败,零碎的响应工夫变慢,或者 CPU 的使用率无奈再回升,那么此时的压力应该是零碎的饱和压力。即此时的能力是零碎以后的最大能力。

零碎存在瓶颈:当零碎在饱和压力下,如果 CPU 的使用率没有靠近 100%,那么阐明这个零碎性能的还有晋升的空间。如果零碎存在如下问题,那么能够应用线程堆栈查找性能瓶颈的办法进行问题定位。

  • 继续运行迟缓。时常发现利用程序运行迟缓。通过扭转环境因子 (如数据库连接数等) 也无奈无效晋升整体响应工夫
  • 零碎性能随工夫的减少逐步降落。在负载稳固的状况下,零碎运行工夫越长速度越慢。可能是因为超出某个阈值范畴,零碎运行频繁出错从而导致系统死锁或解体。
  • 零碎性能随负载的减少逐步降落。随着用户数目标增多,应用程序的运行越发迟缓。若干用户退出零碎,应用程序便可能恢复正常运行状态。

6.2 常见的性能瓶颈

  • 因为不失当的同步导致的资源争用
    • 不相干的两个函数,共用了一个锁或者不同的共享变量共用了一个锁,无谓地制作出了资源争用
    • 锁的粒度过大,对共享资源拜访实现之后,没有将后续的代码放在 synchronized 同步代码块之外。
  • sleep 的滥用:sleep 只适宜用在期待固定时长的场合,如果轮询代码中夹杂着 sleep()调用,这 种设计必然是一种蹩脚的设计。这种设计在某些场合下会导致重大的性能瓶颈。
  • String + 滥用
  • 不失当的线程模型:在多线程场合下,如果线程模型不失当,也会使性能低下。
  • 效率低下的 SQL 语句或者不失当的数据库设计
  • 线程数量有余:在应用线程池的场合,如果线程池的线程配置太少,也会导致性能低下。
  • 内存透露导致的频繁 GC:内存透露会导致 GC 越来越频繁,而 GC 操作是 CPU 密集型操作,频 繁 GC 会导致系统整体性能重大降落。

6.3 压测发现性能瓶

性能瓶颈的特色

  • 以后的性能瓶颈只有一处,只有当解决的这一块,才晓得下一处。没有解决以后的性能瓶颈,下一处性能瓶颈是不会呈现的
  • 性能瓶颈是动静的,低负载下不是瓶颈的中央,在高负载下可能成为瓶颈。

6.4 如何通过线程堆栈辨认性能瓶颈

一个零碎一旦呈现性能瓶颈,从堆栈上剖析,有如下三种最为典型的堆栈特色:

  1. 绝大多数线程的堆栈都体现为在同一个调用上下文上,且只剩下非常少的闲暇线程。可能的起因如下:
  • 线程的数量过少
  • 锁的粒度过大导致的锁竞争。
  • 资源竞争(如数据库连接池中连贯有余,导致有些希图获取连贯的线程被阻塞)
  • 锁范畴内有大量耗时操作(如大量的磁盘 IO),导致锁争用。
  • 近程通信的对方解决迟缓(甚至导致 socket 缓冲区写满),如数据库侧的 SQL 代码性能 低下。
  1. 绝大多数线程处于期待状态,只有几个工作的线程,总体性能上不去。可能的起因是,系 统存在要害门路,在该要害门路上没有足够的能力给下个阶段输送大量的工作,导致其 它中央闲暇。如在音讯散发零碎,音讯散发个别是一个线程,而音讯解决是多个线程,这 时候音讯散发是瓶颈的话,那么从线程堆栈就会察看到下面提到的景象: 即该要害门路 没有足够的能力给下个阶段输送大量的工作,导致其它中央闲暇。
  2. 线程总的数量很少。导致性能瓶颈的起因与下面的相似。这里线程很少,是因为某些线 程池实现应用另一种设计思路,当工作来了之后才 new 出线程来,这种实现形式下,线程 的数量上不去,就象征有在某处要害门路上没有足够的能力给下个阶段输送大量的工作,从而不须要更多的线程来解决。

6.5 线程堆栈进行性能剖析总结

07 总结

本文是在浏览《java 问题定位技术》等相干书籍和文档,联合产生在生产环境下的实在案例下进行梳理和总结,一方面晋升问题排查能力,同时也对其进行总结和提炼,另外一方面心愿通过总结和提炼本文可能帮忙到大家晋升问题排查能力和对线程堆栈的充分认识。

08 参考资料

《java 问题定位技术》

文 / 小宝

关注得物技术,做最潮技术人

正文完
 0