These old forums are deprecated now and set to read-only. We are waiting for you on our new forums!
More modern, Discourse-based and with GitHub/Google/Twitter authentication built-in.

View unanswered posts | View active topics


Board index » Hibernate & Java Persistence » Hibernate Users

All times are UTC - 5 hours [ DST ]


Forum locked This topic is locked, you cannot edit posts or make further replies.  Page 1 of 1
  [ 1 post ] 
  Previous topic | Next topic 
Author Message
SGlimpff
 Post subject: 2cd level cache ! working with List on restart of hibernate
PostPosted: Wed May 05, 2010 4:39 pm 
Newbie

Joined: Thu Apr 29, 2010 11:52 am
Posts: 3
Tested with hibernate 3.2.6 and 3.5.2 Final

I have a hierarchy of objects where the base class has a List of base objects. This is represented in the hbn as follows

Code:
        <list name="children" inverse="true" lazy="true" cascade="all">
        <cache usage="read-write"/>
           <key column="PARENTID" on-delete="cascade"/>
           <list-index column="MOID"/>
           <one-to-many class="ManagedObject" />
        </list>


When I add the a node into the system and then query it I see the 2cd level cache hit. I can do this repeatedly and the cache is hit each time. If I restart the system and query the same node, the cache logs indicate that the "children" are locked and because of this the database is queried for this list of objects. If I add a new node in the system it works correctly.

Below are the logs I'm seeing from 3.2.6. I'm not sure why logs are duplicated. I noticed in the 3.5.1 version of hibernate that the logs aren't duplicated BUT the logs indicating if something is locked are no longer there.

Note: This is 3rd party code that has migrated to use Hibernate that I'm building on top of. We saw about a 100 fold increase in SQL statements under this platform which caused me to investigate the configuration of Hibernate. So far most of what I've seen and read looks correct but neither I or the code owners know the cause of this issue.

Code:

