Hi @rzo,
I am troubleshooting an escalation for my service where it is shutting down abruptly and here is what I see in the wrapper logs:
INFO|wrapper|21-08-03 01:55:42|stopping process with pid/timeout 1988 135000 INFO|wrapper|21-08-03 01:55:42|Shutting down Wrapper INFO|1988/0|21-08-03 01:55:43|wrapper manager received Message:STOP::USER INFO|wrapper|21-08-03 01:55:43|waitpid 1988 0 INFO|wrapper|21-08-03 01:55:43|exit code posix process: 0 application(status/signal): 0/0 INFO|wrapper|21-08-03 01:55:43|shutdown wrapper due to exit code rule INFO|wrapper|21-08-03 01:55:43|killing 1988 INFO|wrapper|21-08-03 01:55:44|process exit code: 0
Other shutdown exit code that I see:
INFO|wrapper|21-08-03 02:01:30|waitpid 1618 15 INFO|wrapper|21-08-03 02:01:30|exit code posix process: 15 application(status/signal): 0/15 INFO|wrapper|21-08-03 02:01:30|killing 1618 INFO|wrapper|21-08-03 02:01:30|shutdown wrapper due to exit code rule INFO|wrapper|21-08-03 02:01:31|process exit code: 0
I unfortunately do not have logs like journalctl logs from this instance to see if there was any service event executed and so I am trying to understand the wrapper logs more closely.
In what scenarios does wrapper says 'stopping process with pid/timeout 1988 135000'?
Here are the service timeouts that I have set:
wrapper.startup.timeout = 120 wrapper.shutdown.timeout = 120 wrapper.ping.timeout = 60
Is there a way to tell if this was user initiated or wrapper/service itself?
There is a monitoring service which when detects that my service is down would try to restart with command - systemctl restart myservice
I tested my service internally and ran same command systemctl restart myservice, I see:
INFO|wrapper|21-11-17 15:51:02|Shutting down Wrapper INFO|wrapper|21-11-17 15:51:02|stopping process with pid/timeout 3606 135000 INFO|3606/0|21-11-17 15:51:02|wrapper manager received Message:STOP::WRAPPER SHUTDOWN INFO|wrapper|21-11-17 15:51:02|waitpid 3606 0 INFO|wrapper|21-11-17 15:51:02|exit code posix process: 0 application(status/signal): 0/0 INFO|wrapper|21-11-17 15:51:02|killing 3606 INFO|wrapper|21-11-17 15:51:03|shutdown wrapper due to exit code rule INFO|wrapper|21-11-17 15:51:03|process exit code: 0
what is the difference in -
wrapper manager received Message:STOP::USER
wrapper manager received Message:STOP::WRAPPER SHUTDOWN
Versions:
OS: Photon VM (Linux)
Java: OpenJDK Java 11
YAJSW: 12.15
Appreciate any feedback on this query!
Please let me know if you would like me to share complete log file and any wrapper configuration.
Thank you!
hello,
STOP::USER means that the daemon was stopped by the user. for example by invoking systemctl stop
STOP::WRAPPER means that the daemon is stopped by the wrapper. This could be for example because the application process crashed, or terminated or because a filter such as wrapper.filter.trigger has triggered or the application invoked WRAPPER_MANAGER.stop(), ....
according to your log file the process received the signal 15 == SIGTERM:
Hope this helps. If you have more questions pls post.
-- Ron
Thank you @rzo for your quick response. This definitely helps clarify the events.
So I have been testing service stop and restart in my internal setup and for both
systemctl stop myservice
systemctl restart myservice
I see in logs:
I did encounter STOP::USER twice with restart but unable to produce that consistently.
I would expect all events be STOP::USER.
I do not have any wrapper.filter.trigger set for my service.
Some more wrapper configuration:
Should I be setting this property since now I am using 12.15:
Also want to point out that before moving to 12.15, I was updating service's unit file.
[Service]
SuccessExitStatus=143
https://serverfault.com/questions/695849/services-remain-in-failed-state-after-stopped-with-systemctl
Refer: https://sourceforge.net/p/yajsw/bugs/173/
I still have this configuration but looks like I can remove that now, right?
Last edit: Arushi Rai 2021-11-18
hello,
i tested this on centos and it seems that when stopped by systemctl it sometimes logs "USER" and sometimes "WRAPPER". Setting in the wrapper conf, wrapper.debug = true, reveals some more information. There seems to be a race condition for the stop reason within the wrapper. I will have to look into this. but this has low priority, since the functionality of stopping is not affected.
Note that the wrapper has no way of "knowing" why/by whom it was stopped. If the application crashed the wrapper will notice this and either shut down or restart the application, depending on the configuration. When invoking systemctl stop, systemd sends a SIGTERM signal to the java application. In this case the wrapper process. This executes a shutdown hook which tries to gracefully stop the application and then terminates.
Setting SuccessExitStatus=143 is, I think, not necessary. At least not on centos. the status is correctly set to inactive.
you can also check /var/log/messages to see if the wrapper was stopped by systemd.
-- Ron
Hi @rzo,
I have set wrapper.debug=true in my internal setup and here is the log snippet for action
systemctl stop myservice:
Let me know if this helps understand the behavior a bit more.
I will be gathering the same from customer's env along with journalctl logs.
Thank you for your assistance on this ticket.