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個事務同時修改統一內容時，後完成的操做不會提交。

可是提交不成功缺沒有報異常，就顯得很怪異了。