Can't use docker stop with tomcat image. Exit code 143 is returned. Exit code 0 was expected

Question

Can't use docker stop with tomcat image. Exit code 143 is returned. Exit code 0 was expected

cpauls opened this issue 8 years ago · 5 comments

Hi,
I played around with the docker container using the docker commands docker start/stop/pause... I'd like to use the docker restart policy with the option on-failure:

on-failure[:max-retries] Restart only if the container exits with a non-zero exit status. Optionally, limit the number of restart retries the Docker daemon attempts.

The tomcat docker container does not stops in the expected way. I expected exit code 0 - but the container stops with exit code 143.

vagrant@development:~$ docker --version
Docker version 1.12.3, build 6b644ec
vagrant@development:~$ docker run -d --name mytomcat tomcat:8.5.8
00eca311039ba413b1dcfb59b0e64551e5460a4af4777057bf1476bc46e84864
vagrant@development:~$ docker stop mytomcat
mytomcat
vagrant@development:~$ docker ps -a
CONTAINER ID        IMAGE               COMMAND             CREATED             STATUS                       PORTS               NAMES
00eca311039b        tomcat:8.5.8        "catalina.sh run"   9 seconds ago       Exited (143) 2 seconds ago                       mytomcat

Possible solution:

do not execute catalina.sh run. Use a wrapper script instead which execute catalina.sh start.
The wrapper script could handle the unix signals using trap as described in trapping-signals-in-docker-containers or in gracefully-stopping-docker-containers/

What do you think about this? Could this be a working solution?

Regards
@cpauls

Answer 1 · 2016-12-10T15:40:36.000Z

Did you check the logs from the container to see why it's failing? (docker logs mytomcat)

Answer 2 · 2016-12-12T10:16:09.000Z

Hi,
the logfiles are looking good.

vagrant@development:~$ docker run -d --name mytomcat tomcat:8.5.8
e2cdfe3c31612b515103958b488c5265736b4530580cc13a4ef64ef233bc4d0e
vagrant@development:~$ docker stop mytomcat
mytomcat
vagrant@development:~$ docker logs mytomcat
12-Dec-2016 09:07:44.868 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version:        Apache Tomcat/8.5.8
12-Dec-2016 09:07:44.871 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          Nov 3 2016 21:14:13 UTC
....
12-Dec-2016 09:07:46.271 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 1195 ms
12-Dec-2016 09:07:48.460 INFO [Thread-5] org.apache.coyote.AbstractProtocol.pause Pausing ProtocolHandler ["http-nio-8080"]
12-Dec-2016 09:07:48.522 INFO [Thread-5] org.apache.coyote.AbstractProtocol.pause Pausing ProtocolHandler ["ajp-nio-8009"]
12-Dec-2016 09:07:48.573 INFO [Thread-5] org.apache.catalina.core.StandardService.stopInternal Stopping service Catalina
12-Dec-2016 09:07:48.617 INFO [Thread-5] org.apache.coyote.AbstractProtocol.stop Stopping ProtocolHandler ["http-nio-8080"]
12-Dec-2016 09:07:48.618 INFO [Thread-5] org.apache.coyote.AbstractProtocol.stop Stopping ProtocolHandler ["ajp-nio-8009"]
12-Dec-2016 09:07:48.619 INFO [Thread-5] org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler ["http-nio-8080"]
12-Dec-2016 09:07:48.620 INFO [Thread-5] org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler ["ajp-nio-8009"]
vagrant@development:~$

I think the problem is executing catalina.sh directly. For starting the docker image the command CMD ["catalina.sh", "run"] is executed.

You can reproduce this by hand.
First I start a docker the tomcat directly in the dockercontainer:

vagrant@development:~$ docker run -ti --rm  --name playground tomcat:8.5.8 /bin/bash
root@27378401fcac:/usr/local/tomcat# /usr/local/tomcat/bin/catalina.sh run
Using CATALINA_BASE:   /usr/local/tomcat
Using CATALINA_HOME:   /usr/local/tomcat
Using CATALINA_TMPDIR: /usr/local/tomcat/temp
Using JRE_HOME:        /usr/lib/jvm/java-8-openjdk-amd64/jre
Using CLASSPATH:       /usr/local/tomcat/bin/bootstrap.jar:/usr/local/tomcat/bin/tomcat-juli.jar
12-Dec-2016 09:53:49.114 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version:        Apache Tomcat/8.5.8
...
12-Dec-2016 09:53:49.355 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.5.8
12-Dec-2016 09:53:49.373 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory /usr/local/tomcat/webapps/ROOT

The tomcat is now running. Now I enter the container directly in a second shell and kill the tomcat process with SIGTERM like docker does.

