Spring Boot - Maven Plugin shutdown broken

[Tom-Br]

As of 2.2.0 the shutdown of a spring-boot application is broken and results in a Build Failure when executed.

I ran mvnw clean install package spring-boot:run as a command.

In attachment the executable file of a boot from https://start.spring.io/ and the resulted build fail. I ran with Java 8, and the Maven wrapper included in the project.

output.txt

[wilkinsona]

Thanks for the log. It seems to show the following commands being run:

• mvnw clean package (succeeds)
• mvnw spring-boot:run (succeeds)
• mvnw spring-boot:run (fails)

That does not match my understanding of your description. Can you please clarify? The best way to do so would be with a small sample, zipped up and attached to this issue, that reproduces the problem, and the exact commands that we need to run to do so.

[Tom-Br]

Steps I did for the creation of this zip.:

• Download a demo application from start.spring.io (Spring Boot V2.2.1, Java 8, Dependencies: Web)
• Extract the demo application
• Ran command mvnw clean install spring-boot:run in the demo application
• Waited for Boot
• After boot -> Stop with ctrl+C

Result: A Build failure

demo.zip
output.txt

[wilkinsona]

Thanks. The problem appears to be specific to Windows. On macOS CTRL+C shuts the app down gently and the build completes successfully:

[INFO] --- spring-boot-maven-plugin:2.2.1.RELEASE:run (default-cli) @ demo ---
[INFO] Attaching agents: []

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.2.1.RELEASE)

2019-11-08 09:57:55.340  INFO 49237 --- [           main] com.example.demo.DemoApplication         : Starting DemoApplication on Andys-MacBook-Pro.local with PID 49237 (/Users/awilkinson/Downloads/demo-2/target/classes started by awilkinson in /Users/awilkinson/Downloads/demo-2)
2019-11-08 09:57:55.342  INFO 49237 --- [           main] com.example.demo.DemoApplication         : No active profile set, falling back to default profiles: default
2019-11-08 09:57:55.840  INFO 49237 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2019-11-08 09:57:55.846  INFO 49237 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2019-11-08 09:57:55.846  INFO 49237 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.27]
2019-11-08 09:57:55.888  INFO 49237 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2019-11-08 09:57:55.888  INFO 49237 --- [           main] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 521 ms
2019-11-08 09:57:55.977  INFO 49237 --- [           main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2019-11-08 09:57:56.066  INFO 49237 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2019-11-08 09:57:56.068  INFO 49237 --- [           main] com.example.demo.DemoApplication         : Started DemoApplication in 0.917 seconds (JVM running for 1.16)
^C2019-11-08 09:57:57.852  INFO 49237 --- [extShutdownHook] o.s.s.concurrent.ThreadPoolTaskExecutor  : Shutting down ExecutorService 'applicationTaskExecutor'
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  7.357 s
[INFO] Finished at: 2019-11-08T09:57:57Z
[INFO] ------------------------------------------------------------------------

On Windows the app seems to be killed rather than being shut down (the shutdown hook does not run) and the build then ends in failure:

[INFO] --- spring-boot-maven-plugin:2.2.1.RELEASE:run (default-cli) @ demo ---
[INFO] Attaching agents: []

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.2.1.RELEASE)

2019-11-08 10:05:16.915  INFO 4676 --- [           main] com.example.demo.DemoApplication         : Starting DemoApplication on WIN-MV32EG1PCS7 with PID 4676 (started by Andy Wilkinson in C:\Users\Andy Wilkinson\Desktop\demo)
2019-11-08 10:05:16.915  INFO 4676 --- [           main] com.example.demo.DemoApplication         : No active profile set, falling back to default profiles: default
2019-11-08 10:05:17.789  INFO 4676 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2019-11-08 10:05:17.804  INFO 4676 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2019-11-08 10:05:17.804  INFO 4676 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.27]
2019-11-08 10:05:17.867  INFO 4676 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2019-11-08 10:05:17.867  INFO 4676 --- [           main] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 905ms
2019-11-08 10:05:18.023  INFO 4676 --- [           main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2019-11-08 10:05:18.241  INFO 4676 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2019-11-08 10:05:18.257  INFO 4676 --- [           main] com.example.demo.DemoApplication         : Started DemoApplication in 1.634 seconds (JVM running for 1.954)
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  01:29 min
[INFO] Finished at: 2019-11-08T10:05:33Z
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal org.springframework.boot:spring-boot-maven-plugin :2.2.1.RELEASE:run (default-cli) on project demo: Application finished with exit code: 1 -> [Help 1]
[ERROR]
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR]
[ERROR] For more information about the errors and possible solutions, please read the following articles:
[ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/MojoExecutionException

[wilkinsona]

The problem doesn't occur if forking is disabled. CTRL+C then shuts down the JVM running Maven and the app, and no output about the outcome of the build is shown:

[INFO] --- spring-boot-maven-plugin:2.2.1.RELEASE:run (default-cli) @ demo ---

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.2.1.RELEASE)

2019-11-08 10:28:53.018  INFO 3152 --- [           main] com.example.demo.DemoApplication         : Starting DemoApplication on WIN-MV32EG1PCS7 with PID 3152 (started by Andy Wilkinson in C:\Users\Andy Wilkinson\Desktop\demo)
2019-11-08 10:28:53.236  INFO 3152 --- [           main] com.example.demo.DemoApplication         : No active profile set, falling back to default profiles: default
2019-11-08 10:28:54.313  INFO 3152 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2019-11-08 10:28:54.328  INFO 3152 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2019-11-08 10:28:54.328  INFO 3152 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.27]
2019-11-08 10:28:54.406  INFO 3152 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2019-11-08 10:28:54.406  INFO 3152 --- [           main] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 1107 ms
2019-11-08 10:28:54.578  INFO 3152 --- [           main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2019-11-08 10:28:54.749  INFO 3152 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2019-11-08 10:28:54.765  INFO 3152 --- [           main] com.example.demo.DemoApplication         : Started DemoApplication in 2.303 seconds (JVM running for 5.611)
2019-11-08 10:28:56.887  INFO 3152 --- [extShutdownHook] o.s.s.concurrent.ThreadPoolTaskExecutor  : Shutting down ExecutorService 'applicationTaskExecutor'
Terminate batch job (Y/N)? y

[wilkinsona]

Related:

• Shutdown hook not firing in forked jvm launched by spring-boot:run on Windows #3093
• App launched from an IDE with spring-boot:run with forking enabled doesn't get shut down properly #5185

[wilkinsona]

On macOS the SIGINT sent by CTRL+C causes the forked JVM to exit with 130. The parent JVM then exits and our RunProcessKiller shutdown hook is run. It attempts to kill the forked JVM which is a no-op as it has already exited.

[wilkinsona]

With Windows, the only difference from the above is that the signal sent by CTRL+C causes the forked JVM to exit with 1.