I have the hibernate EHCache configured. I expect this works as a second-level process cache, independent of Sessions. However, I noticed , through logging in entity object constructors and finalizers, as well as through hash code outputs, that a new object is being created for the same DB record. A query is also being fired each time.
What would I be doing wrong that is causing this? Looks like secondary-level caching isnot working at all....
Not sure what I'm doing wrong..went through all forum questions and documentation too without any luck.. Greatly appreciate any help!
Configuration, source and logs are below:
Hibernate version:2.1
Mapping documents: <!DOCTYPE hibernate-configuration PUBLIC "-//Hibernate/Hibernate Configuration DTD//EN" "http://hibernate.sourceforge.net/hibernate-configuration-2.0.dtd">
<hibernate-configuration>
<session-factory> <property name="hibernate.connection.driver_class">oracle.jdbc.driver.OracleDriver</property> <property name="hibernate.connection.url">jdbc:oracle:thin:@172.25.44.194:1521:fkt2</property> <property name="hibernate.connection.username">madmax</property> <property name="hibernate.connection.password">cubby</property> <property name="dialect">net.sf.hibernate.dialect.OracleDialect</property> <property name="show_sql">true</property> <property name="transaction.factory_class"> net.sf.hibernate.transaction.JDBCTransactionFactory </property> <property name="hibernate.cache.provider_class"> net.sf.hibernate.cache.EhCacheProvider </property>
<mapping resource="../eg/org/hibernate/auction/PlanWorksheet.hbm.xml"/>
</session-factory> </hibernate-configuration>
<?xml version="1.0"?> <!DOCTYPE hibernate-mapping PUBLIC "-//Hibernate/Hibernate Mapping DTD 2.0//EN" "http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd"> <hibernate-mapping package="org.hibernate.auction">
<class name="PlanWorksheet" table="maxdata.planworksheet" > <cache usage="transactional" /> <id name="id" column="planworksheet_id"> <generator class="native"/> </id> <timestamp name="last_update_date"/> <property name="planworksheet_id" insert="false" update="false" /> <property name="planversion_id" /> <property name="planmaster_id" /> <property name="plangroup_id" /> <property name="description" /> <property name="from_merch_name" /> <property name="create_date"/> <property name="plan_count"/> <property name="name"/> </class> </hibernate-mapping>
Code between sessionFactory.openSession() and session.close(): public void viewAllPlanGroups() throws Exception { System.out.println("Viewing all plan groups info thru Hibernate");
Session s = factory.openSession(); setMemMarker(); Transaction tx=null; try { tx = s.beginTransaction();
List worksheets=null;Iterator iter=null; long currTime=0;
currTime=System.currentTimeMillis(); worksheets = s.createCriteria(PlanWorksheet.class).add( Expression.eq("planworksheet_id", new Long(10636))).list(); eet_id=10636"); System.out.println("Num of ws ="+worksheets.size()); iter = worksheets.iterator(); while ( iter.hasNext() ) { PlanWorksheet ai = (PlanWorksheet) iter.next(); System.out.println("hash code="+ai.hashCode()); System.out.println(ai); }
System.out.println("Total query time="+(System.currentTimeMillis()-currTime)); outMemory(worksheets.size()); tx.commit(); } catch (Exception e) { if (tx!=null) tx.rollback(); throw e; } finally { s.close(); } } public static void main(String[] args) throws Exception {
final Main test = new Main();
Configuration cfg = new Configuration(); cfg.configure(); test.factory = cfg.buildSessionFactory(); test.viewAllPlanGroups(); //expect cache to be hit on second call-but goes to DB again.... test.viewAllPlanGroups(); }
Full stack trace of any exception that occurs:
Oracle 8.1.7 driver
org.hibernate.auction.Main 15:56:06,094 INFO Environment:469 - Hibernate 2.1.6 15:56:06,094 INFO Environment:498 - hibernate.properties not found 15:56:06,109 INFO Environment:529 - using CGLIB reflection optimizer 15:56:06,109 INFO Environment:540 - JVM does not support Statement.getGenerated Keys() 15:56:06,109 INFO Environment:551 - JVM does not support LinkedHasMap, LinkedHa shSet - ordered maps and sets disabled 15:56:06,109 INFO Environment:554 - using workaround for JVM bug in java.sql.Ti mestamp 15:56:06,125 INFO Configuration:895 - configuring from resource: /hibernate.cfg .xml 15:56:06,125 INFO Configuration:867 - Configuration resource: /hibernate.cfg.xm l 15:56:06,500 INFO Configuration:331 - Mapping resource: ../eg/org/hibernate/auc tion/PlanWorksheet.hbm.xml 15:56:06,625 INFO Binder:229 - Mapping class: org.hibernate.auction.PlanWorkshe et -> maxdata.planworksheet 15:56:06,719 INFO Configuration:1053 - Configured SessionFactory: null 15:56:06,719 INFO Configuration:627 - processing one-to-many association mappin gs 15:56:06,719 INFO Configuration:636 - processing one-to-one association propert y references 15:56:06,734 INFO Configuration:661 - processing foreign key constraints 15:56:06,750 INFO Dialect:82 - Using dialect: net.sf.hibernate.dialect.OracleDi alect 15:56:06,765 INFO SettingsFactory:63 - Use outer join fetching: true 15:56:06,765 INFO DriverManagerConnectionProvider:42 - Using Hibernate built-in connection pool (not for production use!) 15:56:06,765 INFO DriverManagerConnectionProvider:43 - Hibernate connection poo l size: 20 15:56:06,781 INFO DriverManagerConnectionProvider:77 - using driver: oracle.jdb c.driver.OracleDriver at URL: jdbc:oracle:thin:@172.25.44.194:1521:fkt2 15:56:06,781 INFO DriverManagerConnectionProvider:78 - connection properties: { user=madmax, password=cubby} 15:56:06,781 INFO TransactionFactoryFactory:31 - Transaction strategy: net.sf.h ibernate.transaction.JDBCTransactionFactory 15:56:06,797 INFO TransactionManagerLookupFactory:33 - No TransactionManagerLoo kup configured (in JTA environment, use of process level read-write cache is not recommended) 15:56:07,125 INFO SettingsFactory:103 - Use scrollable result sets: true 15:56:07,125 INFO SettingsFactory:106 - Use JDBC3 getGeneratedKeys(): false 15:56:07,125 INFO SettingsFactory:109 - Optimize cache for minimal puts: false 15:56:07,125 INFO SettingsFactory:115 - echoing all SQL to stdout 15:56:07,125 INFO SettingsFactory:118 - Query language substitutions: {} 15:56:07,125 INFO SettingsFactory:129 - cache provider: net.sf.hibernate.cache. EhCacheProvider 15:56:07,125 INFO Configuration:1116 - instantiating and configuring caches 15:56:07,297 INFO SessionFactoryImpl:118 - building session factory ******pw obj created ****cnt=1 Finalizing object of id 0 15:56:07,922 INFO SessionFactoryObjectFactory:82 - Not binding factory to JNDI, no JNDI name configured Viewing all plan groups info thru Hibernate free memory=133157816 Hibernate: select this.planworksheet_id as planwork1_0_, this.last_update_date a s last_upd2_0_, this.planworksheet_id as planwork1_0_, this.planversion_id as pl anvers3_0_, this.planmaster_id as planmast4_0_, this.plangroup_id as plangrou5_0 _, this.description as descript6_0_, this.from_merch_name as from_mer7_0_, this. create_date as create_d8_0_, this.plan_count as plan_count0_, this.name as name0 _ from maxdata.planworksheet this where this.planworksheet_id=? ******pw obj created ****cnt=2 Num of ws =1 hash code=3426001 id=10636 description=null create_date=2004-04-01 00:00:00.0 plan_count=4211649 last_update_date=2004-04-01 00:00:00.0 from_merch_name= Company : Merchandise Total - TOTAL Total query time=78 free memory=133119912 memory used=38 KB memory used per record=38312 bytes Viewing all plan groups info thru Hibernate 15:56:08,281 WARN SessionImpl:3400 - unclosed connection free memory=132974216 Finalizing object of id 10636 Hibernate: select this.planworksheet_id as planwork1_0_, this.last_update_date a s last_upd2_0_, this.planworksheet_id as planwork1_0_, this.planversion_id as pl anvers3_0_, this.planmaster_id as planmast4_0_, this.plangroup_id as plangrou5_0 _, this.description as descript6_0_, this.from_merch_name as from_mer7_0_, this. create_date as create_d8_0_, this.plan_count as plan_count0_, this.name as name0 _ from maxdata.planworksheet this where this.planworksheet_id=? ******pw obj created ****cnt=3 Num of ws =1 hash code=7346727 id=10636 description=null create_date=2004-04-01 00:00:00.0 plan_count=4211649 last_update_date=2004-04-01 00:00:00.0 from_merch_name= Company : Merchandise Total - TOTAL Total query time=32 free memory=133099296 memory used=-124 KB memory used per record=-124672 bytes 15:56:08,437 INFO SessionFactoryImpl:534 - closing 15:56:08,437 INFO DriverManagerConnectionProvider:143 - cleaning up connection:
[code][/code]
|