Java性能分析工具JMC使用教程

JMC java mission control是java性能分析利器.从实践出发,学习如何使用.
本文从JMC Tutorial英文版中提炼出来,涵盖了文中所有重要的topic.请点击下载所有源代码.

Install JMC

从java7自带JMC,示例使用java 8环境. 可以执行JAVA_HOME/bin/jmc来启动JMC.

也可以作为eclipse插件安装,从略.

JFR使用

Java Flight Recorder (JFR)顾名思义,就是java运行情况的黑匣子. 先启动Java进程,然后使用JFR记录程序运行情况.需要在启动命令行加参数 -XX:+UnlockCommercialFeatures -XX:+FlightRecorder

解压源代码,在目录下10_Console_LoadAndDeadlock/bin 启动:java -XX:+UnlockCommercialFeatures -XX:+FlightRecorder LoadAndDeadlock

把jmc关联到java进程

jmc截图

点击启动飞行记录,点击保存.

飞行记录

一分钟之后可以看到应用程序的统计采样.

Hot Methods

目标:使用JMC找到进程中的Hot Spot,也就是耗费时间最多的代码段.

使用JMC代开文件02_JFR_HotMethods/hotmethods.jfr.分析这个JFR记录文件.

可以看到这个耗费最多执行时间点的方法调用

public class Initiator {
	private Collection<Integer> collection;

	public Initiator() {
		collection = new LinkedList<Integer>();
	}

	// Hint: This creates a list of unique elements!
	public void initiate(int seed) {
		collection.clear();
		for (int i = 1; i < 10000; i++) {
			if ((i % seed) != 0)
				collection.add(i);
		}
	}

	protected Collection<Integer> getCollection() {
		return collection;
	}

	public int countIntersection(Initiator other) {
		int count = 0;
		for (Integer i : collection) {
			if (other.getCollection().contains(i)) {
				count++;
			}
		}
		return count;
	}
}

这个代码的问题在于countIntersection方法中是对两个LinkedList做遍历,和元素个数相关10000个元素的平方太大了,改成Hashset存储会修复这个问题.

Latencies

Latencies主要用来监控线程间阻塞等待:打开03_JFR_Latencies/latency.jfr,切换到Events->Graph的tab.我们看到粉红色的事件类型特别多.

提示信息是阻塞在Logger.log(String)这个方法上.

public class Logger {
	private static Logger myInstance = new Logger();
	
	public static Logger getLogger() {
		return myInstance;
	}


	public synchronized void log(String text) {
		LogEvent event = new LogEvent(CustomEventLatencies.LOG_EVENT_TOKEN, text);
		event.begin();
		// Do logging here
		// Write the text to a database or similar...
		try {
			// Simulate that this takes a little while.
			Thread.sleep(200);
		} catch (InterruptedException e) {
			// Don't care.
		}
		event.end();
		event.commit();
	}
}

可以看到是log方法,如果没有竞争资源的可以去掉synchronized关键字即可. 顺便看看fix之后理想的状态是这样的:

Note:在线程的tab争用的tab下面也提示了是哪个类带来的瓶颈.

GC垃圾回收

GC垃圾回收打开allocator.jfr在04_JFR_GC目录下: 可以看到很多的垃圾回收的动作,虽然都是defnew.新生代的垃圾回收,过于频繁也是问题.

切换到allcations看到对象是Integer,stack trace中看到分配的代码栈,是在Allocator.main->Allocator.go->Integer.valueOf方法中.

public class Allocator {
	// Integer -> MyAlloc
	private HashMap<Integer, MyAlloc> map = new HashMap<Integer, MyAlloc>();//FIX 使用int
	
	private static class MyAlloc {
		private int id;
		
		private MyAlloc(int id) {
			this.id = id;
		}
		
		private int getId() {
			return id;
		}
	}
	
	public static void main(String[] args) {
		new Allocator().go();
	}

	private void go() {
		alloc(10000);
		long yieldCounter = 0;
		while(true) {
			Collection<MyAlloc> myAllocSet = map.values();
			for (MyAlloc c : myAllocSet ) {
				if (!map.containsKey(c.getId())) //拆装箱
					System.out.println("Now this is strange!");
				if (++yieldCounter % 1000 == 0)
					Thread.yield();
			}
		}
	}

	private void alloc(int count) {
		for (int i = 0; i < count; i++) {
			map.put(i, new MyAlloc(i));
		}
	}
}

自动拆装箱生成了太多的无用Integer对象,Fix方案也很简单,使用原始类型int代替Integer.

Exception

Exception对于jvm来说比较耗京能,如果抛出太多异常也是需要关注的. 打开exceptions.jfr 在 06_JFR_Exceptions 从上图可以看到应用抛出的异常. 小技巧操作集:在上图中把ScaryException上点击右键加入到操作集合,想知道具体异常在什么时间抛出的去事件->日志 tab.选择只显示操作集.可以看到异常抛出的时间.

Mbean browser

Mbean的用处就不介绍了.在JMC左侧选取进程,然后选取Mbean 服务器. 会出现当前jvm进程的概览.有cpu内存等指标的dashboard,你可以在dashboard中添加自己关注的指标图表.

我们主要来看Mbean的tab.这里可以选取你关心的指标,可以看到老年代的垃圾收集器是PS MarkSweep.

可以查看当前的Thread相关的信息,比如当前的线程个数.

可以在诊断命令tab中执行想要执行的命令,比如获取线程的执行栈.

线程tab,可以检测死锁情况.点击死锁检测checkbox,看到Thread3 和Thread4是死锁状态.

触发器一栏可以设置知己关心的报警指标和条件.比如CPU使用率过高.

JCMD使用

先运行13_Memleak_Leak/bin下面执行:(参考launcers/Leak.launch)

java -Djava.net.preferIPv4Stack=true -XX:+UnlockCommercialFeatures -XX:+FlightRecorder -Xmx128m -Xms128m Leak 2 1

运行jcm命令,看到Leak的进程号是87728. 使用jcmd 87728 help命令查看可以使用的操作命令. 使用jcmd 87728 GC.class_histogram命令得到java堆的使用情况的统计数据. 过几分在运行一次得到当前的的堆的统计情况,可以看到Leak$DemoObject狂涨.

也可以使用jcm来启动一次JFR记录.并把记录文件dump出来

jcmd 87728 JFR.start
JFR.dump recording=1 filename=/tmp/leak.jfr
jcmd 87728 JFR.stop recording=1

以上三个命令分别是启动,dump,停止JFR.然后可以打开/tmp/leak.jfr文件来查看JFR记录.

其他

weblogic插件因为不常用略过了,感兴趣的同学可以查看原文.
Dtrace 是在Solaris上才能使用,本身对Dtrace背景要求比较高,可以使用Dtrace自带的各种探针.JMC默认是没有Dtrace插件的,先安装.在帮助菜单->安装新软件,选择Dtrace相关的插件.

参考

JMC tutorial