java 线程僵死_一次线上jboss僵死问题分析

问题再现:

个人中心在上周四上线(2012.9.13)第一次上线,由于种种缘由,遗留了部分低级别的BUG,后于次日修复,下午4时再次上线。

当日晚上8点,运维发现user-web 五台服务器中四台jboss僵死,无法响应用户请求。

问题分析:

问题发生当日,运维截留了当时的日志信息并dump 了JVM内存信息,关键信息如下:

java.lang.NullPointerException

Message2012-09-15 02:47:56,992 - com.dianping.userweb.service.processor.MyInfoFavouriteModuleProcessor -235970 [myInfoThreadPoolTaskExecutor-1] ERROR - com.dianping.userweb.service.processor.MyInfoFavouriteModuleProcessor process module exception.

......

"http-0.0.0.0-8080-271" daemon prio=10 tid=0x00002b6ef4211000 nid=0x292a waiting on condition [0x00002b6eac592000]

java.lang.Thread.State: WAITING (parking)

at sun.misc.Unsafe.park(Native Method)

- parking to wait for  <0x00000007c4a3f0f0> (a java.util.concurrent.CountDownLatch$Sync)

at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)

at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:811)

at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:969)

at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1281)

at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:207)

at com.dianping.userweb.framework.concurrent.ConcurrentSidebarManager.execute(ConcurrentSidebarManager.java:46)

at com.dianping.userweb.action.page.myinfo.MyInfoIndexAction.sideBarManagerExecute(MyInfoIndexAction.java:39)

......

从以上日志中我们可以得到两个信息

1.一个 process报了空指针异常,

2.一个线程一直处在waiting状态。

根据日志找到对应的代码:

@Override

public void execute(final UCActionContext context) throws ProjectException {

final CountDownLatch countDownLatch = new CountDownLatch(getHeadSize() + getLeftSize() + getRightSize());

barHandleExecute(context, countDownLatch, sideBar);

try {

countDownLatch.await();                            --- A

} catch (InterruptedException e) {

logger.error("current handle error!", e);

throw new ProjectException("current handle error!");

}

}

这段是处理并行的核心代码,通过CountDownLatch来处理并行的执行,主线程通过 countDownLatch.await();等待子线程的完成。这个方法会抛除InterruptedException异常,这个异常包含三个含义:

1.这是一个异常,需要业务根据时间情况处理,当然有些废话

2.这是一个等待方法,等待的时间不根据CPU或是内存的情况,而是依赖于定时器或是磁盘IO的返回,本案是根据子线程的执行情况

3.这个等待线程是可以中断的

所以当一个请求过来时,主线程会在这个A处等待,直到所有子线程告诉我,所有子线程已经执行完成了。

再看barHandleExecute方法的处理:

protected void barHandleExecute(final UCActionContext context, final CountDownLatch countDownLatch, SideBar sideBar) {

.......

threadPoolTaskExecutor.execute(new Runnable() {

@Override

public void run() {

Transaction t = Cat.getProducer().newTransaction("Modules",

moduleProcessor.getClass().getName());// 接入cat

try {

moduleProcessor.execute(context);

countDownLatch.countDown();

t.setStatus(Transaction.SUCCESS);

} catch (Throwable e) {

Cat.getProducer().logError(e);// 用log4j记录系统异常,以便在Logview中看到此信息

t.setStatus(e);

} finally {

t.complete();

}

}

});

.......

}

对于多个线程,通过线程池来处理,每个线程也就是moduleProcessor处理完成后, countDownLatch.countDown();告诉主线程我已经执行完成了,当主线程收到所有子线程的答复后,继续往下执行,进行页面的渲染。

以上都是正常流程的流转过程,但是,若我们其中的一个moduleProcessor抛出异常后,会出现什么情况呢?这个异常会被接入CAT监控的代码会吃掉,告诉CAT一个日志信息,然后就什么都不做了。那countDownLatch.countDown();这段代码就永远不会被执行,而主线程又依赖于子线程通过countDownLatch.countDown();来告知是否执行完了。这个时候就悲剧了,主线程一直在等待子线程的消息,无法渲染页面返回结果,这个时候用户的第一反应会是是不是网络原因导致没有加载数据,不停的F5,每次都会产生一个新的请求进来,若是刷新的人越多,这些进程就永远僵死在那边,不释放内存,造成系统雪崩。

