Issue Details (XML | Word | Printable)

Key: NUCCORE-557
Type: Bug Bug
Status: Closed Closed
Resolution: Fixed
Priority: Major Major
Assignee: Andy Jefferson
Reporter: Yang ZHONG
Votes: 0
Watchers: 0
Operations

If you were logged in you would be able to see more operations.
DataNucleus Core

Deadlock when reading/writing fields of object and performing PM level operation

Created: 30/Aug/10 11:19 PM   Updated: 20/Oct/10 09:29 AM   Resolved: 05/Oct/10 03:02 PM
Component/s: Persistence
Affects Version/s: 2.0.4
Fix Version/s: 2.2.0.m2

Environment: Java 5, Linux

Severity: Production


 Description  « Hide
3XMTHREADINFO "RMI TCP Connection(59895)-9.42.25.49" (TID:0x1CDCBE00, sys_thread_t:0x49E75578, state:B, native ID:0x00003E58) prio=5
4XESTACKTRACE at org/datanucleus/store/rdbms/query/PersistentClassROF.getObjectForApplicationId(PersistentClassROF.java:449(Compiled Code))
4XESTACKTRACE at org/datanucleus/store/rdbms/query/PersistentClassROF.getObject(PersistentClassROF.java:347(Compiled Code))
4XESTACKTRACE at org/datanucleus/store/rdbms/fieldmanager/ResultSetGetter.fetchObjectField(ResultSetGetter.java:144(Compiled Code))
4XESTACKTRACE at org/datanucleus/state/AbstractStateManager.replacingObjectField(AbstractStateManager.java:1191(Compiled Code))
4XESTACKTRACE at ...Jdo.jdoReplaceField(...Jdo.java(Compiled Code))
4XESTACKTRACE at ...Jdo.jdoReplaceFields(...Jdo.java(Compiled Code))
4XESTACKTRACE at org/datanucleus/jdo/state/JDOStateManagerImpl.replaceFields(JDOStateManagerImpl.java:2860(Compiled Code))
4XESTACKTRACE at org/datanucleus/jdo/state/JDOStateManagerImpl.replaceFields(JDOStateManagerImpl.java:2879(Compiled Code))
4XESTACKTRACE at org/datanucleus/store/rdbms/request/FetchRequest.execute(FetchRequest.java:335(Compiled Code))
4XESTACKTRACE at org/datanucleus/store/rdbms/RDBMSPersistenceHandler.fetchObject(RDBMSPersistenceHandler.java:240(Compiled Code))
4XESTACKTRACE at org/datanucleus/jdo/state/JDOStateManagerImpl.loadFieldsFromDatastore(JDOStateManagerImpl.java:1929(Compiled Code))
4XESTACKTRACE at org/datanucleus/jdo/state/JDOStateManagerImpl.loadSpecifiedFields(JDOStateManagerImpl.java:1556(Compiled Code))
4XESTACKTRACE at org/datanucleus/jdo/state/JDOStateManagerImpl.isLoaded(JDOStateManagerImpl.java:2013(Compiled Code))

3XMTHREADINFO "RMI TCP Connection(61568)-9.42.25.49" (TID:0x0AC82600, sys_thread_t:0x43B9B9F8, state:B, native ID:0x00004BF4) prio=5
4XESTACKTRACE at org/datanucleus/jdo/state/JDOStateManagerImpl.replaceFields(JDOStateManagerImpl.java:2822(Compiled Code))
4XESTACKTRACE at org/datanucleus/jdo/state/JDOStateManagerImpl.replaceFields(JDOStateManagerImpl.java:2879(Compiled Code))
4XESTACKTRACE at org/datanucleus/jdo/state/JDOStateManagerImpl.clearFieldsByNumbers(JDOStateManagerImpl.java:1135(Compiled Code))
4XESTACKTRACE at org/datanucleus/jdo/state/JDOStateManagerImpl.clearNonPrimaryKeyFields(JDOStateManagerImpl.java:1118(Compiled Code))
4XESTACKTRACE at org/datanucleus/jdo/state/PersistentClean.transitionCommit(PersistentClean.java:100)
4XESTACKTRACE at org/datanucleus/state/AbstractStateManager.postCommit(AbstractStateManager.java:602(Compiled Code))
4XESTACKTRACE at org/datanucleus/ObjectManagerImpl.postCommit(ObjectManagerImpl.java:3677(Compiled Code))
4XESTACKTRACE at org/datanucleus/TransactionImpl.internalPostCommit(TransactionImpl.java:554(Compiled Code))
4XESTACKTRACE at org/datanucleus/TransactionImpl.commit(TransactionImpl.java:325(Compiled Code))
4XESTACKTRACE at org/datanucleus/jdo/JDOTransaction.commit(JDOTransaction.java:83(Compiled Code))

