Home » Modeling » EMF » [CDO] Locking in CDO 3 and 4
| [CDO] Locking in CDO 3 and 4 [message #663312] |
Mon, 04 April 2011 15:07  |
 Sebastian Paul
Messages: 106
Registered: July 2009 |
Senior Member |
|
|
Hi,
I am evaluating WriteLocks to avoid conflicts due to concurrent
modification. As far as I understood, I just have to call
cdoWriteLock().lock(). On commit, the lock is automatically released, right?
For this, I have written a small test:
public void testModifyElementWithLocking() throws Exception {
LOGGER.debug("[1] adding resource with content");
addContentToResource(transaction1
.getOrCreateResource(CDO_RESOURCE_PATH));
transaction1.commit();
// modify element
final boolean[] errorInThread = { false };
final Runnable runnable1 = new Runnable() {
@Override
public void run() {
final CDOResource resource = transaction1
.getResource(CDO_RESOURCE_PATH);
final CDOObject element = (CDOObject) resource.getContents()
.get(0);
LOGGER.debug("[1] get write lock");
if (!element.cdoWriteLock().tryLock()) {
LOGGER.debug("[1] already locked, waiting...");
element.cdoWriteLock().lock();
}
try {
LOGGER.debug("[1] modifying element");
modifyElement(resource,
CMTPackage.Literals.NAMED_ELEMENT__NAME, "name1");
LOGGER.debug("[1] committing transaction");
transaction1.commit();
} catch (final CommitException e) {
errorInThread[0] = true;
throw new RuntimeException(e);
} finally {
// this is said to be done during commit
// LOGGER.debug("[1] release write lock");
// element.cdoWriteLock().unlock();
}
}
};
final Runnable runnable2 = new Runnable() {
@Override
public void run() {
final CDOResource resource = transaction2
.getResource(CDO_RESOURCE_PATH);
final CDOObject element = (CDOObject) resource.getContents()
.get(0);
LOGGER.debug("[2] get write lock");
if (!element.cdoWriteLock().tryLock()) {
LOGGER.debug("[2] already locked, waiting...");
element.cdoWriteLock().lock();
}
try {
LOGGER.debug("[2] modifying element");
modifyElement(resource,
CMTPackage.Literals.NAMED_ELEMENT__NAME, "name2");
LOGGER.debug("[2] committing transaction");
transaction2.commit();
} catch (final CommitException e) {
errorInThread[0] = true;
throw new RuntimeException(e);
} finally {
// this is said to be done during commit
// LOGGER.debug("[2] release write lock");
// element.cdoWriteLock().unlock();
}
}
};
final ExecutorService executorService = Executors.newFixedThreadPool(2);
executorService.execute(runnable1);
executorService.execute(runnable2);
executorService.awaitTermination(10, TimeUnit.SECONDS);
assertFalse("error during concurrent execution", errorInThread[0]);
LOGGER.debug("[1] checking name of element");
assertElementValue(session1, CMTPackage.Literals.NAMED_ELEMENT__NAME,
anyOf(equalTo("name1"), equalTo("name2")));
LOGGER.debug("[2] checking name of element");
assertElementValue(session2, CMTPackage.Literals.NAMED_ELEMENT__NAME,
anyOf(equalTo("name1"), equalTo("name2")));
}
A few words:
There are 2 sessions. At the beginning, I just populate the repository
using one of the session.
Then I modify an particular object in both sessions. This is done in
parallel threads.
At the end I check my assertions.
When using CDO 3.0.1, the test succeeds. But I'm wondering why the
second commit takes approximately 10 sec. And I am wondering why I don't
see "already locked, waiting..." in my log. Shouldn't tryLock return
immediately when the object is already locked?
Here's an excerpt from my log:
2011-04-04 16:37:10,445 DEBUG [pool-2-thread-1] ITCdoConcurrency - [1]
get write lock
pool-1-thread-2 [debug] Created Resource Query: prep12: SELECT cdo_id
FROM eresource_CDOResourceFolder WHERE cdo_version>0 AND cdo_container=?
AND name=? {1: 0, 2: 'ITCdoConcurrency_1301927829601'};
pool-1-thread-2 [debug] Created Resource Query: prep13: SELECT cdo_id
FROM eresource_CDOResource WHERE cdo_version>0 AND cdo_container=? AND
name=? {1: 0, 2: 'ITCdoConcurrency_1301927829601'};
pool-1-thread-2 [debug] Resource query returned ID 4
2011-04-04 16:37:10,445 DEBUG [pool-2-thread-1] ITCdoConcurrency - [1]
modifying element
2011-04-04 16:37:10,445 DEBUG [pool-2-thread-1] ITCdoConcurrency - [1]
committing transaction
2011-04-04 16:37:10,445 DEBUG [pool-2-thread-2] ITCdoConcurrency - [2]
get write lock
Thread-10 [debug.sql] prep7: INSERT IGNORE INTO cdo_commit_infos(commit_time,
branch_id, user_id, comment) VALUES (?, ?, ?, ?) {1: 1301927830445, 2:
0, 3: NULL, 4: NULL};
Thread-10 [debug.sql] prep22: UPDATE cmt_Project SET cdo_version=?
,cdo_created=? , name =? WHERE cdo_id=? {1: 2, 2: 1301927830445, 3:
'name1', 4: 2};
Thread-10 [debug] --- DB COMMIT ---
2011-04-04 16:37:10,460 DEBUG [pool-2-thread-2] ITCdoConcurrency - [2]
modifying element
2011-04-04 16:37:10,460 DEBUG [pool-2-thread-2] ITCdoConcurrency - [2]
committing transaction
Thread-14 [debug.sql] prep7: INSERT IGNORE INTO cdo_commit_infos(commit_time,
branch_id, user_id, comment) VALUES (?, ?, ?, ?) {1: 1301927830460, 2:
0, 3: NULL, 4: NULL};
Thread-14 [debug.sql] prep22: UPDATE cmt_Project SET cdo_version=?
,cdo_created=? , name =? WHERE cdo_id=? {1: 3, 2: 1301927830460, 3:
'name2', 4: 2};
Thread-14 [debug] --- DB COMMIT ---
2011-04-04 16:37:20,445 DEBUG [main] ITCdoConcurrency - [1] checking
name of element
pool-1-thread-3 [debug] Created Resource Query: prep12: SELECT cdo_id
FROM eresource_CDOResourceFolder WHERE cdo_version>0 AND cdo_container=?
AND name=? {1: 0, 2: 'ITCdoConcurrency_1301927829601'};
pool-1-thread-3 [debug] Created Resource Query: prep13: SELECT cdo_id
FROM eresource_CDOResource WHERE cdo_version>0 AND cdo_container=? AND
name=? {1: 0, 2: 'ITCdoConcurrency_1301927829601'};
pool-1-thread-3 [debug] Resource query returned ID 4
2011-04-04 16:37:20,460 DEBUG [main] ITCdoConcurrency - [2] checking
name of element
pool-1-thread-4 [debug] Created Resource Query: prep12: SELECT cdo_id
FROM eresource_CDOResourceFolder WHERE cdo_version>0 AND cdo_container=?
AND name=? {1: 0, 2: 'ITCdoConcurrency_1301927829601'};
pool-1-thread-4 [debug] Created Resource Query: prep13: SELECT cdo_id
FROM eresource_CDOResource WHERE cdo_version>0 AND cdo_container=? AND
name=? {1: 0, 2: 'ITCdoConcurrency_1301927829601'};
pool-1-thread-4 [debug] Resource query returned ID 4
So far about CDO 3.0. In CDO 4.0, the situation is different. In most
cases, my test fails:
2011-04-04 16:31:40,980 DEBUG [pool-2-thread-1] ITCdoConcurrency - [1]
get write lock
pool-1-thread-2 [debug] Created Resource Query: prep16: SELECT cdo_id
FROM eresource_CDOResourceFolder WHERE cdo_version>0 AND cdo_container=?
AND name=? {1: 0, 2: 'ITCdoConcurrency_1301927500027'};
pool-1-thread-2 [debug] Created Resource Query: prep17: SELECT cdo_id
FROM eresource_CDOResource WHERE cdo_version>0 AND cdo_container=? AND
name=? {1: 0, 2: 'ITCdoConcurrency_1301927500027'};
pool-1-thread-2 [debug] Resource query returned ID OID2
2011-04-04 16:31:40,980 DEBUG [pool-2-thread-1] ITCdoConcurrency - [1]
modifying element
2011-04-04 16:31:40,980 DEBUG [pool-2-thread-1] ITCdoConcurrency - [1]
committing transaction
2011-04-04 16:31:40,980 DEBUG [pool-2-thread-2] ITCdoConcurrency - [2]
get write lock
Thread-14 [debug.sql] prep11: INSERT IGNORE INTO cdo_commit_infos(commit_time,
previous_time, branch_id, user_id, commit_comment) VALUES (?, ?, ?, ?,
?) {1: 1301927500980, 2: 1301927500886, 3: 0, 4: NULL, 5: NULL};
Thread-14 [debug.sql] prep26: UPDATE cmt_Project SET cdo_version=?
,cdo_created=? , name=? WHERE cdo_id=? {1: 2, 2: 1301927500980, 3:
'name1', 4: 3};
Thread-14 [debug] --- DB COMMIT ---
2011-04-04 16:31:40,980 DEBUG [pool-2-thread-2] ITCdoConcurrency - [2]
modifying element
2011-04-04 16:31:40,980 DEBUG [pool-2-thread-2] ITCdoConcurrency - [2]
committing transaction
Exception in thread "pool-2-thread-2" java.lang.RuntimeException:
org.eclipse.emf.cdo.util.CommitException: This transaction has conflicts
at ITCdoConcurrency$2.run(ITCdoConcurrency.java:378)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Threa dPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo lExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
Caused by: org.eclipse.emf.cdo.util.CommitException: This transaction
has conflicts
at
org.eclipse.emf.internal.cdo.transaction.CDOTransactionImpl. commit(CDOTransactionImpl.java:1044)
at
org.eclipse.emf.internal.cdo.transaction.CDOTransactionImpl. commit(CDOTransactionImpl.java:1073)
at ITCdoConcurrency$2.run(ITCdoConcurrency.java:374)
... 3 more
Strange that there's a conflict. Is it possible that changes from the
first session have not yet reached the second session?
However, sometimes the test passes, but I see an exception in the log:
2011-04-04 16:34:26,416 DEBUG [pool-2-thread-1] ITCdoConcurrency - [1]
get write lock
pool-1-thread-2 [debug] Created Resource Query: prep16: SELECT cdo_id
FROM eresource_CDOResourceFolder WHERE cdo_version>0 AND cdo_container=?
AND name=? {1: 0, 2: 'ITCdoConcurrency_1301927665509'};
pool-1-thread-2 [debug] Created Resource Query: prep17: SELECT cdo_id
FROM eresource_CDOResource WHERE cdo_version>0 AND cdo_container=? AND
name=? {1: 0, 2: 'ITCdoConcurrency_1301927665509'};
pool-1-thread-2 [debug] Resource query returned ID OID2
2011-04-04 16:34:26,431 DEBUG [pool-2-thread-1] ITCdoConcurrency - [1]
modifying element
2011-04-04 16:34:26,431 DEBUG [pool-2-thread-1] ITCdoConcurrency - [1]
committing transaction
2011-04-04 16:34:26,431 DEBUG [pool-2-thread-2] ITCdoConcurrency - [2]
get write lock
Thread-13 [debug.sql] prep11: INSERT IGNORE INTO cdo_commit_infos(commit_time,
previous_time, branch_id, user_id, commit_comment) VALUES (?, ?, ?, ?,
?) {1: 1301927666431, 2: 1301927666337, 3: 0, 4: NULL, 5: NULL};
Thread-13 [debug.sql] prep26: UPDATE cmt_Project SET cdo_version=?
,cdo_created=? , name=? WHERE cdo_id=? {1: 2, 2: 1301927666431, 3:
'name1', 4: 3};
Thread-13 [debug] --- DB COMMIT ---
Exception in thread "pool-2-thread-2"
org.eclipse.emf.cdo.util.StaleRevisionLockException
at
org.eclipse.emf.cdo.internal.net4j.protocol.LockObjectsReque st.confirming(LockObjectsRequest.java:98)
at
org.eclipse.emf.cdo.internal.net4j.protocol.LockObjectsReque st.confirming(LockObjectsRequest.java:1)
at
org.eclipse.emf.cdo.internal.net4j.protocol.CDOClientRequest .confirming(CDOClientRequest.java:91)
at
org.eclipse.net4j.signal.RequestWithConfirmation.doExtendedI nput(RequestWithConfirmation.java:123)
at org.eclipse.net4j.signal.Signal.doInput(Signal.java:326)
at
org.eclipse.net4j.signal.RequestWithConfirmation.doExecute(R equestWithConfirmation.java:103)
at org.eclipse.net4j.signal.SignalActor.execute(SignalActor.jav a:51)
at org.eclipse.net4j.signal.Signal.runSync(Signal.java:251)
at
org.eclipse.net4j.signal.SignalProtocol.startSignal(SignalPr otocol.java:396)
at
org.eclipse.net4j.signal.RequestWithConfirmation.doSend(Requ estWithConfirmation.java:87)
at
org.eclipse.net4j.signal.RequestWithConfirmation.send(Reques tWithConfirmation.java:73)
at
org.eclipse.emf.cdo.internal.net4j.protocol.CDOClientProtoco l.lockObjects(CDOClientProtocol.java:225)
at
org.eclipse.emf.internal.cdo.view.CDOViewImpl.lockObjects(CD OViewImpl.java:266)
at
org.eclipse.emf.internal.cdo.object.CDOLockImpl.tryLock(CDOL ockImpl.java:115)
at ITCdoConcurrency$2.run(ITCdoConcurrency.java:364)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Threa dPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo lExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
2011-04-04 16:34:36,415 DEBUG [main] ITCdoConcurrency - [1] checking
name of element
pool-1-thread-3 [debug] Created Resource Query: prep16: SELECT cdo_id
FROM eresource_CDOResourceFolder WHERE cdo_version>0 AND cdo_container=?
AND name=? {1: 0, 2: 'ITCdoConcurrency_1301927665509'};
pool-1-thread-3 [debug] Created Resource Query: prep17: SELECT cdo_id
FROM eresource_CDOResource WHERE cdo_version>0 AND cdo_container=? AND
name=? {1: 0, 2: 'ITCdoConcurrency_1301927665509'};
pool-1-thread-3 [debug] Resource query returned ID OID2
2011-04-04 16:34:36,431 DEBUG [main] ITCdoConcurrency - [2] checking
name of element
pool-1-thread-4 [debug] Created Resource Query: prep16: SELECT cdo_id
FROM eresource_CDOResourceFolder WHERE cdo_version>0 AND cdo_container=?
AND name=? {1: 0, 2: 'ITCdoConcurrency_1301927665509'};
pool-1-thread-4 [debug] Created Resource Query: prep17: SELECT cdo_id
FROM eresource_CDOResource WHERE cdo_version>0 AND cdo_container=? AND
name=? {1: 0, 2: 'ITCdoConcurrency_1301927665509'};
pool-1-thread-4 [debug] Resource query returned ID OID2
So my first question is, am I using the locking stuff correctly? Are
WriteLocks suitable to avoid conflicts?
Maybe my assumptions are wrong? Isn't CDO thread safe?
Should I better stick to CDO 3.0, as locking in 4.0 is not yet stable?
Thanks for any hints. And sorry for so many lines ;)
--
Best regards,
Sebastian Paul
|
|
|
| Re: [CDO] Locking in CDO 3 and 4 [message #663505 is a reply to message #663312] |
Tue, 05 April 2011 12:05  |
|
Hi Sebastian,
Comments below...
Am 04.04.2011 17:07, schrieb Sebastian Paul:
> Hi,
> I am evaluating WriteLocks to avoid conflicts due to concurrent modification. As far as I understood, I just have to call cdoWriteLock().lock().
Yes, but you should always use the method with the timeout period and handle a possible TimeoutException.
> On commit, the lock is automatically released, right?
Yes, unless you override this default via CDOTransaction.Options.setAutoReleaseLocksEnabled(false).
>
> For this, I have written a small test:
>
> public void testModifyElementWithLocking() throws Exception {
>
> LOGGER.debug("[1] adding resource with content");
> addContentToResource(transaction1
> .getOrCreateResource(CDO_RESOURCE_PATH));
> transaction1.commit();
>
> // modify element
> final boolean[] errorInThread = { false };
> final Runnable runnable1 = new Runnable() {
>
> @Override
> public void run() {
> final CDOResource resource = transaction1
> .getResource(CDO_RESOURCE_PATH);
> final CDOObject element = (CDOObject) resource.getContents()
> .get(0);
>
> LOGGER.debug("[1] get write lock");
> if (!element.cdoWriteLock().tryLock()) {
> LOGGER.debug("[1] already locked, waiting...");
> element.cdoWriteLock().lock();
> }
That seems at least over complicated. Better:
try
{
element.cdoWriteLock().lock(2000L);
}
catch (TimeoutException ex)
{
// Do everything again
}
>
> try {
> LOGGER.debug("[1] modifying element");
> modifyElement(resource,
> CMTPackage.Literals.NAMED_ELEMENT__NAME, "name1");
>
> LOGGER.debug("[1] committing transaction");
> transaction1.commit();
> } catch (final CommitException e) {
> errorInThread[0] = true;
> throw new RuntimeException(e);
> } finally {
> // this is said to be done during commit
> // LOGGER.debug("[1] release write lock");
> // element.cdoWriteLock().unlock();
> }
> }
> };
>
> final Runnable runnable2 = new Runnable() {
>
> @Override
> public void run() {
> final CDOResource resource = transaction2
> .getResource(CDO_RESOURCE_PATH);
> final CDOObject element = (CDOObject) resource.getContents()
> .get(0);
>
> LOGGER.debug("[2] get write lock");
> if (!element.cdoWriteLock().tryLock()) {
> LOGGER.debug("[2] already locked, waiting...");
> element.cdoWriteLock().lock();
> }
See above.
>
> try {
> LOGGER.debug("[2] modifying element");
> modifyElement(resource,
> CMTPackage.Literals.NAMED_ELEMENT__NAME, "name2");
>
> LOGGER.debug("[2] committing transaction");
> transaction2.commit();
> } catch (final CommitException e) {
> errorInThread[0] = true;
> throw new RuntimeException(e);
> } finally {
> // this is said to be done during commit
> // LOGGER.debug("[2] release write lock");
> // element.cdoWriteLock().unlock();
> }
> }
> };
>
> final ExecutorService executorService = Executors.newFixedThreadPool(2);
> executorService.execute(runnable1);
> executorService.execute(runnable2);
> executorService.awaitTermination(10, TimeUnit.SECONDS);
> assertFalse("error during concurrent execution", errorInThread[0]);
>
> LOGGER.debug("[1] checking name of element");
> assertElementValue(session1, CMTPackage.Literals.NAMED_ELEMENT__NAME,
> anyOf(equalTo("name1"), equalTo("name2")));
> LOGGER.debug("[2] checking name of element");
> assertElementValue(session2, CMTPackage.Literals.NAMED_ELEMENT__NAME,
> anyOf(equalTo("name1"), equalTo("name2")));
> }
>
> A few words:
> There are 2 sessions. At the beginning, I just populate the repository using one of the session.
> Then I modify an particular object in both sessions. This is done in parallel threads.
> At the end I check my assertions.
>
> When using CDO 3.0.1, the test succeeds. But I'm wondering why the second commit takes approximately 10 sec. And I am wondering why I don't see "already locked, waiting..." in my log. Shouldn't tryLock return immediately when the object is already locked?
I think so but it would be easier for me to understand what's going on if you'd provide a complete, executable test case without other dependencies than those that are already in our test plugin (e.g. no LOGGER). Can you please submit a bugzilla and attach this test case?
>
> Here's an excerpt from my log:
>
> 2011-04-04 16:37:10,445 DEBUG [pool-2-thread-1] ITCdoConcurrency - [1] get write lock
> pool-1-thread-2 [debug] Created Resource Query: prep12: SELECT cdo_id FROM eresource_CDOResourceFolder WHERE cdo_version>0 AND cdo_container=? AND name=? {1: 0, 2: 'ITCdoConcurrency_1301927829601'};
> pool-1-thread-2 [debug] Created Resource Query: prep13: SELECT cdo_id FROM eresource_CDOResource WHERE cdo_version>0 AND cdo_container=? AND name=? {1: 0, 2: 'ITCdoConcurrency_1301927829601'};
> pool-1-thread-2 [debug] Resource query returned ID 4
> 2011-04-04 16:37:10,445 DEBUG [pool-2-thread-1] ITCdoConcurrency - [1] modifying element
> 2011-04-04 16:37:10,445 DEBUG [pool-2-thread-1] ITCdoConcurrency - [1] committing transaction
> 2011-04-04 16:37:10,445 DEBUG [pool-2-thread-2] ITCdoConcurrency - [2] get write lock
> Thread-10 [debug.sql] prep7: INSERT IGNORE INTO cdo_commit_infos(commit_time, branch_id, user_id, comment) VALUES (?, ?, ?, ?) {1: 1301927830445, 2: 0, 3: NULL, 4: NULL};
> Thread-10 [debug.sql] prep22: UPDATE cmt_Project SET cdo_version=? ,cdo_created=? , name =? WHERE cdo_id=? {1: 2, 2: 1301927830445, 3: 'name1', 4: 2};
> Thread-10 [debug] --- DB COMMIT ---
> 2011-04-04 16:37:10,460 DEBUG [pool-2-thread-2] ITCdoConcurrency - [2] modifying element
> 2011-04-04 16:37:10,460 DEBUG [pool-2-thread-2] ITCdoConcurrency - [2] committing transaction
> Thread-14 [debug.sql] prep7: INSERT IGNORE INTO cdo_commit_infos(commit_time, branch_id, user_id, comment) VALUES (?, ?, ?, ?) {1: 1301927830460, 2: 0, 3: NULL, 4: NULL};
> Thread-14 [debug.sql] prep22: UPDATE cmt_Project SET cdo_version=? ,cdo_created=? , name =? WHERE cdo_id=? {1: 3, 2: 1301927830460, 3: 'name2', 4: 2};
> Thread-14 [debug] --- DB COMMIT ---
> 2011-04-04 16:37:20,445 DEBUG [main] ITCdoConcurrency - [1] checking name of element
> pool-1-thread-3 [debug] Created Resource Query: prep12: SELECT cdo_id FROM eresource_CDOResourceFolder WHERE cdo_version>0 AND cdo_container=? AND name=? {1: 0, 2: 'ITCdoConcurrency_1301927829601'};
> pool-1-thread-3 [debug] Created Resource Query: prep13: SELECT cdo_id FROM eresource_CDOResource WHERE cdo_version>0 AND cdo_container=? AND name=? {1: 0, 2: 'ITCdoConcurrency_1301927829601'};
> pool-1-thread-3 [debug] Resource query returned ID 4
> 2011-04-04 16:37:20,460 DEBUG [main] ITCdoConcurrency - [2] checking name of element
> pool-1-thread-4 [debug] Created Resource Query: prep12: SELECT cdo_id FROM eresource_CDOResourceFolder WHERE cdo_version>0 AND cdo_container=? AND name=? {1: 0, 2: 'ITCdoConcurrency_1301927829601'};
> pool-1-thread-4 [debug] Created Resource Query: prep13: SELECT cdo_id FROM eresource_CDOResource WHERE cdo_version>0 AND cdo_container=? AND name=? {1: 0, 2: 'ITCdoConcurrency_1301927829601'};
> pool-1-thread-4 [debug] Resource query returned ID 4
>
>
> So far about CDO 3.0. In CDO 4.0, the situation is different. In most cases, my test fails:
>
> 2011-04-04 16:31:40,980 DEBUG [pool-2-thread-1] ITCdoConcurrency - [1] get write lock
> pool-1-thread-2 [debug] Created Resource Query: prep16: SELECT cdo_id FROM eresource_CDOResourceFolder WHERE cdo_version>0 AND cdo_container=? AND name=? {1: 0, 2: 'ITCdoConcurrency_1301927500027'};
> pool-1-thread-2 [debug] Created Resource Query: prep17: SELECT cdo_id FROM eresource_CDOResource WHERE cdo_version>0 AND cdo_container=? AND name=? {1: 0, 2: 'ITCdoConcurrency_1301927500027'};
> pool-1-thread-2 [debug] Resource query returned ID OID2
> 2011-04-04 16:31:40,980 DEBUG [pool-2-thread-1] ITCdoConcurrency - [1] modifying element
> 2011-04-04 16:31:40,980 DEBUG [pool-2-thread-1] ITCdoConcurrency - [1] committing transaction
> 2011-04-04 16:31:40,980 DEBUG [pool-2-thread-2] ITCdoConcurrency - [2] get write lock
> Thread-14 [debug.sql] prep11: INSERT IGNORE INTO cdo_commit_infos(commit_time, previous_time, branch_id, user_id, commit_comment) VALUES (?, ?, ?, ?, ?) {1: 1301927500980, 2: 1301927500886, 3: 0, 4: NULL, 5: NULL};
> Thread-14 [debug.sql] prep26: UPDATE cmt_Project SET cdo_version=? ,cdo_created=? , name=? WHERE cdo_id=? {1: 2, 2: 1301927500980, 3: 'name1', 4: 3};
> Thread-14 [debug] --- DB COMMIT ---
> 2011-04-04 16:31:40,980 DEBUG [pool-2-thread-2] ITCdoConcurrency - [2] modifying element
> 2011-04-04 16:31:40,980 DEBUG [pool-2-thread-2] ITCdoConcurrency - [2] committing transaction
> Exception in thread "pool-2-thread-2" java.lang.RuntimeException: org.eclipse.emf.cdo.util.CommitException: This transaction has conflicts
> at ITCdoConcurrency$2.run(ITCdoConcurrency.java:378)
> at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Threa dPoolExecutor.java:886)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo lExecutor.java:908)
> at java.lang.Thread.run(Thread.java:662)
> Caused by: org.eclipse.emf.cdo.util.CommitException: This transaction has conflicts
> at org.eclipse.emf.internal.cdo.transaction.CDOTransactionImpl. commit(CDOTransactionImpl.java:1044)
> at org.eclipse.emf.internal.cdo.transaction.CDOTransactionImpl. commit(CDOTransactionImpl.java:1073)
> at ITCdoConcurrency$2.run(ITCdoConcurrency.java:374)
> ... 3 more
>
> Strange that there's a conflict. Is it possible that changes from the first session have not yet reached the second session?
Yes, that's always possible, even with two local transactions that are driven by the same thread. Update notifications from other transactions anywhere in the net (including the local current thread) are always processed in a local background thread.
>
> However, sometimes the test passes, but I see an exception in the log:
>
> 2011-04-04 16:34:26,416 DEBUG [pool-2-thread-1] ITCdoConcurrency - [1] get write lock
> pool-1-thread-2 [debug] Created Resource Query: prep16: SELECT cdo_id FROM eresource_CDOResourceFolder WHERE cdo_version>0 AND cdo_container=? AND name=? {1: 0, 2: 'ITCdoConcurrency_1301927665509'};
> pool-1-thread-2 [debug] Created Resource Query: prep17: SELECT cdo_id FROM eresource_CDOResource WHERE cdo_version>0 AND cdo_container=? AND name=? {1: 0, 2: 'ITCdoConcurrency_1301927665509'};
> pool-1-thread-2 [debug] Resource query returned ID OID2
> 2011-04-04 16:34:26,431 DEBUG [pool-2-thread-1] ITCdoConcurrency - [1] modifying element
> 2011-04-04 16:34:26,431 DEBUG [pool-2-thread-1] ITCdoConcurrency - [1] committing transaction
> 2011-04-04 16:34:26,431 DEBUG [pool-2-thread-2] ITCdoConcurrency - [2] get write lock
> Thread-13 [debug.sql] prep11: INSERT IGNORE INTO cdo_commit_infos(commit_time, previous_time, branch_id, user_id, commit_comment) VALUES (?, ?, ?, ?, ?) {1: 1301927666431, 2: 1301927666337, 3: 0, 4: NULL, 5: NULL};
> Thread-13 [debug.sql] prep26: UPDATE cmt_Project SET cdo_version=? ,cdo_created=? , name=? WHERE cdo_id=? {1: 2, 2: 1301927666431, 3: 'name1', 4: 3};
> Thread-13 [debug] --- DB COMMIT ---
> Exception in thread "pool-2-thread-2" org.eclipse.emf.cdo.util.StaleRevisionLockException
> at org.eclipse.emf.cdo.internal.net4j.protocol.LockObjectsReque st.confirming(LockObjectsRequest.java:98)
> at org.eclipse.emf.cdo.internal.net4j.protocol.LockObjectsReque st.confirming(LockObjectsRequest.java:1)
> at org.eclipse.emf.cdo.internal.net4j.protocol.CDOClientRequest .confirming(CDOClientRequest.java:91)
> at org.eclipse.net4j.signal.RequestWithConfirmation.doExtendedI nput(RequestWithConfirmation.java:123)
> at org.eclipse.net4j.signal.Signal.doInput(Signal.java:326)
> at org.eclipse.net4j.signal.RequestWithConfirmation.doExecute(R equestWithConfirmation.java:103)
> at org.eclipse.net4j.signal.SignalActor.execute(SignalActor.jav a:51)
> at org.eclipse.net4j.signal.Signal.runSync(Signal.java:251)
> at org.eclipse.net4j.signal.SignalProtocol.startSignal(SignalPr otocol.java:396)
> at org.eclipse.net4j.signal.RequestWithConfirmation.doSend(Requ estWithConfirmation.java:87)
> at org.eclipse.net4j.signal.RequestWithConfirmation.send(Reques tWithConfirmation.java:73)
> at org.eclipse.emf.cdo.internal.net4j.protocol.CDOClientProtoco l.lockObjects(CDOClientProtocol.java:225)
> at org.eclipse.emf.internal.cdo.view.CDOViewImpl.lockObjects(CD OViewImpl.java:266)
> at org.eclipse.emf.internal.cdo.object.CDOLockImpl.tryLock(CDOL ockImpl.java:115)
> at ITCdoConcurrency$2.run(ITCdoConcurrency.java:364)
> at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Threa dPoolExecutor.java:886)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo lExecutor.java:908)
> at java.lang.Thread.run(Thread.java:662)
This exception has been introduced with bugzilla 334981: LockObjectsIndication inappropriately throws exception for stale revisions
https://bugs.eclipse.org/bugs/show_bug.cgi?id=334981
Perhaps we should consider a better solution than just throwing an exception after we've detetcted the situation that a client is trying to put a lock on an outdated revision of an object (either because a rspective change notification has not yet arrived/processed at this client or this client has switched off these notifications with passiveUpdates==false). Your comments on this bugzilla are welcome.
> 2011-04-04 16:34:36,415 DEBUG [main] ITCdoConcurrency - [1] checking name of element
> pool-1-thread-3 [debug] Created Resource Query: prep16: SELECT cdo_id FROM eresource_CDOResourceFolder WHERE cdo_version>0 AND cdo_container=? AND name=? {1: 0, 2: 'ITCdoConcurrency_1301927665509'};
> pool-1-thread-3 [debug] Created Resource Query: prep17: SELECT cdo_id FROM eresource_CDOResource WHERE cdo_version>0 AND cdo_container=? AND name=? {1: 0, 2: 'ITCdoConcurrency_1301927665509'};
> pool-1-thread-3 [debug] Resource query returned ID OID2
> 2011-04-04 16:34:36,431 DEBUG [main] ITCdoConcurrency - [2] checking name of element
> pool-1-thread-4 [debug] Created Resource Query: prep16: SELECT cdo_id FROM eresource_CDOResourceFolder WHERE cdo_version>0 AND cdo_container=? AND name=? {1: 0, 2: 'ITCdoConcurrency_1301927665509'};
> pool-1-thread-4 [debug] Created Resource Query: prep17: SELECT cdo_id FROM eresource_CDOResource WHERE cdo_version>0 AND cdo_container=? AND name=? {1: 0, 2: 'ITCdoConcurrency_1301927665509'};
> pool-1-thread-4 [debug] Resource query returned ID OID2
>
>
> So my first question is, am I using the locking stuff correctly?
Mostly. See above.
> Are WriteLocks suitable to avoid conflicts?
They should be. Due to the asynchronous nature of the passiveUpdates==true mode it may be necessary to react to the StaleRevisionLockException in a similar way as to a CommitException that indicates a conflict. Your local view of the object graph is not yet in sync with the repository and you should try it again. Note that this situation can happen multiple times in sequence if the repository is under heavy commit load modifying the same objects again and again. Let us know if you have a better approach in mind.
> Maybe my assumptions are wrong? Isn't CDO thread safe?
We think CDO is thread safe.
> Should I better stick to CDO 3.0, as locking in 4.0 is not yet stable?
I'd say it's stable according to the requirements as they're specified today. See above.
Please note that CDO 3.0 had a lot of other issues in the area of thread safety and locking that we hope to have overcome with CDO 4.0.
Cheers
/Eike
----
http://www.esc-net.de
http://thegordian.blogspot.com
http://twitter.com/eikestepper
Cheers
/Eike
----
http://www.esc-net.de
http://thegordian.blogspot.com
http://twitter.com/eikestepper
|
|
|
| Re: [CDO] Locking in CDO 3 and 4 [message #663572 is a reply to message #663505] |
Tue, 05 April 2011 16:04 |
Sebastian Paul
Messages: 106
Registered: July 2009 |
Senior Member |
|
|
Hi Eike,
Comments below...
>> LOGGER.debug("[1] get write lock");
>> if (!element.cdoWriteLock().tryLock()) {
>> LOGGER.debug("[1] already locked, waiting...");
>> element.cdoWriteLock().lock();
>> }
> That seems at least over complicated. Better:
>
> try
> {
> element.cdoWriteLock().lock(2000L);
> }
> catch (TimeoutException ex)
> {
> // Do everything again
> }
I did this intentionally to see that one of the two sessions must wait
until the other session released the lock. I expected to see "already
locked, waiting..." in the log, but it never appeared at all. What do
you think?
> I think so but it would be easier for me to understand what's going on
> if you'd provide a complete, executable test case without other
> dependencies than those that are already in our test plugin (e.g. no
> LOGGER). Can you please submit a bugzilla and attach this test case?
Sure, I'm going to provide it asap.
>> Strange that there's a conflict. Is it possible that changes from the
>> first session have not yet reached the second session?
> Yes, that's always possible, even with two local transactions that are
> driven by the same thread. Update notifications from other transactions
> anywhere in the net (including the local current thread) are always
> processed in a local background thread.
My goal is avoiding conflicts. A successfully acquired writelock does
not ensure that I won't have conflicts, as changes may be pushed
asynchronously, right? Is there a way to pull changes synchronously? I
guess this is the API one has to use with passiveUpdates=false?
> This exception has been introduced with bugzilla 334981:
> LockObjectsIndication inappropriately throws exception for stale revisions
> https://bugs.eclipse.org/bugs/show_bug.cgi?id=334981
>
> Perhaps we should consider a better solution than just throwing an
> exception after we've detetcted the situation that a client is trying to
> put a lock on an outdated revision of an object (either because a
> rspective change notification has not yet arrived/processed at this
> client or this client has switched off these notifications with
> passiveUpdates==false). Your comments on this bugzilla are welcome.
The discussion in BZ goes too deep for my knowledge, but wouldn't it be
best when an object is updated when acquiring a lock (at least when
using passive updates)?
>> Are WriteLocks suitable to avoid conflicts?
> They should be. Due to the asynchronous nature of the
> passiveUpdates==true mode it may be necessary to react to the
> StaleRevisionLockException in a similar way as to a CommitException that
> indicates a conflict. Your local view of the object graph is not yet in
> sync with the repository and you should try it again. Note that this
> situation can happen multiple times in sequence if the repository is
> under heavy commit load modifying the same objects again and again. Let
> us know if you have a better approach in mind.
See above. If a writelock ensures an up-to-date object, I won't ever get
CommitException or StaleRevisionLockException.
--
Best regards,
Sebastian Paul
|
|
|
| Re: [CDO] Locking in CDO 3 and 4 [message #663662 is a reply to message #663572] |
Wed, 06 April 2011 05:57 |
|
Hi Sebastian,
Please give me some time to discuss this issue with Caspar, who changed the locking behaviour in 4.0...
Cheers
/Eike
----
http://www.esc-net.de
http://thegordian.blogspot.com
http://twitter.com/eikestepper
Am 05.04.2011 18:04, schrieb Sebastian Paul:
> Hi Eike,
> Comments below...
>
>>> LOGGER.debug("[1] get write lock");
>>> if (!element.cdoWriteLock().tryLock()) {
>>> LOGGER.debug("[1] already locked, waiting...");
>>> element.cdoWriteLock().lock();
>>> }
>> That seems at least over complicated. Better:
>>
>> try
>> {
>> element.cdoWriteLock().lock(2000L);
>> }
>> catch (TimeoutException ex)
>> {
>> // Do everything again
>> }
> I did this intentionally to see that one of the two sessions must wait until the other session released the lock. I expected to see "already locked, waiting..." in the log, but it never appeared at all. What do you think?
>
>> I think so but it would be easier for me to understand what's going on
>> if you'd provide a complete, executable test case without other
>> dependencies than those that are already in our test plugin (e.g. no
>> LOGGER). Can you please submit a bugzilla and attach this test case?
> Sure, I'm going to provide it asap.
>
>>> Strange that there's a conflict. Is it possible that changes from the
>>> first session have not yet reached the second session?
>> Yes, that's always possible, even with two local transactions that are
>> driven by the same thread. Update notifications from other transactions
>> anywhere in the net (including the local current thread) are always
>> processed in a local background thread.
> My goal is avoiding conflicts. A successfully acquired writelock does not ensure that I won't have conflicts, as changes may be pushed asynchronously, right? Is there a way to pull changes synchronously? I guess this is the API one has to use with passiveUpdates=false?
>
>> This exception has been introduced with bugzilla 334981:
>> LockObjectsIndication inappropriately throws exception for stale revisions
>> https://bugs.eclipse.org/bugs/show_bug.cgi?id=334981
>>
>> Perhaps we should consider a better solution than just throwing an
>> exception after we've detetcted the situation that a client is trying to
>> put a lock on an outdated revision of an object (either because a
>> rspective change notification has not yet arrived/processed at this
>> client or this client has switched off these notifications with
>> passiveUpdates==false). Your comments on this bugzilla are welcome.
> The discussion in BZ goes too deep for my knowledge, but wouldn't it be best when an object is updated when acquiring a lock (at least when using passive updates)?
>
>>> Are WriteLocks suitable to avoid conflicts?
>> They should be. Due to the asynchronous nature of the
>> passiveUpdates==true mode it may be necessary to react to the
>> StaleRevisionLockException in a similar way as to a CommitException that
>> indicates a conflict. Your local view of the object graph is not yet in
>> sync with the repository and you should try it again. Note that this
>> situation can happen multiple times in sequence if the repository is
>> under heavy commit load modifying the same objects again and again. Let
>> us know if you have a better approach in mind.
> See above. If a writelock ensures an up-to-date object, I won't ever get CommitException or StaleRevisionLockException.
>
Cheers
/Eike
----
http://www.esc-net.de
http://thegordian.blogspot.com
http://twitter.com/eikestepper
|
|
| | | | | |
| Re: [CDO] Locking in CDO 3 and 4 [message #664108 is a reply to message #664012] |
Thu, 07 April 2011 13:39 |
|
Am 07.04.2011 10:02, schrieb Sebastian Paul:
> I searched the Wiki for some information, but without success. Is there already documentation about the test framework? Maybe we should add to the FAQ "How to write tests for Bugzilla".
I would be happy to have more tutorials for the production code :P
No kidding, all contributors so far have easily found into the test bed. There are a number of test models:
/org.eclipse.emf.cdo.tests.mango
/org.eclipse.emf.cdo.tests.model1
/org.eclipse.emf.cdo.tests.model2
/org.eclipse.emf.cdo.tests.model3
/org.eclipse.emf.cdo.tests.model4
/org.eclipse.emf.cdo.tests.model4interfaces
/org.eclipse.emf.cdo.tests.model5
And almost 1500 test cases mostly in these packages:
org.eclipse.emf.cdo.tests
org.eclipse.emf.cdo.tests.bugzilla
You don't have to care for repository setup in most situations. Just call openSession() (once or multiple times) and write any client test logic on the returned session. The framework can execute these tests in multiple IScenarios, which are each specified in terms of currently 4 IConfig dimensions:
org.eclipse.emf.cdo.tests.config.IScenario.getContainerConfi g()
org.eclipse.emf.cdo.tests.config.IScenario.getRepositoryConf ig()
org.eclipse.emf.cdo.tests.config.IScenario.getSessionConfig( )
org.eclipse.emf.cdo.tests.config.IScenario.getModelConfig()
Have a look at the patch that I refactored from your standalone/plugin test zip.
If you want to write a brief article about CDO testing, that would be great ;-)
Cheers
/Eike
----
http://www.esc-net.de
http://thegordian.blogspot.com
http://twitter.com/eikestepper
>
> Am 2011-04-06 18:04, schrieb Eike Stepper:
>> Am 06.04.2011 14:07, schrieb Sebastian Paul:
>>> I fear it would
>>> have taken more time to understand the test framework. But maybe I
>>> take a look next time ;) Is there already a proxy for simulating lost
>>> connections?
>> No, we're simulating that by shutting down the peer port.
>
>
Cheers
/Eike
----
http://www.esc-net.de
http://thegordian.blogspot.com
http://twitter.com/eikestepper
|
|
|
Goto Forum:
Current Time: Tue Apr 16 16:43:18 GMT 2024
Powered by FUDForum. Page generated in 0.35969 seconds |
] 
Search
Help
Register
Login
Home
