Error after upgrade to SB 1.4.2 - java.io.FileNotFoundException: JAR entry !/META-INF/services/javax.validation.spi.ValidationProvider

[davidmelia]

Hi,

After upgrading from Spring Boot 1.4.1 to 1.4.2 i get an error which seems to be a strange combination of injecting a LocalValidatorFactoryBean with a @FilterRegistrationBean definition.

@SpringBootApplication
public class SpringDevtoolsIssueApplication {

	public static void main(String[] args) {
		SpringApplication.run(SpringDevtoolsIssueApplication.class, args);
	}

	@Autowired
	private org.springframework.validation.beanvalidation.LocalValidatorFactoryBean validator;

	@Bean
	public LocalValidatorFactoryBean validator() {
		return new LocalValidatorFactoryBean();
	}

	@Bean
	public FilterRegistrationBean create() {
		FilterRegistrationBean bean = new FilterRegistrationBean();
       . . . . . 

This error only occurs running standalone. Very odd. The error occurs on Linux / Windows and Mac.

I've managed to simplify and recreate the issue on bitbucket: https://bitbucket.org/davidmelia/spring-boot-validation-error (mvn clean install and run start.sh)

If you downgrade tomcat to 8.5.5 in the war pom.xml the problem goes away and I think it's related to the Tomcat 8.5.6 bugfix https://bz.apache.org/bugzilla/show_bug.cgi?id=60087

The error is

Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'validator' defined in com.example.SpringDevtoolsIssueApplication: Invocation of init method failed; nested exception is java.util.ServiceConfigurationError: javax.validation.spi.ValidationProvider: Error reading configuration file
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1583) ~[spring-beans-4.3.4.RELEASE.jar!/:4.3.4.RELEASE]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:553) ~[spring-beans-4.3.4.RELEASE.jar!/:4.3.4.RELEASE]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:482) ~[spring-beans-4.3.4.RELEASE.jar!/:4.3.4.RELEASE]
        at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:306) ~[spring-beans-4.3.4.RELEASE.jar!/:4.3.4.RELEASE]
        at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230) ~[spring-beans-4.3.4.RELEASE.jar!/:4.3.4.RELEASE]
        at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:302) ~[spring-beans-4.3.4.RELEASE.jar!/:4.3.4.RELEASE]
        at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202) ~[spring-beans-4.3.4.RELEASE.jar!/:4.3.4.RELEASE]
        at org.springframework.beans.factory.config.DependencyDescriptor.resolveCandidate(DependencyDescriptor.java:207) ~[spring-beans-4.3.4.RELEASE.jar!/:4.3.4.RELEASE]
        at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:1131) ~[spring-beans-4.3.4.RELEASE.jar!/:4.3.4.RELEASE]
        at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1059) ~[spring-beans-4.3.4.RELEASE.jar!/:4.3.4.RELEASE]
        at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.java:589) ~[spring-beans-4.3.4.RELEASE.jar!/:4.3.4.RELEASE]
        ... 35 common frames omitted
Caused by: java.util.ServiceConfigurationError: javax.validation.spi.ValidationProvider: Error reading configuration file
        at java.util.ServiceLoader.fail(ServiceLoader.java:232) ~[na:1.8.0_51]
        at java.util.ServiceLoader.parse(ServiceLoader.java:309) ~[na:1.8.0_51]
        at java.util.ServiceLoader.access$200(ServiceLoader.java:185) ~[na:1.8.0_51]
        at java.util.ServiceLoader$LazyIterator.hasNextService(ServiceLoader.java:357) ~[na:1.8.0_51]
        at java.util.ServiceLoader$LazyIterator.hasNext(ServiceLoader.java:393) ~[na:1.8.0_51]
        at java.util.ServiceLoader$1.hasNext(ServiceLoader.java:474) ~[na:1.8.0_51]
        at javax.validation.Validation$GetValidationProviderListAction.loadProviders(Validation.java:354) ~[validation-api-1.1.0.Final.jar!/:na]
        at javax.validation.Validation$GetValidationProviderListAction.run(Validation.java:329) ~[validation-api-1.1.0.Final.jar!/:na]
        at javax.validation.Validation$GetValidationProviderListAction.getValidationProviderList(Validation.java:316) ~[validation-api-1.1.0.Final.jar!/:na]
        at javax.validation.Validation$DefaultValidationProviderResolver.getValidationProviders(Validation.java:299) ~[validation-api-1.1.0.Final.jar!/:na]
        at javax.validation.Validation$GenericBootstrapImpl.configure(Validation.java:257) ~[validation-api-1.1.0.Final.jar!/:na]
        at org.springframework.validation.beanvalidation.LocalValidatorFactoryBean.afterPropertiesSet(LocalValidatorFactoryBean.java:248) ~[spring-context-4.3.4.RELEASE.jar!/:4.3.4.RELEASE]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1642) ~[spring-beans-4.3.4.RELEASE.jar!/:4.3.4.RELEASE]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1579) ~[spring-beans-4.3.4.RELEASE.jar!/:4.3.4.RELEASE]
        ... 45 common frames omitted
Caused by: java.io.FileNotFoundException: JAR entry !/META-INF/services/javax.validation.spi.ValidationProvider not found in /var/folders/2b/kfywdyt92x5dhdb11335m4bc0000gn/T/jar_cache3414609321058860736.tmp
        at sun.net.www.protocol.jar.JarURLConnection.connect(JarURLConnection.java:142) ~[na:1.8.0_51]
        at sun.net.www.protocol.jar.JarURLConnection.getInputStream(JarURLConnection.java:150) ~[na:1.8.0_51]
        at java.net.URL.openStream(URL.java:1038) ~[na:1.8.0_51]
        at java.util.ServiceLoader.parse(ServiceLoader.java:304) ~[na:1.8.0_51]
        ... 57 common frames omitted

