【发布时间】:2010-11-19 05:55:09
【问题描述】:
我正在使用第 3 方库,它可以动态创建 Java 类的实例并在 Introspector.getBeanInfo 的帮助下填充这些实例。某些请求可能会导致 5 或 6 次连续调用 Introspector.getBeanInfo。我发现当应用程序空闲大约一个小时左右时,对Introspector.getBeanInfo 的第一次调用与后续调用(
在尝试使用简单的测试应用程序重新创建该行为时,我发现当 Java 应用程序本身没有运行一个小时时会出现类似的行为。例如,如果我运行以下控制台应用程序,可能需要 15 毫秒才能完成。如果我然后等待一个小时并重新运行应用程序,则需要 20 秒才能完成。
long start = System.currentTimeMillis();
System.out.println("Start");
Introspector.getBeanInfo(MyClass.class, Object.class);
long end = System.currentTimeMillis();
System.out.println("End: " + (end-start));
我最初认为该问题可能与 Introspector 类尝试基于我的应用程序中不存在的标准命名约定(例如,MyClassBeanInfo)创建类的实例有关,并且它占用了很长时间来扫描 jar 文件以试图找到这些类(我的 java 应用程序有 100 多个引用的 jar 文件),但我使用反射调用了Introspector.getBeanInfo(MyClass.class, Object.class, Introspector.IGNORE_ALL_BEANINFO)(这是 Sun 的 JRE 中的一个私有方法,从查看代码似乎跳过了 BeanInfo 类的查找),我仍然能够重现延迟。
我还搜索了有关任何类型的 JRE/JVM jar 缓存的信息,但尚未找到任何似乎可以解释这种行为的信息。任何人都知道为什么会这样,如果有什么我可以做的来解决它?
附带说明,我在 Windows XP 上使用 JDK 1.6.0_21。我使用的第 3 方库是 BlazeDS。我的应用程序使用 Spring/BlazeDS 集成托管在 Tomcat 中。我重写了许多 BlazeDS 类,以便准确指出延迟的位置(这是在 getPropertyDescriptorCacheEntry 的 flex.messaging.io.BeanProxy 方法中对 Introspector.getBeanInfo 的调用)。此外,BlazeDS 确实缓存了 BeanInfo,因此仅在 Blaze 反序列化映射到尚未处理的 Java 类的对象时才调用Introspector.getBeanInfo。所以,我确实有其他方法可以解决这个问题,但我真的很想知道这种行为是否有有效的解释。
编辑: 我在重现问题时多次在该进程上运行 jstack(感谢@Tom),并确认它与加载 jar 文件有关。我在 20 秒的时间范围内(延迟的总时间)转储了 5 次线程,每次都产生以下结果:
"http-8080-exec-6" daemon prio=6 tid=0x65cae800 nid=0x1a50 runnable [0x67a3d000]
java.lang.Thread.State: RUNNABLE
at java.util.zip.ZipFile.open(Native Method)
at java.util.zip.ZipFile.<init>(Unknown Source)
at java.util.jar.JarFile.<init>(Unknown Source)
at java.util.jar.JarFile.<init>(Unknown Source)
at org.apache.catalina.loader.WebappClassLoader.openJARs(WebappClassLoader.java:2704)
at org.apache.catalina.loader.WebappClassLoader.findResourceInternal(WebappClassLoader.java:2945)
- locked <0x1804cc18> (a [Ljava.util.jar.JarFile;)
at org.apache.catalina.loader.WebappClassLoader.findClassInternal(WebappClassLoader.java:2739)
at org.apache.catalina.loader.WebappClassLoader.findClass(WebappClassLoader.java:1144)
at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1639)
- locked <0x1803dd38> (a org.apache.catalina.loader.WebappClassLoader)
at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1517)
at java.beans.Introspector.instantiate(Unknown Source)
at java.beans.Introspector.findExplicitBeanInfo(Unknown Source)
- locked <0x434649a0> (a java.lang.Class for java.beans.Introspector)
at java.beans.Introspector.<init>(Unknown Source)
at java.beans.Introspector.getBeanInfo(Unknown Source)
- locked <0x181bed70> (a java.lang.Object)
我不禁想到有某种 JRE/JVM jar 缓存会在一小时后过期并强制重新扫描 jar 文件,但我在网上找不到任何概述此类行为的内容。
编辑:
事实证明,Tomcat WebappClassLoader 确实缓存了 JAR 文件并定期清除该缓存。现在来看看缓存是否可以配置...
编辑:
Tomcat 在最后一次访问 jar 文件后 90 秒关闭所有 JAR 文件。当 jar 文件关闭时,我覆盖了 WebappClassLoader 以打印出来。 jar 文件关闭后,我尝试重现延迟,但无法重现。所以,这告诉我,要么存在 JRE/JVM jar 文件缓存,要么只是操作系统(或我的机器、防病毒软件等)中固有的东西在长时间延迟后导致加载时间变慢。还在努力中……
【问题讨论】:
-
您可以尝试使用
jstack或类似的方法来查看程序的位置。另外,是否涉及任何网络连接? -
yourkit profiler 可以为您节省一天的时间。在阳光下看 java 代码很好,您可以学习有趣的东西,但需要太多时间。
-
感谢@Tom - 运行 jstack 后查看上面的编辑
标签: java performance reflection blazeds javabeans