search

MicroShed / boost

Boost Maven and Gradle plugins for MicroProfile development
Eclipse Public License 1.0
27 stars 13 forks source link

boost-gradle-plugin not working with fresh install of Spring Boot #258

Closed hongminzhu closed 5 years ago

hongminzhu commented 5 years ago

Hi there,

I created a fresh spring boot app with spring initializr, and built the boost-gradle-plugin locally. Here is my build.gradle

buildscript {
    ext {
        springBootVersion = '2.1.2.RELEASE'
    }
    repositories {
        mavenLocal()
        mavenCentral()
    }
    dependencies {
        classpath("org.springframework.boot:spring-boot-gradle-plugin:${springBootVersion}")
        classpath 'io.openliberty.boost:boost-gradle-plugin:0.1.1-SNAPSHOT'
    }
}

apply plugin: 'java'
apply plugin: 'org.springframework.boot'
apply plugin: 'io.spring.dependency-management'
apply plugin: 'boost'

group = 'com.example'
version = '0.0.1-SNAPSHOT'
sourceCompatibility = '1.8'

repositories {
    mavenCentral()
}

dependencies {
    implementation 'org.springframework.boot:spring-boot-starter-web'
    testImplementation 'org.springframework.boot:spring-boot-starter-test'
}

After running gradle boostPackage, I expected the app to "just run", however I'm getting the following errors:

$ java -jar build/libs/demo-0.0.1-SNAPSHOT.jar
Extracting files to C:\Users\chs30\wlpExtract\demo-0.0.1-SNAPSHOT_435171978242541\wlp
Successfully extracted all product files.
Launching BoostServer (Open Liberty 18.0.0.4/wlp-1.0.23.cl180420181121-0300) on Java HotSpot(TM) 64-Bit Server VM, version 1.8.0_162-b12 (en_CA)
[AUDIT   ] CWWKE0001I: The server BoostServer has been launched.
[AUDIT   ] CWWKG0093A: Processing configuration drop-ins resource: C:\Users\chs30\wlpExtract\demo-0.0.1-SNAPSHOT_435171978242541\wlp\usr\servers\BoostServer\configDropins\defaults\install_apps_configuration_1491924271.xml
[AUDIT   ] CWWKZ0058I: Monitoring dropins for applications.

 :: Spring Boot ::        (v2.1.2.RELEASE)
