On Tomcat6 shutdown web apps are not able to log anything

I case this is important:

java -version
java version "1.6.0_26"
Java(TM) SE Runtime Environment (build 1.6.0_26-b03)
Java HotSpot(TM) 64-Bit Server VM (build 20.1-b02, mixed mode)

We have tomcat6 deployed for multiple servers running our inhouse apps and have no shutdown problems.

What applications are you running? Could you do a jstack printout* AFTER you've called service tomcat6 stop? Does tomcat accept new connections or multiple SHUTDOWN requests after running the service tomcat6 stop for the first time?

Note that you'll need to run jstack as the tomcat user, with extra arguments to compensate for java.io.tmpdir, for example: "-J-Djava.io.tmpdir=$WHEREEVER_YOUR_TOMCAT_TEMP_IS".

For one of my installations its:

$ sudo -u tomcat jstack -l -J-Djava.io.tmpdir=/tmp/tomcat6-tmp <tomcatPid>

Thanks for the hint with jstack, I should have at least tested it in debug mode - my bad.

According to jstack the destroy method is called correctly. The problem seems to be the logging during shutdown instead. Nothing is logged after the shutdown is triggered and so this lead to my wrong assumption.
To be precise, I mean the log files in /var/log/tomcat6 .

Hmm, I can confirm that logs say nothing about stopping. I don't think that it should be like that.

It'd seem that some times I've got the lines into my catalina.out:

Jul 21, 2011 10:09:14 AM org.apache.catalina.startup.Catalina start
INFO: Server startup in 27464 ms
Jul 21, 2011 12:35:38 PM org.apache.coyote.http11.Http11Protocol pause
INFO: Pausing Coyote HTTP/1.1 on http-80

But when I just did the stop procedure (service tomcat6 stop) and confirmed that java process exited afterwards nothing was written out.

Perhaps you should change the bug description?

Changed headline and description.

Please find attached this small test web app which will simply log "init" if the Servlet's init() method is called and "destroy" when the destroy() method is called.

 public void init(ServletConfig config) throws ServletException {
  Logger.getLogger(getClass().getName()).warning("init");
 }

 public void destroy() {
  Logger.getLogger(getClass().getName()).warning("destroy");
 }

mdxyz - thanks for the test.war - helped alot with confirming this issue.

I was able to confirm this problem using the init script.

There are two ways of shutting down a running tomcat6 instance:

1) Send it the TERM signal - this is what the init script does through start-stop-daemon; when tomcat is shutdown this way I see no logging of any description.

2) Use the /usr/share/tomcat6/bin/shutdown.sh script to connect to the shutdown port (normally 8005) and initiate the shutdown that way: shutting down the tomcat6 instance this way results in correct shutdown logging to /var/log/tomcat6:

19-Aug-2011 14:32:49 org.apache.coyote.http11.Http11Protocol pause
INFO: Pausing Coyote HTTP/1.1 on http-8080
19-Aug-2011 14:32:50 org.apache.catalina.core.StandardService stop
INFO: Stopping service Catalina
19-Aug-2011 14:32:50 de.mdiener.test.TestDestroy destroy
WARNING: destroy
19-Aug-2011 14:32:50 org.apache.coyote.http11.Http11Protocol destroy
INFO: Stopping Coyote HTTP/1.1 on http-8080

I would suspect that sending the process the TERM signal differs from initiating a tomcat controlled shutdown; I'll take a look at the source and see.

I suspect this issue is associated with this bug:

 https://issues.apache.org/bugzilla/show_bug.cgi?id=48831

As all shutdown handlers are fired in parallel its possible the logging handler shutdown hook completes before the Catalina server shutdown hook resulting in no logging.

As this is fixed in 6.0.26+ marked as 'Fix Released' and Nominating for Lucid.