[03 May 2010 11:32:05:286] cache.ReadWriteCache: Caching: com.adventnet.nms.topodb.ManagedObject.children#5
[03 May 2010 11:32:05:286] cache.ReadWriteCache: Caching: com.adventnet.nms.topodb.ManagedObject.children#5
[03 May 2010 11:32:05:286] cache.EhCache: key: com.adventnet.nms.topodb.ManagedObject.children#5
[03 May 2010 11:32:05:286] cache.ReadWriteCache: Cached: com.adventnet.nms.topodb.ManagedObject.children#5
[03 May 2010 11:32:05:286] cache.ReadWriteCache: Cached: com.adventnet.nms.topodb.ManagedObject.children#5
[03 May 2010 11:32:05:286] cache.ReadWriteCache: Cache lookup: com.adventnet.nms.topodb.ManagedObject.groups#10.52.30.38
[03 May 2010 11:32:05:286] cache.ReadWriteCache: Cache lookup: com.adventnet.nms.topodb.ManagedObject.groups#10.52.30.38
[03 May 2010 11:32:05:286] cache.EhCache: key: com.adventnet.nms.topodb.ManagedObject.groups#10.52.30.38
[03 May 2010 11:32:05:286] cache.ReadWriteCache: Cache hit: com.adventnet.nms.topodb.ManagedObject.groups#10.52.30.38
[03 May 2010 11:32:05:286] cache.ReadWriteCache: Cache hit: com.adventnet.nms.topodb.ManagedObject.groups#10.52.30.38
[03 May 2010 11:32:05:286] cache.ReadWriteCache: Cache lookup: com.adventnet.nms.topodb.ManagedObject.members#10.52.30.38
[03 May 2010 11:32:05:286] cache.ReadWriteCache: Cache lookup: com.adventnet.nms.topodb.ManagedObject.members#10.52.30.38
[03 May 2010 11:32:05:286] cache.EhCache: key: com.adventnet.nms.topodb.ManagedObject.members#10.52.30.38
[03 May 2010 11:32:05:286] cache.ReadWriteCache: Cache hit: com.adventnet.nms.topodb.ManagedObject.members#10.52.30.38
[03 May 2010 11:32:05:286] cache.ReadWriteCache: Cache hit: com.adventnet.nms.topodb.ManagedObject.members#10.52.30.38
[03 May 2010 11:32:05:302] cache.ReadWriteCache: Invalidating: com.adventnet.nms.topodb.ManagedObject.children#5
[03 May 2010 11:32:05:302] cache.ReadWriteCache: Invalidating: com.adventnet.nms.topodb.ManagedObject.children#5
[03 May 2010 11:32:05:302] cache.EhCache: key: com.adventnet.nms.topodb.ManagedObject.children#5
[03 May 2010 11:32:05:302] cache.ReadWriteCache: Invalidating: com.adventnet.nms.topodb.ManagedObject.children#5
[03 May 2010 11:32:05:302] cache.ReadWriteCache: Invalidating: com.adventnet.nms.topodb.ManagedObject.children#5
[03 May 2010 11:32:05:302] cache.EhCache: key: com.adventnet.nms.topodb.ManagedObject.children#5
[03 May 2010 11:32:05:302] cache.UpdateTimestampsCache: Pre-invalidating space [ManagedObject]
[03 May 2010 11:32:05:302] cache.UpdateTimestampsCache: Pre-invalidating space [ManagedObject]
[03 May 2010 11:32:05:302] cache.ReadWriteCache: Releasing: com.adventnet.nms.topodb.ManagedObject.children#5
[03 May 2010 11:32:05:302] cache.ReadWriteCache: Releasing: com.adventnet.nms.topodb.ManagedObject.children#5
[03 May 2010 11:32:05:302] cache.EhCache: key: com.adventnet.nms.topodb.ManagedObject.children#5
[03 May 2010 11:32:05:302] cache.UpdateTimestampsCache: Invalidating space [ManagedObject], timestamp: 5213801370836997
[03 May 2010 11:32:05:302] cache.ReadWriteCache: Releasing: com.adventnet.nms.topodb.ManagedObject.children#5
[03 May 2010 11:32:05:302] cache.ReadWriteCache: Releasing: com.adventnet.nms.topodb.ManagedObject.children#5
[03 May 2010 11:32:05:302] cache.EhCache: key: com.adventnet.nms.topodb.ManagedObject.children#5
[03 May 2010 11:32:05:302] cache.UpdateTimestampsCache: Invalidating space [ManagedObject], timestamp: 5213801370836999
[03 May 2010 11:32:05:333] cache.StandardQueryCache: checking cached query results in region: org.hibernate.cache.StandardQueryCache
[03 May 2010 11:32:05:333] cache.EhCache: key: sql: /* criteria query */ select this_.MOID as MOID0_0_, this_.NAME as NAME0_0_, this_.CLASSNAME as CLASSNAME0_0_, this_.DISPLAYNAME as DISPLAYN5_0_0_, this_.FAILURECOUNT as FAILUREC6_0_0_, this_.FAILURETHRESHOLD as FAILURET7_0_0_, this_.ISCONTAINER as ISCONTAI8_0_0_, this_.ISGROUP as ISGROUP0_0_, this_.MANAGED as MANAGED0_0_, this_.PARENTKEY as PARENTKEY0_0_, this_.POLLINTERVAL as POLLINT12_0_0_, this_.STATUS as STATUS0_0_, this_.STATUSCHANGETIME as STATUSC14_0_0_, this_.STATUSPOLLENABLED as STATUSP15_0_0_, this_.STATUSUPDATETIME as STATUSU16_0_0_, this_.TESTER as TESTER0_0_, this_.TYPE as TYPE0_0_, this_.UCLASS as UCLASS0_0_, this_.WEBNMS as WEBNMS0_0_, this_.PARENTID as PARENTID0_0_, this_.DISCRIMINATOR as DISCRIMI2_0_0_ from ManagedObject this_ where (this_.NAME=?); parameters: 10.52.30.38, ; transformer: org.hibernate.transform.RootEntityResultTransformer@d2be98
[03 May 2010 11:32:05:333] cache.StandardQueryCache: returning cached query results
[03 May 2010 11:32:05:333] cache.ReadWriteCache: Cache lookup: com.adventnet.nms.topodb.ManagedObject#5
[03 May 2010 11:32:05:333] cache.ReadWriteCache: Cache lookup: com.adventnet.nms.topodb.ManagedObject#5
[03 May 2010 11:32:05:333] cache.EhCache: key: com.adventnet.nms.topodb.ManagedObject#5
[03 May 2010 11:32:05:333] cache.ReadWriteCache: Cache hit: com.adventnet.nms.topodb.ManagedObject#5
[03 May 2010 11:32:05:333] cache.ReadWriteCache: Cache hit: com.adventnet.nms.topodb.ManagedObject#5
[03 May 2010 11:32:05:333] cache.ReadWriteCache: Cache lookup: com.adventnet.nms.topodb.ManagedObject.children#5
[03 May 2010 11:32:05:333] cache.ReadWriteCache: Cache lookup: com.adventnet.nms.topodb.ManagedObject.children#5
[03 May 2010 11:32:05:333] cache.EhCache: key: com.adventnet.nms.topodb.ManagedObject.children#5

