3:53 p.m.
Test for this is
org.jboss.cache.integration.hibernate.UpdateTimestampsCachingTest.testTimestampUpdateInAfterCompletionOptimistic()
Brian Stansberry wrote:
Thanks. :) Good news, bad news.
Good news is the JBCACHE-1170 problem seems to be gone!
Bad news is a problem that seems to come from the JBCACHE-1309 fix.
Hibernate 2nd Level Cache, OPTIMISTIC locking.
Here's what happens:
Hibernate registers a tx Synchronization. So does JBC. But Hibernate's
executes before JBC's. So any beforeCompletion()/afterCompletion() will
be invoked by Hibernate before the same is done for JBC. So,
1) Say a tx updates an entity, resulting in a put: to Fqn
cache.put("/test/Accounts/ENTITY/id@1", ITEM, value);
2) Tx goes into commit. beforeCompletion() gets called on on Hibernate
and JBC synchronizations. JBC.beforeCompletion() acquires locks on the
main tree.
3) Hibernate.afterCompletion() gets called. JBC.afterCompletion() not
yet called, so locks are held on main cache. Hibernate uses the callback
to update the timestamps caches, which will invalidate any queries using
entity types affected by the tx. Logic boils down to this pseudo-code:
// Suspend any ongoing tx
Transaction tx = tm.suspend();
// Timestamp updates must go async
cache.getInvocationContext().getOptionOverrides().setForceAsynchronous(true);
cache.put("/TS/test/org/hibernate/cache/UpdateTimestampsCache/Accounts",
ITEM, value);
tm.resume(tx);
Note there is no overlap in Fqn between the two puts. The call with the
transaction suspended is not trying to write to the same subtree as the
uncommitted tx.
The put is failing with a lock acquisition timeout:
org.jboss.cache.lock.TimeoutException: write lock for / could not be
acquired after 15000 ms. Locks: Read lock owners:
[GlobalTransaction:<127.0.0.1:43985>:72]
Write lock owner: null
(caller=GlobalTransaction:<127.0.0.1:43985>:74, lock info: read
owners=[GlobalTransaction:<127.0.0.1:43985>:72] (activeReaders=1,
activeWriter=null, waitingReaders=0, waitingWriters=0, waitingUpgrader=0))
at
org.jboss.cache.lock.IdentityLock.acquireWriteLock0(IdentityLock.java:249)
at
org.jboss.cache.lock.IdentityLock.acquireWriteLock(IdentityLock.java:172)
at
org.jboss.cache.interceptors.OptimisticInterceptor.lockAndCreateWorkspaceNode(OptimisticInterceptor.java:112)
at
org.jboss.cache.interceptors.OptimisticNodeInterceptor.fetchWorkspaceNode(OptimisticNodeInterceptor.java:542)
at
org.jboss.cache.interceptors.OptimisticNodeInterceptor.fetchWorkspaceNode(OptimisticNodeInterceptor.java:571)
at
org.jboss.cache.interceptors.OptimisticNodeInterceptor.fetchWorkspaceNode(OptimisticNodeInterceptor.java:571)
at
org.jboss.cache.interceptors.OptimisticNodeInterceptor.fetchWorkspaceNode(OptimisticNodeInterceptor.java:571)
at
org.jboss.cache.interceptors.OptimisticNodeInterceptor.fetchWorkspaceNode(OptimisticNodeInterceptor.java:571)
at
org.jboss.cache.interceptors.OptimisticNodeInterceptor.fetchWorkspaceNode(OptimisticNodeInterceptor.java:571)
at
org.jboss.cache.interceptors.OptimisticNodeInterceptor.fetchWorkspaceNode(OptimisticNodeInterceptor.java:571)
at
org.jboss.cache.interceptors.OptimisticNodeInterceptor.fetchWorkspaceNode(OptimisticNodeInterceptor.java:571)
at
org.jboss.cache.interceptors.OptimisticNodeInterceptor.invoke(OptimisticNodeInterceptor.java:81)
at
......
org.jboss.cache.invocation.CacheInvocationDelegate.put(CacheInvocationDelegate.java:488)
What's going on here is fetchWorkspaceNode() is walking up the tree from
/TS/test/org/hibernate/cache/UpdateTimestampsCache/Accounts to Fqn.ROOT,
calling lockAndCreateWorkspaceNode() on each Fqn. When it gets to
Fqn.ROOT it fails. This is because lockAndCreateWorkspaceNode() wants a
write lock on the target node before making the workspace copy. In this
case the WL can't be obtained, because a RL is held by the suspended tx.
Does lockAndCreateWorkspaceNode() need a write lock here?
I'll add a unit test for this; seems like a good candidate for the start
of the integration tests I'd talked about. This one is for sure a weird
usage; hard to imagine a regular JBC test exercising this call pattern.
- Brian
Manik Surtani wrote:
> Guys, this is now done.
>
> It is pretty much a snapshot of trunk as of today, with Elias' Amazon
> S3 cache loader stuff removed (don't want to introduce this in a micro
> version - it will be there in 2.2.0).
>
> Brian, I have even built a snapshot on the JBoss snapshot Maven repo,
> so please give it a whirl and see if issues like JBCACHE-1170 have
> successfully been taken care of.
>
> Cheers,
> --
> Manik Surtani
> Lead, JBoss Cache
> manik(a)jboss.org
>
>
>
>
>
>
> _______________________________________________
> jbosscache-dev mailing list
> jbosscache-dev(a)lists.jboss.org
> https://lists.jboss.org/mailman/listinfo/jbosscache-dev
--
Brian Stansberry
Lead, AS Clustering
JBoss, a division of Red Hat
brian.stansberry(a)redhat.com