Login/Register
Spring Boot with spring-boot-maven plug-in - unable to RESTART the application server after running integration tests
Asked Answered
javamavenspring-bootjmxspring-boot-maven-plugin
P

1

9

I have a Spring Boot application and that application has integration tests.

Here is the relevant snippet from my pom.xml for running the integration tests.

<plugin>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-maven-plugin</artifactId>
    <configuration>
      <mainClass>com.xyz.Application</mainClass>
      <executable>true</executable>
      <fork>true</fork>
      <jmxPort>7654</jmxPort>
    </configuration>
    <executions>
      <execution>
        <id>pre-integration-test</id>
        <goals>
          <goal>start</goal>
        </goals>
        <configuration>
          <fork>true</fork>
          <jmxPort>7654</jmxPort>
        </configuration>
      </execution>
      <execution>
        <id>post-integration-test</id>
        <goals>
          <goal>stop</goal>
        </goals>
        <configuration>
          <fork>true</fork>
          <jmxPort>7654</jmxPort>
        </configuration>
      </execution>
    </executions>
  </plugin>

When I run mvn verify, I see the unit tests running first. Then the application server starts and the integration tests run successfully. The mvn process exits with a success.

I also see the following in the console log which leads me to believe that the application server is being shutdown correctly - 

[INFO] --- spring-boot-maven-plugin:2.1.1.RELEASE:stop (post-integration-test) @ application ---
[DEBUG] Configuring mojo org.springframework.boot:spring-boot-maven-plugin:2.1.1.RELEASE:stop from plugin realm ClassRealm[plugin>org.springframework.boot:spring-boot-maven-plugin:2.1.1.RELEASE, parent: sun.misc.Launcher$AppClassLoader@42a57993]
[DEBUG] Configuring mojo 'org.springframework.boot:spring-boot-maven-plugin:2.1.1.RELEASE:stop' with basic configurator -->
[DEBUG]   (f) fork = true
[DEBUG]   (f) jmxPort = 7654
[DEBUG]   (f) project = MavenProject: com.xyz:application:1.0-SNAPSHOT @ /Users/me/code/my-project/pom.xml
[DEBUG]   (f) skip = false
[DEBUG] -- end configuration --
[INFO] Stopping application...
2019-01-07 14:18:18.375  INFO [-,,,] 38653 --- [on(4)-127.0.0.1] inMXBeanRegistrar$SpringApplicationAdmin : Application shutdown requested.
2019-01-07 14:18:18.375  INFO [-,,,] 38653 --- [on(4)-127.0.0.1] ConfigServletWebServerApplicationContext : Closing org.springframework.boot.web.servlet.context.AnnotationConfigServletWebServerApplicationContext@449465bf: startup date [Mon Jan 07 14:17:22 EST 2019]; parent: org.springframework.context.annotation.AnnotationConfigApplicationContext@475a6eb6
2019-01-07 14:18:18.376  INFO [-,,,] 38653 --- [on(4)-127.0.0.1] ConfigServletWebServerApplicationContext : Closing org.springframework.boot.web.servlet.context.AnnotationConfigServletWebServerApplicationContext@4cf0901e: startup date [Mon Jan 07 14:17:30 EST 2019]; parent: org.springframework.boot.web.servlet.context.AnnotationConfigServletWebServerApplicationContext@449465bf
2019-01-07 14:18:18.385  INFO [-,,,] 38653 --- [on(4)-127.0.0.1] o.e.jetty.server.AbstractConnector       : Stopped ServerConnector@e45db77{HTTP/1.1,[http/1.1]}{0.0.0.0:8081}
2019-01-07 14:18:18.385  INFO [-,,,] 38653 --- [on(4)-127.0.0.1] org.eclipse.jetty.server.session         : node0 Stopped scavenging
2019-01-07 14:18:18.387  INFO [-,,,] 38653 --- [on(4)-127.0.0.1] o.e.j.s.h.ContextHandler.application     : Destroying Spring FrameworkServlet 'dispatcherServlet'
2019-01-07 14:18:18.388  INFO [-,,,] 38653 --- [on(4)-127.0.0.1] o.e.jetty.server.handler.ContextHandler  : Stopped o.s.b.w.e.j.JettyEmbeddedWebAppContext@16b7a081{application,/,[file:///private/var/folders/sc/d2x30b2j6jj5hpvfkqx9p31n5jmbmc/T/jetty-docbase.6078950105283659171.8081/, jar:file:/Users/me/.m2/repository/io/springfox/springfox-swagger-ui/2.9.2/springfox-swagger-ui-2.9.2.jar!/META-INF/resources],UNAVAILABLE}
2019-01-07 14:18:18.390  INFO [-,,,] 38653 --- [on(4)-127.0.0.1] o.s.c.support.DefaultLifecycleProcessor  : Stopping beans in phase 2147483647
2019-01-07 14:18:18.393  INFO [-,,,] 38653 --- [on(4)-127.0.0.1] o.s.j.e.a.AnnotationMBeanExporter        : Unregistering JMX-exposed beans on shutdown
2019-01-07 14:18:18.393  INFO [-,,,] 38653 --- [on(4)-127.0.0.1] o.s.j.e.a.AnnotationMBeanExporter        : Unregistering JMX-exposed beans
2019-01-07 14:18:18.403  INFO [-,,,] 38653 --- [on(4)-127.0.0.1] s.c.a.AnnotationConfigApplicationContext : Closing FeignContext-cse-service: startup date [Mon Jan 07 14:17:27 EST 2019]; parent: org.springframework.boot.web.servlet.context.AnnotationConfigServletWebServerApplicationContext@449465bf
...
2019-01-07 14:18:18.472  WARN [-,,,] 38653 --- [pool-1-thread-5] c.n.c.sources.URLConfigurationSource     : No URLs will be polled as dynamic configuration sources.
2019-01-07 14:18:18.472  INFO [-,,,] 38653 --- [pool-1-thread-5] c.n.c.sources.URLConfigurationSource     : To enable URLs as dynamic configuration sources, define System property archaius.configurationSource.additionalUrls or make config.properties available on classpath.
2019-01-07 14:18:18.473  INFO [-,,,] 38653 --- [pool-1-thread-5] c.netflix.config.DynamicPropertyFactory  : DynamicPropertyFactory is initialized with configuration sources: com.netflix.config.ConcurrentCompositeConfiguration@139bf1b8
...
2019-01-07 14:18:18.628  INFO [-,,,] 38653 --- [on(4)-127.0.0.1] o.e.jetty.server.AbstractConnector       : Stopped ServerConnector@678b05be{HTTP/1.1,[http/1.1]}{0.0.0.0:8080}
2019-01-07 14:18:18.628  INFO [-,,,] 38653 --- [on(4)-127.0.0.1] org.eclipse.jetty.server.session         : node0 Stopped scavenging
2019-01-07 14:18:18.629  INFO [-,,,] 38653 --- [on(4)-127.0.0.1] o.e.j.s.h.ContextHandler.application     : Destroying Spring FrameworkServlet 'dispatcherServlet'
2019-01-07 14:18:18.629  INFO [-,,,] 38653 --- [on(4)-127.0.0.1] o.e.jetty.server.handler.ContextHandler  : Stopped o.s.b.w.e.j.JettyEmbeddedWebAppContext@4808c18e{application,/api/v1,[file:///private/var/folders/sc/d2x30b2j6jj5hpvfkqx9p31n5jmbmc/T/jetty-docbase.6019952027552218513.8080/, jar:file:/Users/me/.m2/repository/io/springfox/springfox-swagger-ui/2.9.2/springfox-swagger-ui-2.9.2.jar!/META-INF/resources],UNAVAILABLE}

Subsequently, when I run mvn verify again, I get the following bind exception.

[DEBUG] Application argument(s): 
[DEBUG] Connecting to local MBeanServer at port 7654
[DEBUG] Waiting for spring application to start...
[DEBUG] Connected to local MBeanServer at port 7654
[DEBUG] Waiting for spring application to start...
[DEBUG] Spring application is not ready yet, waiting 500ms (attempt 1)
Error: Exception thrown by the agent : java.rmi.server.ExportException: Port already in use: 7654; nested exception is: 
        java.net.BindException: Address already in use (Bind failed)

Using netstat and ps I am able to ascertain that there is some process that is still holding on to port 7654, and jps tells me that it is this process - 

47148 Application -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=7654 -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false -Djava.rmi.server.hostname=127.0.0.1

I don't know how to get the JMX process to shutdown. I assumed that the spring-boot-maven plug-in would do that. And that does not seem to be the case.

What am I doing wrong and can someone please help? Really appreciate you taking time to look at this (potential) problem.

Priceless answered 7/1, 2019 at 20:16 Comment(9)
Do you have an old session you forgot about? In other words, does it work after a reboot? – Tallie
If I kill the process (kill <PID>) that is running and then call mvn verify I don't get the bind exception. I was expecting to NOT have to do this process termination manually and my assumption is that spring-boot-maven would do it as part of its stop goal. Is my assumption incorrect? FWIW, I am on macOS Mojave with the latest patch that my employer allows. (Only reason I am saying this is because I am not sure if this problem could be a OS specific one.) – Priceless
Have a look with visualvm and see if there are any non-daemon threads Spring doesn't know about. – Tallie
In VisualVM, all processes that are spawned are shutdown, EXCEPT for one which is called class Application annotated with @SpringBootApplication. The arguments passed to this are --spring.application.admin.enabled=true --spring.application.admin.jmx-name=org.springframework.boot:type=Admin,name=SpringApplication. This process also has the following JMX JVM arguments -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=7654 -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false -Djava.rmi.server.hostname=127.0.0.1 – Priceless
This process is started when the application server starts for running the integration tests. And this is the process that also leads to a bind exception upon subsequent call of mvn verify. There are no other processes running on my machine. – Priceless
Ok, then I have no idea. Consider adding a bounty. – Tallie
hi, any updates about this?? – Wamble
Apologies for the delayed reply. None - we still have this problem. – Priceless
I'm also seeing this problem when fork is true. If I set fork to false then the stop goal works fine. However I require fork to be true so that doesn't get me anywhere. – Asbestosis
C
9

I was facing the same issue, not being able to rerun tests before killing the JMX process. Next to that, my Azure DevOps pipeline was hanging because of the JMX process not being stopped.

The STDIO streams did not close within 10 seconds of the exit event from process '/usr/share/apache-maven-3.6.3/bin/mvn'. This may indicate a child process inherited the STDIO streams and has not yet exited.

When I browsed through the source code: https://github.com/spring-projects/spring-boot/blob/master/spring-boot-project/spring-boot-tools/spring-boot-maven-plugin/src/main/java/org/springframework/boot/maven/StartMojo.java#L128, I discovered that the JMX agent would not be booted if I did not fork the maven process.

I'm not sure this is applicable for you, but I did not require forking per se, and also did not need JMX metrics, so this fixed it for me:

<configuration>
  <fork>false</fork>
</configuration>

I also tried to override the jmx arguments (-Dcom.sun.management.jmxremote), by specifying them in the plugin configuration, but since the arguments are added (hardcoded) as the final arguments, that was not working for me.

Chloechloette answered 29/1, 2021 at 10:45 Comment(1)
well, I cannot thank you enough. Now I just need to find out why they design it this way – Sulfathiazole

© 2022 - 2024 — McMap. All rights reserved.