**** SHOWS LOCKED HERE SO GOES TO THE DATABASE
[03 May 2010 11:32:05:333] cache.ReadWriteCache: Cached item was locked: com.adventnet.nms.topodb.ManagedObject.children#5
[03 May 2010 11:32:05:333] cache.ReadWriteCache: Cached item was locked: com.adventnet.nms.topodb.ManagedObject.children#5
[03 May 2010 11:32:05:396] cache.ReadWriteCache: Caching: com.adventnet.nms.topodb.ManagedObject#6
[03 May 2010 11:32:05:396] cache.ReadWriteCache: Caching: com.adventnet.nms.topodb.ManagedObject#6
[03 May 2010 11:32:05:396] cache.EhCache: key: com.adventnet.nms.topodb.ManagedObject#6


Code retrieved from
http://www.javadocexamples.com/org/hibernate/cache/org.hibernate.cache.ReadWriteCache-source.html
  57:    /**
  58:     * Do not return an item whose timestamp is later than the current
  59:     * transaction timestamp. (Otherwise we might compromise repeatable
  60:     * read unnecessarily.) Do not return an item which is soft-locked.
  61:     * Always go straight to the database instead.<br>
  62:     * <br>
  63:     * Note that since reading an item from that cache does not actually
  64:     * go to the database, it is possible to see a kind of phantom read
  65:     * due to the underlying row being updated after we have read it
  66:     * from the cache. This would not be possible in a lock-based
  67:     * implementation of repeatable read isolation. It is also possible
  68:     * to overwrite changes made and committed by another transaction
  69:     * after the current transaction read the item from the cache. This
  70:     * problem would be caught by the update-time version-checking, if
  71:     * the data is versioned or timestamped.
  72:     */
  73:...       public synchronized Object get(Object key, long txTimestamp) throws CacheException {
  74:
  75:        if ( log.isTraceEnabled() ) log.trace("Cache lookup: " + key);
  76:
  77:...           try {
  78:            cache.lock(key);
  79:
  80:            Lockable lockable = (Lockable) cache.get(key);
  81:
  82:            boolean gettable = lockable!=null && lockable.isGettable(txTimestamp);
  83:
  84:...               if (gettable) {
  85:                if ( log.isTraceEnabled() ) log.trace("Cache hit: " + key);
  86:                return ( (Item) lockable ).getValue();
  87:            }
  88:...               else {
  89:...                   if ( log.isTraceEnabled() ) {
  90:...                       if (lockable==null) {
  91:                        log.trace("Cache miss: " + key);
  92:                    }
  93:...                       else {
  94:                        log.trace("Cached item was locked: " + key);
  95:                    }
  96:                }
  97:                return null;
  98:            }
  99:        }
100:...           finally {
101:            cache.unlock(key);
102:        }
103:    }

105:    /**
106:     * Stop any other transactions reading or writing this item to/from
107:     * the cache. Send them straight to the database instead. (The lock
108:     * does time out eventually.) This implementation tracks concurrent
109:     * locks of transactions which simultaneously attempt to write to an
110:     * item.
111:     */
112:...       public synchronized SoftLock lock(Object key, Object version) throws CacheException {
113:        if ( log.isTraceEnabled() ) log.trace("Invalidating: " + key);
114:
115:...           try {
116:            cache.lock(key);
117:
118:            Lockable lockable = (Lockable) cache.get(key);
119:            long timeout = cache.nextTimestamp() + cache.getTimeout();
120:            final Lock lock = (lockable==null) ?
121:                new Lock( timeout, nextLockId(), version ) :
122:                lockable.lock( timeout, nextLockId() );
123:            cache.update(key, lock);
124:            return lock;
125:        }
126:...           finally {
127:            cache.unlock(key);
128:        }
129:
130:    }


189:    /**
190:     * Release the soft lock on the item. Other transactions may now
191:     * re-cache the item (assuming that no other transaction holds a
192:     * simultaneous lock).
193:     */
194:...       public synchronized void release(Object key, SoftLock clientLock) throws CacheException {
195:        if ( log.isTraceEnabled() ) log.trace("Releasing: " + key);
196:
197:...           try {
198:            cache.lock(key);
199:
200:            Lockable lockable = (Lockable) cache.get(key);
201:...               if ( isUnlockable(clientLock, lockable) ) {
202:                decrementLock(key, (Lock) lockable);
203:            }
204:...               else {
205:                handleLockExpiry(key);
206:            }
207:        }
208:...           finally {
209:            cache.unlock(key);
210:        }
211:    }
212:
Top
 Profile  
 
Display posts from previous:  Sort by  
Forum locked This topic is locked, you cannot edit posts or make further replies.  Page 1 of 1
  [ 1 post ] 

Board index » Hibernate & Java Persistence » Hibernate Users

All times are UTC - 5 hours [ DST ]

You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum

Search for:
© Copyright 2014, Red Hat Inc. All rights reserved. JBoss and Hibernate are registered trademarks and servicemarks of Red Hat, Inc.