Hibernate一级缓存以及脏数据问题

发现这个问题是由于测试两个事务同时操做一行数据时隔离级别的工做状况，结果发现了hibernate（我用的hibernate4.1）的这个很怪异问题。测试代码是起两线程t1,t2,它们都对activity的url这个字段进行修改，t1先启动，而后t2启动：

@Test
	public void test() {
		Thread t1 = new Thread(new Runnable() {
			
			@Override
			public void run() {
				activityService.updateUrl(1l, "1111");
			}
		});
		Thread t2 = new Thread(new Runnable() {
			
			@Override
			public void run() {
				activityService.updateUrl2(1l, "2222");
			}
		});
		t1.start();
		
		try {
			Thread.sleep(3000);
		} catch (InterruptedException e) {
			// TODO Auto-generated catch block
			e.printStackTrace();
		}
		
		t2.start();
		try {
			Thread.sleep(8000);
		} catch (InterruptedException e) {
			// TODO Auto-generated catch block
			e.printStackTrace();
		}
	}

再看看updateUrl和updateUrl2的代码：

public void updateUrl(Long id, String url) {
		ActivityInfo info = activityDao.getActivity(id);
		
		logger.error("1 updateUrl info url is :" + info.getUrlName());
		
		try {
			Thread.sleep(6000);
		} catch (InterruptedException e) {
			// TODO Auto-generated catch block
			e.printStackTrace();
		}// 等updateUrl2更新
		
		info = activityDao.getActivityByUrl("2222"); // 再次获取activityInfo对象
		logger.error("2 updateUrl info url is :" + info.getUrlName());
		
		info.setUrlName(url);
		
		activityDao.updateUrl(info);
		
		logger.error("3 updateUrl info url is :" + info.getUrlName());
	}
	
	public void updateUrl2(Long id, String url) {
		ActivityInfo info = activityDao.getActivity(id);
		
		logger.error("updateUrl2 before info url is :" + info.getUrlName());
		info.setUrlName(url);
		info.setActivityName("new");
		activityDao.updateUrl(info);
		
		logger.error("updateUrl2 after info url is :" + info.getUrlName());
	}

updateUrl的跨度长点，主要是为了等待updateUrl2里面更新过url字段后，再次获取activityInfo对象看看能不能获取到 updateUrl2更新后的值。updateUrl里面第二次获取activityInfo对象时特意没有使用根据主键获取的方法，防止直接从session里面获取老的对象。

public ActivityInfo getActivityByUrl(String url) {
		String hql = "from ActivityInfo where urlName=:url";
		List list = getSession().createQuery(hql).setString("url", url).list();
		
		ActivityInfo info = (ActivityInfo)list.get(0);
		logger.error("ActivityDaoImpl param is {}, url is {}, name is {}",url, info.getUrlName(), info.getActivityName());
		return info;
	}

很简单直接根据url获取（url不会重复）。 结果测试下来，发现有问题。上面代码的log打印的是：

ActivityDaoImpl param is 2222, url is 1111。也就是说根据url=2222这个条件查出的对象里面的url是1111。

第一个反应就是hibernate一级缓存的问题，获得的结果应该仍是从缓存里面取到的，开了hibernate的日志，看到这两段：

org.hibernate.loader.Loader:853 - Result set row: 0
org.hibernate.loader.Loader:1348 - Result row: EntityKey[org.bear.bo.ActivityInfo#1]

这里能够看到list查询最终会调用Loader的。看下代码发现hibernate的list通过N步骤最后会调用HIbernate Loader的doQueryAndInitializeNonLazyCollections方法，这个方法会调用doQuery方法，它最后又调用getRow方法，getRow里面有以下内容：

//If the object is already loaded, return the loaded one
				object = session.getEntityUsingInterceptor( key );
				if ( object != null ) {
					//its already loaded so don't need to hydrate it
					instanceAlreadyLoaded(
							rs,
							i,
							persisters[i],
							key,
							object,
							lockModes[i],
							session
						);
				}
				else {
					object = instanceNotYetLoaded(
							rs,
							i,
							persisters[i],
							descriptors[i].getRowIdAlias(),
							key,
							lockModes[i],
							optionalObjectKey,
							optionalObject,
							hydratedObjects,
							session
						);
				}

上面的key就是日志中打印的EntityKey[org.bear.bo.ActivityInfo#1]。也就是说session里面，即便咱们不以主键查询，获得的结果集，hibernate也会一个一个根据查询的结果主键到当前session的一级缓存里面对应，若是有了就直接返回缓存里面已有的对象，而不是从数据库里面读取的对象。并且在绝大部分应用场景中我么都是一个session对于一个transaction，这就使得read_uncommitted和read_committed这两种隔离级别，在hibernate session存在的状况下根本体现不了，由于数据都是从session取得。

hibernate 这么作的缘由应该是为了数据统一。这样致使的一个问题就是在一个session里面取不到最新的数据库里面的数据，而这时有可能其余事务对数据进行了修改。就如同测试代码在t1第二次获取activityInfo时其实数据库里面的url已经被修改了，这时会发现t1后面的update操做并无提交。看日志：

t2的更新日志里面有：

o.h.event.internal.AbstractFlushingEventListener:143 - Processing flush-time cascades
o.h.event.internal.AbstractFlushingEventListener:183 - Dirty checking collections
o.h.event.internal.AbstractFlushingEventListener:117 - Flushed: 0 insertions, 1 updates, 0 deletions to 1 objects
o.h.event.internal.AbstractFlushingEventListener:124 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections

后面还有update的sql语句，可是t1最后的操做日志是：

o.h.event.internal.AbstractFlushingEventListener:143 - Processing flush-time cascades
o.h.event.internal.AbstractFlushingEventListener:183 - Dirty checking collections
o.h.event.internal.AbstractFlushingEventListener:117 - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
o.h.event.internal.AbstractFlushingEventListener:124 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections

并且后面也没有update sql语句，数据库也没有修改。

经过查找在hibernate org.hibernate.event.internal.DefaultFlushEntityEventListener的onFlushEntity方法里面有这么一段：

/**
	 * Flushes a single entity's state to the database, by scheduling
	 * an update action, if necessary
	 */
	public void onFlushEntity(FlushEntityEvent event) throws HibernateException {
		...

		if ( isUpdateNecessary( event, mightBeDirty ) ) {
			substitute = scheduleUpdate( event ) || substitute;
		}

		...

	}

而后看看isUpdateNecessary代码:

private boolean isUpdateNecessary(final FlushEntityEvent event, final boolean mightBeDirty) {
		final Status status = event.getEntityEntry().getStatus();
		if ( mightBeDirty || status==Status.DELETED ) {
			// compare to cached state (ignoring collections unless versioned)
			dirtyCheck(event);
			if ( isUpdateNecessary(event) ) {
				return true;
			}
			else {
				...
				return false;
			}
		}
		else {
			...
		}
	}

大致就是脏判断，具体没有精力看了，isUpdateNecessary若是返回false，就不会更新数据了。总之实际测试的状况是当2个事务同时修改统一内容时，后完成的操做不会提交。

可是提交不成功缺没有报异常，就显得很怪异了。