tomcat进程意外退出的问题分析

请看挂掉前的日志：

INFO: A valid shutdown command was received via the shutdown port. Stopping the Server instance.
Nov 3, 2014 6:05:23 PM org.apache.coyote.AbstractProtocol pause
INFO: Pausing ProtocolHandler ["http-bio-8080"]
Nov 3, 2014 6:05:23 PM org.apache.coyote.AbstractProtocol pause
INFO: Pausing ProtocolHandler ["ajp-bio-8009"]
Nov 3, 2014 6:05:23 PM org.apache.catalina.core.StandardService stopInternal
INFO: Stopping service Catalina
Nov 3, 2014 6:05:23 PM org.apache.catalina.loader.WebappClassLoader clearReferencesJdbc
SEVERE: The web application [] registered the JDBC driver [com.mysql.jdbc.Driver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
Nov 3, 2014 6:05:23 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [] appears to have started a thread named [Timer-1] but has failed to stop it. This is very likely to create a memory leak.
Nov 3, 2014 6:05:24 PM org.apache.catalina.loader.WebappClassLoader clearReferencesJdbc
SEVERE: The web application [/system] registered the JDBC driver [com.mysql.jdbc.Driver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
Nov 3, 2014 6:05:24 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/system] appears to have started a thread named [Timer-0] but has failed to stop it. This is very likely to create a memory leak.
Nov 3, 2014 6:05:24 PM org.apache.coyote.AbstractProtocol stop
INFO: Stopping ProtocolHandler ["http-bio-8080"]
Nov 3, 2014 6:05:24 PM org.apache.coyote.AbstractProtocol stop
INFO: Stopping ProtocolHandler ["ajp-bio-8009"]
Nov 3, 2014 6:05:24 PM org.apache.coyote.AbstractProtocol pause
INFO: Pausing ProtocolHandler ["http-bio-8088"]
Nov 3, 2014 6:05:24 PM org.apache.coyote.AbstractProtocol pause
INFO: Pausing ProtocolHandler ["ajp-bio-8089"]
Nov 3, 2014 6:05:24 PM org.apache.catalina.core.StandardService stopInternal
INFO: Stopping service Catalina1
Nov 3, 2014 6:05:24 PM org.apache.catalina.core.ApplicationContext log
INFO: Destroying Spring FrameworkServlet 'spring'
Nov 3, 2014 6:05:24 PM org.apache.catalina.core.ApplicationContext log
INFO: Shutting down log4j
Nov 3, 2014 6:05:24 PM org.apache.catalina.core.ApplicationContext log
INFO: Closing Spring root WebApplicationContext
Nov 3, 2014 6:05:24 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [] appears to have started a thread named [Abandoned connection cleanup thread] but has failed to stop it. This is very likely to create a memory leak.
Nov 3, 2014 6:05:24 PM org.apache.catalina.core.ApplicationContext log
INFO: Destroying Spring FrameworkServlet 'spring'
Nov 3, 2014 6:05:24 PM org.apache.catalina.core.ApplicationContext log
INFO: Shutting down log4j
Nov 3, 2014 6:05:24 PM org.apache.catalina.core.ApplicationContext log
INFO: Closing Spring root WebApplicationContext
Nov 3, 2014 6:05:24 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/temple-0.0.1-SNAPSHOT] appears to have started a thread named [Abandoned connection cleanup thread] but has failed to stop it. This is very likely to create a memory leak.
Nov 3, 2014 6:05:24 PM org.apache.coyote.AbstractProtocol stop
INFO: Stopping ProtocolHandler ["http-bio-8088"]
Nov 3, 2014 6:05:24 PM org.apache.coyote.AbstractProtocol stop
INFO: Stopping ProtocolHandler ["ajp-bio-8089"]
Nov 3, 2014 6:05:24 PM org.apache.coyote.AbstractProtocol pause
INFO: Pausing ProtocolHandler ["http-bio-8090"]
Nov 3, 2014 6:05:24 PM org.apache.coyote.AbstractProtocol pause
INFO: Pausing ProtocolHandler ["ajp-bio-8091"]
Nov 3, 2014 6:05:24 PM org.apache.catalina.core.StandardService stopInternal
INFO: Stopping service Catalina2
Nov 3, 2014 6:05:24 PM org.apache.catalina.core.ApplicationContext log
INFO: Destroying Spring FrameworkServlet 'spring'
Nov 3, 2014 6:05:24 PM org.apache.catalina.core.ApplicationContext log
INFO: Shutting down log4j
Nov 3, 2014 6:05:24 PM org.apache.catalina.core.ApplicationContext log
INFO: Closing Spring root WebApplicationContext
Nov 3, 2014 6:05:24 PM org.apache.catalina.loader.WebappClassLoader clearReferencesJdbc
SEVERE: The web application [] registered the JDBC driver [com.mysql.jdbc.Driver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
Nov 3, 2014 6:05:24 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [] appears to have started a thread named [Abandoned connection cleanup thread] but has failed to stop it. This is very likely to create a memory leak.
Nov 3, 2014 6:05:24 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [] appears to have started a thread named [Resource Destroyer in BasicResourcePool.close()] but has failed to stop it. This is very likely to create a memory leak.
Nov 3, 2014 6:05:24 PM org.apache.catalina.core.ApplicationContext log
INFO: Destroying Spring FrameworkServlet 'spring'
Nov 3, 2014 6:05:24 PM org.apache.catalina.core.ApplicationContext log
INFO: Shutting down log4j
Nov 3, 2014 6:05:24 PM org.apache.catalina.core.ApplicationContext log
INFO: Closing Spring root WebApplicationContext
Nov 3, 2014 6:05:24 PM org.apache.catalina.loader.WebappClassLoader clearReferencesJdbc
SEVERE: The web application [/templeManager] registered the JDBC driver [com.mysql.jdbc.Driver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
Nov 3, 2014 6:05:24 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/templeManager] appears to have started a thread named [Abandoned connection cleanup thread] but has failed to stop it. This is very likely to create a memory leak.
Nov 3, 2014 6:05:24 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/templeManager] appears to have started a thread named [Resource Destroyer in BasicResourcePool.close()] but has failed to stop it. This is very likely to create a memory leak.
Nov 3, 2014 6:05:24 PM org.apache.coyote.AbstractProtocol stop
INFO: Stopping ProtocolHandler ["http-bio-8090"]
Nov 3, 2014 6:05:24 PM org.apache.coyote.AbstractProtocol stop
INFO: Stopping ProtocolHandler ["ajp-bio-8091"]
Nov 3, 2014 6:05:24 PM org.apache.coyote.AbstractProtocol destroy
INFO: Destroying ProtocolHandler ["http-bio-8080"]
Nov 3, 2014 6:05:24 PM org.apache.coyote.AbstractProtocol destroy
INFO: Destroying ProtocolHandler ["ajp-bio-8009"]
Nov 3, 2014 6:05:24 PM org.apache.coyote.AbstractProtocol destroy
INFO: Destroying ProtocolHandler ["http-bio-8088"]
Nov 3, 2014 6:05:24 PM org.apache.coyote.AbstractProtocol destroy
INFO: Destroying ProtocolHandler ["ajp-bio-8089"]
Nov 3, 2014 6:05:24 PM org.apache.coyote.AbstractProtocol destroy
INFO: Destroying ProtocolHandler ["http-bio-8090"]
Nov 3, 2014 6:05:24 PM org.apache.coyote.AbstractProtocol destroy
INFO: Destroying ProtocolHandler ["ajp-bio-8091"]

