Java性能问题定位

系统负载

  1. top
    top
  1. uptime
    uptime

image.png | left | 532x47
通过这两个常用的linux命令，我们可以大致了解我们的系统负载以及每个运行进程的资源消耗。

load average 的三个数字分别代表：最近1分钟 5分钟 15分钟的系统负载，上图中该值分别是：1.71 1.24 1.09。

问题分类

常见的问题有：

  • CPU异常高，甚至到100%
  • IO wait过高
  • JVM进程Hang
  • OOM
  • 内存泄露
  • 频繁GC
  • ......

问题定位工具

jconsole

Starts a graphical console that lets you monitor and manage Java applications

一个监控和管理java应用程序的图像化界面。

TIM截图20180904141459.png | center | 683x356

jps

列出本地或者远程主机上的所有JVM进程。

使用方法：

jps [options] [hostid]

options:

  • -m : 显示传递给main方法的参数，即main(String[] args)中的args
    • l : 显示主类的全限定包名或者jar包的全路径名
  • -v : 显示传递给JVM的参数
  • -q : 仅仅显示jvm进程id

hostid： 由[:]组成。

例如：

jps -lm

image.png | left | 636x49

jstack

jstack - Prints Java thread stack traces for a Java process, core file, or remote debug server.

主要JVM进程的线程栈信息：
用法：

  • jstack [options] [pid]
  • jstack [options] executable core：可以从Core File中读取线程栈信息
  • jstack [options] [serverid@]remote-hostname-or-ip

options:

  • -F (Force)当jstack pid无响应的时候，强制打印stack trace 信息
  • -l （long listing）打印额外的关于该线程的锁的信息
  • -m (mixed)打印混合的stack trace信息，除了java线程栈、还有native c/c++栈

例如：一段出现死锁的代码，运行在线程

public class DeadLock {
	public static void main(String[] args) {
		Object left = new Object(), right = new Object();
		new Thread(new MTask(left, right)).start();
		new Thread(new MTask(right, left)).start();

	}

}

class MTask implements Runnable{
	
	private Object left, right;

	public MTask() {
	}

	public MTask(Object left, Object right) {
		this.left = left;
		this.right = right;
	}

	@Override
	public void run() {
		synchronized(left) {
			System.out.println("Hold lock@" + left + "waiting for lock@" + right);
			synchronized(right){
				
			}
		}
	}
}

运行这段代码，直到产生死锁。

产生死锁后，使用jstack命令查看：
首先通过jsp找到jvm进程id，然后运行jstack。


jstack -l 

2018-09-04 17:25:10
Full thread dump OpenJDK 64-Bit Server VM (25.03-b03 mixed mode):

"Attach Listener" #21 daemon prio=9 os_prio=0 tid=0x00007f2be0001000 nid=0x8e8b waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"DestroyJavaVM" #20 prio=5 os_prio=0 tid=0x00007f2c68009800 nid=0x8dc2 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"Thread-1" #19 prio=5 os_prio=0 tid=0x00007f2c68141800 nid=0x8de7 waiting for monitor entry [0x00007f2bcf5f4000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at MTask.run(DeadLock.java:30)
	- waiting to lock <0x000000067205cfd8> (a java.lang.Object)
	- locked <0x000000067205cfe8> (a java.lang.Object)
	at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
	- None

"Thread-0" #18 prio=5 os_prio=0 tid=0x00007f2c68140000 nid=0x8de6 waiting for monitor entry [0x00007f2bcf6f5000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at MTask.run(DeadLock.java:30)
	- waiting to lock <0x000000067205cfe8> (a java.lang.Object)
	- locked <0x000000067205cfd8> (a java.lang.Object)
	at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
	- None

