Jstack 分析哪一行代码慢 ?jvm 打印出线程栈分析

面试题:后台只有一台服务器,上线后发现,只有1个接口请求很慢,其他接口的请求和反应时间很正常,该怎么分析?怎么找出是哪行代码导致的慢?

是在线上,当然不能测试或单步调试。

答案:打印出线程栈分析。

什么是线程堆栈?
线程栈:
Java线程堆栈是某个时间对所有线程的一个快照,其中主要记录了如下信息
– 线程的名称
- 线程的ID
- 原生线程ID
- 线程的运行状态
- 锁的状态
- 调用堆栈,也就是每个线程在各个方法调用的栈
上面描述的信息,接下来我们会具体的介绍与分析
 

举例:

/**
 * @Author liuyazhou
 * @Date 2021/2/25 16:30
 * @Version 1.0
 * @Desc
 */


/**
 * 同步线程
 */
class SyncThread implements Runnable {
    private static int count;

    public SyncThread() {
        count = 0;
    }

    public synchronized static void method() {
        for (int i = 0; ; i++) {
            try {
                System.out.println(Thread.currentThread().getName() + ":" + (count++));
                Thread.sleep(100);
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
        }
    }

    public synchronized void run() {
        method();
    }
}

public class SynchronizedObject2 {


    public static void main(String[] args) {
        SyncThread syncThread1 = new SyncThread();
        SyncThread syncThread2 = new SyncThread();
        Thread thread1 = new Thread(syncThread1, "SyncThread1");
        Thread thread2 = new Thread(syncThread2, "SyncThread2");
        thread1.start();
        thread2.start();
    }
}

输出:

SyncThread1:.......
SyncThread1:81069
SyncThread1:81070
SyncThread1:81071
SyncThread1:81072
SyncThread1:81073
SyncThread1:81074
SyncThread1:.......

查看进程:

ZBMAC-f2b04ccbd:~ liuyazhou$ jps
26144 Launcher
95274 SynchronizedObject2
45701
26184 Jps
ZBMAC-f2b04ccbd:~ liuyazhou$

 

ZBMAC-f2b04ccbd:~ liuyazhou$ jstack 95274
2021-02-27 18:14:28
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.231-b11 mixed mode):

"RMI Scheduler(0)" #18 daemon prio=9 os_prio=31 tid=0x00007fa021065800 nid=0x9e03 waiting on condition [0x00007000102c2000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000006c000d6b8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1081)
	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

"RMI TCP Accept-0" #16 daemon prio=9 os_prio=31 tid=0x00007fa02106c800 nid=0xa203 runnable [0x00007000100bc000]
   java.lang.Thread.State: RUNNABLE
	at java.net.PlainSocketImpl.socketAccept(Native Method)
	at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:409)
	at java.net.ServerSocket.implAccept(ServerSocket.java:545)
	at java.net.ServerSocket.accept(ServerSocket.java:513)
	at sun.management.jmxremote.LocalRMIServerSocketFactory$1.accept(LocalRMIServerSocketFactory.java:52)
	at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.java:405)
	at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:377)
	at java.lang.Thread.run(Thread.java:748)

"Attach Listener" #14 daemon prio=9 os_prio=31 tid=0x00007fa022832800 nid=0xa303 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"DestroyJavaVM" #13 prio=5 os_prio=31 tid=0x00007fa026809000 nid=0xf03 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"SyncThread2" #12 prio=5 os_prio=31 tid=0x00007fa026808000 nid=0x5803 waiting for monitor entry [0x000070000feb6000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at SyncThread.method(SynchronizedObject2.java:20)
	- waiting to lock <0x00000006c0012348> (a java.lang.Class for SyncThread)
	at SyncThread.run(SynchronizedObject2.java:31)
	- locked <0x00000006c00123b8> (a SyncThread)
	at java.lang.Thread.run(Thread.java:748)

"SyncThread1" #11 prio=5 os_prio=31 tid=0x00007fa0260a2000 nid=0xa603 waiting on condition [0x000070000fdb3000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
	at java.lang.Thread.sleep(Native Method)
	at SyncThread.method(SynchronizedObject2.java:23)
	- locked <0x00000006c0012348> (a java.lang.Class for SyncThread)
	at SyncThread.run(SynchronizedObject2.java:31)
	- locked <0x00000006c0012dd0> (a SyncThread)
	at java.lang.Thread.run(Thread.java:748)

"Service Thread" #10 daemon prio=9 os_prio=31 tid=0x00007fa0260a1000 nid=0xa903 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C1 CompilerThread3" #9 daemon prio=9 os_prio=31 tid=0x00007fa02380c000 nid=0x5503 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread2" #8 daemon prio=9 os_prio=31 tid=0x00007fa024802000 nid=0x3c03 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" #7 daemon prio=9 os_prio=31 tid=0x00007fa027002000 nid=0x3e03 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #6 daemon prio=9 os_prio=31 tid=0x00007fa02101f800 nid=0x3f03 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Monitor Ctrl-Break" #5 daemon prio=5 os_prio=31 tid=0x00007fa021846800 nid=0x3903 runnable [0x000070000f69e000]
   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 sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
	at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
	at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
	- locked <0x00000006c0023918> (a java.io.InputStreamReader)
	at java.io.InputStreamReader.read(InputStreamReader.java:184)
	at java.io.BufferedReader.fill(BufferedReader.java:161)
	at java.io.BufferedReader.readLine(BufferedReader.java:324)
	- locked <0x00000006c0023918> (a java.io.InputStreamReader)
	at java.io.BufferedReader.readLine(BufferedReader.java:389)
	at com.intellij.rt.execution.application.AppMainV2$1.run(AppMainV2.java:64)

