-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
Marcin,
You may have better luck posting this to the tomcat-dev mailing list
(d...@tomcat.apache.org). You will have to join the list before posting.
- -chris
On 7/28/2009 7:55 AM, BALCER, Marcin (Marcin) wrote:
> 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: users-unsubscr...@tomcat.apache.org
> For additional commands, e-mail: users-h...@tomcat.apache.org
>
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (MingW32)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/
iEYEARECAAYFAkpvMREACgkQ9CaO5/Lv0PCKKgCdH69ZVprAVDsfNE8zMcR0dEuC
UhoAoKdKTtUgIu7CTjCRXoap1/0OxxR1
=pnqX
-----END PGP SIGNATURE-----
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org
