Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Error deploying a Spring Boot / Liquibase app on Cloud Foundry #1792

Closed
jdubois opened this issue Oct 30, 2014 · 22 comments
Closed

Error deploying a Spring Boot / Liquibase app on Cloud Foundry #1792

jdubois opened this issue Oct 30, 2014 · 22 comments
Assignees
Labels
type: bug A general bug
Milestone

Comments

@jdubois
Copy link
Contributor

jdubois commented Oct 30, 2014

I am trying to deploy a Spring Boot 1.1.8 application + Liquibase 3.1.1 application on Cloud Foundry (Version 2/26/2014 (ccbd61)). I've also tried with Liquibase 3.0.8, which is the one provided by default, and I get the same result.

It fails with the stacktrace I have posted at the end of this ticket.

Please note that on the latest (3.2.2) version of Liquibase, they have changed their API and the SpringPackageScanClassResolver does not override the correct method.

I only have this issue on Cloud Foundry, it works everywhere else (my machine, Heroku, Openshift...), so it must be something specific to Cloud Foundry (once again, I am with Version 2/26/2014 (ccbd61)).
BTW, this has also been reported on BlueMix, but as it's based on CloudFoundry (and as the reporter uses a JHipster application, like me) this is the same issue here:
https://developer.ibm.com/answers/questions/27960/using-liquibase-with-bluemix-fails-when-reading-url-file-home-vcap-app-meta-inf-manifest-mf.html

I'm reporting this here as:

  • Spring Boot has modified the Liquibase configuration classes, and I expect it to make Liquibase work correctly everywhere
  • The issue is with Cloud Foundry, and as this is the same company as Spring Boot: I hope you can sort it out internally (I can't debug it)

I'm notifying @nvoxland because he might also help with this.

2014-10-30T15:26:20.52+0100 [App/0]   ERR java.lang.reflect.InvocationTargetException
2014-10-30T15:26:20.52+0100 [App/0]   ERR   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2014-10-30T15:26:20.52+0100 [App/0]   ERR   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
2014-10-30T15:26:20.53+0100 [App/0]   ERR   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2014-10-30T15:26:20.53+0100 [App/0]   ERR   at java.lang.reflect.Method.invoke(Method.java:606)
2014-10-30T15:26:20.53+0100 [App/0]   ERR   at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:53)
2014-10-30T15:26:20.53+0100 [App/0]   ERR   at java.lang.Thread.run(Thread.java:745)
2014-10-30T15:26:20.53+0100 [App/0]   ERR Caused by: java.lang.ExceptionInInitializerError
2014-10-30T15:26:20.53+0100 [App/0]   ERR   at org.springframework.boot.liquibase.LiquibaseServiceLocatorApplicationListener$LiquibasePresent.replaceServiceLocator(LiquibaseServiceLocatorApplicationListener.java:38)
2014-10-30T15:26:20.53+0100 [App/0]   ERR   at org.springframework.boot.liquibase.LiquibaseServiceLocatorApplicationListener.onApplicationEvent(LiquibaseServiceLocatorApplicationListener.java:28)
2014-10-30T15:26:20.53+0100 [App/0]   ERR   at org.springframework.boot.liquibase.LiquibaseServiceLocatorApplicationListener.onApplicationEvent(LiquibaseServiceLocatorApplicationListener.java:19)
2014-10-30T15:26:20.53+0100 [App/0]   ERR   at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:98)
2014-10-30T15:26:20.53+0100 [App/0]   ERR   at org.springframework.boot.context.event.EventPublishingRunListener.publishEvent(EventPublishingRunListener.java:100)
2014-10-30T15:26:20.53+0100 [App/0]   ERR   at org.springframework.boot.context.event.EventPublishingRunListener.started(EventPublishingRunListener.java:54)
2014-10-30T15:26:20.53+0100 [App/0]   ERR   at org.springframework.boot.SpringApplication.run(SpringApplication.java:276)
2014-10-30T15:26:20.53+0100 [App/0]   ERR   at com.mycompany.myapp.Application.main(Application.java:56)
2014-10-30T15:26:20.53+0100 [App/0]   ERR   ... 6 more
2014-10-30T15:26:20.53+0100 [App/0]   ERR Caused by: liquibase.exception.UnexpectedLiquibaseException: java.net.UnknownServiceException: protocol doesn't support input
2014-10-30T15:26:20.53+0100 [App/0]   ERR   at liquibase.servicelocator.ServiceLocator.setResourceAccessor(ServiceLocator.java:109)
2014-10-30T15:26:20.53+0100 [App/0]   ERR   at liquibase.servicelocator.ServiceLocator.<init>(ServiceLocator.java:44)
2014-10-30T15:26:20.53+0100 [App/0]   ERR   at liquibase.servicelocator.ServiceLocator.<clinit>(ServiceLocator.java:31)
2014-10-30T15:26:20.53+0100 [App/0]   ERR   ... 14 more
2014-10-30T15:26:20.53+0100 [App/0]   ERR Caused by: java.net.UnknownServiceException: protocol doesn't support input
2014-10-30T15:26:20.53+0100 [App/0]   ERR   at java.net.URLConnection.getInputStream(URLConnection.java:839)
2014-10-30T15:26:20.53+0100 [App/0]   ERR   at java.net.URL.openStream(URL.java:1037)
2014-10-30T15:26:20.53+0100 [App/0]   ERR   at liquibase.servicelocator.ServiceLocator.setResourceAccessor(ServiceLocator.java:98)
2014-10-30T15:26:20.53+0100 [App/0]   ERR   ... 16 more
@dsyer
Copy link
Member

