不活动后调用 java.beans.Introspector.getBeanInfo 时的性能问题
我正在使用一个第三方库,它动态创建 Java 类的实例,并在 Introspector.getBeanInfo
的帮助下填充这些实例。某些请求可能会导致 5 或 6 次连续调用 Introspector.getBeanInfo
。我发现,当应用程序空闲大约一个小时左右时,与后续调用(Introspector.getBeanInfo
)相比,第一次调用所需的执行时间要长得多(20-60 秒)。 100 毫秒)。接下来几分钟内拨打的电话将继续占用<< 100 毫秒,但当我再等一个小时时,第一次调用再次需要 20-60 秒。
在尝试使用简单的测试应用程序重新创建行为时,我发现当 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 类,以便准确定位延迟所在的位置(这是对 flex.messaging 的
)。此外,BlazeDS 会缓存 BeanInfo,因此仅当 Blaze 反序列化映射到尚未处理的 Java 类的对象时才会调用 getPropertyDescriptorCacheEntry
方法中的 Introspector.getBeanInfo
的调用.io.BeanProxyIntrospector.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 文件。我覆盖了 WebappClassLoader
以在 jar 文件关闭时打印出来。 jar 文件关闭后,我尝试重现延迟,但无法。因此,这告诉我,要么是 JRE/JVM jar 文件缓存,要么是操作系统(或我的机器、防病毒软件等)中固有的某些东西在长时间延迟后导致加载速度缓慢。仍在努力中...
I am using a 3rd party library that dynamically creates instances of Java classes and populates those instances with the help of Introspector.getBeanInfo
. Certain requests may result in 5 or 6 successive calls to Introspector.getBeanInfo
. I have found that when the application is idle for about an hour or so the first call to Introspector.getBeanInfo
takes a significantly much longer time to execute (20-60 seconds) vs the subsequent calls (< 100 milliseconds). Calls made within the next few minutes continue to take < 100 milliseconds, but when I wait another hour the first call again takes 20-60 seconds.
In an attempt to re-create the behavior with a simple test application I have found similar behavior when a java application itself is not run for an hour. For example, if I run the following console app it may take 15 milliseconds to complete. If I then wait an hour and re-run the application it takes 20 seconds to complete.
long start = System.currentTimeMillis();
System.out.println("Start");
Introspector.getBeanInfo(MyClass.class, Object.class);
long end = System.currentTimeMillis();
System.out.println("End: " + (end-start));
I originally thought the issue may be related to the fact that the Introspector class attempts to create instances of classes based on standard naming conventions that do not exist in my application (for example, MyClassBeanInfo
), and it was taking a long time to scan the jar files in an attempt to find those classes (my java application has a little over 100 referenced jar files), but I called Introspector.getBeanInfo(MyClass.class, Object.class, Introspector.IGNORE_ALL_BEANINFO)
using reflection (it is a private method in Sun's JRE which from looking at the code seems to skip the lookup of the BeanInfo classes), and I was still able to reproduce the delay.
I have also searched for information regarding any type of JRE/JVM jar cache, but have yet to find anything that seems to explain this behavior. Anyone have any clue why this behaves the way it does, and if there is anything I can do to fix it?
As a side note I am using JDK 1.6.0_21 on Windows XP. The 3rd party library I am using is BlazeDS. My application is hosted in Tomcat using Spring/BlazeDS integration. I overwrote a number of BlazeDS classes in order to pinpoint exactly where the delay was (which is the call to Introspector.getBeanInfo
in the getPropertyDescriptorCacheEntry
method of flex.messaging.io.BeanProxy
). Also, BlazeDS does cache the BeanInfo, so calls to Introspector.getBeanInfo
are only made when Blaze is deserializing an object that is mapped to a Java class that has yet to be processed. So, I do have other ways to work around this issue, but I would really like to know if there is a valid explanation for this behavior.
EDIT:
I ran jstack on the process multiple times while reproducing the issue (thanks @Tom) and did confirm that it is related to loading jar files. I dumped the threads 5 times over a 20 second time frame (total time of the delay) and each time produced the following result:
"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)
I can't help but think there is some kind of JRE/JVM jar cache that is expiring after an hour and forcing the jar files to be re-scanned, but I can't find anything online that outlines such behavior.
EDIT:
As it turns out the Tomcat WebappClassLoader
does cache JAR files and periodically purges that cache. Now to find out if that cache is configurable in anyway...
EDIT:
Tomcat closes all JAR files 90 seconds after the last time a jar file was accessed. I overwrote the WebappClassLoader
to print out when the jar files were closed. After the jar files were closed I tried to reproduce the delay, but was unable to. So, this tells me that there is either a JRE/JVM jar file cache, or just something inherent in the operating system (or my machine, antivirus, etc) that is causing slow load times after a long delay. Still working on it...
如果你对这篇内容有疑问,欢迎到本站社区发帖提问 参与讨论,获取更多帮助,或者扫码二维码加入 Web 技术交流群。
绑定邮箱获取回复消息
由于您还没有绑定你的真实邮箱,如果其他用户或者作者回复了您的评论,将不能在第一时间通知您!
发布评论
评论(3)
在我的雇主,我们也严重依赖动态生成的类。由于
Introspector
的问题及其行为方式(例如依赖于 ClassLoader 行为)并尝试加载许多我们没有的*BeanInfo
类,这是一个不可行的方法。选择我们,我们决定不使用 Introspector 并自行重新实现该功能。不确定您真正需要多少 BeanInfo,但使用反射和自行开发的属性元数据信息组件可能更容易,您可以更好地控制它们。更容易的是,一旦您将应用程序部署到其他应用程序服务器上,您的神经就会安全,这些服务器有自己的类加载器行为,并且比 Tomcat 上的类加载器行为更重且不可配置。
BeanInfo 和相关组件是接口,因此您甚至可能只需要重新实现 Introspector 本身,而不需要重新实现使用它的所有代码。
At my employer, we too are heavily relying on dynamically generated classes. With the problems of the
Introspector
and how it behaves (e.g. relying on ClassLoader behavior) and trying to load many*BeanInfo
classes which we do not have, it was a no-go for us and we decided to not use Introspector and reimplement the functionality on our own.Not sure how much of the BeanInfo you really need, but it may be easier to use reflection and a home-grown property-metadata-information component, which you have better under control. And with easier, I also mean the nerves you will safe once you deploy the app on other application servers, which have their own ClassLoader behaviors and which are even more heavy and unconfigurable than the ones on Tomcat.
BeanInfo and related components are interfaces, so you may even need only to reimplement the Introspector itself and not all your code which uses it.
java.beans.Introspector
在 OSGi 环境中可能是一个真正的问题,其中搜索不存在类的成本可能特别高。在 Equinox 中尤其如此,因为伙伴类加载:Eclipse-BuddyPolicy: depenent
和Eclipse-BuddyPolicy: global
可能会导致严重的性能问题。java.beans.Introspector
在一些意想不到的地方使用org.apache.log4j.config.PropertySetter
org.springframework.beans.CachedIntrospectionResults
org.hibernate.util.Cloneable#copyListeners
一般来说,当指定
Introspector.IGNORE_ALL_BEANINFO
标志时,Introspector 在 Equinox 中应该相对安全。事实并非如此,因为在当前的 Oracle JVM 实现中,除非指定了 Introspector.USE_ALL_BEANINFO,否则不会使用 BeanInfo 缓存。显然,这与 javadocs 直接冲突,所以我想说这实际上是 Introspector 实现(或文档)中的一个错误。java.beans.Introspector
can be a real problem in OSGi environment where searching for non-existing classes can be particulary expensive. It's especially true in Equinox because of buddy class loading:Eclipse-BuddyPolicy: depenent
andEclipse-BuddyPolicy: global
can cause serious performance problems.java.beans.Introspector
is used in few unexpected placesorg.apache.log4j.config.PropertySetter
org.springframework.beans.CachedIntrospectionResults
org.hibernate.util.Cloneable#copyListeners
In general, Introspector should be relatively safe in Equinox when
Introspector.IGNORE_ALL_BEANINFO
flag is specified. It's not, beacause in current Oracle JVM implementation BeanInfo caching isn't used unless Introspector.USE_ALL_BEANINFO is specified. That is, obviously, in direct conflict with the javadocs, so I'd say that this is actually a bug in the Introspector implementation (or documentation).正如我提到的,Tomcat 中的
WebAppClassLoader
默认情况下会缓存 JAR 文件 90 秒。 90 秒后调用Introspector.getBeanInfo
时,我确实验证了 Tomcat 正在重新加载 JAR 文件。几分钟不活动后,延迟很小,但仍然存在延迟。我从来没有确定为什么在一小时不活动后延迟时间会如此之长。最终,我的解决方案是重写
WebAppClassLoader
并无限期缓存 JAR。在我们的场景中,这是完全可以接受的,因为我们将 Tomcat 包装在我们自己的应用程序中,没有其他 Web 应用程序共享同一 Tomcat 实例,并且我们不允许自动重新加载我们的 Web 应用程序。如果您正在考虑实施类似的解决方案,请记住这一点。下面是覆盖 JAR 缓存行为的代码(
cacheJarFiles
是我添加到WebAppClassLoader
类中的自定义布尔值):...
...
本质上,我是中止对
closeJARs
的调用。我们现在看到的性能提升是相当可观的。闲置一小时后,我们在新调用Introspector.getBeanInfo
时节省了 10-60 秒以上的时间。几分钟不活动后,我们可以节省 100-200 毫秒。As I mentioned, the
WebAppClassLoader
in Tomcat by default caches JAR files for 90 seconds. When callingIntrospector.getBeanInfo
after 90 seconds I did verify that Tomcat was reloading the JAR files. The delay was minimal after a few minutes of inactivity, but there was still a delay. I never did determine why the delay was so much longer after an hour of inactivity.Ultimately, my solution was to override the
WebAppClassLoader
and cache the JARs indefinitely. In our scenario this is perfectly acceptable because we are wrapping Tomcat in our own application, there are no other web applications that share the same instance of Tomcat, and we do not allow our web application to be automatically reloaded. Keep this in mind if you are considering implementing a similar solution.Here is the code for overriding the JAR caching behavior (
cacheJarFiles
is a custom boolean that I have added to theWebAppClassLoader
class):...
...
Essentially, I am aborting the call to
closeJARs
. The performance increase we are now seeing is fairly substantial. After an hour of inactivity we save 10-60+ seconds on new calls toIntrospector.getBeanInfo
. After a few minutes of inactivity we save 100-200 milliseconds.