NO.16 在有PreUpdateEventListener.onPreUpdate情况下的Hibernate脏数据检查机制(Dirty Checking)分析

    故事的起因是在对某个业务环节做SQL分析时，发现一个表Update操作了四次，但后三次除了一个更新时间的字段被更新成了Update时的数据库服务器系统时间之外（相差最多1秒），其他字段都没变。显然这三次操作是无意义的。
    调查后发现是系统中一个修改数据时自动更新操作时间字段的Listener有问题导致的，做了几个试验后，对Hibernate的DirtyChecking总算明白一些了。

    先贴一下下面这个实验的一些结论吧：

  1.三个主角:event.getEntity(具体说来应该是实体中的属性)；event.getState;event.getOldState;
  2.Dirty Checking根据oldState,state是否一致来判断PO是不是脏了
  3.hibernate根据state回写DataBase
  4.onPreUpdate发生在Dirty Checking之后
  5.事务后，Property值不变，State的值变成事务前Property的值 ，OldState的值变成事务前State的值

附整个实验及推论过程：  
  先贴代码：    
public boolean onPreUpdate(PreUpdateEvent event) { String[] names = event.getPersister().getPropertyNames(); if ((this.operateTimeField == null) || (this.operateTimeField.trim().length() == 0)) { this.operateTimeField = "operateTime"; } for (int i = 0; i < names.length; ++i) { if (this.operateTimeField.equalsIgnoreCase(names[i])) { try { //System.out.println("######State1:"+event.getState()[i]); //System.out.println("######oldState1:"+ event.getOldState()[i]); //System.out.println("######Property1:"+BeanUtils.getProperty(event.getEntity(), operateTimeField)); //修改state Timestamp t = retrieveCurrentTimestamp(event .getPersister().getFactory()); event.getState()[i] = t; // 调用setter方法修改PO属性值，使得Hibernate的脏检查生效 BeanUtils.forceSetProperty(event.getEntity(), operateTimeField, t); //System.out.println("######State2:"+event.getState()[i]); //System.out.println("######oldState2:"+ event.getOldState()[i]); //System.out.println("######Property2:"+BeanUtils.getProperty(event.getEntity(), operateTimeField)); } catch (NoSuchFieldException e) { if (logger.isErrorEnabled()) { logger.error(e.toString(), e); } } break; } } return false; }  
    这里不但修改了event.getState还通过PO的setter方法修改了event.getEntity相应属性值，两者缺一不可。
    若只修改state或只修改Entity属性值，都会导致若session后面的事务提交时认为这个PO是脏数据，而再次发生update及触发onPreUpdate。在系统实际应用中产生性能问题。
    通过以下实验即明白为什么两种情况下，Hibernate认为PO是脏数据的原因.

    以下试验注掉修改state/Property其中一个，放开6个System.out来查看数据的变化情况。
    下面是我试验的例子：
    试验样本：一个session中有两个事务,其间Thread.sleep(1000)且打印"==================================",仅在第一个事务中有一个持久化PO调用了非操作时间属性的setter（也就是第一次数据变脏是这个setter搞的，而第二次则是onPreUpdate搞的鬼了）

 

试验1:只修改state
######state1:2010-03-18 18:44:01.0（原始值）
######oldState1:2010-03-18 18:44:01.0（原始值）
######property1:2010-03-18 18:44:01.0（原始值）

######state2:2010-03-19 11:17:45.0（修改为最新值）
######oldState2:2010-03-18 18:44:01.0（未变）
######property2:2010-03-18 18:44:01.0（未变）
P6SPY打印的SQL中值：2010-03-19 11:17:45.0(体现最新值)
==================================
######state1:2010-03-18 18:44:01.0（再次变回原始值）
######oldState1:2010-03-19 11:17:45.0（变成上次事务中修改值）
######property1:2010-03-18 18:44:01.0（较上次事务未变:原始值）

######state2:2010-03-19 11:17:46.0（修改为最新值）
######oldState2:2010-03-19 11:17:45.0（事务内未变）
######property2:2010-03-18 18:44:01.0（事务内未变）
P6SPY打印的SQL中值：2010-03-19 11:17:46.0(体现最新值)

查看数据库，相关字段已由最初的2010-03-18 18:44:01.0变成2010-03-19 11:17:46.0
可知：发生了两次update,触发了两次onPreUpdate

 

试验2：只修改Entity属性值 
######state1:2010-03-19 11:17:46.0（原始值）
######oldState1:2010-03-19 11:17:46.0（原始值）
######property1:2010-03-19 11:17:46.0（原始值）

######state2:2010-03-19 11:17:46.0（未变）
######oldState2:2010-03-19 11:17:46.0（未变）
######property2:2010-03-19 11:21:22.0（修改为最新值）
P6SPY打印的SQL中值：2010-03-19 11:17:46.0(未体现最新值)
==================================
######state1:2010-03-19 11:21:22.0（变成上次事务中修改值）
######oldState1:2010-03-19 11:17:46.0（较上次事务未变:原始值）
######property1:2010-03-19 11:21:22.0（较上次事务未变）

######state2:2010-03-19 11:21:22.0（事务内未变）
######oldState2:2010-03-19 11:17:46.0（事务内未变）
######property2:2010-03-19 11:21:24.0（修改为最新值）
P6SPY打印的SQL中值：2010-03-19 11:21:22.0（体现上次修改值）
查看数据库，相关字段已由最初的2010-03-19 11:17:46.0变成2010-03-19 11:21:22.0
可知：发生了两次update,触发了两次onPreUpdate

 

两个都修改的情况（而这也是对的情况）
######state1:2010-03-19 11:21:22.0
######oldState1:2010-03-19 11:21:22.0
######property1:2010-03-19 11:21:22.0

######state2:2010-03-19 11:39:49.0
######oldState2:2010-03-19 11:21:22.0
######property2:2010-03-19 11:39:49.0
P6SPY打印的SQL中值2010-03-19 11:39:49.0(体现新值)
==================================
查看数据库，相关字段已由2010-03-19 11:21:22.0变成2010-03-19 11:39:49.0
可知：发生了一次update,触发了一次onPreUpdate

先来让试验1、2的信息简明化一下，下面分别用1、2、3（代表数据值）列出两次事务里State、OldState、Property、数据库数值的前后变化
试验1：
   State:1->2->1->3
OldState:1->1->2->2
Property:1->1->1->1
    DB:1----->2----->3
试验2：
   State:1->1->2->2
OldState:1->1->1->1
Property:1->2->2->3
    DB:1----->1----->2

  关于Hibernate的脏数据检查机制(Dirty Checking),在网上查了很多资料(讲得比较清楚的参见文后参考资料2)，一种可能的步骤是这样的：
  1.首先要存在从数据库中select出来的某数据成为持久化状态的PO；
  2.程序中对此PO使用setter改变了属性值；
  3.事务提交时对所有PO进行持久化检查，发现此PO前后状态发生变化，Update此PO，并使之与库中保持一持。
  但在PreUpdateEventListener搅和进来以后，事情变得更加有趣了......

结合上述试验，可以推出以下结论：
  1.本次事件中有三个主角:event.getEntity(具体说来应该是实体中的属性)；event.getState;event.getOldState;
  2.Dirty Checking根据oldState,state是否一致来判断PO是不是脏了
    可以看到试验1，2中第二次事务onPreUpdate中修改值前打印（state1和oldState1）值不相同
  3.hibernate根据state回写DataBase
    试验1中onPreUpdate只修改state，事务提交时回写DB的值与state修改后值相同；
    而试验2中只调用setter修改Entiry的property，并未影响本次事务的DB回写值，回写值还是与当时state值相同；
  4.onPreUpdate发生在Dirty Checking之后
    Dirty Checking发现脏数据从而Update从而触发onPreUpdate，否则不会发生实验1，2中的第二次onPreUpdate.
  5.事务后，Property值不变，State的值变成事务前Property的值 ，OldState的值变成事务前State的值
    从实验1、2第二次事务onPreUpdate中修改值前打印与上次事务onPreUpdate中修改值后打印各值的变化即可看出。
    这个结论也解释了为什么网上有的人只使用反射改了Entity的属性却发现没用，值没改回到DataBase。
  
OK,在有PreUpdateEventListener情况下的Dirty Checking的路线图大致推断如下：
  1.一个持久化PO的出现（select）
  2.PO setter的调用（值变不变无所谓），hibernate标记其为Dirty
  3.事务提交->....Dirty Checking:发现某个PO某个Property的state发生变化（或存在标记的PO），将这个PO扔进待更新队列
  4.update之调用了onPreUpdate（两试验虽然改的地儿不一样，却导致故事按一个路子在发展）
  5.hibernate按state拼写Update SQL并调用Jdbc执行，而后Commit，OldState的值变成State的值,State的值变成Property的值 ，此时第一次事务结束。
  6.二次事务提交时，OK，OldState与state不一致，继续3、4步的故事
 
  相关的参考资料：
  1.https://forum.hibernate.org/viewtopic.php?p=2424513
  2.http://blog.csdn.net/javacoffe/archive/2007/07/13/1688594.aspx