Hi
I am having problem when shutting down tomcat.
Tomcat: 6.0.14.
OS: Linux 2.6.16.21-0.8-smp #1 SMP Mon Jul 3 18:25:39 UTC 2006 x86_64
Java: "1.5.0_14" Java(TM) 2 Runtime Environment, Standard Edition (build
1.5.0_14-b03) Java HotSpot(TM) 64-Bit Server VM (build 1.5.0_14-b03, mixed mode)
The scenario is as follows:
org.apache.tomcat.util.net.JIoEndpoint.pause is called
calls: unlockAccept();
org.apache.tomcat.util.net.JIoEndpoint.stop is called
calls: unlockAccept();
The second call is not necessary when the connector has already been paused in
my opinion.
Please consider changing the JioEndpoint code as follows:
public void stop() {
if (running) {
running = false;
if (!paused) {
unlockAccept();
}
}
}
The same problem exists in org.apache.tomcat.util.net.AprEndpoint
In my scenario Tomcat is stopped under heavy load. From tomcat logs I can see
that most of the "stop time" is consumed to by the unlockAccept method (see
stack trace and logs below).
Tomcat log:
2009-07-28 13:34:12,914 ( ) INFO org.apache.coyote.http11.Http11Protocol
[221] - Pausing Coyote HTTP/1.1 on http-8800
2009-07-28 13:34:13,921 ( ) INFO org.apache.catalina.core.StandardService
[576] - Stopping service internal
2009-07-28 13:34:13,921 ( ) INFO org.apache.catalina.core.StandardService
[576] - Stopping service internal
2009-07-28 13:35:05,290 ( ) INFO org.apache.coyote.http11.Http11Protocol
[237] - Stopping Coyote HTTP/1.1 on http-8800
2009-07-28 13:38:14,295 ( ) INFO org.apache.coyote.http11.Http11Protocol
[221] - Pausing Coyote HTTP/1.1 on http-7080
2009-07-28 13:38:14,295 ( ) INFO org.apache.coyote.http11.Http11Protocol
[221] - Pausing Coyote HTTP/1.1 on http-7443
2009-07-28 13:38:15,381 ( ) INFO org.apache.catalina.core.StandardService
[576] - Stopping service main
2009-07-28 13:38:15,381 ( ) INFO org.apache.catalina.core.StandardService
[576] - Stopping service main
2009-07-28 13:38:15,621 ( ) INFO org.apache.catalina.core.StandardWrapper
[1355] - Waiting for 28 instance(s) to be deallocated
2009-07-28 13:38:15,621 ( ) INFO org.apache.catalina.core.StandardWrapper
[1355] - Waiting for 28 instance(s) to be deallocated
2009-07-28 13:38:16,737 ( ) INFO org.apache.catalina.core.StandardWrapper
[1355] - Waiting for 24 instance(s) to be deallocated
2009-07-28 13:38:16,737 ( ) INFO org.apache.catalina.core.StandardWrapper
[1355] - Waiting for 24 instance(s) to be deallocated
2009-07-28 13:38:17,778 ( ) INFO org.apache.catalina.core.StandardWrapper
[1355] - Waiting for 24 instance(s) to be deallocated
2009-07-28 13:38:17,778 ( ) INFO org.apache.catalina.core.StandardWrapper
[1355] - Waiting for 24 instance(s) to be deallocated
2009-07-28 13:38:17,885 ( ) INFO org.apache.catalina.core.StandardWrapper
[1355] - Waiting for 75 instance(s) to be deallocated
2009-07-28 13:38:17,885 ( ) INFO org.apache.catalina.core.StandardWrapper
[1355] - Waiting for 75 instance(s) to be deallocated
2009-07-28 13:38:19,004 ( ) INFO org.apache.catalina.core.StandardWrapper
[1355] - Waiting for 59 instance(s) to be deallocated
2009-07-28 13:38:19,004 ( ) INFO org.apache.catalina.core.StandardWrapper
[1355] - Waiting for 59 instance(s) to be deallocated
2009-07-28 13:38:20,044 ( ) INFO org.apache.catalina.core.StandardWrapper
[1355] - Waiting for 47 instance(s) to be deallocated
2009-07-28 13:38:20,044 ( ) INFO org.apache.catalina.core.StandardWrapper
[1355] - Waiting for 47 instance(s) to be deallocated
2009-07-28 13:38:20,855 ( ) INFO org.apache.coyote.http11.Http11Protocol
[237] - Stopping Coyote HTTP/1.1 on http-7080
2009-07-28 13:38:20,859 ( ) INFO org.apache.coyote.http11.Http11Protocol
[237] - Stopping Coyote HTTP/1.1 on http-7443
2009-07-28 13:38:20,860 ( ) INFO org.apache.coyote.http11.Http11NioProtocol
[183] - Pausing Coyote HTTP/1.1 on http-8080
2009-07-28 13:38:20,860 ( ) INFO org.apache.coyote.http11.Http11NioProtocol
[183] - Pausing Coyote HTTP/1.1 on http-8443
2009-07-28 13:38:21,866 ( ) INFO org.apache.catalina.core.StandardService
[576] - Stopping service comet
2009-07-28 13:38:21,866 ( ) INFO org.apache.catalina.core.StandardService
[576] - Stopping service comet
2009-07-28 13:38:21,867 ( ) INFO org.apache.catalina.core.StandardWrapper
[1355] - Waiting for 84 instance(s) to be deallocated
2009-07-28 13:38:21,867 ( ) INFO org.apache.catalina.core.StandardWrapper
[1355] - Waiting for 84 instance(s) to be deallocated
2009-07-28 13:38:22,910 ( ) INFO org.apache.catalina.core.StandardWrapper
[1355] - Waiting for 72 instance(s) to be deallocated
2009-07-28 13:38:22,910 ( ) INFO org.apache.catalina.core.StandardWrapper
[1355] - Waiting for 72 instance(s) to be deallocated
2009-07-28 13:38:23,954 ( ) INFO org.apache.catalina.core.StandardWrapper
[1355] - Waiting for 63 instance(s) to be deallocated
2009-07-28 13:38:23,954 ( ) INFO org.apache.catalina.core.StandardWrapper
[1355] - Waiting for 63 instance(s) to be deallocated
2009-07-28 13:38:24,397 ( ) INFO org.apache.coyote.http11.Http11NioProtocol
[199] - Stopping Coyote HTTP/1.1 on http-8080
2009-07-28 13:38:24,540 ( ) INFO org.apache.coyote.http11.Http11NioProtocol
[199] - Stopping Coyote HTTP/1.1 on http-8443
Simple listener class added to each context, host, engine, connector, service
to log the event (source code added below):
Tue Jul 28 13:34:12 CEST 2009 Event. type:before_stop
Source:StandardService[internal] class:class
org.apache.catalina.core.StandardService
Tue Jul 28 13:34:13 CEST 2009 Event. type:stop Source:StandardService[internal]
class:class org.apache.catalina.core.StandardService
Tue Jul 28 13:34:13 CEST 2009 Event. type:before_stop
Source:StandardEngine[internal] class:class
org.apache.catalina.core.StandardEngine
Tue Jul 28 13:34:13 CEST 2009 Event. type:stop Source:StandardEngine[internal]
class:class org.apache.catalina.core.StandardEngine
Tue Jul 28 13:34:13 CEST 2009 Event. type:before_stop
Source:StandardEngine[internal].StandardHost[localhost] class:class
org.apache.catalina.core.StandardHost
Tue Jul 28 13:34:13 CEST 2009 Event. type:stop
Source:StandardEngine[internal].StandardHost[localhost] class:class
org.apache.catalina.core.StandardHost
Tue Jul 28 13:34:13 CEST 2009 Event. type:before_stop
Source:StandardEngine[internal].StandardHost[localhost].StandardContext[/messagehandler]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:34:13 CEST 2009 Event. type:stop
Source:StandardEngine[internal].StandardHost[localhost].StandardContext[/messagehandler]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:34:14 CEST 2009 Event. type:after_stop
Source:StandardEngine[internal].StandardHost[localhost].StandardContext[/messagehandler]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:34:14 CEST 2009 Event. type:before_stop
Source:StandardEngine[internal].StandardHost[localhost].StandardContext[/clientregistry]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:34:14 CEST 2009 Event. type:stop
Source:StandardEngine[internal].StandardHost[localhost].StandardContext[/clientregistry]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:34:14 CEST 2009 Event. type:after_stop
Source:StandardEngine[internal].StandardHost[localhost].StandardContext[/clientregistry]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:34:14 CEST 2009 Event. type:before_stop
Source:StandardEngine[internal].StandardHost[localhost].StandardContext[/smtpmda]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:34:14 CEST 2009 Event. type:stop
Source:StandardEngine[internal].StandardHost[localhost].StandardContext[/smtpmda]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:34:15 CEST 2009 Event. type:after_stop
Source:StandardEngine[internal].StandardHost[localhost].StandardContext[/smtpmda]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:34:15 CEST 2009 Event. type:before_stop
Source:StandardEngine[internal].StandardHost[localhost].StandardContext[/smppmda]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:35:05 CEST 2009 Event. type:stop
Source:StandardEngine[internal].StandardHost[localhost].StandardContext[/smppmda]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:35:05 CEST 2009 Event. type:after_stop
Source:StandardEngine[internal].StandardHost[localhost].StandardContext[/smppmda]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:35:05 CEST 2009 Event. type:before_stop
Source:StandardEngine[internal].StandardHost[localhost].StandardContext[/smppmsa]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:35:05 CEST 2009 Event. type:stop
Source:StandardEngine[internal].StandardHost[localhost].StandardContext[/smppmsa]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:35:05 CEST 2009 Event. type:after_stop
Source:StandardEngine[internal].StandardHost[localhost].StandardContext[/smppmsa]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:35:05 CEST 2009 Event. type:after_stop
Source:StandardEngine[internal].StandardHost[localhost] class:class
org.apache.catalina.core.StandardHost
Tue Jul 28 13:35:05 CEST 2009 Event. type:after_stop
Source:StandardEngine[internal] class:class
org.apache.catalina.core.StandardEngine
Tue Jul 28 13:35:05 CEST 2009 Event. type:stop
Source:org.apache.catalina.connector.connec...@7ec78e02 class:class
org.apache.catalina.connector.Connector port=8800
info:org.apache.catalina.connector.Connector/2.1
ProtocolHandlerClassNameorg.apache.coyote.http11.Http11Protocol
HERE 3min 5s
Tue Jul 28 13:38:14 CEST 2009 Event. type:after_stop
Source:StandardService[internal] class:class
org.apache.catalina.core.StandardService
Tue Jul 28 13:38:14 CEST 2009 Event. type:before_stop
Source:StandardService[main] class:class
org.apache.catalina.core.StandardService
Tue Jul 28 13:38:15 CEST 2009 Event. type:stop Source:StandardService[main]
class:class org.apache.catalina.core.StandardService
Tue Jul 28 13:38:15 CEST 2009 Event. type:before_stop
Source:StandardEngine[main] class:class org.apache.catalina.core.StandardEngine
Tue Jul 28 13:38:15 CEST 2009 Event. type:stop Source:StandardEngine[main]
class:class org.apache.catalina.core.StandardEngine
Tue Jul 28 13:38:15 CEST 2009 Event. type:before_stop
Source:StandardEngine[main].StandardHost[localhost] class:class
org.apache.catalina.core.StandardHost
Tue Jul 28 13:38:15 CEST 2009 Event. type:stop
Source:StandardEngine[main].StandardHost[localhost] class:class
org.apache.catalina.core.StandardHost
Tue Jul 28 13:38:15 CEST 2009 Event. type:before_stop
Source:StandardEngine[main].StandardHost[localhost].StandardContext[/]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:38:20 CEST 2009 Event. type:stop
Source:StandardEngine[main].StandardHost[localhost].StandardContext[/]
class:class org.apache.catalina.core.StandardContext
log4j:WARN No appenders could be found for logger
(org.springframework.transaction.interceptor.TransactionInterceptor).
log4j:WARN Please initialize the log4j system properly.
Tue Jul 28 13:38:20 CEST 2009 Event. type:after_stop
Source:StandardEngine[main].StandardHost[localhost].StandardContext[/]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:38:20 CEST 2009 Event. type:before_stop
Source:StandardEngine[main].StandardHost[localhost].StandardContext[/Download]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:38:20 CEST 2009 Event. type:stop
Source:StandardEngine[main].StandardHost[localhost].StandardContext[/Download]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:38:20 CEST 2009 Event. type:after_stop
Source:StandardEngine[main].StandardHost[localhost].StandardContext[/Download]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:38:20 CEST 2009 Event. type:before_stop
Source:StandardEngine[main].StandardHost[localhost].StandardContext[/tomcatMonitor]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:38:20 CEST 2009 Event. type:stop
Source:StandardEngine[main].StandardHost[localhost].StandardContext[/tomcatMonitor]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:38:20 CEST 2009 Event. type:after_stop
Source:StandardEngine[main].StandardHost[localhost].StandardContext[/tomcatMonitor]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:38:20 CEST 2009 Event. type:before_stop
Source:StandardEngine[main].StandardHost[localhost].StandardContext[/manager]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:38:20 CEST 2009 Event. type:stop
Source:StandardEngine[main].StandardHost[localhost].StandardContext[/manager]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:38:20 CEST 2009 Event. type:after_stop
Source:StandardEngine[main].StandardHost[localhost].StandardContext[/manager]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:38:20 CEST 2009 Event. type:after_stop
Source:StandardEngine[main].StandardHost[localhost] class:class
org.apache.catalina.core.StandardHost
Tue Jul 28 13:38:20 CEST 2009 Event. type:after_stop
Source:StandardEngine[main] class:class org.apache.catalina.core.StandardEngine
Tue Jul 28 13:38:20 CEST 2009 Event. type:stop
Source:org.apache.catalina.connector.connec...@14e44dd3 class:class
org.apache.catalina.connector.Connector port=7080
info:org.apache.catalina.connector.Connector/2.1
ProtocolHandlerClassNameorg.apache.coyote.http11.Http11Protocol
Tue Jul 28 13:38:20 CEST 2009 Event. type:stop
Source:org.apache.catalina.connector.connec...@28278a47 class:class
org.apache.catalina.connector.Connector port=7443
info:org.apache.catalina.connector.Connector/2.1
ProtocolHandlerClassNameorg.apache.coyote.http11.Http11Protocol
Tue Jul 28 13:38:20 CEST 2009 Event. type:after_stop
Source:StandardService[main] class:class
org.apache.catalina.core.StandardService
Tue Jul 28 13:38:20 CEST 2009 Event. type:before_stop
Source:StandardService[comet] class:class
org.apache.catalina.core.StandardService
Tue Jul 28 13:38:21 CEST 2009 Event. type:stop Source:StandardService[comet]
class:class org.apache.catalina.core.StandardService
Tue Jul 28 13:38:21 CEST 2009 Event. type:before_stop
Source:StandardEngine[comet] class:class org.apache.catalina.core.StandardEngine
Tue Jul 28 13:38:21 CEST 2009 Event. type:stop Source:StandardEngine[comet]
class:class org.apache.catalina.core.StandardEngine
Tue Jul 28 13:38:21 CEST 2009 Event. type:before_stop
Source:StandardEngine[comet].StandardHost[localhost] class:class
org.apache.catalina.core.StandardHost
Tue Jul 28 13:38:21 CEST 2009 Event. type:stop
Source:StandardEngine[comet].StandardHost[localhost] class:class
org.apache.catalina.core.StandardHost
Tue Jul 28 13:38:21 CEST 2009 Event. type:before_stop
Source:StandardEngine[comet].StandardHost[localhost].StandardContext[/notifservlet]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:38:24 CEST 2009 Event. type:stop
Source:StandardEngine[comet].StandardHost[localhost].StandardContext[/notifservlet]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:38:24 CEST 2009 Event. type:after_stop
Source:StandardEngine[comet].StandardHost[localhost].StandardContext[/notifservlet]
class:class org.apache.catalina.core.StandardContext
Tue Jul 28 13:38:24 CEST 2009 Event. type:after_stop
Source:StandardEngine[comet].StandardHost[localhost] class:class
org.apache.catalina.core.StandardHost
Tue Jul 28 13:38:24 CEST 2009 Event. type:after_stop
Source:StandardEngine[comet] class:class org.apache.catalina.core.StandardEngine
Tue Jul 28 13:38:24 CEST 2009 Event. type:stop
Source:org.apache.catalina.connector.connec...@64fe7a67 class:class
org.apache.catalina.connector.Connector port=8080
info:org.apache.catalina.connector.Connector/2.1
ProtocolHandlerClassNameorg.apache.coyote.http11.Http11NioProtocol
Tue Jul 28 13:38:24 CEST 2009 Event. type:stop
Source:org.apache.catalina.connector.connec...@3a6bf80b class:class
org.apache.catalina.connector.Connector port=8443
info:org.apache.catalina.connector.Connector/2.1
ProtocolHandlerClassNameorg.apache.coyote.http11.Http11NioProtocol
Tue Jul 28 13:38:24 CEST 2009 Event. type:after_stop
Source:StandardService[comet] class:class
org.apache.catalina.core.StandardService
The stack trace recorded by sending -QUIT signal to JVM when stop process
freezes from 3 minutes:
"main" prio=1 tid=0x0000000040116130 nid=0x5695 runnable
[0x00007fff40c01000..0x00007fff40c02640]
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:333)
- locked <0x00002ac3b7257bd0> (a java.net.SocksSocketImpl)
at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:195)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:182)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366)
at java.net.Socket.connect(Socket.java:520)
at java.net.Socket.connect(Socket.java:470)
at java.net.Socket.<init>(Socket.java:367)
at java.net.Socket.<init>(Socket.java:180)
at
org.apache.tomcat.util.net.JIoEndpoint.unlockAccept(JIoEndpoint.java:584)
at org.apache.tomcat.util.net.JIoEndpoint.stop(JIoEndpoint.java:552)
at org.apache.tomcat.util.net.JIoEndpoint.destroy(JIoEndpoint.java:561)
at
org.apache.coyote.http11.Http11Protocol.destroy(Http11Protocol.java:238)
at org.apache.catalina.connector.Connector.stop(Connector.java:1190)
at
org.apache.catalina.core.StandardService.stop(StandardService.java:593)
- locked <0x00002ac2915796d0> (a
[Lorg.apache.catalina.connector.Connector;)
at org.apache.catalina.core.StandardServer.stop(StandardServer.java:744)
at org.apache.catalina.startup.Catalina.stop(Catalina.java:616)
at org.apache.catalina.startup.Catalina.start(Catalina.java:591)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:288)
at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:413)
Source code of listener used for debugging:
package listeners;
import java.util.Date;
import org.apache.catalina.LifecycleEvent;
import org.apache.catalina.connector.Connector;
public class TomcatListener implements org.apache.catalina.LifecycleListener {
public void lifecycleEvent(LifecycleEvent event) {
if (event != null) {
Object source = event.getSource();
if (source == null) {
source = "null";
}
if (event.getType().equalsIgnoreCase("periodic")) {
return;
}
if (source instanceof Connector) {
Connector connector = (Connector) source;
System.out.println(new Date() + " Event. type:"
+ event.getType() + " Source:"
+ source + " class:"
+ source.getClass() + " port="
+ connector.getPort()
+ " info:" + connector.getInfo()
+ " ProtocolHandlerClassName"
+
connector.getProtocolHandlerClassName());
} else {
System.out.println(new Date() + " Event. type:"
+ event.getType() + " Source:"
+ source + " class:"
+ source.getClass());
}
}
}
}
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org