原因分析：

从上面日志来可以判断：

 tomcat不是通过脚本正常关闭(viaport: 即通过8005端口发送shutdown指令)

因为正常关闭(viaport)的话会在 pause 之前有这样的一句warn日志：

    org.apache.catalina.core.StandardServer await
    A valid shutdown command was received via the shutdown port. Stopping the Server instance.
    然后才是 pause -> stop -> destroy 

先通过排查代码，应用方和中间件团队都排查了System.exit在这个应用中使用的可能。那就只剩下Signal的情况了；经过一番排查后，发现每次tomcat意外退出的时间与ssh会话结束的时间正好吻合。

tomcat启动为后，当前shell进程并没有退出，而是挂住在tail进程，往终端输出日志内容。这种情况下，如果用户直接关闭ssh终端的窗口(用鼠标或快捷键)，则java进程也会退出。而如果先ctrl-c终止test.sh进程，然后再关闭ssh终端的话，则java进程不会退出。

这是一个有趣的现象，catalina.sh start方式启动的tomcat会把java进程挂到init(进程id为1)的父进程下，已经与当前test.sh进程脱离了父子关系，也与ssh进程没有关系，为什么关闭ssh终端窗口会导致java进程退出？

我们的推测是ssh窗口在关闭时，对当前交互的shell以及正在运行的test.sh等子进程发送某个退出的Signal。

此时java后台进程继承父进程catalina.sh的pgid，而catalina.sh不再使用test.sh的进程组，而是自己的pid作为pgid。

总结：服务器使用catalina.sh start这种方式，在关闭shell客户端后，服务器端tomcat会关闭，所以建议使用./startup.sh方式启动服务器。