非并发原因引起的乐观锁异常故障分析

新项目上线后,发现经常会报乐观锁错

org.springframework.orm.jpa.JpaOptimisticLockingFailureException: Optimistic locking errors were detected when flushing to the data store.  The following objects may have been concurrently modified in another transaction: [entity.Counter-entity.Counter-57218]; nested exception is <openjpa-1.1.0-r422266:657916 nonfatal store error> org.apache.openjpa.persistence.OptimisticLockException: Optimistic locking errors were detected when flushing to the data store.  The following objects may have been concurrently modified in another transaction: [entity.Counter-entity.Counter-57218]

 

这是一个典型的乐观锁错,自然想到代码中是否存在并发写入问题

 

检查代码后没找到可疑代码,而且看报错的实体Counter一般情况下也不会存在并发

 

分析了下报错的数据和报错时间,发现基本都是0点之后开始(定时任务主要集中在0点),重启后故障解除; 而且负责执行定时任务的那台机器报错情况少于另一台机器,但是也有报错

 

检查了所有定时任务,也没发现问题

 

但是问题性质基本上可以认定:有实体被更新后,jpa的datecache没有更新;可能和群集有关.

 

首先根据报错的实体类型(Counter,UserStat)分别检查

 

查了最近2天的UserStat类报错的数据,都是该用户有过收藏操作的,而正好有个定时任务是重置收藏数据的,所以就很自然联想到是否是该定时任务的的更新没有同步群集

 

更新语句用到jpa的批量更新api: Query.executeUpdate();

 

在线上2台应用服务器上做了简单测试后确认了猜想: 目前用到的jpa群集实现不支持批量更新操作- -! 没办法,暂时只能将更新语句改成传统的List查询后逐个merge()

 

这个问题解决后,第二天发现线上还是有很多异常,侥幸心理+失望...

 

实在想不出其他原因,只好开始查该异常出现的时间点, 发现是从2周前切换新服务器后开始的, 问系统组同事要了切换前的服务器日志,发现没有这个问题,那就奇怪了,服务器切换并没有改动程序,那问题原因估计也和程序无关!

 

不经意间,发现旧服务器日志里有大量群集同步异常

[07-17 00:02:39.469] 2010-07-17 00:02:39,468 ERROR [openjpa.Runtime] 100 - 发出消息出错!
[07-17 00:02:39.469] java.lang.NullPointerException
[07-17 00:02:39.469]  at openjpa.event.MulticastRemoteCommitProvider$SendThread.run(MulticastRemoteCommitProvider.java:152)
[07-17 00:02:39.469]  at java.lang.Thread.run(Thread.java:619)

 

恍然大悟!!服务器切换后,旧的应用没有停掉,仍旧在跑,并且每天0点会执行定时任务,导致新应用的jpa缓存和数据库不同步,造成大量乐观锁错!

 

停掉旧应用,问题解决~

 

---

 

总结:

这起故障的原因:1,群集实现不支持的更新操作; 2,未在群集中的应用更新数据导致不同步; 两个不同的原因导致jpa的数据缓存和数据库中的不一样,从而引发乐观锁异常

在处理故障时,思维还是太狭窄,效率不高(前前后后一共花了3天)

明明能肯定是jpa缓存过期导致的,但是由于找不到可能造成过期的代码和原因,所以不敢确定.

 

福尔摩斯有过一句话:

当所有的不可能都排除时，剩下的，就算再不可能，也是真相。

--When you have eliminated all which is impossible, then whatever remains, however improbable, must be the truth

 

借用此话聊以自慰:)