2LKDEADLOCKTHR Thread "RMI TCP Connection(61568)-9.42.25.49" (0x0AC82600)
3LKDEADLOCKWTR is waiting for:
4LKDEADLOCKMON sys_mon_t:0x32D634B0 infl_mon_t: 0x32D634F0:
4LKDEADLOCKOBJ java/lang/Object@6BA58228/6BA58234:
3LKDEADLOCKOWN which is owned by:
2LKDEADLOCKTHR Thread "RMI TCP Connection(59895)-9.42.25.49" (0x1CDCBE00)
3LKDEADLOCKWTR which is waiting for:
4LKDEADLOCKMON sys_mon_t:0x4396EE70 infl_mon_t: 0x4396EEB0:
4LKDEADLOCKOBJ org/datanucleus/ObjectManagerImpl@6B4ED648/6B4ED654:
3LKDEADLOCKOWN which is owned by:
2LKDEADLOCKTHR Thread "RMI TCP Connection(61568)-9.42.25.49" (0x0AC82600)


Thread "RMI TCP Connection(59895)-9.42.25.49" was owning AbstractStateManager#currFMmonitor during JDOStateManagerImpl.replaceFields
and asking for ObjectManagerImpl.
Thread "RMI TCP Connection(61568)-9.42.25.49" was owning ObjectManagerImpl during ObjectManagerImpl#postCommit
and asking for AbstractStateManager#currFMmonitor.

The race condition is too hard to be reproduced by just a simple Test Case...

1 of fixes may be replacing all "synchronized(currFMmonitor)" w/ "synchronized(myOM){synchronized(currFMmonitor)...}" even simply "synchronized(myOM)" within JDOStateManagerImpl.java

Sort Order: Ascending order - Click to sort in descending order
[ Permalink | « Hide ]
Yang ZHONG added a comment - 30/Aug/10 11:29 PM
The proposed fix(es) may also be able to fix this:


1LKDEADLOCK Deadlock detected !!!
NULL ---------------------
NULL
2LKDEADLOCKTHR Thread "RMI TCP Connection(169)-10.208.253.72" (0x76EDEF00)
3LKDEADLOCKWTR is waiting for:
4LKDEADLOCKMON sys_mon_t:0x760A9F18 infl_mon_t: 0x760A9F58:
4LKDEADLOCKOBJ org/datanucleus/ObjectManagerImpl@855A5570/855A557C:
3LKDEADLOCKOWN which is owned by:
2LKDEADLOCKTHR Thread "RMI TCP Connection(227)-10.208.253.72" (0x757F7E00)
3LKDEADLOCKWTR which is waiting for:
4LKDEADLOCKMON sys_mon_t:0x08A5A338 infl_mon_t: 0x08A5A378:
4LKDEADLOCKOBJ java/lang/Object@859BCF88/859BCF94:
3LKDEADLOCKOWN which is owned by:
2LKDEADLOCKTHR Thread "RMI TCP Connection(169)-10.208.253.72" (0x76EDEF00)

---