dsyer commented Oct 31, 2014

Is it an executable JAR? Cloud Foundry runs that as an exploded archive, which is probably different than the other platforms. Can you run it locally by exploding your JAR and running with "-classpath ."?

@jdubois
Copy link
Contributor Author

jdubois commented Oct 31, 2014

Hi @dsyer !
Yes it's an executable Spring Boot war file.
By the way you can check what I'm doing here, it's a Yeoman sub-generator to automatically deploy a JHipster application to Cloud Foundry (cool, eh?)
I'm going to try to run it with "-classpath", but as I can run it by right-clicking on my IDE on the Application class (you can try doing it on the sample app) it works outside of CloudFoundry.

@jdubois
Copy link
Contributor Author

jdubois commented Oct 31, 2014

I got it working by adding:

    /**
     * Set the liquibases.scan.packages to avoid an exception from ServiceLocator.
     */
    private static void addLiquibaseScanPackages() {
        System.setProperty("liquibase.scan.packages", "liquibase.change" + "," + "liquibase.database" + "," +
                "liquibase.parser" + "," + "liquibase.precondition" + "," + "liquibase.datatype" + "," +
                "liquibase.serializer" + "," + "liquibase.sqlgenerator" + "," + "liquibase.executor" + "," +
                "liquibase.snapshot" + "," + "liquibase.logging" + "," + "liquibase.diff" + "," +
                "liquibase.structure" + "," + "liquibase.structurecompare" + "," + "liquibase.lockservice" + "," +
                "liquibase.ext" + "," + "liquibase.changelog");
    }

This is of course a big hack, the root cause of the issue being that Liquibase fails to start when running

manifests = resourceAccessor.getResourcesAsStream("META-INF/MANIFEST.MF");

This is only on CloudFoundry, and you would (of course) expect that Spring Boot works on Cloud Foundry!

I'm going to clean up and test everything, I will post here when I have something correct.

@nvoxland
Copy link
Contributor

There is a pull request in to spring-boot to support the new Liquibase API. There have been additional fixes in Liquibase that may help as well if you can get it updated to the newest version. Note: I'm working to get 3.3.0 out today.

@jdubois
Copy link
Contributor Author

jdubois commented Oct 31, 2014

Thanks @nvoxland !
I'll make it work with my hack for the moment, and I'll clean up m'y code when Spring Boot is updated.

@jdubois
Copy link
Contributor Author

jdubois commented Nov 3, 2014

I'm closing this as my hack works, still I don't find this very user-friendly!

@jdubois jdubois closed this as completed Nov 3, 2014
@wilkinsona
Copy link
Member

While the workaround lowers the priority of this issue, I don't think it should be closed. At the least, it would be nice to understand why Liquibase is unable to read from a file: URI on CloudFoundry.

@wilkinsona wilkinsona reopened this Nov 3, 2014
@nebhale
Copy link
Member

