@yanbo-ai
2015-07-06T09:57:41.000000Z
字数 4950
阅读 4231
Tomcat Shutdown JVM Exception
通常, 我们的服务程序都会设计成容错的。错误包括几种常见的方式: kill -9 强杀; 服务器断电;网络中断;服务器硬件故障。这些错误会导致程序异常终止或无法访问可用资源。这意味着我们要尽可能地保护重要数据不被这些错误引起数据丢失。为了避免程序在非正常 shutdown 时发生数据丢失,在 shutdown 过程中我们只做资源回收不做业务操作。
但这并不是绝对的,例如:我们为了降低重复计算给服务器带来的压力会在程序正常 shutdown 时将我们的数据进行持久化。这些数据有的被保存在本地,有的被保存外部存储中心。这些数据在程序重启后再次使用,或者是共享给集群内的其他节点使用。
在 hprice_api 中,为了避免重复抓取酒店报价 hprice_api 在内存中保存了抓取状态。这些状态数据会在程序 shutdown 时被‘回写’到 Memcached 中。要完成这一过程需要多个组件(服务)一起合作。在任务完成之前所有的组件都应该处于服务状态。否则就会引起任务失败,这些失败的原因回使用异常的形式展现出来。今天我们要解决的就是它们:
[2015-07-01 16:14:19 ERROR XMemClientService.java:326] xmemcached put MemcachedException, key=hlpt/2015-07-01/2015-07-02/beijing_city/108?, Xmemcached is stopped
从上面的日志可以看出:在某个地方调用 XMemClientService 时,Xmemcached 客户端实例已经被停止。要从根本上解决这个问题,我们还需要了解整个 hprice_api 的生命周期。
从 hprice_api 的 pom.xml 可以很简单地知道 hprice_api 是一个 WAR 程序。WAR 程序通常被运行在一个 Servlet Container 中。我们需要从 Servlet Container 的生命周期入手。
<artifactId>hotel_price_api</artifactId><version>2.0.0</version><packaging>war</packaging>