"Service Thread" #17 daemon prio=9 os_prio=0 tid=0x00007f2c680e1000 nid=0x8de4 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"C1 CompilerThread11" #16 daemon prio=9 os_prio=0 tid=0x00007f2c680dc000 nid=0x8de3 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"C1 CompilerThread10" #15 daemon prio=9 os_prio=0 tid=0x00007f2c680da800 nid=0x8de2 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"C1 CompilerThread9" #14 daemon prio=9 os_prio=0 tid=0x00007f2c680d8000 nid=0x8de1 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"C1 CompilerThread8" #13 daemon prio=9 os_prio=0 tid=0x00007f2c680d6000 nid=0x8de0 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"C2 CompilerThread7" #12 daemon prio=9 os_prio=0 tid=0x00007f2c680d4800 nid=0x8ddf waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"C2 CompilerThread6" #11 daemon prio=9 os_prio=0 tid=0x00007f2c680d2000 nid=0x8dde waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"C2 CompilerThread5" #10 daemon prio=9 os_prio=0 tid=0x00007f2c680d0800 nid=0x8ddd waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"C2 CompilerThread4" #9 daemon prio=9 os_prio=0 tid=0x00007f2c680ce000 nid=0x8ddc waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"C2 CompilerThread3" #8 daemon prio=9 os_prio=0 tid=0x00007f2c680cc000 nid=0x8ddb waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"C2 CompilerThread2" #7 daemon prio=9 os_prio=0 tid=0x00007f2c680c7800 nid=0x8dda waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"C2 CompilerThread1" #6 daemon prio=9 os_prio=0 tid=0x00007f2c680c6000 nid=0x8dd9 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"C2 CompilerThread0" #5 daemon prio=9 os_prio=0 tid=0x00007f2c680c3000 nid=0x8dd8 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

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

   Locked ownable synchronizers:
	- None

"Finalizer" #3 daemon prio=8 os_prio=0 tid=0x00007f2c68099800 nid=0x8dd6 in Object.wait() [0x00007f2bf5184000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x0000000672008ee0> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
	- locked <0x0000000672008ee0> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
	at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

   Locked ownable synchronizers:
	- None

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

   Locked ownable synchronizers:
	- None

"VM Thread" os_prio=0 tid=0x00007f2c6808d800 nid=0x8dd4 runnable 

"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007f2c6801f000 nid=0x8dc5 runnable 

"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007f2c68020800 nid=0x8dc6 runnable 

"GC task thread#2 (ParallelGC)" os_prio=0 tid=0x00007f2c68022800 nid=0x8dc7 runnable 

"GC task thread#3 (ParallelGC)" os_prio=0 tid=0x00007f2c68024000 nid=0x8dc8 runnable 

"GC task thread#4 (ParallelGC)" os_prio=0 tid=0x00007f2c68026000 nid=0x8dc9 runnable 

"GC task thread#5 (ParallelGC)" os_prio=0 tid=0x00007f2c68027800 nid=0x8dca runnable 

"GC task thread#6 (ParallelGC)" os_prio=0 tid=0x00007f2c68029800 nid=0x8dcb runnable 

"GC task thread#7 (ParallelGC)" os_prio=0 tid=0x00007f2c6802b000 nid=0x8dcc runnable 

"GC task thread#8 (ParallelGC)" os_prio=0 tid=0x00007f2c6802d000 nid=0x8dcd runnable 

"GC task thread#9 (ParallelGC)" os_prio=0 tid=0x00007f2c6802e800 nid=0x8dce runnable 

"GC task thread#10 (ParallelGC)" os_prio=0 tid=0x00007f2c68030800 nid=0x8dcf runnable 

"GC task thread#11 (ParallelGC)" os_prio=0 tid=0x00007f2c68032000 nid=0x8dd0 runnable 

"GC task thread#12 (ParallelGC)" os_prio=0 tid=0x00007f2c68034000 nid=0x8dd1 runnable 

"GC task thread#13 (ParallelGC)" os_prio=0 tid=0x00007f2c68035800 nid=0x8dd2 runnable 

"GC task thread#14 (ParallelGC)" os_prio=0 tid=0x00007f2c68037800 nid=0x8dd3 runnable 

"VM Periodic Task Thread" os_prio=0 tid=0x00007f2c680e3800 nid=0x8de5 waiting on condition 

JNI global references: 6


Found one Java-level deadlock:
=============================
"Thread-1":
  waiting to lock monitor 0x00007f2be80060b8 (object 0x000000067205cfd8, a java.lang.Object),
  which is held by "Thread-0"
"Thread-0":
  waiting to lock monitor 0x00007f2be8003828 (object 0x000000067205cfe8, a java.lang.Object),
  which is held by "Thread-1"

