On Fri, 2008-07-25 at 11:42 -0700, Pinaki Poddar wrote:
> Hi,
> 1. As persistence context is TRANSACTION scoped, the context will terminate
> (by Spring or whomever) after every transaction and all managed instances
> will be detached. btw, OpenJPA does allow programmatic detach through
> extended OpenJPAEntityManager API. However, from the description, it seems
> instances are getting detached all right and as merging context is a new
> transaction-scoped context -- hence these areas are unlikely cause of the
> conflict.
>
> 2. Another angle: are you enhancing at run-time or build-time? Noticed few
> anomalies with runtime enhanced entities dirty state transitions. To narrow
> the source of error, it is advisable to enhance the entities at build-time.
>
I am enhancing at run-time. Off-topic, I also do that on the test case
for OPENJPA-571, which runs fine when I replace OpenJPA with Hibernate
JPA. Still hoping someone will look at that one.
> 3. Is it possible to switch to a long/int version field rather than
> timestamp? Again not permanently but to narrow down the cause.
>
Not easily. But I did tweak the schema to work with integral seconds
after I found out that PostgreSQL's default timestamp format is floating
point. The hard way.
> 4. If possible, post the error stack.
>
That's easily done. Look down. All I did was comment out the post-merge
re-fetch.
> 5. Are you flushing before queries?
>
No.
>
>
>
> Tim Holloway wrote:
> >
> > On Thu, 2008-07-24 at 15:18 -0400, Tim Holloway wrote:
> >
> > I've appended some additional info.
> >
> >> OK, here goes...
> >>
> >> On Thu, 2008-07-24 at 07:42 -0700, Pinaki Poddar wrote:
> >> > Hi,
> >> > > Unfortunately, that's rather murky in this context.
> >> > Sounds like it.
> >> >
> >> > But let us try to clear the murkiness. Answer to following questions
> >> might.
> >> >
> >> > 1. Let X be an instance managed in persistence context C1 in
> >> transaction T1
> >> > when X is detached.
> >> >
> >> > 2. what action triggered detachment of X?
> >> > Commit of T1?
> >> > Close of C1?
> >> > Clearing of C1?
> >> > Explicit programmatic detach?
> >> >
> >>
> >> Here's my understanding, occasionally muddled from exposure to similar
> >> platforms such as JDO:
> >>
> >> A. I didn't think that committing was supposed to be able to cause a
> >> detach
> >> B. Probably this, but
> >> C. Maybe this
> >> D. JDO2 supports explicit detach, but if JPA does, it's not obvious to
> >> me.
> >>
> >> The service class uses the following mechanism for injection of the
> >> EntityManager:
> >>
> >>
> >> @PersistenceContext
> >> public void setEntityManager(EntityManager entityManager) {
> >> this.entityManager = entityManager;
> >> }
> >>
> >> The service class methods only do queries, merge() and persist(). Any
> >> other operation is coming from Spring or some other external non-visible
> >> binding.
> >>
> >> > 3. was X dirty or clean when it was detached from C1?
> >> >
> >>
> >> In all cases, X should have been clean.
> >>
> >> > 4. is that detach trigger controlled explicitly by your application or
> >> is it
> >> > happening implicitly by the other management artifacts of the
> >> environment?
> >> > For example, X is getting detached because Spring is closing the
> >> > persistence context C1.
> >> >
> >>
> >> There is no explicit detachment here. As mentioned, anything above the
> >> CRUD primitives is coming from outside.
> >>
> >> > 5. There is no "hanging transaction". X gets modified out of any
> >> persistence
> >> > context, and then X is merged to persistence context C2.
> >> > C2 is definitely not the same as C1. Is that true?
> >> > Or is it that X gets merged to C1 but now C1 is running a
> >> different
> >> > transaction T2?
> >> >
> >>
> >> I haven't verified about the overall contexts, but I'm virtually certain
> >> that the service manager is application-scoped and the entityManager is
> >> injected once and only once in the life of the application.
> >>
> >> Yes, these are 2 separate transactions, coming from 2 separate HTTP
> >> requests. I have no actual need to detach at all, since these are all in
> >> the same JVM, although it would not be a good idea in case the
> >> HttpSession was serialized (e.g. load balance or cluster operations).
> >> And, in fact, I am not doing anything explicit to cause detachment,
> >> short of perhaps not fine-tuning framework options.
> >>
> >> > The document I referred addressed a different use case where
> >> modified X
> >> > gets merged to original (C1,T1).
> >> >
> >> > 6. Does class of X has a version field?
> >> >
> >>
> >> It does now. It didn't make any difference, however.
> >>
> >> > 7. > The problem is, if that object - or the object returned from the
> >> merge
> >> > -is then later merged again,
> >> > > an OptimisticLockingException results and the reasons aren't obvious.
> >> > Yes it is not obvious -- because repeated chain of detach and merge
> >> to a
> >> > series of different contexts is a supported use case.
> >> >
> >> > 8. What is the scope of persistence context -- TRANSACTION or EXTENDED?
> >> >
> >>
> >> TRANSACTION
> >> >
> >> >
> >>
> >> What I find most vexing is that if I work with the object returned from
> >> the merge(), I get the lock violation, but if I insert a
> >> "findByPrimaryKey" query right after that, the object I get from the
> >> query works just fine. By my understanding, the two objects should be in
> >> an identical state, but in practice, the return from the merge has its
> >> internal dirty field bits still set, but the results from the query do
> >> not. Worse, I *think* the return from the query is not merely an
> >> otherwise equivalent object - it's the exact same object. I think I'm
> >> going to go back and verify that.
> >
> > I can't find it in an FM yet, but the default operation of the Spring
> > transaction framework is to detach at the end of the transaction
> > according to several informal sources. This makes it consistent with
> > Hibernate and ensures that the objects are POJOS and need no DTOs. My
> > debugger verifies that at all times in my business layer the objects are
> > in fact detached.
> >
> > For those who prefer lazy-loading, there's a filter to prevent this, but
> > I didn't design the app to lazy-load anyway.
> >
> > I was wrong - the results of the find query are NOT the identical object
> > as what came back from the merge. However, I'm at a loss as to why the
> > merge isn't resetting the dirty flags and why the output from the merge
> > is considered as older than the persistent data.
> >
> > This is the versioning definition:
> >
> > @Basic
> > @Column(name="change_time", nullable=false)
> > @Version
> > private Timestamp changeTime;
> >
> > The merge returns an updated changeTime. The query returns the same
> > changeTime. Only the "dirty flags" distinguish them.
> >
> >
Failure log:
16:33:44,434 DEBUG openjpa.jdbc.SQL:72 - <t 16757535, conn 27534602> executing
prepstmnt 7525605 SELECT t0.change_time, t0.description, t0.
inbound, t0.street1_block, t1.street_direction_id, t1.description,
t2.street_type_id, t2.description, t0.street2_block, t3.street_direction
_id, t3.description, t4.street_type_id, t4.description FROM
public.bus_stops t0 LEFT OUTER JOIN public.lk_street_directions t1 ON
t0.street
1_direction = t1.street_direction_id LEFT OUTER JOIN
public.lk_street_types t2 ON t0.street1_type = t2.street_type_id LEFT
OUTER JOIN publi
c.lk_street_directions t3 ON t0.street2_direction =
t3.street_direction_id LEFT OUTER JOIN public.lk_street_types t4 ON
t0.street2_type = t
4.street_type_id WHERE t0.stop_id = ? [params=(int) 4]
16:33:44,443 DEBUG openjpa.jdbc.SQL:72 - <t 16757535, conn 27534602> [8
ms] spent
16:33:44,447 DEBUG openjpa.jdbc.JDBC:72 - <t 16757535, conn 0> [0 ms]
close
16:33:44,450 DEBUG openjpa.jdbc.JDBC:72 - The batch limit is set to 0.
16:33:44,455 DEBUG openjpa.jdbc.SQL:72 - <t 16757535, conn 27534602>
executing prepstmnt 32638273 UPDATE public.bus_stops SET description =
?, inbound = ?, change_time = ? WHERE stop_id = ? AND change_time = ?
[params=(String) Citi Center Transfer Junction, (boolean) true, (Tim
estamp) 2008-07-25 16:33:44.45, (int) 4, (Timestamp) 2008-07-25
16:32:50.36]
16:33:44,466 DEBUG openjpa.jdbc.SQL:72 - <t 16757535, conn 27534602> [2
ms] spent
16:33:44,497 DEBUG openjpa.Runtime:76 - An exception occurred while
ending the transaction. This exception will be re-thrown.
<openjpa-1.2.0-SNAPSHOT-rexported nonfatal store error>
org.apache.openjpa.util.OptimisticException: Optimistic locking errors
were detecte
d when flushing to the data store. The following objects may have been
concurrently modified in another transaction: [com.mousetech.jta.pe
rsist.BusStops-4]
at
org.apache.openjpa.kernel.BrokerImpl.newFlushException(BrokerImpl.java:2160)
at
org.apache.openjpa.kernel.BrokerImpl.flush(BrokerImpl.java:2010)
at
org.apache.openjpa.kernel.BrokerImpl.flushSafe(BrokerImpl.java:1908)
at
org.apache.openjpa.kernel.BrokerImpl.beforeCompletion(BrokerImpl.java:1826)
at
org.apache.openjpa.kernel.LocalManagedRuntime.commit(LocalManagedRuntime.java:81)
at
org.apache.openjpa.kernel.BrokerImpl.commit(BrokerImpl.java:1350)
at
org.apache.openjpa.kernel.DelegatingBroker.commit(DelegatingBroker.java:877)
at
org.apache.openjpa.persistence.EntityManagerImpl.commit(EntityManagerImpl.java:512)
at
org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:433)
at
org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java
:662)
at
org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:632)
at
org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.ja
va:314)
at
org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:117)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:166)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at $Proxy22.update(Unknown Source)
at
com.mousetech.jta.backing.BusStopsBackingBean.doCommitAction(BusStopsBackingBean.java:275)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.apache.el.parser.AstValue.invoke(AstValue.java:152)
at
org.apache.el.MethodExpressionImpl.invoke(MethodExpressionImpl.java:276)
at
com.sun.facelets.el.TagMethodExpression.invoke(TagMethodExpression.java:68)
at
javax.faces.component._MethodExpressionToMethodBinding.invoke(_MethodExpressionToMethodBinding.java:75)
at
org.apache.myfaces.application.ActionListenerImpl.processAction(ActionListenerImpl.java:54)
at javax.faces.component.UICommand.broadcast(UICommand.java:121)
> >
>