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

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

Comment From: wilkinsona

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

Comment From: 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.

Comment From: 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.

Comment From: 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.

Comment From: 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.

Comment From: 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()

Comment From: 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.

Comment From: 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).

Comment From: markt-asf

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

Comment From: wilkinsona

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

Comment From: markt-asf

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

Comment From: 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.

Comment From: philwebb

Looks like Tomcat issue 60368 is now fixed.

Comment From: philwebb

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

Comment From: 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.

Comment From: wilkinsona

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

Comment From: 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.

Comment From: 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

Comment From: wilkinsona

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