CONTAINER ID        IMAGE               COMMAND             CREATED             STATUS              PORTS               NAMES
27378401fcac        tomcat:8.5.8        "/bin/bash"         4 minutes ago       Up 3 minutes        8080/tcp            playground
vagrant@development:~$ docker exec -ti playground ps -ef
UID        PID  PPID  C STIME TTY          TIME CMD
root         1     0  0 09:53 ?        00:00:00 /bin/bash
root         5     1  1 09:53 ?        00:00:02 /usr/lib/jvm/java-8-openjdk-amd6
root        31     0  0 09:57 ?        00:00:00 ps -ef
vagrant@development:~$ docker exec -ti playground kill -15 5
TERM
vagrant@development:~$

In the first shell the tomcat is stopping. I can ask for the exit code with echo $?. The exitcode is 143 instead of 0

12-Dec-2016 09:53:49.355 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.5.8
12-Dec-2016 09:53:49.373 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory /usr/local/tomcat/webapps/ROOT
12-Dec-2016 09:55:26.908 INFO [localhost-startStop-1] org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [97,094] milliseconds.
12-Dec-2016 09:55:26.941 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory /usr/local/tomcat/webapps/ROOT has finished in 97,568 ms
12-Dec-2016 09:55:26.941 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory /usr/local/tomcat/webapps/host-manager
12-Dec-2016 09:55:27.012 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory /usr/local/tomcat/webapps/host-manager has finished in 71 ms
12-Dec-2016 09:55:27.013 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory /usr/local/tomcat/webapps/manager
12-Dec-2016 09:55:27.057 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory /usr/local/tomcat/webapps/manager has finished in 44 ms
12-Dec-2016 09:55:27.058 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory /usr/local/tomcat/webapps/examples
12-Dec-2016 09:55:27.468 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory /usr/local/tomcat/webapps/examples has finished in 410 ms
12-Dec-2016 09:55:27.469 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory /usr/local/tomcat/webapps/docs
12-Dec-2016 09:55:27.497 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory /usr/local/tomcat/webapps/docs has finished in 28 ms
12-Dec-2016 09:55:27.507 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler [http-nio-8080]
12-Dec-2016 09:55:27.522 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler [ajp-nio-8009]
12-Dec-2016 09:55:27.530 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 98222 ms
12-Dec-2016 10:01:45.220 INFO [Thread-5] org.apache.coyote.AbstractProtocol.pause Pausing ProtocolHandler ["http-nio-8080"]
12-Dec-2016 10:01:45.234 INFO [Thread-5] org.apache.coyote.AbstractProtocol.pause Pausing ProtocolHandler ["ajp-nio-8009"]
12-Dec-2016 10:01:45.235 INFO [Thread-5] org.apache.catalina.core.StandardService.stopInternal Stopping service Catalina
12-Dec-2016 10:01:45.290 INFO [Thread-5] org.apache.coyote.AbstractProtocol.stop Stopping ProtocolHandler ["http-nio-8080"]
12-Dec-2016 10:01:45.291 INFO [Thread-5] org.apache.coyote.AbstractProtocol.stop Stopping ProtocolHandler ["ajp-nio-8009"]
12-Dec-2016 10:01:45.292 INFO [Thread-5] org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler ["http-nio-8080"]
12-Dec-2016 10:01:45.294 INFO [Thread-5] org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler ["ajp-nio-8009"]
root@27378401fcac:/usr/local/tomcat# echo $?
143
root@27378401fcac:/usr/local/tomcat#

So back to the Possible solutions:

Tomcat itself has to fix it - I think the won't do that 😑
develop a wrapper script as suggested in my first post

Answer 3 · 2016-12-12T17:45:09.000Z

Arg, I see -- I've been researching a little, and it seems like there might not actually be a nice way for Tomcat upstream to fix this issue.

http://stackoverflow.com/a/4192488/433558: exit code 143 corresponds to SIGTERM

http://stackoverflow.com/a/2541618/433558: Java applications can respond to the shutdown that's initiated by SIGTERM, but it does not appear that they can distinguish it from SIGINT or modify the resulting exit code in any sane way 😞

😭

Answer 4 · 2016-12-12T21:22:22.000Z

In my opinion this is not an issue, everything works as described

docker stop does exactly as the documentation states:

... a SIGTERM is sent to the main proces. ...

From the docker ps -a you are informed that indeed SIGTERM (143) has resulted in stopping the tomcat container.

Further notice: It may also have been a SIGKILL (137) if tomcat would have used more time then the grace period (default: 10 seconds) to shut down.

In the description of the run command with regard to the restart-policies it is stated that

....and so on until either the on-failure limit is hit, or when you docker stop or docker rm -f the container. ...

So when you give the stop command it will NOT be restarted.

What could be wrong is that giving the SIGTERM internally (without docker stop) one would expect the container to be restarted in this setup. But that may depend on the docker implementation...

I further tested the case when you send a different signal (e.g. kill -1 1). In that case the container is restarted as i would expect it to...

@cpauls can you describe what you wish to accomplish?

Note that i have a setup usig systemd (on CoreOS) in which i specified in the unit file to restart the tomcat container in this case (Restart=on-success and SuccessExitStatus=143). But that may not be an option in your case.

Answer 5 · 2018-04-24T21:00:12.000Z

Closing, given that this appears either resolved or working appropriately. 👍