2nd Level Cache Eviction not cascading

huangjd · **Joined:** Wed Jun 21, 2006 10:08 am **Posts:** 26

Hibernate version: 3.2
Cache: JBoss Tree Cache in Local mode

Mapping documents:

Code:

<hibernate-mapping default-lazy="false" >
   <class name="Client" table="client">

      <cache usage="read-only" include="all" />
      <id name="clientId" type="integer" column="CLIENT_ID" />
      
      <bag name="orgLevel" inverse="true" cascade="all,delete-orphan" >
      <cache usage="read-only" />
         <key column="CLIENT_ID" not-null="true" />
         <one-to-many class="OrgLevel"/>
      </bag>
   </class>
</hibernate-mapping>

I simplified my mapping a lot, there are really 7 bags, all being cascaded.
I've tried using cascad types of: all, evict, all-delete-orphan and none of them will cascade the eviction.

Here is essentially what I am doing (using the CaveatEmptor DAOFactory pattern):

evictIfStale(Client.class, oldDate, 1);
Client myClient = DAOFactory.getInstance().getClientDAO().findById(1);
evictIfStale(Client.class, oldDate, 1);

I call evict twice (mostly for testing purposes), but it removes it before and after just in case.

Here is the code for viewing my cache manager.

Code:

String[] regionNames = stats.getSecondLevelCacheRegionNames();

for(int i = 0; i < regionNames.length; i++) {
   
   Map cacheEntries = stats.getSecondLevelCacheStatistics(regionNames[i]).getEntries();
   out.println("<b>Cache Region:</b> " + regionNames[i] + "<BR>");
   out.println("<b>Cache Stats: </b>" + stats.getSecondLevelCacheStatistics(regionNames[i]).toString() + "<BR>");
   Object[] keys = cacheEntries.keySet().toArray();
   
   for(int j = 0; j < cacheEntries.size(); j++) {

      out.println("<b>Cached Item: </b>" + cacheEntries.get(keys[j]) + "<BR>");
   }
   out.println("<hr>");
}

The cache manager shows that the Client object is being evicted, but none of it's collections are.

I've looked through the forums for a few hours as well as Jira and can't find a solution. I saw in the past, session.evict had issues. Did I miss reading somewhere the 2nd level cache cascading eviction is broken (or is non-existant)? The API for Session.evict() explicitly says "cascade="evict" will evict it's children. But the SessionFactory.evict doesn't mention it...

Anyone have any ideas? I'm pretty stumped at this point.

huangjd · **Joined:** Wed Jun 21, 2006 10:08 am **Posts:** 26

Anyone?

my debug is as follow for when an eviction starts. As you can see, Client gets evicted but none of it's associations cascade the evict, even though I am telling it to in the mapping file...

Code:

=========== Start Evicting Client =============
[DEBUG][org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:290)]- allowing method [beginTransaction] in non-transacted context
[DEBUG][org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:300)]- allowing proxied method [beginTransaction] to proceed to real session
[DEBUG][org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:54)]- begin
[DEBUG][org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:415)]- opening JDBC connection
[DEBUG][org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:59)]- current autocommit status: false
[DEBUG][org.hibernate.jdbc.JDBCContext.afterTransactionBegin(JDBCContext.java:194)]- after transaction begin

[INFO][ClientDAOHibernate.evictIfStaleByDate(ClientDAOHibernate.java:52)]- Trying to evict Client with id: 1

[DEBUG][org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:300)]- allowing proxied method [connection] to proceed to real session

[INFO][ClientDAOHibernate.evictIfStaleByDate(ClientDAOHibernate.java:58)]- Trying to evict Client with id: 1 - SQL Executed: select updated_date from cas_client where client_id = 1
[INFO][ClientDAOHibernate.evictIfStaleByDate(ClientDAOHibernate.java:61)]- Client with id: 1 exists in DB
[INFO][ClientDAOHibernate.evictIfStaleByDate(ClientDAOHibernate.java:64)]- evicting Client with id: 1. Clients's Date: Sat Aug 04 13:25:31 EST 21. Database Date: 2003-03-11

