关于Hibernate Cache

近段时间正好在使用HIBERNATE与数据库打交道. 由于使用环境中读操作占了相当大的比例, 所以想起用HIBERNATE的CACHE功能. 在论坛里搜了一把, 发现了不少关于CACHE的帖子. 但好像都是关于JCS的, 那时似乎还没有QueryCache. 所以就把这两天自己尝试的内容记了下来.

Cache In Hibernate
HIBERNATE中的CACHE有两级. 一级是在Session范围内的CACHE. 即每个Session有自己的一个CACHE, 当前操作的对象都会被保留在CACHE中. 但是Session关闭后这个CACHE也就没有. 可见这级CACHE的生命期是很短的. 另一级CACHE是在SessionFactory范围的, 可以被来自同一个SessionFactory的Session共享. 在HIBERNATE的文档中称其为SECOND LEVEL CACHE. 显然后者的优势较明显, 也比较复合当前的使用环境.

还有一个类型的CACHE就是QueryCache. 它的作用就是缓存一个Query以及Query返回对象的Identifier以及对象的类型. 有了QueryCache后就可以高效的使用SECOND LEVEL CACHE.

Second Level Cache
这里使用ehcache来作为HIBERNATE的SECOND LEVEL CACHE. 由于这是HIBERNATE默认的CACHE提供者, 所以无须做什么设置. 两个很简单的POJO, Person & Address, 一对多的关系. HBM如下:

<hibernate-mapping 
	package="goncha.hb.bean">
	<class name="Person" table="hb.person">
		<!-- enable second level cache -->
		<cache usage="read-write"/>

		<id name="id">
			<generator class="native"/>
		</id>

		<property name="name" not-null="true" unique="true"/>
		<property name="age" type="java.lang.Integer" not-null="true"/>
	
		<!-- relationship -->
		<set name="addresses" lazy="true" inverse="true" cascade="save-update">
			<key column="owner_id"/>
			<one-to-many class="Address"/>
		</set>
	</class>	
</hibernate-mapping>


<hibernate-mapping 
	package="goncha.hb.bean">
	<class name="Address" table="hb.address">
		<!-- enable second level cache -->
		<cache usage="read-write"/>

		<id name="id">
			<generator class="native"/>
		</id>

		<property name="location" not-null="true" unique="true"/>
		<property name="phone" not-null="true" unique="true"/>
	
		<many-to-one name="owner" column="owner_id" not-null="true"/>
	</class>	
</hibernate-mapping>

这两个类都使用了SECOND LEVEL CACHE, 并且两者之间存在关系映射.

ehcache的配置文件ehcache.xml:

<ehcache>

    <diskStore path="java.io.tmpdir"/>



    <defaultCache

        maxElementsInMemory="10000"

        eternal="false"

        timeToIdleSeconds="120"

        timeToLiveSeconds="120"

        overflowToDisk="true"

        />



    <cache name="goncha.hb.bean.Person"

        maxElementsInMemory="10"

        eternal="false"

        timeToIdleSeconds="100"

        timeToLiveSeconds="100"

        overflowToDisk="false"

        />



    <cache name="goncha.hb.bean.Address"

        maxElementsInMemory="10"

        eternal="false"

        timeToIdleSeconds="100"

        timeToLiveSeconds="100"

        overflowToDisk="false"

        />



</ehcache>

一段简单的测试代码, 可以清楚的看到HIBERNATE如何来使用SECOND LEVEL CACHE. 在运行这段代码前需要作一些工作: 在HIBERNATE的配置文件中允许输出生成的SQL语句; 在LOG4J的配置文件中, 处了net.sf.hibernate.cache在DEBUG级别, 其余都在WARN级别, 为了没有干扰

# log4j.properties
log4j.logger.net.sf.hibernate=warn
log4j.logger.net.sf.hibernate.cache=debug


# hibernate.properties
hibernate.show_sql true

至此就可以运行以下代码

//: Main.java

package goncha.hb;

import java.util.Iterator;
import java.util.List;
import java.util.Set;

