Using component scanning in signed jars is very slow [SPR-4694]

[spring-projects-issues]

Todd Huss opened SPR-4694 and commented

Since upgrading from Spring 2.0.8 to Spring 2.5.3 our application that runs in signed jars (as required by webstart) starts VERY slowly. It runs fine in a signed jar with Spring 2.0.8 but since the upgrade now takes 5 or more minutes to start as opposed to 10-15 seconds under Spring 2.0.8.

What's interesting is that it's equally fast with Spring 2.5.3 as long as the jar is unsigned. However, as soon as you sign the jar and then run the application (via java -cp ourfile.jar mainclass) it takes forever to start. Downgrading back to Spring 2.0.8 also solves the issue. Getting stack dumps show that it seems like as of Spring 2.5.x (we tried 2.5.1-2.5.3) during startup on a signed jar is now spending a tremendous amount of time doing jar verification triggered from org.springframework.core.io.UrlResource. Here are a couple sample stack dumps of what the application is doing during the now very long startup period:

....
at java.util.jar.JarFile.getManifestFromReference(JarFile.java:159)
at java.util.jar.JarFile.getManifest(JarFile.java:146)
at sun.net.www.protocol.jar.URLJarFile.isSuperMan(URLJarFile.java:155)
- locked <0x8c031f88> (a sun.net.www.protocol.jar.URLJarFile)
at sun.net.www.protocol.jar.URLJarFile.getManifest(URLJarFile.java:121)
at java.util.jar.JarFile.maybeInstantiateVerifier(JarFile.java:287)
at java.util.jar.JarFile.getInputStream(JarFile.java:381)
- locked <0x8c031f88> (a sun.net.www.protocol.jar.URLJarFile)
at sun.net.www.protocol.jar.JarURLConnection.getInputStream(JarURLConnection.java:144)
at org.springframework.core.io.UrlResource.getInputStream(UrlResource.java:123)
at org.springframework.core.type.classreading.SimpleMetadataReaderFactory.getMetadataReader(SimpleMetadataReaderFactory.java:74)

or here