在确定 hprice_api 的生命周期之前,我们需要查看 web.xml 中 Listener 的加载顺序:
<filter><filter-name>watcher</filter-name><filter-class>qunar.ServletWatcher</filter-class></filter><filter-mapping><filter-name>watcher</filter-name><url-pattern>/*</url-pattern></filter-mapping><!-- listeners --><listener><listener-class>com.qunar.hotel.price.base.listener.InitListener</listener-class></listener><listener><listener-class>com.qunar.hotel.price.base.listener.SchedulerInitListener</listener-class></listener>
根据上面的配置,我们可以得出 hprice_api 的初始化与销毁的过程:

上图并未包含所有 Filter,只列出了其中几个关键的。
初始化与销毁过程
1. Web 容器在启动的时候执行 InitListener 的初始化
2. 在 InitListener 初始化的过程中初始化 QunarServer
3. 在 QunarServer 初始化的过程中初始化qunar.xml中的所有服务。例如: XMemService, HPService
4. SchedulerInitListener 初始化,里面包含的是一些 SchedulePool
5. ServletWatcher 初始化。
6. 销毁过程则是按相反的顺序执行,QunarServer 在销毁过程中是通过倒序遍历或反转实现的。
了解 hprice_api 的生命周期是非常有必要的,当我们遇到依赖的服务不能使用时就需要根据 hprice_api 的生命周期去确定需要的服务在哪里被初始化在哪里被销毁。
要定位问题,我们需要找出是谁在 Memcached 停止了之后还依然使用 Memcached 服务。下面的日志会给我们线索:
[2015-07-01 16:14:19 ERROR XMemClientService.java:326] xmemcached put MemcachedException, key=hlpt/2015-07-01/2015-07-02/beijing_city/108?, Xmemcached is stopped
根据日志,我们能确定异常是在 XMemClientService 的 326 行抛出的。我们在这行代码注册一个JPDA断点。然后使用 kill 命令关闭 tomcat 来重现问题。
ps -ef | grep tomcatkill $tomcat_pid
Note
不要使用 stop_tomcat.sh 来停止 tomcat。因为在这个停止的脚本中,如果 10 秒后没有正常停止完成就会使用 kill -9 强杀。要知道它是怎么实现的可以前往测试环境上执行cat /home/q/tools/bin/stop_tomcat.sh一探究竟。
当执行断点时,我们可以看到调用堆栈:

根据上面的信息,我们可以完整调用顺序:
com.qunar.hotel.price.base.service.HPService.destroy()com.qunar.hotel.price.rt.RTService.cancel()java.Thread.run()com.qunar.hotel.price.rt.bean.RTWrapper.store()com.qunar.hotel.price.base.service.XMemClientService.put()
刚刚我们已经找到了在 HPService destroy 的时候会调用 XMemClientService 的 put 方法。我们可以在 qunar.xml 里可以看到 XMemClientService 在 service 的最前面,那么它在 QunarServer中应该被第一个初始化,最后一个被销毁。这表明了并不是我在定义 qunar.xml 中服务的位置有问题。
那到底是谁调用了 Memcached 的 stop 方法呢?答案是:shutdown hooks! 要证明这个想法很简单,我们只需要要在 java.lang.ApplicationShutdownHooks.runHooks#L96 加上断点就可以了。当执行到断点的时候,我们能发现 java.lang.ApplicationShutdownHooks.hooks 包含了下面2个关闭 Memcached 的线程:
XMemcachedClient 的 shutdown hook:

MemcachedConnector 的 shutdown hook:

我们能在下面这个2个地方找到注册它们的地方:
net.rubyeye.xmemcached.XMemcachedClient#L620com.google.code.yanf4j.core.impl.AbstractController#L360
我们大概有2种以上的方式解决它:
1. Fork Xmemecached 并将注册 shutdown hook 的操作移除。
2. 在 XMemcached 初始化之后,通过获取 shutdownHookThread 并且调用 java.lang.Runtime.removeShutdownHook 将它移除。
这2中方法都能解决问题。但是第一种方法涉及到的过程会比较长,为了避免以后升级兼容的问题,我们需要向源 repositry 提交PR。需要快速解决这个问题,我们选择了第二种方法。
将 com.qunar.hotel.price.base.service.XMemClientService 的 init 片段作一下修改:
MemcachedClient memcachedClient = builder.build();memcachedClient.setOptimizeGet(false);memcachedClient.setOptimizeMergeBuffer(false);
修改成:
MemcachedClient memcachedClient = builder.build();memcachedClient.setOptimizeGet(false);memcachedClient.setOptimizeMergeBuffer(false);removeXMemcachedClientShutdownHook(memcachedClient);private void removeXMemcachedClientShutdownHook(MemcachedClient memcachedClient) {if (memcachedClient instanceof XMemcachedClient) {_removeXMemcachedClientShutdownHook(XMemcachedClient.class, memcachedClient);_removeXMemcachedClientShutdownHook(AbstractController.class, memcachedClient.getConnector());}}private void _removeXMemcachedClientShutdownHook(Class objectClass, Object memcachedClient) {try {Field shutdownHookField = objectClass.getDeclaredField("shutdownHookThread");shutdownHookField.setAccessible(true);Thread shutdownHook = (Thread) ReflectionUtils.getField(shutdownHookField, memcachedClient);Field shutdownCalledField = objectClass.getDeclaredField("isHutdownHookCalled");shutdownCalledField.setAccessible(true);ReflectionUtils.setField(shutdownCalledField, memcachedClient, true);Runtime.getRuntime().removeShutdownHook(shutdownHook);} catch (Exception e) {logger.error(e.getLocalizedMessage(), e);}}
_removeXMemcachedClientShutdownHook可以看作是一个隐藏函数
在修复这种因为服务(资源)依赖的问题时,首先我们需要确认:
1. 服务是否是被有序第安全地关闭。
2. 是否有组件通过shutdown 关闭自己。
http://docs.oracle.com/cd/B14504_01/dl/web/B10321_01/filters.htm
http://download.oracle.com/otn-pub/jcp/servlet-3.0-fr-eval-oth-JSpec/servlet-3_0-final-spec.pdf