02.10.2024 19:58, Brian Reichert wrote:
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
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
There is no log line about stopping this service which implies that your
application died and systemd executed ExecStop after it happened.
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?
systemd assumes your service is stopped as soon as ExecStop finshed. If
it is not, it will send signal(s) to whatever processes still remained.
Your ExecStop command needs to actually wait until application is stopped.
Here's my service file:
10-153-68-12:/home/webapp # cat /etc/systemd/system/webapp.service
[Unit]
Description=example webapp
Before=getty@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