....
at java.util.jar.JarVerifier.processEntry(JarVerifier.java:250)
- locked <0x8d9c05a0> (a [B)
at java.util.jar.JarVerifier.update(JarVerifier.java:188)
at java.util.jar.JarFile.initializeVerifier(JarFile.java:321)
at java.util.jar.JarFile.getInputStream(JarFile.java:386)
- locked <0x8dc380e8> (a sun.net.www.protocol.jar.URLJarFile)
at sun.net.www.protocol.jar.JarURLConnection.getInputStream(JarURLConnection.java:144)
at org.springframework.core.io.UrlResource.getInputStream(UrlResource.java:123)

---

Affects: 2.5.1, 2.5.2, 2.5.3

Issue Links:

• Spring-specific index file for component candidate classes [SPR-11890] #16509 Spring-specific index file for component candidate classes

13 votes, 10 watchers

[spring-projects-issues]

Juergen Hoeller commented

The first stacktrace looks like you're using component scanning... So I assume the configuration of your application is not identical when running against Spring 2.0.8 versus 2.5.3?

It sounds like the issue also shows when simply replacing the 2.0.8 jar with a 2.5.3 jar, but I guess only the second stacktrace applies in that scenario... Where does that UrlResource.getInputStream() call come from there?

Juergen

[spring-projects-issues]

Todd Huss commented

Hi Juergen,

To answer your first question I don't believe we are using component scanning because the application configuration is identical between 2.0.8 and 2.5.3. I built the same code once using 2.0.8 and signed the jar and then I built it with 2.5.3 and signed the jar and once the jar is signed the startup time goes from 10-15 seconds to 5 or more minutes. With the jar unsigned startup time is the same between 2.0.8 and 2.5.3.

Sorry, I should have included a complete stack trace the first time. Here's a complete stack trace running Spring 2.5.3 where the application is taking minutes to start. To answer your second question our code is initializing Spring with the following code which is how UrlResource.getInputStream() ultimately gets called:

String[] paths = {"classpath:gs/data/applicationContext-data.xml",
"classpath:gs/data/dao/hibernate/applicationContext-hibernate.xml",
"classpath:gs/data/school/performance/applicationContext-performance.xml"
};
ClassPathXmlApplicationContext ctx =new ClassPathXmlApplicationContext(paths);

Here's the stack trace:

at java.util.Arrays.copyOfRange(Arrays.java:3209)
at java.lang.String.<init>(String.java:216)
at java.lang.StringBuilder.toString(StringBuilder.java:430)
at sun.security.util.ManifestDigester.<init>(ManifestDigester.java:150)
at java.util.jar.JarVerifier.processEntry(JarVerifier.java:250)
- locked <0x8df507f8> (a [B)
at java.util.jar.JarVerifier.update(JarVerifier.java:188)
at java.util.jar.JarFile.initializeVerifier(JarFile.java:321)
at java.util.jar.JarFile.getInputStream(JarFile.java:386)
- locked <0x8e1c8008> (a sun.net.www.protocol.jar.URLJarFile)
at sun.net.www.protocol.jar.JarURLConnection.getInputStream(JarURLConnection.java:144)
at org.springframework.core.io.UrlResource.getInputStream(UrlResource.java:123)
at org.springframework.core.type.classreading.SimpleMetadataReaderFactory.getMetadataReader(SimpleMetadataReaderFactory.java:74)
at org.springframework.core.type.classreading.CachingMetadataReaderFactory.getMetadataReader(CachingMetadataReaderFactory.java:68)
- locked <0x8d4ff2a8> (a java.util.HashMap)
at org.springframework.context.annotation.ClassPathScanningCandidateComponentProvider.findCandidateComponents(ClassPathScanningCandidateComponentProvider.java:181)
at org.springframework.context.annotation.ClassPathBeanDefinitionScanner.doScan(ClassPathBeanDefinitionScanner.java:200)
at org.springframework.context.annotation.ComponentScanBeanDefinitionParser.parse(ComponentScanBeanDefinitionParser.java:84)
at org.springframework.beans.factory.xml.NamespaceHandlerSupport.parse(NamespaceHandlerSupport.java:69)
at org.springframework.beans.factory.xml.BeanDefinitionParserDelegate.parseCustomElement(BeanDefinitionParserDelegate.java:1253)
at org.springframework.beans.factory.xml.BeanDefinitionParserDelegate.parseCustomElement(BeanDefinitionParserDelegate.java:1243)
at org.springframework.beans.factory.xml.DefaultBeanDefinitionDocumentReader.parseBeanDefinitions(DefaultBeanDefinitionDocumentReader.java:135)
at org.springframework.beans.factory.xml.DefaultBeanDefinitionDocumentReader.registerBeanDefinitions(DefaultBeanDefinitionDocumentReader.java:92)
at org.springframework.beans.factory.xml.XmlBeanDefinitionReader.registerBeanDefinitions(XmlBeanDefinitionReader.java:507)
at org.springframework.beans.factory.xml.XmlBeanDefinitionReader.doLoadBeanDefinitions(XmlBeanDefinitionReader.java:398)
at org.springframework.beans.factory.xml.XmlBeanDefinitionReader.loadBeanDefinitions(XmlBeanDefinitionReader.java:342)
at org.springframework.beans.factory.xml.XmlBeanDefinitionReader.loadBeanDefinitions(XmlBeanDefinitionReader.java:310)
at org.springframework.beans.factory.support.AbstractBeanDefinitionReader.loadBeanDefinitions(AbstractBeanDefinitionReader.java:143)
at org.springframework.beans.factory.support.AbstractBeanDefinitionReader.loadBeanDefinitions(AbstractBeanDefinitionReader.java:178)
at org.springframework.beans.factory.support.AbstractBeanDefinitionReader.loadBeanDefinitions(AbstractBeanDefinitionReader.java:149)
at org.springframework.beans.factory.support.AbstractBeanDefinitionReader.loadBeanDefinitions(AbstractBeanDefinitionReader.java:212)
at org.springframework.context.support.AbstractXmlApplicationContext.loadBeanDefinitions(AbstractXmlApplicationContext.java:113)
at org.springframework.context.support.AbstractXmlApplicationContext.loadBeanDefinitions(AbstractXmlApplicationContext.java:80)
at org.springframework.context.support.AbstractRefreshableApplicationContext.refreshBeanFactory(AbstractRefreshableApplicationContext.java:123)
at org.springframework.context.support.AbstractApplicationContext.obtainFreshBeanFactory(AbstractApplicationContext.java:423)
at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:353)
- locked <0x8d455c30> (a java.lang.Object)
at org.springframework.context.support.ClassPathXmlApplicationContext.<init>(ClassPathXmlApplicationContext.java:139)
at org.springframework.context.support.ClassPathXmlApplicationContext.<init>(ClassPathXmlApplicationContext.java:93)
at gs.data.util.SpringUtil.<clinit>(SpringUtil.java:31)

[spring-projects-issues]

Juergen Hoeller commented

Hmm, this is odd... Your stacktrace clearly indicates the use of a context:component-scan element in one of your XML bean definition files. Could you please double-check that? Note that context:component-scan is a Spring 2.5 only feature...

Juergen

[spring-projects-issues]

Todd Huss commented

Juergen, you were of course spot on, another developer had enabled component scanning and I wasn't aware of it. Disabling component scanning in a signed jar seems to resolve the issue. Here's the component scanning config we had:

<context:component-scan base-package="gs.data">
<context:include-filter type="annotation" expression="org.springframework.stereotype.Repository"/>
</context:component-scan>

Disabling component scanning fixes the issue so here's where we are now:

Spring 2.5.3 Unsigned jar with component scanning = fast startup
Spring 2.5.3 Signed jar without component scanning = fast startup
Spring 2.5.3 Signed jar with component scanning = very slow startup

[spring-projects-issues]

Tom Jahncke commented

I am experiencing the same issue.

It seems that the scanning is about 4 times slower with signed jars.

If I crank down the logging to debug I see the "ClassPathBeanDefinitionScanner" being logged 241 times for our application. Running without the signed jars took 6 seconds and running with signed jars took 23 seconds.

I will greatly appreciate any fixes you can provided to increase the performance. FYI, we are using spring in a Swing application so this overhead is greatly impacting the launch time for our application and causing frustration with the user community.

Thanks!

• Tom

[spring-projects-issues]

Tom Jahncke commented

Here is an idea on how to address this issue:

If there was the ability to generate a file based on the output of the component-scan functionality. Spring would need to have a hook to look for this file when doing component-scan. This file would ideally be built at build time of the jar. The build process could generate this file and include it in the classpath. Then the jars don't have to be scanned each time the application launches. This would increase the launch time of all spring application that utilize component-scan.

It this functionality already exist, I apologize for my ignorance :)

Thanks!

Tom

[spring-projects-issues]

Juergen Hoeller commented

Closing groups of outdated issues. Please reopen if still relevant.

[spring-projects-issues]

Theodor P commented

The problem still exists (I'm currently using Spring 4.3.0).
Although closed for being outdated, I dare to reopen it as I want to ask whether this a Spring or Java performance problem.

The hint to remove component scanning has partially worked. Some Apache CXF web services generated using introspection at runtime still require a fair amount of time.
This wouldn't be an easy applicable solution either when one has already dozens (perhaps hundreds?) of annotated components that have to be replaced with XML bean definitions

[spring-projects-issues]

Juergen Hoeller commented

I'm afraid there's nothing we can do about this particular case since it simply is bound by the number of class files that we have to peek into here... and with every single class InputStream being super-expensive to obtain, this adds up.

We did implement an alternative along the lines of the above in 5.0 though, allowing for a build-time generated index that is transparently picked up by component-scan instructions in an application: please see #16509.

The corresponding reference docs: https://docs.spring.io/spring/docs/current/spring-framework-reference/core.html#beans-scanning-index