[systemd-devel] Springboot and systemd, clean shutdown

Wed Oct 2 21:35:59 UTC 2024

Am Mittwoch, dem 02.10.2024 um 12:58 -0400 schrieb Brian Reichert:
> ```
> My goal:
> 
>   Under SLES12 SP5 running systemd-228, I want to cleanly terminate
>   a Java-based SpringBoot application.
> 
> My problem: 
> 
>   systemd (or at least the version available to me) seemingly is
>   terminating my JVM differently than my ExecStop directive should
>   yield.
> 
> Just for quick background, a SpringBoot application is a self-hosted
> web server and web app, and you're excepted to interact with it via
> 'endpoints', basically several specific URLs.
> 
> According to the SpringBoot documentation, the desired way is to
> POST to the shutdown URL.
> 
>   [https://docs.spring.io/spring-boot/api/rest/actuator/shutdown.html](https://docs.spring.io/spring-boot/api/rest/actuator/shutdown.html)
> 
> Ignoring systemd: when the JVM is run is the foreground, using the
> shutdown endpoint yields a clean exit:
> 
>   10-153-68-12:/home/webapp # env SERVER_PORT=8888 LOG_DIR=/home/webapp/log
>   JDK_JAVA_OPTIONS=-Dlogging.config=log4j2.properties -Dloader.path=lib/
>   SPRING_MAIN_LAZY_INITIALIZATION=true /home/webapp/jdk/bin/java
>   -jar webapp.jar; echo $?
>   NOTE: Picked up JDK_JAVA_OPTIONS: -Dlogging.config=log4j2.properties
>   2024-10-02 12:20:24,685 main ERROR appender File has no parameter
>   that matches element Policies
>   0
> 
>   10-153-68-12:/home/webapp # /usr/bin/curl -X POST localhost:8888/shutdown
>   {"message":"Shutting down, bye..."}
> 
> (Note the '0' exit status above.)
> 
> When I've started my service via my service file, if I manually
> invoke the shutdown endpoint, I can see that the JVM exited with
> 0, but my ExecPost (using curl), was invoked, and that died as there
> was no longer a listener:
> 
>   10-153-68-12:/home/webapp # systemctl status webapp.service --full
>      webapp.service - example webapp
>      Loaded: loaded (/etc/systemd/system/webapp.service; disabled; vendor preset: disabled)
>      Active: failed (Result: exit-code) since Wed 2024-10-02 12:46:58 EDT; 7s ago
>     Process: 27573 ExecStop=/usr/bin/curl -X POST localhost:${SERVER_PORT}/shutdown (code=exited, status=7)
>     Process: 27434 ExecStart=/home/webapp/jdk/bin/java -jar ${JAR_FILE} ${JAR_ARGS} (code=exited, status=0/SUCCESS)
>    Main PID: 27434 (code=exited, status=0/SUCCESS)
>   
>   Oct 02 12:46:40 10-153-68-12 systemd[1]: Started example webapp.
>   Oct 02 12:46:40 10-153-68-12 java[27434]: NOTE: Picked up JDK_JAVA_OPTIONS: -Dlogging.config=log4j2.properties -Dloader.path=lib/
>   Oct 02 12:46:42 10-153-68-12 java[27434]: 2024-10-02 12:46:42,417 main ERROR appender File has no parameter that matches element Policies
>   Oct 02 12:46:58 10-153-68-12 curl[27573]:   % Total    % Received % Xferd Average Speed   Time    Time     Time  Current
>   Oct 02 12:46:58 10-153-68-12 curl[27573]: Dload  Upload   Total   Spent    Left  Speed
>   Oct 02 12:46:58 10-153-68-12 curl[27573]: [158B blob data]
>   Oct 02 12:46:58 10-153-68-12 curl[27573]: curl: (7) Failed to connect to localhost port 8888 after 2 ms: Couldn't connect to server
>   Oct 02 12:46:58 10-153-68-12 systemd[1]: webapp.service: Control process exited, code=exited status=7
>   Oct 02 12:46:58 10-153-68-12 systemd[1]: webapp.service: Unit entered failed state.
>   Oct 02 12:46:58 10-153-68-12 systemd[1]: webapp.service: Failed with result 'exit-code'.
> 
> I admit that's not a typical use case, so I'm not very worried, but
> it would be nice to harden against that.
> 
> But it does show, that using curl to hit the shutdown endpoint does cause the JVM to exit cleanly.
> 
> But, my real concern is when I use systemd to stop this service, I
> can see that curl was invoked, got content, and itself exited
> cleanly, but somehow my JVM is exiting with an exit status of 143:
> 
>   10-153-68-12:/home/webapp # systemctl status webapp.service --full
>      webapp.service - example webapp
>      Loaded: loaded (/etc/systemd/system/webapp.service; disabled; vendor preset: disabled)
>      Active: failed (Result: exit-code) since Wed 2024-10-02 12:30:22 EDT; 9s
>   ago
>     Process: 24220 ExecStop=/usr/bin/curl -X POST
>   localhost:${SERVER_PORT}/shutdown (code=exited, status=0/SUCCESS)
>     Process: 23462 ExecStart=/home/webapp/jdk/bin/java -jar ${JAR_FILE} ${JAR_ARGS} (code=exited, status=143)
>    Main PID: 23462 (code=exited, status=143)
>   
>   Oct 02 12:27:20 10-153-68-12 java[23462]: NOTE: Picked up JDK_JAVA_OPTIONS: -Dlogging.config=log4j2.properties -Dloader.path=lib/
>   Oct 02 12:27:23 10-153-68-12 java[23462]: 2024-10-02 12:27:23,015 main ERROR appender File has no parameter that matches element Policies
>   Oct 02 12:30:21 10-153-68-12 systemd[1]: Stopping example webapp...
>   Oct 02 12:30:21 10-153-68-12 curl[24220]:   % Total    % Received % Xferd Average Speed   Time    Time     Time  Current
>   Oct 02 12:30:21 10-153-68-12 curl[24220]: Dload  Upload   Total   Spent    Left  Speed
>   Oct 02 12:30:22 10-153-68-12 curl[24220]: [237B blob data]
>   Oct 02 12:30:22 10-153-68-12 systemd[1]: webapp.service: Main process exited, code=exited, status=143/n/a
>   Oct 02 12:30:22 10-153-68-12 systemd[1]: Stopped example webapp.
>   Oct 02 12:30:22 10-153-68-12 systemd[1]: webapp.service: Unit entered failed state.
>   Oct 02 12:30:22 10-153-68-12 systemd[1]: webapp.service: Failed with result 'exit-code'.
> 
> Further, when I compare logs, I can see that when I use the standalone
> execution, I can see the Springboot app cleanly shuts down it's
> listener; I don't see these entries when I use systemd to manage
> this webapp:
> 
>   [INFO ] 2024-10-02 12:27:20.656 [Thread-2] Http11NioProtocol - Pausing ProtocolHandler ["http-nio-8888"]
>   [INFO ] 2024-10-02 12:27:20.656 [Thread-2] StandardService - Stopping service [Tomcat]
>   [INFO ] 2024-10-02 12:27:20.658 [Thread-2] [/] - Destroying Spring FrameworkServlet 'dispatcherServlet'
>   [INFO ] 2024-10-02 12:27:20.661 [Thread-2] Http11NioProtocol - Stopping ProtocolHandler ["http-nio-8888"]
>   [INFO ] 2024-10-02 12:27:20.665 [Thread-2] Http11NioProtocol - Destroying ProtocolHandler ["http-nio-8888"]
> 
> Does anyone have any insight on why I'm seeing this?
> 
> Here's my service file:
> 
>   10-153-68-12:/home/webapp # cat /etc/systemd/system/webapp.service
>   [Unit]
>   Description=example webapp
>   Before=getty at tty1.service plymouth-quit.service
>   DefaultDependencies=no
>   
>   Requires=local-fs.target
>   After=local-fs.target
>   
>   [Service]
>   User=webapp
>   Group=webapp
>   
>   WorkingDirectory=/home/webapp
>   EnvironmentFile=/home/webapp/webapp.env
>   
>   PassEnvironment=JAVA_HOME JDK_JAVA_OPTIONS JAR_FILE JAR_ARGS SERVER_PORT
>   
>   ExecStart=/home/webapp/jdk/bin/java -jar ${JAR_FILE} ${JAR_ARGS}
>   ExecStop=/usr/bin/curl -X POST localhost:${SERVER_PORT}/shutdown
>   
>   TimeoutStopSec=30
>   KillMode=mixed
>   NotifyAccess=all
>   Restart=no
>   
>   [Install]
>   WantedBy=multi-user.target
> 
> 
> ```

Hi,

according to https://www.springcloud.io/post/2022-02/spring-boot-graceful-shutdown/#gsc.tab=0 you can just send `SIGTERM` to the MainPID as kill signal and be happy. No need to fiddle with some `curl` command. This is the same as spring boot is doing it in kubernetes (https://docs.spring.io/spring-boot/how-to/deployment/cloud.html#howto.deployment.cloud.kubernetes.container-lifecycle).

So here is my suggestion for a `webapp.service`.

```ini
[Unit]
Description=Example Webapp

[Service]
User=webapp
Group=Webapp
WorkingDirectory=/home/webapp
EnvironmentFile=/home/webapp/webapp.env

ExecStart=/home/webapp/jdk/bin/java -jar ${JAR_FILE} ${JAR_ARGS}

[Install]
WantedBy=multi-user.target
```

No need for a special `KillMode=`, as all subsequent processes will be SIGKILL'ed after the SIGTERM to MAINPID is done.

BR
Silvio