nebhale commented Nov 3, 2014

@wilkinsona I do find that strange since I'm guessing that Boot itself reads that file when starting...

@nebhale
Copy link
Member

nebhale commented Nov 3, 2014

Actually @wilkinsona, is the answer in the IBM issue? Is it possible that Liquibase is using URLConnection which cannot be used to open files on the filesystem?

@wilkinsona
Copy link
Member

As far as I can tell the comment on the IBM issue is wrong. sun.net.www.protocol.file.FileURLConnection, which is the default connection type returned from URL.openConnection() for a file: URL, is perfectly capable of providing an InputStream.

@wilkinsona
Copy link
Member

Perhaps CloudFoundry customises the handler for file: URLs?

@nebhale
Copy link
Member

nebhale commented Nov 3, 2014

No, that's not likely to be it. I build OpenJDK directly and it's as stock as I can make it. @jdubois Can you please provide me with a fully built JAR as it would be deployed to Cloud Foundry? I'll take a look at reproducing the issue using the exact command line that Cloud Foundry would use, but I don't think it's related to Cloud Foundry per se. In fact, I believe that Sagan originally used Liquibase in Spring Boot on Cloud Foundry without any problems at all.

@jdubois
Copy link
Contributor Author

jdubois commented Nov 3, 2014

@nebhale sure, do you want it working with MySQL or Postgresql?

@nebhale
Copy link
Member

nebhale commented Nov 3, 2014

Anything that reproduces your problem will work.

@jdubois
Copy link
Contributor Author

jdubois commented Nov 3, 2014

Here is one:
https://www.dropbox.com/s/0463gnv15i0t4vh/jhipster-0.0.1-SNAPSHOT.war?dl=0

It's working with Postgresql, with the "prod" profile.

Here is my manifest.yml:

---
path: .
instances: 1
services:
- hipster2
applications:
- name: hipster2
  env:
    SPRING_PROFILES_ACTIVE: prod

And here is the output (of course it works without my hack!):

2014-11-03T17:58:23.51+0100 [DEA]     OUT Starting app instance (index 0) with guid 01a2348e-25f5-4537-be12-f62e808b3222
2014-11-03T17:58:32.19+0100 [App/0]   ERR java.lang.reflect.InvocationTargetException
2014-11-03T17:58:32.20+0100 [App/0]   ERR   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2014-11-03T17:58:32.20+0100 [App/0]   ERR   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2014-11-03T17:58:32.20+0100 [App/0]   ERR   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2014-11-03T17:58:32.20+0100 [App/0]   ERR   at java.lang.reflect.Method.invoke(Method.java:483)
2014-11-03T17:58:32.20+0100 [App/0]   ERR   at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:53)
2014-11-03T17:58:32.20+0100 [App/0]   ERR   at java.lang.Thread.run(Thread.java:745)
2014-11-03T17:58:32.20+0100 [App/0]   ERR Caused by: java.lang.ExceptionInInitializerError
2014-11-03T17:58:32.20+0100 [App/0]   ERR   at org.springframework.boot.liquibase.LiquibaseServiceLocatorApplicationListener$LiquibasePresent.replaceServiceLocator(LiquibaseServiceLocatorApplicationListener.java:38)
2014-11-03T17:58:32.20+0100 [App/0]   ERR   at org.springframework.boot.liquibase.LiquibaseServiceLocatorApplicationListener.onApplicationEvent(LiquibaseServiceLocatorApplicationListener.java:28)
2014-11-03T17:58:32.20+0100 [App/0]   ERR   at org.springframework.boot.liquibase.LiquibaseServiceLocatorApplicationListener.onApplicationEvent(LiquibaseServiceLocatorApplicationListener.java:19)
2014-11-03T17:58:32.20+0100 [App/0]   ERR   at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:98)
2014-11-03T17:58:32.20+0100 [App/0]   ERR   at org.springframework.boot.context.event.EventPublishingRunListener.publishEvent(EventPublishingRunListener.java:100)
2014-11-03T17:58:32.20+0100 [App/0]   ERR   at org.springframework.boot.context.event.EventPublishingRunListener.started(EventPublishingRunListener.java:54)
2014-11-03T17:58:32.20+0100 [App/0]   ERR   at org.springframework.boot.SpringApplication.run(SpringApplication.java:276)
2014-11-03T17:58:32.20+0100 [App/0]   ERR   at com.mycompany.myapp.Application.main(Application.java:56)
2014-11-03T17:58:32.20+0100 [App/0]   ERR   ... 6 more
2014-11-03T17:58:32.20+0100 [App/0]   ERR Caused by: liquibase.exception.UnexpectedLiquibaseException: java.net.UnknownServiceException: protocol doesn't support input
2014-11-03T17:58:32.20+0100 [App/0]   ERR   at liquibase.servicelocator.ServiceLocator.setResourceAccessor(ServiceLocator.java:109)
2014-11-03T17:58:32.20+0100 [App/0]   ERR   at liquibase.servicelocator.ServiceLocator.<init>(ServiceLocator.java:44)
2014-11-03T17:58:32.20+0100 [App/0]   ERR   at liquibase.servicelocator.ServiceLocator.<clinit>(ServiceLocator.java:31)
2014-11-03T17:58:32.20+0100 [App/0]   ERR   ... 14 more
2014-11-03T17:58:32.20+0100 [App/0]   ERR Caused by: java.net.UnknownServiceException: protocol doesn't support input
2014-11-03T17:58:32.20+0100 [App/0]   ERR   at java.net.URLConnection.getInputStream(URLConnection.java:830)
2014-11-03T17:58:32.20+0100 [App/0]   ERR   at java.net.URL.openStream(URL.java:1038)
2014-11-03T17:58:32.20+0100 [App/0]   ERR   at liquibase.servicelocator.ServiceLocator.setResourceAccessor(ServiceLocator.java:98)
2014-11-03T17:58:32.20+0100 [App/0]   ERR   ... 16 more
2014-11-03T17:58:32.24+0100 [App/0]   OUT
2014-11-03T17:58:32.30+0100 [DEA]     ERR Instance (index 0) failed to start accepting connections