import net.sf.hibernate.Query;
import net.sf.hibernate.Session;
import net.sf.hibernate.SessionFactory;
import net.sf.hibernate.Transaction;
import net.sf.hibernate.cfg.Configuration;

import goncha.hb.bean.*;


public class Main {

    public static void main(String[] args); throws Exception {
	SessionFactory sessions = buildSessionFactory();;

	pushDataIntoCache(sessions);;
	popDataFromCache(sessions);;
    }

    static SessionFactory buildSessionFactory(); throws Exception {
	Configuration config = new Configuration();;
	config.addClass(Person.class);.addClass(Address.class);;
	return config.buildSessionFactory();;
    }

    static void pushDataIntoCache(SessionFactory sessions); throws Exception {
	System.out.println("======= Push some data into cache =======");;

	Session sess = sessions.openSession();;
	Transaction tx = sess.beginTransaction();;
	
	Person goncha = (Person);sess.load(Person.class, new Integer(1););;
	System.out.println(goncha);;

	Person chengang = (Person);sess.load(Person.class, new Integer(2););;
	System.out.println(chengang);;

	goncha.getAddresses();.size();;
	tx.commit();;
	sess.close();;
    }

    static void popDataFromCache(SessionFactory sessions); throws Exception {
	System.out.println("======= Pop some data into cache =======");;

	Session sess = sessions.openSession();;
	Transaction tx = sess.beginTransaction();;

	Person goncha = (Person);sess.load(Person.class, new Integer(1););;
	System.out.println(goncha);;

	Person chengang = (Person);sess.load(Person.class, new Integer(2););;
	System.out.println(chengang);;
	
	Person tommy = (Person);sess.load(Person.class, new Integer(3););;
	System.out.println(tommy);;

	Person mary = (Person);sess.load(Person.class, new Integer(4););;
	System.out.println(mary);;


	List persons = sess.find("from Person as person");;

	Set addresses = goncha.getAddresses();;
	Iterator it = addresses.iterator();;
	while(it.hasNext();); {
	    System.out.println((Address);it.next(););;
	}

	tx.commit();;
	sess.close();;
    }
}

以下是程序的输出

Buildfile: build.xml

init:

build:

run:
     [java] 23:14:04,878 DEBUG CacheFactory:32 - cache for: goncha.hb.bean.Person usage strategy: read-write
     [java] 23:14:05,156 DEBUG CacheFactory:32 - cache for: goncha.hb.bean.Address usage strategy: read-write
     [java] Initializing c3p0 pool... com.mchange.v2.c3p0.PoolBackedDataSource@17bd6a1 [ connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@8b819f [ acquireIncrement -> 2, autoCommitOnClose -> false, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, idleConnectionTestPeriod -> 3000, initialPoolSize -> 2, maxIdleTime -> 5000, maxPoolSize -> 2, maxStatements -> 100, minPoolSize -> 2, nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource@147ee05 [ description -> null, driverClass -> null, factoryClassLocation -> null, jdbcUrl -> jdbc:postgresql:test, properties -> {user=pgsql, password=pgsql} ] , propertyCycle -> 300, testConnectionOnCheckout -> false ] , factoryClassLocation -> null, numHelperThreads -> 3 ] 
     [java] 23:14:07,390  INFO UpdateTimestampsCache:35 - starting update timestamps cache at region: net.sf.hibernate.cache.UpdateTimestampsCache
     [java] 23:14:07,396  INFO QueryCache:39 - starting query cache at region: net.sf.hibernate.cache.QueryCache
     [java] __======= Push some data into cache =======__
     [java] 23:14:07,492 DEBUG ReadWriteCache:68 - Cache lookup: 1
     [java] 23:14:07,494 DEBUG ReadWriteCache:84 - Cache miss: 1
     [java] Hibernate: select person0_.id as id0_, person0_.name as name0_, person0_.age as age0_ from hb.person person0_ where person0_.id=?
     [java] 23:14:07,584 DEBUG ReadWriteCache:132 - Caching: 1
     [java] 23:14:07,594 DEBUG ReadWriteCache:143 - Cached: 1
     [java] Person ['goncha'; 23]
     [java] 23:14:07,599 DEBUG ReadWriteCache:68 - Cache lookup: 2
     [java] 23:14:07,601 DEBUG ReadWriteCache:84 - Cache miss: 2
     [java] Hibernate: select person0_.id as id0_, person0_.name as name0_, person0_.age as age0_ from hb.person person0_ where person0_.id=?
     [java] 23:14:07,609 DEBUG ReadWriteCache:132 - Caching: 2
     [java] 23:14:07,611 DEBUG ReadWriteCache:143 - Cached: 2
     [java] Person ['chengang'; 23]
     [java] Hibernate: select addresses0_.id as id__, addresses0_.owner_id as owner_id__, addresses0_.id as id0_, addresses0_.location as location0_, addresses0_.phone as phone0_, addresses0_.owner_id as owner_id0_ from hb.address addresses0_ where addresses0_.owner_id=?
     [java] 23:14:07,624 DEBUG ReadWriteCache:132 - Caching: 1
     [java] 23:14:07,630 DEBUG ReadWriteCache:143 - Cached: 1
     [java] 23:14:07,632 DEBUG ReadWriteCache:132 - Caching: 2
     [java] 23:14:07,633 DEBUG ReadWriteCache:143 - Cached: 2
     [java] 23:14:07,635 DEBUG ReadWriteCache:132 - Caching: 6
     [java] 23:14:07,637 DEBUG ReadWriteCache:143 - Cached: 6
     [java] __======= Pop some data into cache =======__
     [java] 23:14:07,669 DEBUG ReadWriteCache:68 - Cache lookup: 1
     [java] 23:14:07,671 DEBUG ReadWriteCache:78 - Cache hit: 1
     [java] Person ['goncha'; 23]
     [java] 23:14:07,675 DEBUG ReadWriteCache:68 - Cache lookup: 2
     [java] 23:14:07,678 DEBUG ReadWriteCache:78 - Cache hit: 2
     [java] Person ['chengang'; 23]
     [java] 23:14:07,680 DEBUG ReadWriteCache:68 - Cache lookup: 3
     [java] 23:14:07,682 DEBUG ReadWriteCache:84 - Cache miss: 3
     [java] Hibernate: select person0_.id as id0_, person0_.name as name0_, person0_.age as age0_ from hb.person person0_ where person0_.id=?
     [java] 23:14:07,691 DEBUG ReadWriteCache:132 - Caching: 3
     [java] 23:14:07,693 DEBUG ReadWriteCache:143 - Cached: 3
     [java] Person ['tommy'; 21]
     [java] 23:14:07,698 DEBUG ReadWriteCache:68 - Cache lookup: 4
     [java] 23:14:07,699 DEBUG ReadWriteCache:84 - Cache miss: 4
     [java] Hibernate: select person0_.id as id0_, person0_.name as name0_, person0_.age as age0_ from hb.person person0_ where person0_.id=?
     [java] 23:14:07,704 DEBUG ReadWriteCache:132 - Caching: 4
     [java] 23:14:07,706 DEBUG ReadWriteCache:143 - Cached: 4
     [java] Person ['mary'; 18]
     [java] Hibernate: select person0_.id as id, person0_.name as name, person0_.age as age from hb.person person0_
     [java] 23:14:07,768 DEBUG ReadWriteCache:132 - Caching: 5
     [java] 23:14:07,770 DEBUG ReadWriteCache:143 - Cached: 5
     [java] 23:14:07,772 DEBUG ReadWriteCache:132 - Caching: 6
     [java] 23:14:07,774 DEBUG ReadWriteCache:143 - Cached: 6
     [java] Hibernate: select addresses0_.id as id__, addresses0_.owner_id as owner_id__, addresses0_.id as id0_, addresses0_.location as location0_, addresses0_.phone as phone0_, addresses0_.owner_id as owner_id0_ from hb.address addresses0_ where addresses0_.owner_id=?
     [java] 23:14:07,809 DEBUG ReadWriteCache:132 - Caching: 1
     [java] 23:14:07,811 DEBUG ReadWriteCache:152 - Item was already cached: 1
     [java] 23:14:07,816 DEBUG ReadWriteCache:132 - Caching: 2
     [java] 23:14:07,817 DEBUG ReadWriteCache:152 - Item was already cached: 2
     [java] 23:14:07,819 DEBUG ReadWriteCache:132 - Caching: 6
     [java] 23:14:07,820 DEBUG ReadWriteCache:152 - Item was already cached: 6
     [java] Address ['goncha'; 'newyork']
     [java] Address ['goncha'; 'shanghai']
     [java] Address ['goncha'; 'guangzhou']