2019-01-29 13:51:35.937  INFO 13208 --- [ecutor-thread-7] com.example.demo.DemoApplication         : Starting DemoApplication on M4XD0143252 with PID 13208 (C:\Users\chs30\wlpExtract\demo-0.0.1-SNAPSHOT_435171978242541\wlp\usr\servers\BoostServer\apps\demo-0.0.1-SNAPSHOT.jar started by chs30 in C:\Users\chs30\wlpExtract\demo-0.0.1-SNAPSHOT_435171978242541\wlp\usr\servers\BoostServer)
2019-01-29 13:51:35.953  INFO 13208 --- [ecutor-thread-7] com.example.demo.DemoApplication         : No active profile set, falling back to default profiles: default
2019-01-29 13:51:37.901  INFO 13208 --- [ecutor-thread-7] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
Jan 29, 2019 1:51:37 PM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-nio-8080"]
Jan 29, 2019 1:51:37 PM org.apache.catalina.core.StandardService startInternal
INFO: Starting service [Tomcat]
Jan 29, 2019 1:51:37 PM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet engine: [Apache Tomcat/9.0.14]
Jan 29, 2019 1:51:37 PM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFO: The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: [C:\Program Files\Java\jdk1.8.0_162\bin;C:\Windows\Sun\Java\bin;C:\Windows\system32;C:\Windows;C:\Users\chs30\bin;C:\Program Files\Git\mingw64\bin;C:\Program Files\Git\usr\local\bin;C:\Program Files\Git\usr\bin;C:\Program Files\Git\usr\bin;C:\Program Files\Git\mingw64\bin;C:\Program Files\Git\usr\bin;C:\Users\chs30\bin;C:\ProgramData\DockerDesktop\version-bin;C:\Program Files\Docker\Docker\Resources\bin;C:\app\Administrator\product\11.2.0\client_1;C:\Program Files\CollabNet\Subversion Client;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0;C:\Program Files (x86)\PuTTY;C:\Program Files\nodejs;C:\apache-maven-3.5.4\bin;C:\gradle-4.10.2\bin;C:\Program Files (x86)\Microsoft Emulator Manager\1.0;C:\Program Files\Java\jdk1.8.0_162\bin;C:\Users\chs30\AppData\Local\Microsoft\WindowsApps;C:\Users\chs30\AppData\Roaming\npm;C:\flutter\bin;C:\Program Files\Git\usr\bin\vendor_perl;C:\Program Files\Git\usr\bin\core_perl;.]
Jan 29, 2019 1:51:38 PM org.apache.catalina.core.ContainerBase startInternal
SEVERE: A child container failed during start
java.util.concurrent.ExecutionException: org.apache.catalina.LifecycleException: Failed to initialize component [org.apache.catalina.webresources.StandardRoot@1c19475c]
        at java.util.concurrent.FutureTask.report(FutureTask.java:122)
        at java.util.concurrent.FutureTask.get(FutureTask.java:192)
        at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:914)
        at org.apache.catalina.core.StandardHost.startInternal(StandardHost.java:831)
        at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
        at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1382)
        at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1372)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
        at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:134)
        at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:907)
        at org.apache.catalina.core.StandardEngine.startInternal(StandardEngine.java:262)
        at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
        at org.apache.catalina.core.StandardService.startInternal(StandardService.java:423)
        at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
        at org.apache.catalina.core.StandardServer.startInternal(StandardServer.java:933)
        at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
        at org.apache.catalina.startup.Tomcat.start(Tomcat.java:398)
        at org.springframework.boot.web.embedded.tomcat.TomcatWebServer.initialize(TomcatWebServer.java:106)
        at org.springframework.boot.web.embedded.tomcat.TomcatWebServer.<init>(TomcatWebServer.java:86)
        at org.springframework.boot.web.embedded.tomcat.TomcatServletWebServerFactory.getTomcatWebServer(TomcatServletWebServerFactory.java:415)
        at org.springframework.boot.web.embedded.tomcat.TomcatServletWebServerFactory.getWebServer(TomcatServletWebServerFactory.java:174)
        at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.createWebServer(ServletWebServerApplicationContext.java:181)
        at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.onRefresh(ServletWebServerApplicationContext.java:154)
        at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:540)
        at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:142)
        at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:775)
        at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:397)
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:316)
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1260)
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1248)
        at com.example.demo.DemoApplication.main(DemoApplication.java:10)
        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:498)
        at com.ibm.ws.app.manager.springboot.internal.SpringBootRuntimeContainer.lambda$invokeSpringMain$6(SpringBootRuntimeContainer.java:137)
        at com.ibm.ws.threading.internal.ExecutorServiceImpl$RunnableWrapper.run(ExecutorServiceImpl.java:232)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
Caused by: org.apache.catalina.LifecycleException: Failed to initialize component [org.apache.catalina.webresources.StandardRoot@1c19475c]
        at org.apache.catalina.util.LifecycleBase.handleSubClassException(LifecycleBase.java:441)
        at org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:139)
        at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:173)
        at org.apache.catalina.core.StandardContext.resourcesStart(StandardContext.java:4778)
        at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:4913)
        at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
        at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1382)
        at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1372)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
        at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:134)
        at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:907)
        ... 38 more