Thanks

[wilkinsona]

Thanks for the sample project. Interestingly, the problem doesn't occur when using jar packaging and embedding Tomcat 8.5.6.

[wilkinsona]

With both Tomcat 8.5.5 and Tomcat 8.5.6 the initial URL is:

jar:war:file:/Users/awilkinson/dev/temp/spring-boot-validation-error/spring-boot-validation-error-war/target/spring-boot-validation-error-war.war*/WEB-INF/lib/hibernate-validator-5.2.4.Final.jar!/!/META-INF/services/javax.validation.spi.ValidationProvider

Things then diverge.

With 8.5.6, org.apache.catalina.webresources.war.Handler.parseURL is called and the URL becomes:

war:file:/Users/awilkinson/dev/temp/spring-boot-validation-error/spring-boot-validation-error-war/target/spring-boot-validation-error-war.war*/WEB-INF/lib/hibernate-validator-5.2.4.Final.jar

Calling openStream() fails.

With 8.5.5, WarURLStreamHandler.parseURL is called and the URL becomes:

war:jar:file:/Users/awilkinson/dev/temp/spring-boot-validation-error/spring-boot-validation-error-war/target/spring-boot-validation-error-war.war!/WEB-INF/lib/hibernate-validator-5.2.4.Final.jar

Calling openStream() works.

@markt-asf Could you take a look at this please? It looks like a regression in Tomcat. 8.5.8 appears to have the same problem.

[markt-asf]

I can take a look. As an aside, that initial URL looks odd. The "...!/!/.." sequence in the middle looks wrong although I don't think it is related to this issue.

[wilkinsona]

@markt-asf Thanks. I agree it looks odd. In addition to …!/!/…, the * in it is also strange. It's the same in both the working and failing case so I haven't dug into it to find out where it's coming from. I might do that now to satisfy my own curiosity if nothing else.

[markt-asf]

The * I'd expect. "*/" in a war: URL is the Tomcat equivalent of "!/" in a jar: URL. If we use !/ in WAR URLs it confuses the JRE's handling of JAR URLs.

[wilkinsona]

Aah, I see. Thanks. The URL is coming from a WebResource returned for a call to

WebResourceRoot.getClassLoaderResources("/META-INF/services/javax.validation.spi.ValidationProvider")

Its baseUrl is:

jar:war:file:/Users/awilkinson/dev/temp/spring-boot-validation-error/spring-boot-validation-error-war/target/spring-boot-validation-error-war.war*/WEB-INF/lib/hibernate-validator-5.2.4.Final.jar!/

And AbstractArchiveResource.getURL() does this:

baseUrl + "!/" + resource.getName()

[markt-asf]

You are ahead of me. I'm still getting my test environment set up. Thanks for that. I should be able to convert that into a unit test.

[markt-asf]

What do you know. That extra !/ does appear to be the issue. I have a test case for jar:war:file: but I want to add some more test cases before committing this. Should have the fix committed later today. The fix will be in the next set of releases (current ETA, around 1 month from now).

[markt-asf]

I can have snapshots available sooner (i.e. shortly after the fix is committed) if that is useful.

[wilkinsona]

Thanks, @markt-asf. A snapshot would be useful.

[markt-asf]

Done:
https://repository.apache.org/content/repositories/snapshots/org/apache/tomcat/

[wilkinsona]

Thanks for the snapshots. I can confirm that they've fixed the problem reported here. Unfortunately, they've introduced a new problem that appears to be a regression in how Connectors are handled during startup. I've opened https://bz.apache.org/bugzilla/show_bug.cgi?id=60368.

[philwebb]

Looks like Tomcat issue 60368 is now fixed.

[philwebb]

When we close this we should also check the server port issue reported in #7615

[wilkinsona]

Unfortunately there's a nasty performance regression in Tomcat 8.5.9 which adds ~4 seconds to the shut down time on macOS when Air Drop is enabled. As I understand it, other OSes with could also be affected depending on the network configuration. The problem is particularly noticeable when using DevTools as it adds ~4 seconds to the time taken for every restart. The regression's been fixed in http://svn.apache.org/viewvc?view=revision&revision=1774098.

Due to the performance degradation, we're going to have to wait for 8.5.10 to fix this issue so it's not going to make it into 1.4.3. If you're affected by this issue but won't be affected by the performance regression or think that you can live with it, overriding tomcat.version to 8.5.9 is a good option.

[wilkinsona]

When the time comes, the necessary changes are available in this branch.

[xenoterracide]

out of curiosity, would 8.5.7 or 8.5.8 be a valid candidate? (until 8.5.10?) because we're hitting the bug where all of the jar's are being added to the static resource cache, that was fixed in 8.5.7.

[wilkinsona]

No, otherwise we would have already upgraded. We need the fix for http://bz.apache.org/bugzilla/show_bug.cgi?id=60368 which is only in 8.5.9

[wilkinsona]

Still blocked. 8.5.11 has been released but it's yet to make it to Maven Central.

[philwebb]

Still missing 8.5.11.

@markt-asf anything you can do to get the bits transferred?

[markt-asf]

https://issues.apache.org/jira/browse/INFRA-13361

[wilkinsona]

The upgrade has broken four Tomcat customisation tests. Reopening.