BUILD SUCCESSFUL
Total time: 7 seconds

这个结果很出乎意外, HERBNATE只能在Session.load()方法中使用CACHE. pushDataIntoCache()方法成功地给CACHE注入两个Person对象("goncha", "chengang")以及三个Address对象(与"goncha"关联). 再看看popDataFromCache()方法. 使用Session.load()时, "goncha"与"chengang"对应的Person对象都是从CACHE中获得, 其余两个是CACHE MISS的, 正常举动. 而Session.find()的数据获取与CACHE没有关系, 完全由JDBC来操办. 最后只是把从JDBC获得的对象注入CACHE. 通过关系查找对象的过程和Session.find()没有异样, 甚至CACHE还报出对象已存在的消息.

不知这样的测试是否会偏面. 但是在具体的使用环境中就是Session.find()和Relationship Collection占了多数. 像上面的例子那样, CACHE不仅没有用到还白白占了内存. 所以在HIBERNATE中使用CACHE还是需要根据具体情况来定制.

Query Cache
老实说, 要做到在JDBC查询之前决定哪些数据需要从JDBC来还是CACHE来不是件容易事. 但是HIBERNATE还是很好地完成了这个任务. 前面说过QueryCache用来缓存查询语句, 及查询结果集中对象的Identifier与Type. 当再次使用已缓存的Query时, 就可以通过对象的Identifier与Type在SECOND LEVEL CACHE中查找实际的对象.

使用QueryCache时需要在hibernate配置文件中设置如下属性:

hibernate.cache.use_query_cache true

在程序中需要为Query对象设置Cachable属性:

Query query = sess.createQuery("from AccountingPeriod as period "
	+ "where period.id.dealerId = ? order by period.id.orderType asc, " 
	+ "period.id.accountingPeriod asc");;
query.setCacheable(true);;
query.setInteger(0, dealerId.intValue(););;
List rs = query.list();;

对于查询结果的CACHE处理算是解决了. 但是, 通过Relationship获得Collection的方式好似还不能利用CACHE来提高性能. 有时间再仔细研究一下文档.

<class name="eg.Cat" .... >
    <jcs-cache usage="read-write"/>
    ....
    <set name="kittens" ... >
        <jcs-cache usage="read-write"/>
        ....
    </set>
</class>

这样才可利用collection cache.

刚才看了一下文档和Mapping的DTD定义, 在<set></set>, <map></map>等集合定义中也可以使用<cache>. 文档中声明了JCS在将来的版本中将不被支持了.

楼主的好文章。感谢你的知识！
其实说到cache还是有一些值得注意的：
cache必须注意保持同步。
在delete集合元素的时候，更应该值得注意cache是否已经与数据库同步，否则在读取集合的时候会发生异常。
关于同步cache在必要的时候，可以采用手工同步的办法

的确是个问题, 还没有尝试过.

楼主的这篇文章我这几天看了好多遍，也在网上搜了很久，
有若干问题，不知道怎么理解，或者怎么解决。
1。我的ehcache的debug消息怎么和楼主的不一样？
2。MISS是不是“cache中没有，现在加入”的意思？
3。query.setCacheable(true)，如果是在一个经常调用&需要ps的地方，是不是在一个static的field里get这个query就可以了？怎么看某个query在不在cache中？
4。ehcache还有hibernate的文档中说管理二级缓存应该在sessionFactory中使用evict，我使用了，但是好像没有生效，它仍然看那个Entity是不是expired?false。
5。怎么写这个部分的测试代码？debug我实在不想看了，首先是我不确定他的每句话都是在干什么，其次也忒多了，不过如果很久还没有人回复，那我自己也能写个简单点的来啃。
6。idle值有必要设的比live短吗？
7。如果不设定cache某个collection，是不是cache中就肯定不会出现collection？（我想知道debug里没有写清的是session cache还是二级）
（以上无涉及session级cache）

