1

最近我们在我们的 java web 应用程序中升级了 hibernate jars。此次升级后,我们发现 CPU 使用率增加了 15-20%。之前和之后的唯一区别是hibernate jar版本。我需要确定 CPU 使用率增加的根本原因。我拍摄了 jvisualvm cpu profiler 快照并将它们转换为火焰图。从两个火焰图中,我看到堆栈跟踪是相同的,但 cpu % 存在差异。

在升级前后执行了具有相同用户负载和用例的负载测试。两个应用程序部署之间的唯一区别是hibernate jars。一个版本具有休眠 4.3.5,另一个具有 5.4.2。火焰图并没有指出休眠功能是导致 CPU 使用率增加的原因,因此我很困惑如何继续进行分析。

我需要一些关于如何比较两个火焰图并解决 cpu 使用率增加的根本原因的指导。请在这些链接中找到火焰图。

采样 5 分钟

之前的火焰图 - https://filebin.net/sxagcfs6lmtie654/old_report_5min.html?t=k4t2i379

之后的火焰图 - https://filebin.net/sxagcfs6lmtie654/report_5min.html?t=k4t2i379

之前的分析器快照 - https://filebin.net/sxagcfs6lmtie654/Old_Hibernate_Sampling_5Minute.nps?t=fvno95sr

之后的探查器快照 - https://filebin.net/sxagcfs6lmtie654/New_Hibernate_Sampling_5Minute.nps?t=fvno95sr

采样 30 分钟

之前的火焰图 - https://filebin.net/sxagcfs6lmtie654/old_report_30min.html?t=ttb7s4k4

之后的火焰图 - https://filebin.net/sxagcfs6lmtie654/report_30min.html?t=ttb7s4k4

之前的分析器快照 - https://filebin.net/sxagcfs6lmtie654/OldHibernateLibrary_30min.nps?t=fvno95sr

之后的探查器快照 - https://filebin.net/sxagcfs6lmtie654/LatestHibernateLibrary_30min.nps?t=fvno95sr

4

1 回答 1

1

比较两个采样会话的一个好方法是比较热方法直方图。它可以在 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.loadClassVisualVM 采样显示在方法中花费的时间增加。不幸的是,这是基于线程转储的采样的限制,您无法在本机方法中选择。

java.lanf.ClassLoader.loadClass两种旧的新方法的利用率都非常高,这让我在框架上有些误解。

java.lanf.ClassLoader.loadClass高时间可能是线程之间争用而不是实际 CPU 使用率的结果。尽管指标的相对变化让我们有理由认为它与 CPU 使用率增长的根本原因有关。

于 2019-07-30T08:35:15.380 回答