openjpa-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Donald Woods <dwo...@apache.org>
Subject Re: OpenJpa, and DB2 shared lock
Date Mon, 27 Apr 2009 15:39:51 GMT
Hi Chandra, can you provide more details on the Spring side of your app, 
like what version of Spring you're using and what if any annotations are 
being used, like the @Transactional for Spring or JPA annotations?

Are you solely using annotations or do you have a persistence.xml and/or 
orm.xml you can post?


-Donald


Kevin Sutter wrote:
> Hi Chandra,
> Interesting data.  First thing I noticed is that all of that exception trace
> data happens for the same deadlock/timeout exception.  There is no retry
> logic that I can see.  The exception is first reported at 12:27:54:977 and
> the last log messages for this exception (before you break out) is logged at
> 12:27:55:400.  Then, it looks like the messages kick in again after you
> force the exit at 12:32:56:103.  So, there's about 5 minutes of nothing from
> an OpenJPA trace viewpoint.
> 
> During those 5 minutes, are you seeing activity with the database itself?
> Do you continue to see the SQL Updates being fired to the database?  From an
> OpenJPA perspective, we should either see "success" statements being logged
> or the SQL exception data.
> 
> A few things come to mind to narrow down the code path...
> 
> o  First off, have you tried the latest 1.2.x version of OpenJPA?  We
> recently released version 1.2.1.  There have been some updates related to
> the next items in my list that may come into play here.
> 
> o  One area that be affecting you is the Statement Batching support.  As a
> test, could you try turning off Statement Batching to see if that changes
> your scenario at all?  You can do this by setting the following property...
> 
> <property name="openjpa.jdbc.DBDictionary" value="batchLimit=0"/>
> 
> o  This next item is a longer shot, but a couple of "unexplained exception
> paths" were traced back to our Query SQL Cache.  You can try turning off
> this support via this property.  (I am not seeing anything in the trace that
> would indicate that this is related, but if you can remove this thread of
> doubt, that would be great.)
> 
> <property name="openjpa.jdbc.QuerySQLCache" value="false"/>
> 
> Based on your provided data, I again re-visited our code and can't find
> where we are doing the retry logic.  But, maybe the experimentation
> suggested above will highlight the spot.  Looking through your trace, there
> is also some interesting interaction between your app and Spring.  In area
> of "savepointing"...
> 
> 	at org.apache.openjpa.persistence.EntityManagerImpl.flush(EntityManagerImpl.java:592)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:64)
> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> 	at java.lang.reflect.Method.invoke(Method.java:615)
> 	at org.springframework.orm.jpa.SharedEntityManagerCreator$SharedEntityManagerInvocationHandler.invoke(SharedEntityManagerCreator.java:194)
> 	at $Proxy2.flush(Unknown Source)
> 	at us.or.state.dhs.framework.dao.jpa.application.JpaApplicationHelper.saveApplicationData(JpaApplicationHelper.java:103)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:64)
> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> 	at java.lang.reflect.Method.invoke(Method.java:615)
> 	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:310)
> 	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
> 	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
> 	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:106)
> 	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
> 	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
> 	at $Proxy53.saveApplicationData(Unknown Source)
> 	at us.or.state.dhs.framework.dao.jpa.application.JpaApplicationDataDao.saveApplicationData(JpaApplicationDataDao.java:25)
> 
> A combination of your app and Spring seem to be deciding that a flush is
> necessary.  But, because I don't see the retry logic happening in this
> trace, I can't tell if this is the source of the retry or not.  Or, maybe
> since there's no trace data for 5 minutes, maybe it's just deadlocked and
> there is no retry logic.
> 
> Let us know what you find out.  Thanks for your patience while we attempt to
> figure out the source of the problem.
> 
> Kevin
> 
> On Fri, Apr 24, 2009 at 8:59 PM, Chandra Sarath <cthella@yahoo.com> wrote:
> 
>> Hi Kevin,
>>
>> We have saved trace in a file and attached here. Please take a look at them
>> and let me know if you find any information about why updates are not timed
>> out. Please note that we we have forced it exit, the updates did not time
>> out on their own.
>>
>> We are using DB2  LUW 9.1 fixpack 4  as our database with Websphere 6.1
>> with
>> EJB3 Fep and OpenJpa 1.2.0. We use a non xa driver
>> (db.driverClassName=com.ibm.db2.jcc.DB2Driver) used by a Datasource created
>> in Websphere.
>> http://n2.nabble.com/file/n2701139/trace_Update_lock_testing.log
>> trace_Update_lock_testing.log .
>>
>> Thanks,
>> Chandra
>>
>>
>>
>> Kevin Sutter wrote:
>>> Hi Chandra,
>>> Do you have the complete trace in a file that you could attach to this
>>> exchange?  Or, post on filebin or something?  Thanks!
>>>
>>> Kevin
>>>
>>> On Fri, Apr 24, 2009 at 3:34 AM, Chandra Sarath <cthella@yahoo.com>
>> wrote:
>>>> Hi,
>>>>
>>>> We have turned on TRACE and we can only see update Sqls for the table
>>>> that
>>>> is locked.
>>>>
>>>>
>>>>                                        <prop
>>>> key="openjpa.Log">DefaultLevel=TRACE, Runtime=TRACE, Tool=TRACE,
>>>> SQL=TRACE</prop>
>>>>                                         <prop key="show_sql">true</prop>
>>>>
>>>> Here is how we tested.
>>>>
>>>>      1. We have locked a child table with shared lock (Read only table)
>>>> and
>>>> ran an update from parent table class.
>>>>         entityManger.merge(parentClass).
>>>>
>>>>       We saw an update sql in TRACE that is trying to update the Locked
>>>> table (say table emp). Since this table is locked, database timed out at
>>>> 30
>>>> sec (timeout property in datasource), but Jpa tried to execute update
>> sql
>>>> again. It tried to update 2 times and timed out and showed the 40001
>> (Db2
>>>> -911) error. for stacktracesee below.
>>>>
>>>>    2. We tried to merge again one more time and it tried to update the
>>>> locked table for 4 times and timeout with the above error.
>>>>
>>>>    3. We tried to merge one more time, and this time it tried to update
>>>> the
>>>> locked table for more than 15 times and continued trying the same until
>>>> we
>>>> disconnected the database manually.
>>>>
>>>> So this is a inconsistent behavior of OpenJPA and is it a bug? We wonder
>>>> why
>>>> it is trying unlimited times to update a locked (read only) table. But
>>>> for
>>>> inserts it times out properly and shows the proper error. I do not knwo
>>>> why
>>>> it is behaving differently for updates.
>>>>
>>>> Please advice any Jpa timeout parameters that I can use for the readonly
>>>> locks.
>>>>
>>>> It is a top priority issue now. Any help on this is greatly appreciated.
>>>> Please find the stacktrace below..
>>>>
>>>> [4/23/09 13:35:27:501 PDT] 00000040 SystemErr     Caused by:
>>>> org.apache.openjpa.lib.jdbc.ReportingSQLException: The
>>>>  current transaction has been rolled back because of a deadlock or
>>>> timeout.
>>>> Reason code "68". {prepstmnt 1684038752
>>>> UPDATE SCHEMA.TABLE SET REC_UPD_TS = ?, AVERAGE_MONTH_INCOME = ?,
>>>> TEST_CODE
>>>> = ?,TEST_PERIOD_CODE = ? WHERE ID = ?
>>>> [params=(Timestamp) 2009-04-23 13:25:25.365, (long) 888, (String) H,
>>>> (String) W, (long) 71383]} [co
>>>> de=-911, state=40001]
>>>>        at
>>>>
>>>>
>> org.apache.openjpa.lib.jdbc.LoggingConnectionDecorator.wrap(LoggingConnectionDecorator.java:192)
>>>>        at
>>>>
>>>>
>> org.apache.openjpa.lib.jdbc.LoggingConnectionDecorator.access$700(LoggingConnectionDecorator.java:57)
>>>>        at
>>>>
>>>>
>> org.apache.openjpa.lib.jdbc.LoggingConnectionDecorator$LoggingConnection$LoggingPreparedStatement.executeU
>>>> pdate(LoggingConnectionDecorator.java:866)
>>>>        at
>>>>
>>>>
>> org.apache.openjpa.lib.jdbc.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:269
>>>> )
>>>>      at
>>>>
>>>>
>> org.apache.openjpa.jdbc.kernel.JDBCStoreManager$CancelPreparedStatement.executeUpdate(JDBCStoreManager.jav
>>>> a:1504)
>>>>        at
>>>>
>>>>
>> org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.executeUpdate(PreparedStatementManagerImpl.jav
>>>> a:151)
>>>>        at
>>>>
>>>>
>> org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.flushAndUpdate(PreparedStatementManagerImpl.ja
>>>> va:120)
>>>>        at
>>>>
>>>>
>> org.apache.openjpa.jdbc.kernel.BatchingPreparedStatementManagerImpl.batchOrExecuteRow(BatchingPreparedStat
>>>> ementManagerImpl.java:102)
>>>>        at
>>>>
>>>>
>> org.apache.openjpa.jdbc.kernel.BatchingPreparedStatementManagerImpl.flushAndUpdate(BatchingPreparedStateme
>>>> ntManagerImpl.java:86)
>>>>        at
>>>>
>>>>
>> org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.flushInternal(PreparedStatementManagerImpl.jav
>>>>
>>>>
>>>> Thanks,
>>>> Chandra
>>>>
>>>>
>>>>
>>>>
>>>> Chandra Sarath wrote:
>>>>> Hi,
>>>>>
>>>>> We use OpenJpa, DB2 and Websphere 6.1. We have created a Datasource in
>>>>> Websphere console that connects DB2 using a non-xa driver.
>>>>>
>>>>> We were testing our application about how it rolls back the data when
>>>>> there is a shared lock in a table. we have following scenarios. We
>> have
>>>>> also set a Timeout of 30 seconds in Datasource/connection properties.
>>>>>
>>>>>   1. Insert a record in a read only (Shared lock).
>>>>>   2. Update a record in read only table (Shared lock).
>>>>>
>>>>>   For Scenario 1, after 30 seconds application times out and gives us
>>>>> proper error. But for scenario 2, it goes in infinite
>>>>>   loop and tries to update Database for every 30 secs, and it never
>>>> stops
>>>>> trying to.
>>>>>
>>>>>   Is there any extra property that we need to set in Jpa level or
>>>>> Datasource level so application can timeout after 30 seconds?
>>>>>
>>>>>   we use entityManager.persist() for inserts and entityManager.merge()
>>>> for
>>>>> updates. Can someone help us on this?
>>>>>
>>>>> Thank you!
>>>>> Chandra
>>>>>
>>>> --
>>>> View this message in context:
>>>>
>> http://n2.nabble.com/OpenJpa%2C-and-DB2-shared-lock-tp2675084p2691242.html
>>>> Sent from the OpenJPA Users mailing list archive at Nabble.com.
>>>>
>>>>
>>>
>> http://n2.nabble.com/file/n2701139/trace_Update_lock_testing.log
>> trace_Update_lock_testing.log
>> --
>> View this message in context:
>> http://n2.nabble.com/OpenJpa%2C-and-DB2-shared-lock-tp2675084p2701139.html
>> Sent from the OpenJPA Users mailing list archive at Nabble.com.
>>
>>
> 

Mime
View raw message