还有一些是不是杞人忧天的问题，
其实我想更多的知道他中间的过程（如果有人知道了，就告知，hibernate源代码的cache那部分没有看太懂）
read-write，如果写成了read-write，那么session1正在执行write操作，还没有结束动作，同时sessionFactory被执行了evict，那么session1之后的动作是些什么？（我知道肯定会出错了，那么该如何解决）
如果在mapping中改成read-only，那么前边的问题没有了，可是我通过什么来执行写操作呢？
或者我把问题改一下，cache中的内容，是不是只是由ehcache的那两个小参数——idle和live——维护的。在某个具体过程中，我有没有暂时不选择cache中内容的权力。

是不是我把事情想复杂了？

没有搞复杂. 这是在具体应用中一定会遇到的情况. 由于前一段时间使用Hibernate大都是处理只读的操作所以没有遇到类似的问题.  有时间了好好试一下b051提到的情况.
至于暂时不选择cache中内容, 好像没有注意到有相关的API.

在hibernate中，
query cache 的 Key 是 QueryKey。(包括hql, parameters, start, maxRows.)
value是 list of DB object。

session factory level cache 的 key是 id.
value 是 DB object.

请问这两个cache之间的对象能够同步吗？

比如，query cache里面，
"from A where ..." 这个query 对应的
object list是 {a (id = 1) , b (id = 2), c (id = 3)}

session factory level cache 的 里面，
有 key = 1,  value = a {id = 1}.

请问，这两个 a 是同一个object吗？
如果不是，两者之间会同步保持相同数据吗？

hibernate的相关源代码为
Loader类，QueryKey关键字

final boolean cacheable = factory.isQueryCacheEnabled(); && queryParameters.isCacheable();;
		
if (cacheable); {
    QueryCache queryCache = factory.getQueryCache(queryParameters.getCacheRegion(); );;
    QueryKey key = new QueryKey( getSQLString();, queryParameters );;
    List result = null;
    if ( !queryParameters.isForceCacheRefresh(); ); {
    result = queryCache.get(key, resultTypes, querySpaces, session);;
  }
  if (result==null); {
    result = doList(session, queryParameters);;
    queryCache.put(key, resultTypes, result, session);;
  }
  return getResultList(result);;
}
else {
  return getResultList( doList(session, queryParameters); );;
}

StandardQueryCache类。get()方法。

List cacheable = (List); queryCache.get(key);;
if (cacheable==null); {return null;}

List result = new ArrayList( cacheable.size();-1 );;
Long timestamp = (Long); cacheable.get(0);;
if ( ! isUpToDate(spaces, timestamp); ); {
  log.debug("cached query results were not up to date");;
  return null;
}

for ( int i=1; i<cacheable.size();; i++ ); {
  if ( returnTypes.length==1 ); {
    result.add( returnTypes[0].assemble( (Serializable); cacheable.get(i);, session, null ); );;
  }
  else {
    result.add( TypeFactory.assemble( (Serializable[]); cacheable.get(i);, returnTypes, session, null ); );;
  }
}
return result;

如果有同步，是在returnTypes[0].assemble() 或者 TypeFactory.assemble 里面做的吗？

StandardQueryCache类。put()方法。

public void put(QueryKey key, Type[] returnTypes, List result, SessionImplementor session); throws HibernateException {
if ( log.isDebugEnabled(); ); log.debug("caching query results in region: " + regionName);;
List cacheable = new ArrayList( result.size();+1 );;
cacheable.add( new Long( session.getTimestamp(); ); );;
for ( int i=0; i<result.size();; i++ ); {
if ( returnTypes.length==1 ); {
	cacheable.add( returnTypes[0].disassemble( result.get(i);, session ); );;
}
else {
	cacheable.add( TypeFactory.disassemble( (Object[]); result.get(i);, returnTypes, session ); );;
}
}
queryCache.put(key, cacheable);;
}