Java stack information for the threads listed above:
===================================================
"Thread-1":
	at MTask.run(DeadLock.java:30)
	- waiting to lock <0x000000067205cfd8> (a java.lang.Object)
	- locked <0x000000067205cfe8> (a java.lang.Object)
	at java.lang.Thread.run(Thread.java:745)
"Thread-0":
	at MTask.run(DeadLock.java:30)
	- waiting to lock <0x000000067205cfe8> (a java.lang.Object)
	- locked <0x000000067205cfd8> (a java.lang.Object)
	at java.lang.Thread.run(Thread.java:745)

Found 1 deadlock.

可以看见jstack能检查到死锁的存在，并显示哪些线程发生了死锁；同时jstack也显示了线程等待在哪些锁上面，而这些锁现在正在被哪些线程拥有。因此jstack主要是用来查看java代码的线程是否存在死锁等问题。

jmap

Prints shared object memory maps or heap memory details for a process, core file, or remote debug server.

jmap主要被用来分析堆内存的工具。
用法：

  • jmap [options] pid
  • jmap [options] executable core
  • jmap [options] [pid] server-id@remote-or-IP

常见的options：

  • -dump:[live,]format=b,file=filename：将java heap信息dump成hprof格式的二进制文件，子选项live被指定的时候，仅仅那些存活的堆内存中对象才会被dump出来。被dump出来的文件可以通过__jhat__工具查看。
  • -finalizerinfo ： 打印关于正在等待finalization的对象的信息。
  • -heap：打印一些堆内存的概要信息，例如使用的GC、堆内存的配置、分代列出堆的使用情况等等；
  • -histo[:live]：打印堆的直方图。对于每个类，有多少个对应的对象，占用的内存大小。
  • -clstats：打印类加载器级别的统计信息，例如对于每个类加载器，它的名字，活跃度，地址，父类加载器，和该类加载器已经加载的类的数量和大小。

示例以一：分代查看堆内存使用情况

jmap --heap pid

TIM截图20180904193404.png | center | 568x934

  • 可以观察到使用的GC器为4线程的Paralle GC。
  • 堆配置：
    • young代的堆最小值为 85Mb，最大值为1358MB；
    • old代的堆的大小为：172MB
    • 两个比例：
      • NewRatio：Old代与Young代的内存比例为2，即老年代的堆内存占总的堆内存的的2/3
      • SurvivalRatio：Young代中Eden区和Survival区域的比例，因为存在两个Survival区域（from、to），因此Survival区域的大小占新生代内存的1/10，但是这个比例怎么不太对呢......
  • 堆内存使用情况：
    • 新生代的Eden区
    • 新生代的From、To Survivor区
    • 老年代区域

示例二：查看堆内存直方图：

jmap --hist pid

TIM截图20180904195957.png | center | 659x658

示例三：查看类加载的信息

jmap --clstats pid

TIM截图20180904200236.png | center | 827x239

这里可以观察到类加载的层次结构：

一共三个类加载器：

  • Bootstrap
  • ExtClassLoader的实例 0x76b2b7f00
  • AppClassLoader的实例 0x76b2c3138，父加载器是 0x76b2b7f00

双亲委派模型中就涉及到了如下层次结构：

  • BootStrap：加载<JAVA_HOME>/lib目录下类文件，该加载器无法被程序直接引用，用户在编写自定义类加载的时候，如果需要将加载请求委托给BootStrap类加载器，直接使用null代替即可。
    • ExtClassLoader：负载加载<JAVA_HOME>libext目录中类文件，开发者可以直接使用扩展类加载器；
      • AppClassLoader：该类加载是ClassLoader::getSystemClassLoader的返回值，所以也成为系统类加载器，负载加载用户ClassPath下的类文件。
        • User ClassLoader

jhat

Analyzes the Java heap.

用法：jhat [options] heap_dum_file

jhat解析java heap dump出来的hprof文件，然后开启一个web服务器。然后我们可以在机器的7000端口通过浏览器访问到这个堆的信息，同时还提供一种OOL查询语言，用来查询堆内存中的一些对象和类信息。

对于使用jmap dump出来的hprof文件，使用jhat可以用作离线分析。

image.png | center | 747x311

image.png | left | 747x241

【推广】 免费学中医，健康全家人
原文地址：https://www.cnblogs.com/Spground/p/9571389.html