[DEBUG][org.hibernate.impl.SessionFactoryImpl.evict(SessionFactoryImpl.java:794)]- evicting second-level cache: [ request.Client#1]
[DEBUG][org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:103)]- commit
[DEBUG][org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:332)]- automatically flushing session
[DEBUG][org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:58)]- flushing session
[DEBUG][org.hibernate.event.def.AbstractFlushingEventListener.prepareEntityFlushes(AbstractFlushingEventListener.java:111)]- processing flush-time cascades
[DEBUG][org.hibernate.engine.Cascade.cascade(Cascade.java:237)]- processing cascade ACTION_SAVE_UPDATE for:  Client
[DEBUG][org.hibernate.engine.Cascade.cascade(Cascade.java:259)]- done processing cascade ACTION_SAVE_UPDATE for:  Client
[DEBUG][org.hibernate.event.def.AbstractFlushingEventListener.prepareCollectionFlushes(AbstractFlushingEventListener.java:153)]- dirty checking collections
[DEBUG][org.hibernate.event.def.AbstractFlushingEventListener.flushEntities(AbstractFlushingEventListener.java:170)]- Flushing entities and processing referenced collections
[DEBUG][org.hibernate.engine.Collections.processReachableCollection(Collections.java:176)]- Collection found: [Client.orgLevel#1], was: [Client.orgLevel#1] (initialized)
[DEBUG][org.hibernate.engine.Collections.processReachableCollection(Collections.java:176)]- Collection found: [Client.smpAtt#1], was: [Client.smpAtt#1] (initialized)
[DEBUG][org.hibernate.engine.Collections.processReachableCollection(Collections.java:176)]- Collection found: [Client.sampleRawOrder#1], was: [Client.sampleRawOrder#1] (initialized)
[DEBUG][org.hibernate.engine.Collections.processReachableCollection(Collections.java:176)]- Collection found: [Client.samplePassthroughRawOrder#1], was: [Client.samplePassthroughRawOrder#1] (initialized)
[DEBUG][org.hibernate.engine.Collections.processReachableCollection(Collections.java:176)]- Collection found: [Client.sampleAttributeOrder#1], was: [.Client.sampleAttributeOrder#1] (initialized)
[DEBUG][org.hibernate.engine.Collections.processReachableCollection(Collections.java:176)]- Collection found: [Client.surveyJobs#1], was: [surveyJobs#1] (initialized)
[DEBUG][org.hibernate.engine.Collections.processReachableCollection(Collections.java:176)]- Collection found: [Client.surveyJobOrder#1], was: [Client.surveyJobOrder#1] (initialized)
[DEBUG][org.hibernate.engine.Collections.processReachableCollection(Collections.java:176)]- Collection found: [Client.surveyStudy#1], was: [Client.surveyStudy#1] (initialized)
[DEBUG][org.hibernate.engine.Collections.processReachableCollection(Collections.java:176)]- Collection found: [Client.clientModule#1], was: [Client.clientModule#1] (initialized)
[DEBUG][org.hibernate.engine.Collections.processReachableCollection(Collections.java:176)]- Collection found: [Client.quenumberMaster#1], was: [Client.quenumberMaster#1] (initialized)
[DEBUG][org.hibernate.event.def.AbstractFlushingEventListener.flushCollections(AbstractFlushingEventListener.java:209)]- Processing unreferenced collections
[DEBUG][org.hibernate.event.def.AbstractFlushingEventListener.flushCollections(AbstractFlushingEventListener.java:223)]- Scheduling collection removes/(re)creates/updates
[DEBUG][org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:85)]- Flushed: 0 insertions, 0 updates, 0 deletions to 10 objects
[DEBUG][org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:91)]- Flushed: 0 (re)creations, 0 updates, 0 removals to 10 collections
[DEBUG][org.hibernate.pretty.Printer.toString(Printer.java:83)]- listing entities:
[DEBUG][org.hibernate.pretty.Printer.toString(Printer.java:90)]- Client{samplePassthroughRawOrder=[], clientServiceEmail=email.com,email.com, surveyJobs=[SurveyJobs#0], schemeId=1, clientLogo=null, masterJob=null, enforceOu=true, schemaOwner=INTERNALMKTING_SAMPLE, portalId=null, ouId=null, securityTable=INTERNAL_SECURITY_VIEW, clientModule=[ CasModuleClient#component[moduleId,clientId]{moduleId=0, clientId=1},  CasModuleClient#component[moduleId,clientId]{moduleId=1, clientId=1},  CasModuleClient#component[moduleId,clientId]{moduleId=2, clientId=1},  CasModuleClient#component[moduleId,clientId]{moduleId=3, clientId=1},  CasModuleClient#component[moduleId,clientId]{moduleId=4, clientId=1},  CasModuleClient#component[moduleId,clientId]{moduleId=6, clientId=1}], masterTable=INTERNAL_MASTER_SAMPLE, defaultView=null, nameTable=null, sampleFilterScope=1, systemUser= User#1, enforceOuDef=0, disabled=false, functionCategoryRoot=null, clientName=Information, surveyJobOrder=[0], sampleRawOrder=[], orgLevel=[], sampleAttributeOrder=[], sampleOu=true, masterSequence=INTERNAL_SEQ, clientId=1, smpAtt=[], quenumberMaster=[], surveyStudy=[ CasStudy#61148]}
[DEBUG][org.hibernate.pretty.Printer.toString(Printer.java:90)]-  SurveyJobs{active=true, uniqueCodes=false, jobNameShort=  Default Job, study= CasStudy#61148, numberOfAutoReminders=0, transactionDisplayName=null, mandatoryRestPeriod=null, startDate=2000-01-01 00:00:00, functionFilter=null, ipFilter=null, disabled=false, maxEmails=null, competitorQuestion=null, job=0, expireSurvey=null, competitorFunction=null, inviteScreenOptions=null, currentJob= TblCurrentJob#0, loyaltyFunction=null, reminderTimeSpan=null, endDate=2000-01-01 00:00:00, jobName=  Default Job}
[DEBUG][org.hibernate.pretty.Printer.toString(Printer.java:90)]-  CasModuleClient{path=/cas/stats, module= CasModule#2, id=component[moduleId,clientId]{moduleId=2, clientId=1}, customPath=null}
[DEBUG][org.hibernate.pretty.Printer.toString(Printer.java:90)]-  CasModuleClient{path=/cas/admin, module= CasModule#6, id=component[moduleId,clientId]{moduleId=6, clientId=1}, customPath=null}
[DEBUG][org.hibernate.pretty.Printer.toString(Printer.java:90)]-  CasModuleClient{path=/cas/project, module= CasModule#0, id=component[moduleId,clientId]{moduleId=0, clientId=1}, customPath=null}
[DEBUG][org.hibernate.pretty.Printer.toString(Printer.java:90)]-  CasModuleClient{path=/cas/reports, module= CasModule#3, id=component[moduleId,clientId]{moduleId=3, clientId=1}, customPath=null}
[DEBUG][org.hibernate.pretty.Printer.toString(Printer.java:90)]-  CasModuleClient{path=/cas/followup, module= CasModule#4, id=component[moduleId,clientId]{moduleId=4, clientId=1}, customPath=null}
[DEBUG][org.hibernate.pretty.Printer.toString(Printer.java:90)]-  CasStudy{studyId=61148, studyName=INTERNAL MARKETING}
[DEBUG][org.hibernate.pretty.Printer.toString(Printer.java:90)]-  CasModuleClient{path=/cas/cmt, module= CasModule#1, id=component[moduleId,clientId]{moduleId=1, clientId=1}, customPath=null}
[DEBUG][org.hibernate.pretty.Printer.toString(Printer.java:90)]-  TblCurrentJob{job=0, transactional=false, archiveType=Ready}
[DEBUG][org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:289)]- executing flush
[DEBUG][org.hibernate.jdbc.ConnectionManager.flushBeginning(ConnectionManager.java:463)]- registering flush begin
[DEBUG][org.hibernate.jdbc.ConnectionManager.flushEnding(ConnectionManager.java:472)]- registering flush end
[DEBUG][org.hibernate.event.def.AbstractFlushingEventListener.postFlush(AbstractFlushingEventListener.java:320)]- post flush
[DEBUG][org.hibernate.jdbc.JDBCContext.beforeTransactionCompletion(JDBCContext.java:185)]- before transaction completion
[DEBUG][org.hibernate.impl.SessionImpl.beforeTransactionCompletion(SessionImpl.java:388)]- before transaction completion
[DEBUG][org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:116)]- committed JDBC Connection
[DEBUG][org.hibernate.jdbc.JDBCContext.afterTransactionCompletion(JDBCContext.java:199)]- after transaction completion
[DEBUG][org.hibernate.jdbc.ConnectionManager.aggressiveRelease(ConnectionManager.java:398)]- aggressively releasing JDBC connection
[DEBUG][org.hibernate.jdbc.ConnectionManager.closeConnection(ConnectionManager.java:435)]- releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
[DEBUG][org.hibernate.impl.SessionImpl.afterTransactionCompletion(SessionImpl.java:417)]- after transaction completion
[INFO][ dao.hibernate.ClientDAOHibernate.evictIfStaleByDate(ClientDAOHibernate.java:114)]- Eviction of Client with id: 1 Occured: true
=========== Done Evicting Client =============

huangjd · **Joined:** Wed Jun 21, 2006 10:08 am **Posts:** 26

So, after some more testing and going through the source as well as talking with other hibernate folks...

It appears that in this scenario:

there is Parent and Child. Parent has a collection of Child called myChildren

Parent.id=1
Parent.myChildren.id=1

Parent.id=2
Parent.myChildren.id=2

Parent.myChildren.id=1 contains Child.id=1, Child.id=2, Child.id=3
Parent.myChildren.id=2 contains Child.id=3, Child.id=4

With second level cache turned on, it creates 3 regions:
Parent
Parent.myChildren
Child

With cascade="evict,all,all-delete-orphan" in the mapping files.

SessionFactory.evict(Parent.class, Parent.id=1) will only evict the Parent object from the Parent region (whose id is 1). It DOES NOT evict it's collection Parent.myChilden.

SessionFactory.evictCollection(Parent.myChildren, Parent.id=1) will only evict Parent.MyChildren from the Parent.myChildren region (whose parent's id is 1). IT DOES NOT evict the assocaited Child objects. These objects would be Child.id=1, Child.id=2, Child.id=3.

This behavior seems poor. From my understanding the Session level cache will evict these objects properly. Why does't the second level cache.?

Any help as to why this is the case woukd be great. If I am wrong, how to do this properly, or maybe a workaround so I can delete the Parent's assoaciated Child objects would also be great!

Thanks!

Stygian · **Joined:** Tue May 16, 2006 3:35 pm **Posts:** 7

I have the same problem! cascade="evict" does not work for SecondLevelCache calling sessionFactory.evict(alpha.class). Beta-Objects won´t evict from SecondLevelCache using cascade="evict" in many-to-one- or/and set-Elements to beta-Objetcs in alpha-class-mapping file. Anybody have a solution for this strange behaviour? I´m using Hibernate v3.1.2...

huangjd · **Joined:** Wed Jun 21, 2006 10:08 am **Posts:** 26

Apparently this is not a strange behaviour but how it is suppose to work.

It has something to do with the ideas behind a cache. The parent object can know about it's collections and references to the actual objects. But it can't actually manipulate those objects because other objects might have references to it as well.

Personally this model never fit the one I was trying to achieve and still think it is flawed until someone learns me caching strategies, as I am no expert.

Only workaround I know of is to obtain the Parent object, programatically go through all of it's collections, evict each object in the collection, then evict the collection. This is where it became pointless because the web of objects in my domain model was many layers deep.

- Jonathan