@nebhale
Copy link
Member

nebhale commented Nov 4, 2014

So, step one of diagnosis is to run this using the buildpack, but locally on the machine:

bhale-desktop: detect
java-buildpack=647c0bd-https://github.com/cloudfoundry/java-buildpack.git#647c0bd java-main open-jdk-jre=1.8.0_25 spring-auto-reconfiguration=1.5.0_RELEASE
bhale-desktop: compile
-----> Java Buildpack Version: 647c0bd | https://github.com/cloudfoundry/java-buildpack.git#647c0bd
-----> Downloading Open Jdk JRE 1.8.0_25 from https://download.run.pivotal.io/openjdk/mountainlion/x86_64/openjdk-1.8.0_25.tar.gz (15.8s)
       Expanding Open Jdk JRE to .java-buildpack/open_jdk_jre (0.6s)
-----> Downloading Spring Auto Reconfiguration 1.5.0_RELEASE from https://download.run.pivotal.io/auto-reconfiguration/auto-reconfiguration-1.5.0_RELEASE.jar (1.1s)
bhale-desktop: release
SERVER_PORT=$PORT $PWD/.java-buildpack/open_jdk_jre/bin/java -cp $PWD/.:$PWD/.java-buildpack/spring_auto_reconfiguration/spring_auto_reconfiguration-1.5.0_RELEASE.jar -Djava.io.tmpdir=$TMPDIR -XX:OnOutOfMemoryError=$PWD/.java-buildpack/open_jdk_jre/bin/killjava.sh -XX:MaxMetaspaceSize=64M -XX:MetaspaceSize=64M org.springframework.boot.loader.WarLauncher
bhale-desktop: SERVER_PORT=$PORT $PWD/.java-buildpack/open_jdk_jre/bin/java -cp $PWD/.:$PWD/.java-buildpack/spring_auto_reconfiguration/spring_auto_reconfiguration-1.5.0_RELEASE.jar -Djava.io.tmpdir=$TMPDIR -XX:OnOutOfMemoryError=$PWD/.java-buildpack/open_jdk_jre/bin/killjava.sh -XX:MaxMetaspaceSize=64M -XX:MetaspaceSize=64M org.springframework.boot.loader.WarLauncher
java.lang.reflect.InvocationTargetException
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:483)
    at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:53)
    at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.ExceptionInInitializerError
    at org.springframework.boot.liquibase.LiquibaseServiceLocatorApplicationListener$LiquibasePresent.replaceServiceLocator(LiquibaseServiceLocatorApplicationListener.java:38)
    at org.springframework.boot.liquibase.LiquibaseServiceLocatorApplicationListener.onApplicationEvent(LiquibaseServiceLocatorApplicationListener.java:28)
    at org.springframework.boot.liquibase.LiquibaseServiceLocatorApplicationListener.onApplicationEvent(LiquibaseServiceLocatorApplicationListener.java:19)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:98)
    at org.springframework.boot.context.event.EventPublishingRunListener.publishEvent(EventPublishingRunListener.java:100)
    at org.springframework.boot.context.event.EventPublishingRunListener.started(EventPublishingRunListener.java:54)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:276)
    at com.mycompany.myapp.Application.main(Application.java:56)
    ... 6 more
