比较两个采样会话的一个好方法是比较热方法直方图。它可以在 VisualVM 中或使用以下SJK命令来完成。
sjk ssa --histo --by-term -f OldHibernateLibrary_30min.nps
Trc (%) Frm N Term (%) Frame
64450 53% 64450 64450 53% java.util.concurrent.LinkedBlockingQueue.poll(Unknown Source)
22503 18% 22503 22503 18% sun.nio.ch.SocketChannelImpl.read(Unknown Source)
8954 7% 8954 8954 7% sun.nio.ch.SelectorImpl.select(Unknown Source)
6943 5% 6943 6943 5% java.lang.ClassLoader.loadClass(Unknown Source)
3828 3% 3828 3828 3% java.lang.Thread.sleep(Native Method)
1918 1% 1918 1918 1% java.lang.Object.wait(Native Method)
1674 1% 1674 1674 1% sun.nio.ch.SocketChannelImpl.write(Unknown Source)
...
Trc (%) Frm N Term (%) Frame
60427 44% 60427 60427 44% java.util.concurrent.LinkedBlockingQueue.poll(Unknown Source)
28568 21% 28568 28568 21% java.lang.ClassLoader.loadClass(Unknown Source)
23072 17% 23072 23072 17% sun.nio.ch.SocketChannelImpl.read(Unknown Source)
6181 4% 6181 6181 4% sun.nio.ch.SelectorImpl.select(Unknown Source)
3030 2% 3030 3030 2% java.lang.Thread.sleep(Native Method)
1542 1% 1542 1542 1% sun.nio.ch.SocketChannelImpl.write(Unknown Source)
1451 1% 1451 1451 1% java.util.concurrent.LinkedBlockingQueue.take(Unknown Source)
...
sjk ssa --histo --by-term -f LatestHibernateLibrary_30min.nps
简要浏览直方图,我可以发现java.lang.ClassLoader.loadClass
从 5% 增长到 21%(请注意,这是总样本数的百分比,它们不会转化为 CPU 使用率)。
假设两个快照都是在相同的负载下拍摄的(我无法从 VisualVM 快照中验证),我可以得出结论,这java.lang.ClassLoader.loadClass
是 CPU 使用率下降的罪魁祸首。
进一步过滤直方图
sjk ssa --histo --by-term -f OldHibernateLibrary_30min.nps -tf java.lang.ClassLoader.loadClass sjk ssa --histo --by-term -f LatestHibernateLibrary_30min.nps -tf java.lang.ClassLoader.loadClass
我看不出新旧版本之间没有区别,版本之间的使用模式保持不变。
java.lanf.ClassLoader.loadClass
从直方图我可以看到所有的路径org.springframework.orm.jpa.SharedEntityManagerCreator$SharedEntityManagerInvocationHandler.invoke
,所以有问题的路径在下面
java.lang.ClassLoader.loadClass(Unknown Source)
org.springframework.util.ClassUtils.isVisible(Unknown Source)
org.springframework.util.ClassUtils.getAllInterfacesForClassAsSet(Unknown Source)
org.springframework.util.ClassUtils.getAllInterfacesForClassAsSet(Unknown Source)
org.springframework.orm.jpa.ExtendedEntityManagerCreator.createProxy(Unknown Source)
org.springframework.orm.jpa.ExtendedEntityManagerCreator.createProxy(Unknown Source)
org.springframework.orm.jpa.ExtendedEntityManagerCreator.createApplicationManagedEntityManager(Unknown Source)
org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.invokeProxyMethod(Unknown Source)
org.springframework.orm.jpa.AbstractEntityManagerFactoryBean$ManagedEntityManagerFactoryInvocationHandler.invoke(Unknown Source)
com.sun.proxy.$Proxy671.createEntityManager(Unknown Source)
com.spmsoftware.appframework.persistence.MultitenantEntityManagerFactory.createEntityManager(Unknown Source)
org.springframework.orm.jpa.SharedEntityManagerCreator$SharedEntityManagerInvocationHandler.invoke(Unknown Source)
结论
java.lanf.ClassLoader.loadClass
VisualVM 采样显示在方法中花费的时间增加。不幸的是,这是基于线程转储的采样的限制,您无法在本机方法中选择。
java.lanf.ClassLoader.loadClass
两种旧的新方法的利用率都非常高,这让我在框架上有些误解。
java.lanf.ClassLoader.loadClass
高时间可能是线程之间争用而不是实际 CPU 使用率的结果。尽管指标的相对变化让我们有理由认为它与 CPU 使用率增长的根本原因有关。