一个合理的介入CAT方式是:

Transaction t = Cat.getProducer().newTransaction("Modules",

moduleProcessor.getClass().getName());// 接入cat

try {

// 业务处理

t.setStatus(Transaction.SUCCESS);

} catch (Throwable e) {

Cat.getProducer().logError(e);

t.setStatus(e);

throw new ProjectException();  //这里必须抛出异常,有业务系统决定如何处理异常

} finally {

t.complete();

}

几个疑问:

1.为什么processor会抛出异常?

当时在porcessor编写的时候,约定各个processor需要cacth自己的异常,不能因为自己的失败导致请求的其他模块加载失败。我们看看报空指针的地方:

.....

context.getParam(DefaultActionContext.Contant.MEMBER_ID.name)

.....

try

...

报错的是从上下文获取memberID的代码,这个操作并没有放在try catch块中。由于个人中心的所有页面都必须依赖于memberID这个字段,所以编码时就忽略了memberId为空的这种情况,而且在我们的action层也对memberID为空的情况作了处理,具体代码如下:

......

private void initMemberInfo(UCActionContext context) throws ProjectException {

// 验证会员存在

if (memberId == null) {

throwException(MemberUtil.MEMBERID_INVALID_TITLE, MemberUtil.MEMBERID_INVALID_MSG);

}

......

所以理论上来说,对于memberId为空的情况不会进入后端处理的processor,所以后端也就没有考虑到从context获取memberID会为空,但是实际情况还是发生了,这段代码也做了拦截,并抛出了异常,不过 在initMemberInfo这个方法的外层,又catch住了这个异常:

try

....

initMemberInfo(context);

catch(){

....

}

所以说ACTION做的处理并没有起到拦截作用,导致这个null的memberid传递到了后端,后端出错后被接入CAT的代码抓住,导致主线程一直得不到返回。

2.为什么在压力测试过程中没有发生这个问题?

压力测试过程时,当时批量处理方法barHandleExecute的源代码如下所示,并没有介入CAT监控代码

protected void barHandleExecute(final UCActionContext context, final CountDownLatch countDownLatch, SideBar sideBar) {

.......

threadPoolTaskExecutor.execute(new Runnable() {

@Override

public void run() {

moduleProcessor.execute(context);

countDownLatch.countDown();

}

});

.......

}

这个地方为什么没有做try catch,是考虑到我们一些并行的processor存在一些依赖关系,processorA出异常的话,processorB就算不出问题,也不渲染页面。所以这里就不cacth异常,由具体的processor来决定是否cacth异常。所以在压力测试过程,就算其中processor抛出异常,框架就认为这是某个依赖processor抛出的异常,就将这个异常抛到WEB,由最外层做控制,跳转到统一的错误页面。所以这主线程僵死的情况就不会出现。

3.周四上线的时候为什么没有让jboss僵死?

个人中心周四晚上9点多上线,当时访问量也不是很大,就算碰到会导致一些无效的memberID的请求进入,也不会立刻让JBOSS僵死。同时我们在周五下午又对个人中心做了一次上线,重启了应用了,所以没报出这个问题,但是在周五晚上,请求增大,各种复杂情况的请求进入后,就触发了我们代码中的缺陷,最终导致JBOSS僵死。

总结:

1.前段action拦截不合理,放入了memberId为NULL的请求,打开了系统出错的门。

2.后端processor信任前段过来的数据,并没有做防御式处理,导致空指针异常,同时又没有将这段获取数据的代码纳入try中,进一步将系统推向奔溃边缘。

3.上线前接入CAT代码,没有考虑全面,这段代码在自己本分(记录系统执行开销及异常)外干了不是它的事,cacth住了我们的系统异常,这个才是压垮系统的最后一根稻草,导致系统雪崩。

4.框架本身考虑不够全面,用一种靠扩展对自身的约束来处理异常情况,没有分开的去处理:多个无关porcessor和多个存在关联processor的两种情况。

以上四步,只要不走错一步,就不会出现周五晚上的JBOSS僵死问题。可见一个重大错误大多是由一系列的错误连锁导致的。

  • 0
    点赞
  • 0
    收藏
    觉得还不错? 一键收藏
  • 0
    评论
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值