Caused by: liquibase.exception.UnexpectedLiquibaseException: java.net.UnknownServiceException: protocol doesn't support input
    at liquibase.servicelocator.ServiceLocator.setResourceAccessor(ServiceLocator.java:109)
    at liquibase.servicelocator.ServiceLocator.<init>(ServiceLocator.java:44)
    at liquibase.servicelocator.ServiceLocator.<clinit>(ServiceLocator.java:31)
    ... 14 more
Caused by: java.net.UnknownServiceException: protocol doesn't support input
    at java.net.URLConnection.getInputStream(URLConnection.java:830)
    at java.net.URL.openStream(URL.java:1038)
    at liquibase.servicelocator.ServiceLocator.setResourceAccessor(ServiceLocator.java:98)
    ... 16 more

The problem is definitely not Cloud Foundry specific, but rather in the way that the application is being run on Cloud Foundry.

@dsyer
Copy link
Member

dsyer commented Nov 4, 2014

Looks like maybe it's that "-cp ..." enhancement we added (for CF buildpack)?

@wilkinsona
Copy link
Member

Thanks, @nebhale.

It's blowing up because Liquibase is being given an ExplodedArchive$FileNotFoundURLConnection by ExplodedArchive when it tries to access the war's /META-INF/MANIFEST.MF. The manifest is there but it's being filtered out by WarLauncher (it hides META-INF and WEB-INF). Crucially, the war's META-INF directory is on the classpath of LaunchedURLClassLoader so ServiceLocator's ClassLoaderResourceAccessor finds it but then can't access it as it's been filtered out of the exploded archive.

@wilkinsona
Copy link
Member

The problem can be reproduced by downloading the app from @jdubois, unzipping it into a fresh directory, moving into that directory, and running

java -cp . org.springframework.boot.loader.WarLauncher

@wilkinsona
Copy link
Member

I'm not sure that filtering in ExplodedArchive is the right thing to do. A web app should be able to access files in META-INF via the ServletContext and I think this filtering will prevent that. Furthermore, I'm surprised that WarLauncher creates a LaunchedURLClassLoader that's got the root of the war on its path. I'd expect it to have WEB-INF/classes and everything in WEB-INF/lib and that's it.

@philwebb Have I misunderstood the intent of the current filtering?

@philwebb
Copy link
Member

@wilkinsona I can't remember why the original archive is added. I have a feeling that we've improved the embedded Tomcat/Jetty support so that entries from the war can be served. That might not have always been the case and adding the filtered WAR archive might have provided a way around that.

I think that /META-INF was filtered because the assumption was that files would be in WEB-INF/classes/META-INF.

@wilkinsona wilkinsona added the type: bug A general bug label Nov 11, 2014
@wilkinsona wilkinsona added this to the 1.2.0.RC1 milestone Nov 11, 2014
@wilkinsona wilkinsona self-assigned this Nov 11, 2014
@wilkinsona
Copy link
Member

I have a fix for this issue – it removes the root of the war file from the classpath. While this is correct for a war file, I'm reluctant to make this change in 1.1.x in case anyone was relying on the existing, incorrect behaviour, particularly as the reporter has a workaround.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
type: bug A general bug
Projects
None yet
Development

No branches or pull requests

6 participants