Caused by: java.lang.Error: factory already defined
        at java.net.URL.setURLStreamHandlerFactory(URL.java:1112)
        at org.apache.catalina.webresources.TomcatURLStreamHandlerFactory.<init>(TomcatURLStreamHandlerFactory.java:130)
        at org.apache.catalina.webresources.TomcatURLStreamHandlerFactory.getInstanceInternal(TomcatURLStreamHandlerFactory.java:53)
        at org.apache.catalina.webresources.TomcatURLStreamHandlerFactory.register(TomcatURLStreamHandlerFactory.java:77)
        at org.apache.catalina.webresources.StandardRoot.registerURLStreamHandlerFactory(StandardRoot.java:699)
        at org.apache.catalina.webresources.StandardRoot.initInternal(StandardRoot.java:682)
        at org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:136)
        ... 48 more

It seems like the tomcat dependencies are not being excluded properly.

mattbsox commented 5 years ago

This seems to be a Windows specific issue. I wasn't able to reproduce the error on macOS.

@chyt Might be a good time to look into testing with Windows on Travis again.

scottkurz commented 5 years ago

I see two issues here:

  1. Boost seems to be only looking at compile dependencies, not implementation in order to decide to generate our Liberty servlet-4.0 feature. So for something like: implementation 'org.springframework.boot:spring-boot-starter-web' we wouldn't bother to generate the feature in the Liberty config, and so Tomcat gets started.

  2. The behavior seems to have changed moving from SpringBoot 2.0.4 to SpringBoot 2.1.2. In 2.0.4 I get a straightforward message:

00:01:38.359 [Default Executor-thread-8] ERROR org.springframework.boot.SpringApplication - Application run failed com.ibm.ws.app.manager.springboot.container.ApplicationError: CWWKC0254E: The application failed to start because it requires a servlet feature to be configured in the server.xml file.

But in 2.1.2 we see the error within the Tomcat container:

Caused by: java.lang.Error: factory already defined at java.net.URL.setURLStreamHandlerFactory(URL.java:1112) ~[na:1.8.0_191]

Also, I don't see this as a Windows issue. I see the same exact thing with an 'implementation' dependency on Windows (using Gradle 4.4.1 if it matters) and Linux using the gradlew wrapper.

anjumfatima90 commented 5 years ago

I opened an issue in open-liberty https://github.com/OpenLiberty/open-liberty/issues/6360 This issue will be fixed in the next release.

scottkurz commented 5 years ago

@anjumfatima90 sounds like the open-liberty #6360 covers the difference btw. the symptom in 2.0.4 vs 2.1.2... (thanks for pointing that out too). However I think boost gradle still has the same underlying problem of not generating the servlet-4.0 feature. @mattbsox do you agree?

mattbsox commented 5 years ago

Yup, I can look into that. Might just need to broaden the scope we're searching to include those extra configurations.

dazavala commented 5 years ago

The spring boot library cache for the demo application unexpectedly contains dependency jar "spring-boot-starter-tomcat-2.1.2.RELEASE.jar and all the related tomcat runtime jars. I assume the pom declares a dependency on spring boot starter v2.1.x. Currently the springBoot utility and server runtimes filter-out (i.e. thin) dependency jars for starter versions 1.5.x and 2.0.x. I can reproduce the unexpected thinning behavior using a sample application on both windows and macOS. I'll discuss this finding with @tjwatson and @anjumfatima90 as I see a few solutions to consider (ref: https://github.com/OpenLiberty/open-liberty/issues/6360.)

dazavala commented 5 years ago

Hello. The update to open-liberty to thin (filter-out) SpringBoot embedded server dependencies, OpenLiberty/open-liberty#6360, has merged into open-liberty 19.0.0.2. Let's verify the update within the Boost gradle plugin.

mattbsox commented 5 years ago

Took a look on Mac and Windows. Worked as expected with OL 19.0.0.2 and the latest version of boost-gradle built from master.

scottkurz commented 5 years ago

@mattbsox, @hongminzhu - Any objection to closing this now?

mattbsox commented 5 years ago

Nope, I'll close it now.