3XMTHREADINFO "RMI TCP Connection(169)-10.208.253.72" (TID:0x76EDEF00, sys_thread_t:0x08A0F9A8, state:B, native ID:0x000006CD) prio=5
4XESTACKTRACE at org/datanucleus/store/rdbms/query/PersistentClassROF.getObjectForApplicationId(PersistentClassROF.java:449(Compiled Code))
4XESTACKTRACE at org/datanucleus/store/rdbms/query/PersistentClassROF.getObject(PersistentClassROF.java:347(Compiled Code))
4XESTACKTRACE at org/datanucleus/store/rdbms/fieldmanager/ResultSetGetter.fetchObjectField(ResultSetGetter.java:144(Compiled Code))
4XESTACKTRACE at org/datanucleus/state/AbstractStateManager.replacingObjectField(AbstractStateManager.java:1191(Compiled Code))
4XESTACKTRACE at ...Jdo.jdoReplaceField(...Jdo.java(Compiled Code))
4XESTACKTRACE at ...Jdo.jdoReplaceField(...Jdo.java(Compiled Code))
4XESTACKTRACE at ...Jdo.jdoReplaceFields(...Jdo.java(Compiled Code))
4XESTACKTRACE at org/datanucleus/jdo/state/JDOStateManagerImpl.replaceFields(JDOStateManagerImpl.java:2860(Compiled Code))
4XESTACKTRACE at org/datanucleus/jdo/state/JDOStateManagerImpl.replaceFields(JDOStateManagerImpl.java:2879(Compiled Code))
4XESTACKTRACE at org/datanucleus/store/rdbms/request/FetchRequest.execute(FetchRequest.java:335(Compiled Code))
4XESTACKTRACE at org/datanucleus/store/rdbms/RDBMSPersistenceHandler.fetchObject(RDBMSPersistenceHandler.java:240(Compiled Code))
4XESTACKTRACE at org/datanucleus/jdo/state/JDOStateManagerImpl.loadFieldsFromDatastore(JDOStateManagerImpl.java:1929(Compiled Code))
4XESTACKTRACE at org/datanucleus/jdo/state/JDOStateManagerImpl.loadSpecifiedFields(JDOStateManagerImpl.java:1556(Compiled Code))
4XESTACKTRACE at org/datanucleus/jdo/state/JDOStateManagerImpl.isLoaded(JDOStateManagerImpl.java:2013(Compiled Code))
4XESTACKTRACE ...

---

3XMTHREADINFO "RMI TCP Connection(227)-10.208.253.72" (TID:0x757F7E00, sys_thread_t:0x08454C88, state:B, native ID:0x000038C0) prio=5
4XESTACKTRACE at org/datanucleus/jdo/state/JDOStateManagerImpl.replaceFields(JDOStateManagerImpl.java:2822(Compiled Code))
4XESTACKTRACE at org/datanucleus/jdo/state/JDOStateManagerImpl.replaceFields(JDOStateManagerImpl.java:2879(Compiled Code))
4XESTACKTRACE at org/datanucleus/jdo/state/JDOStateManagerImpl.clearFieldsByNumbers(JDOStateManagerImpl.java:1135(Compiled Code))
4XESTACKTRACE at org/datanucleus/jdo/state/JDOStateManagerImpl.clearNonPrimaryKeyFields(JDOStateManagerImpl.java:1118(Compiled Code))
4XESTACKTRACE at org/datanucleus/jdo/state/PersistentNontransactional.transitionEvict(PersistentNontransactional.java:133(Compiled Code))
4XESTACKTRACE at org/datanucleus/state/AbstractStateManager.evict(AbstractStateManager.java:436(Compiled Code))
4XESTACKTRACE at org/datanucleus/ObjectManagerImpl.evictAllObjects(ObjectManagerImpl.java:1015(Compiled Code))
4XESTACKTRACE at org/datanucleus/jdo/JDOPersistenceManager.evictAll(JDOPersistenceManager.java:409)

[ Permalink | « Hide ]
Yang ZHONG added a comment - 30/Aug/10 11:37 PM
An alternative fix may be making AbstractStateManager#currFMmonitor public or JDOStateManagerImpl synchronizing on "this" instead of "currFMmonitor", then for both ObjectManagerImpl#evictAllObjects & ObjectManagerImpl#postCommit to synchronize on AbstractStateManager#currFMmonitor or StateManager instead.

However, there're many other synchronized ObjectManagerImpl methods not explicitly/directly accessing StateManager, not sure if any of them end(s) up w/ accessing any StateManager implicitly/indirectly...

[ Permalink | « Hide ]
Erik Bengtson added a comment - 12/Sep/10 10:44 AM
on commit, there should not have any other threads reading objects.

We probably need to define a new monitor to ensure that while you read/write, you cannot commit/rollback, and vice versa.


[ Permalink | « Hide ]
Andy Jefferson added a comment - 05/Oct/10 03:02 PM
Added readWrite lock to ObjectManager (locked during pre/post commit/rollback and some other operations). OM.readWriteLock also added to sync in StateManager so any such operations shouldn't get in each others way. Left as an exercise for users to actually test it since none of these cases are reproduceable

Atlassian JIRA (v4.0#466) | Report a problem | Request a feature | Contact administrators
Powered by a free Atlassian JIRA open source license for JPOX Java Persistent Objects. Try JIRA - bug tracking software for your team.