或者是在put的时候，type.dissemble做的？

再来看，ObjectType的assemble和dissemble代码。

public Object assemble(
Serializable cached,
SessionImplementor session,
Object owner);
throws HibernateException {

ObjectTypeCacheEntry e = (ObjectTypeCacheEntry); cached;
return (cached==null); ? null : session.load(e.clazz, e.id);;
}

/**
* @see net.sf.hibernate.type.Type#disassemble(Object, SessionImplementor);
*/
public Serializable disassemble(Object value, SessionImplementor session);
throws HibernateException {
return (value==null); ? 
null : 
new ObjectTypeCacheEntry( 
	HibernateProxyHelper.getClass(value);, 
	session.getEntityIdentifierIfNotUnsaved(value); 
);;
}

从代码看不出来什么。
有时间，我看看能不能把hibernate source编译，跟踪一下，到底是怎么回事。如果有人知道这方面，愿意回答，就非常感谢了。

----



对，是这样的。对应代码为：
SessionImpl.java.

private void endLoadingCollections(CollectionPersister persister, List resultSetCollections);{

//now finish them
for ( int i=0; i<count; i++ ); {
...
if ( noQueuedAdds && persister.hasCache(); && !ce.doremove ); {
persister.getCache();.put( 
lce.id, lce.collection.disassemble(persister);, getTimestamp();, version, versionComparator
);;
}
}

这里只是把list的object按照id放入到缓存里面。
这也许就是应该 使用query cache的场合吧？

刚写了一个测试：

 log.info("Start");;
        Session session = Hibernator.currentSession();;
        String name = "test.admin";
        Users admin = Users.getUser(name);;
        Query query = session.createQuery("select user.name "
                + "from Users as user where user.username=:name");;
        query.setCacheable(true);;
        query.setParameter("name", name);;
        log.info(query.list(););;
        admin.setName("1");;
        log.info(query.list(););;

输出是：

[12-18 17:05:05]Start
{此处省略97行,内容为将诸相关entity加载入二级缓存}
[12-18 17:05:05]key: 297e6d8400e457e70100e457ee570003
[12-18 17:05:05]bean.UsersCache: MemoryStore miss for 297e6d8400e457e70100e457ee570003
[12-18 17:05:05]bean.Users cache - Miss
[12-18 17:05:05]Element for 297e6d8400e457e70100e457ee570003 is null
[12-18 17:05:05]297e6d8400e4578a0100e457924d0007 now: 1103360705906
[12-18 17:05:05]297e6d8400e4578a0100e457924d0007 Creation Time: 1103360705906 Next To Last Access Time: 0
[12-18 17:05:05]297e6d8400e4578a0100e457924d0007 mostRecentTime: 1103360705906
[12-18 17:05:05]297e6d8400e4578a0100e457924d0007 Age to Idle: 300000 Age Idled: 0
[12-18 17:05:05]bean.Users: Is element with key 297e6d8400e4578a0100e457924d0007 expired?: false
[12-18 17:05:05]key: sql: select users0_.REALNAME as x0_0_ from MDC_USERS users0_ where (users0_.USERNAME=? );; parameters: ; named parameters: {name=test.admin}
[12-18 17:05:05]net.sf.hibernate.cache.StandardQueryCacheCache: MemoryStore miss for sql: select users0_.REALNAME as x0_0_ from MDC_USERS users0_ where (users0_.USERNAME=? );; parameters: ; named parameters: {name=test.admin}
[12-18 17:05:05]net.sf.hibernate.cache.StandardQueryCache cache - Miss
[12-18 17:05:05]Element for sql: select users0_.REALNAME as x0_0_ from MDC_USERS users0_ where (users0_.USERNAME=? );; parameters: ; named parameters: {name=test.admin} is null
[12-18 17:05:05]sql: select users0_.REALNAME as x0_0_ from MDC_USERS users0_ where (users0_.USERNAME=? );; parameters: ; named parameters: {name=test.admin} now: 1103360705937
[12-18 17:05:05]sql: select users0_.REALNAME as x0_0_ from MDC_USERS users0_ where (users0_.USERNAME=? );; parameters: ; named parameters: {name=test.admin} Creation Time: 1103360705937 Next To Last Access Time: 0
[12-18 17:05:05]sql: select users0_.REALNAME as x0_0_ from MDC_USERS users0_ where (users0_.USERNAME=? );; parameters: ; named parameters: {name=test.admin} mostRecentTime: 1103360705937
[12-18 17:05:05]sql: select users0_.REALNAME as x0_0_ from MDC_USERS users0_ where (users0_.USERNAME=? );; parameters: ; named parameters: {name=test.admin} Age to Idle: 0 Age Idled: 0
[12-18 17:05:05]net.sf.hibernate.cache.StandardQueryCache: Is element with key sql: select users0_.REALNAME as x0_0_ from MDC_USERS users0_ where (users0_.USERNAME=? );; parameters: ; named parameters: {name=test.admin} expired?: false
[12-18 17:05:05][null]
[12-18 17:05:05]net.sf.hibernate.cache.UpdateTimestampsCache: Is element with key MDC_USERS expired?: false
[12-18 17:05:05]key: 297e6d8400e457e70100e457ee570003
[12-18 17:05:05]bean.UsersCache: MemoryStore hit for 297e6d8400e457e70100e457ee570003
[12-18 17:05:05]297e6d8400e457e70100e457ee570003 now: 1103360705937
[12-18 17:05:05]297e6d8400e457e70100e457ee570003 Creation Time: 1103360705906 Next To Last Access Time: 0
[12-18 17:05:05]297e6d8400e457e70100e457ee570003 mostRecentTime: 1103360705906
[12-18 17:05:05]297e6d8400e457e70100e457ee570003 Age to Idle: 300000 Age Idled: 31
[12-18 17:05:05]bean.Users: Is element with key 297e6d8400e457e70100e457ee570003 expired?: false
[12-18 17:05:05]key: sql: select users0_.REALNAME as x0_0_ from MDC_USERS users0_ where (users0_.USERNAME=? );; parameters: ; named parameters: {name=test.admin}
[12-18 17:05:05]net.sf.hibernate.cache.StandardQueryCacheCache: MemoryStore hit for sql: select users0_.REALNAME as x0_0_ from MDC_USERS users0_ where (users0_.USERNAME=? );; parameters: ; named parameters: {name=test.admin}
[12-18 17:05:05]sql: select users0_.REALNAME as x0_0_ from MDC_USERS users0_ where (users0_.USERNAME=? );; parameters: ; named parameters: {name=test.admin} now: 1103360705937
[12-18 17:05:05]sql: select users0_.REALNAME as x0_0_ from MDC_USERS users0_ where (users0_.USERNAME=? );; parameters: ; named parameters: {name=test.admin} Creation Time: 1103360705937 Next To Last Access Time: 0
[12-18 17:05:05]sql: select users0_.REALNAME as x0_0_ from MDC_USERS users0_ where (users0_.USERNAME=? );; parameters: ; named parameters: {name=test.admin} mostRecentTime: 1103360705937
[12-18 17:05:05]sql: select users0_.REALNAME as x0_0_ from MDC_USERS users0_ where (users0_.USERNAME=? );; parameters: ; named parameters: {name=test.admin} Age to Idle: 0 Age Idled: 0
[12-18 17:05:05]net.sf.hibernate.cache.StandardQueryCache: Is element with key sql: select users0_.REALNAME as x0_0_ from MDC_USERS users0_ where (users0_.USERNAME=? );; parameters: ; named parameters: {name=test.admin} expired?: false
[12-18 17:05:05]key: MDC_USERS
[12-18 17:05:05]net.sf.hibernate.cache.UpdateTimestampsCacheCache: MemoryStore hit for MDC_USERS
[12-18 17:05:05]net.sf.hibernate.cache.UpdateTimestampsCache: Is element with key MDC_USERS expired?: false
[12-18 17:05:05][1]