"Signal Dispatcher" #4 daemon prio=9 os_prio=31 tid=0x00007fa02600e000 nid=0x3803 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" #3 daemon prio=8 os_prio=31 tid=0x00007fa02101b800 nid=0x3103 in Object.wait() [0x000070000f392000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144)
	- locked <0x00000006c002d448> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:165)
	at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:216)

"Reference Handler" #2 daemon prio=10 os_prio=31 tid=0x00007fa024801800 nid=0x4a03 in Object.wait() [0x000070000f28f000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	at java.lang.Object.wait(Object.java:502)
	at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
	- locked <0x00000006c0023af8> (a java.lang.ref.Reference$Lock)
	at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)

"VM Thread" os_prio=31 tid=0x00007fa022016800 nid=0x4b03 runnable 

"GC task thread#0 (ParallelGC)" os_prio=31 tid=0x00007fa021001000 nid=0x1c07 runnable 

"GC task thread#1 (ParallelGC)" os_prio=31 tid=0x00007fa024800000 nid=0x2003 runnable 

"GC task thread#2 (ParallelGC)" os_prio=31 tid=0x00007fa021001800 nid=0x1d03 runnable 

"GC task thread#3 (ParallelGC)" os_prio=31 tid=0x00007fa024801000 nid=0x2a03 runnable 

"GC task thread#4 (ParallelGC)" os_prio=31 tid=0x00007fa025000000 nid=0x5303 runnable 

"GC task thread#5 (ParallelGC)" os_prio=31 tid=0x00007fa023800800 nid=0x5103 runnable 

"GC task thread#6 (ParallelGC)" os_prio=31 tid=0x00007fa021002800 nid=0x2b03 runnable 

"GC task thread#7 (ParallelGC)" os_prio=31 tid=0x00007fa021003000 nid=0x4f03 runnable 

"GC task thread#8 (ParallelGC)" os_prio=31 tid=0x00007fa025800000 nid=0x2d03 runnable 

"GC task thread#9 (ParallelGC)" os_prio=31 tid=0x00007fa024005800 nid=0x2e03 runnable 

"VM Periodic Task Thread" os_prio=31 tid=0x00007fa022031800 nid=0xa703 waiting on condition 

JNI global references: 231

ZBMAC-f2b04ccbd:~ liuyazhou$ 

Java线程状态转化

-------------------------------------

我们使用jdk自带的jstack来分析。当linux出现cpu被java程序消耗过高时,以下过程说不定可以帮上你的忙:

1.top查找出哪个进程消耗的cpu高
21125 co_ad2    18   0 1817m 776m 9712 S  3.3  4.9  12:03.24 java                                                                                          
5284 co_ad     21   0 3028m 2.5g 9432 S  1.0 16.3   6629:44 java                                                                                          
21994 mysql     15   0  449m  88m 5072 S  1.0  0.6  67582:38 mysqld                                                                                        
8657 co_sparr  19   0 2678m 892m 9220 S  0.3  5.7 103:06.13 java

这里我们分析21125这个java进程。

2.top中shift+h查找出哪个线程消耗的cpu高
先输入top,然后再按shift+h
21233 co_ad2    15   0 1807m 630m 9492 S  1.3  4.0   0:05.12 java                                                                                          
20503 co_ad2_s  15   0 1360m 560m 9176 S  0.3  3.6   0:46.72 java                                                                                          
21134 co_ad2    15   0 1807m 630m 9492 S  0.3  4.0   0:00.72 java                                                                                          
22673 co_ad2    15   0 1807m 630m 9492 S  0.3  4.0   0:03.12 java

这里我们分析21233这个线程,并且注意的是,这个线程是属于21125这个进程的。

3.jstack查找这个线程的信息
jstack [进程]|grep -A 10 [线程的16进制]
即:

Java代码 

  1. jstack 21125|grep -A 10 52f1  


-A 10表示查找到所在行的后10行。21233用计算器转换为16进制52f1,注意字母是小写。
结果:

Java代码 

  1. "http-8081-11" daemon prio=10 tid=0x00002aab049a1800 nid=0x52bb in Object.wait() [0x0000000042c75000]  
  2.    java.lang.Thread.State: WAITING (on object monitor)  
  3.      at java.lang.Object.wait(Native Method)  
  4.      at java.lang.Object.wait(Object.java:485)  
  5.      at org.apache.tomcat.util.net.JIoEndpoint$Worker.await(JIoEndpoint.java:416)  


说不定可以一下子定位到出问题的代码。

 

参考 

https://blog.csdn.net/T1DMzks/article/details/82719998

https://www.iteye.com/topic/1114219

相关推荐
©️2020 CSDN 皮肤主题: 大白 设计师:CSDN官方博客 返回首页