Created: (JCR-335) Deadlock caused by versioning operations within transaction

Email lists > Jackrabbit Open Source Content Repository for Java

Thread: Created: (JCR-335) Deadlock caused by versioning operations within transaction

Search this list only Search all lists
Created: (JCR-335) Deadlock caused by versioning operations within transaction
	2006-03-07 15:05:40
Deadlock caused by versioning operations within transaction ----------------------------------------------------------- Key: JCR-335 URL: http://i ssues.apache.org/jira/browse/JCR-335 Project: Jackrabbit Type: Bug Components: versioning Versions: 0.9 Environment: r383887 Reporter: Tobias Bocanegra Fix For: 1.1 Deadlock occurs, while running a very simple test, which is just trying to checkout/checkin node within transaction concurrently from 2 threads. Find enclosed thread dump, log and simple Java program. I'm using UserTransaction implementation from jackrabbit test suite. Regards Przemo Pakulski www.cognifide.com Full thread dump Java HotSpot(TM) Client VM (1.4.2_08-b03 mixed mode): "Thread-5" prio=5 tid=0x03054c48 nid=0x180c in Object.wait() [355f000..355fd8c] at java.lang.Object.wait(Native Method) - waiting on <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) at java.lang.Object.wait(Object.java:429) at EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock.acquire(Unknown Source) - locked <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) at org.apache.jackrabbit.core.state.SharedItemStateManager.acqu ireWriteLock(SharedItemStateManager.java:1137) at org.apache.jackrabbit.core.state.SharedItemStateManager.acce ss$200(SharedItemStateManager.java:110) at org.apache.jackrabbit.core.state.SharedItemStateManager$Upda te.begin(SharedItemStateManager.java:456) at org.apache.jackrabbit.core.state.SharedItemStateManager.begi nUpdate(SharedItemStateManager.java:651) at org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:150) at org.apache.jackrabbit.core.TransactionContext.prepare(Transa ctionContext.java:128) - locked <0x11565ac8> (a org.apache.jackrabbit.core.TransactionContext) at org.apache.jackrabbit.core.XASessionImpl.prepare(XASessionIm pl.java:300) at com.oyster.mom.contentserver.jcr.transaction.JackrabbitUserT ransaction.commit(JackrabbitUserTransaction.java:102) at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. run(JrTestDeadlock.java:97) "Thread-4" prio=5 tid=0x0303b348 nid=0x9d0 in Object.wait() [351f000..351fd8c] at java.lang.Object.wait(Native Method) - waiting on <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) at java.lang.Object.wait(Object.java:429) at EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock.acquire(Unknown Source) - locked <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) at org.apache.jackrabbit.core.state.SharedItemStateManager.acqu ireWriteLock(SharedItemStateManager.java:1137) at org.apache.jackrabbit.core.state.SharedItemStateManager.acce ss$200(SharedItemStateManager.java:110) at org.apache.jackrabbit.core.state.SharedItemStateManager$Upda te.begin(SharedItemStateManager.java:456) at org.apache.jackrabbit.core.state.SharedItemStateManager.begi nUpdate(SharedItemStateManager.java:651) at org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:150) at org.apache.jackrabbit.core.TransactionContext.prepare(Transa ctionContext.java:128) - locked <0x1156f558> (a org.apache.jackrabbit.core.TransactionContext) at org.apache.jackrabbit.core.XASessionImpl.prepare(XASessionIm pl.java:300) at com.oyster.mom.contentserver.jcr.transaction.JackrabbitUserT ransaction.commit(JackrabbitUserTransaction.java:102) at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. run(JrTestDeadlock.java:97) "IndexMerger" daemon prio=5 tid=0x030388b8 nid=0x1858 in Object.wait() [34df000..34dfd8c] at java.lang.Object.wait(Native Method) - waiting on <0x114fd280> (a org.apache.commons.collections.buffer.BlockingBuffer) at java.lang.Object.wait(Object.java:429) at org.apache.commons.collections.buffer.BlockingBuffer.remove( BlockingBuffer.java:107) - locked <0x114fd280> (a org.apache.commons.collections.buffer.BlockingBuffer) at org.apache.jackrabbit.core.query.lucene.IndexMerger.run(Inde xMerger.java:235) "Thread-2" daemon prio=5 tid=0x0303a230 nid=0xe4c in Object.wait() [349f000..349fd8c] at java.lang.Object.wait(Native Method) - waiting on <0x114fd2e0> (a java.util.TaskQueue) at java.util.TimerThread.mainLoop(Timer.java:429) - locked <0x114fd2e0> (a java.util.TaskQueue) at java.util.TimerThread.run(Timer.java:382) "Thread-1" daemon prio=5 tid=0x0301b7a0 nid=0x1a00 in Object.wait() [345f000..345fd8c] at java.lang.Object.wait(Native Method) - waiting on <0x114f9058> (a java.util.TaskQueue) at java.lang.Object.wait(Object.java:429) at java.util.TimerThread.mainLoop(Timer.java:403) - locked <0x114f9058> (a java.util.TaskQueue) at java.util.TimerThread.run(Timer.java:382) "ObservationManager" daemon prio=5 tid=0x02ef6c50 nid=0x10d8 in Object.wait() [341f000..341fd8c] at java.lang.Object.wait(Native Method) - waiting on <0x114f38e0> (a org.apache.commons.collections.buffer.BlockingBuffer) at java.lang.Object.wait(Object.java:429) at org.apache.commons.collections.buffer.BlockingBuffer.remove( BlockingBuffer.java:107) - locked <0x114f38e0> (a org.apache.commons.collections.buffer.BlockingBuffer) at org.apache.jackrabbit.core.observation.ObservationManagerFac tory.run(ObservationManagerFactory.java:155) at java.lang.Thread.run(Thread.java:534) "Signal Dispatcher" daemon prio=10 tid=0x00a05590 nid=0x1914 waiting on condition [0..0] "Finalizer" daemon prio=9 tid=0x00a027f8 nid=0x17a4 in Object.wait() [2c9f000..2c9fd8c] at java.lang.Object.wait(Native Method) - waiting on <0x113db118> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111) - locked <0x113db118> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:1 59) "Reference Handler" daemon prio=10 tid=0x00a01478 nid=0x16d4 in Object.wait() [2c5f000..2c5fd8c] at java.lang.Object.wait(Native Method) - waiting on <0x113db180> (a java.lang.ref.Reference$Lock) at java.lang.Object.wait(Object.java:429) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java: 115) - locked <0x113db180> (a java.lang.ref.Reference$Lock) "main" prio=5 tid=0x0003e6f0 nid=0x1470 in Object.wait() [7f000..7fc38] at java.lang.Object.wait(Native Method) - waiting on <0x11524f10> (a com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock) at java.lang.Thread.join(Thread.java:1001) - locked <0x11524f10> (a com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock) at java.lang.Thread.join(Thread.java:1054) at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. main(JrTestDeadlock.java:33) "VM Thread" prio=5 tid=0x00a42730 nid=0x17d0 runnable "VM Periodic Task Thread" prio=10 tid=0x00a45540 nid=0x1928 waiting on condition "Suspend Checker Thread" prio=10 tid=0x00a04af8 nid=0x17ac runnable import javax.jcr.Node; import javax.jcr.RepositoryException; import javax.jcr.Session; import javax.jcr.SimpleCredentials; import org.apache.jackrabbit.core.RepositoryImpl; import org.apache.jackrabbit.core.config.RepositoryConfig; public class JrTestDeadlock extends Thread { private static final org.apache.commons.logging.Log log = org.apache.commons.logging.LogFactory.getLog(JrTestDeadlock. class); public static String REPOSITORY_HOME = "d:/repo/jackrabbit/"; public static String REPOSITORY_CONFIG = REPOSITORY_HOME + "repository.xml"; public static void main(String[] args) throws Exception { JrTestDeadlock test = new JrTestDeadlock(-1); test.startup(); JrTestDeadlock tests[] = new JrTestDeadlock[2]; for (int i = 0; i < tests.length; i++) { JrTestDeadlock x = new JrTestDeadlock(i); x.start(); tests[i] = x; } for (int i = 0; i < tests.length; i++) { tests[i].join(); } test.shutdown(); } private static RepositoryImpl repository; private int id; public JrTestDeadlock(int i) { this.id = i; } public void startup() throws Exception { System.setProperty("java.security.auth.login.config&q uot;, "c:/jaas.config"); RepositoryConfig config = RepositoryConfig.create(REPOSITORY_CONFIG, REPOSITORY_HOME); repository = RepositoryImpl.create(config); Session session = repository.login(new SimpleCredentials("admin", "admin".toCharArray())); Node rootNode = session.getRootNode(); if (!rootNode.hasNode("folder")) { Node folder = rootNode.addNode("folder"); folder.addMixin("mix:versionable"); folder.addMixin("mix:lockable"); rootNode.save(); } session.logout(); } public void shutdown() throws RepositoryException { repository.shutdown(); } public Node getFolder(Session session) throws RepositoryException { return session.getRootNode().getNode("folder"); } public void run() { try { Session session = repository.login(new SimpleCredentials("admin", "admin".toCharArray())); for (int i = 0; i < 100; i++) { log.error("START id:" + id + ", i=" + i); boolean success = false; JackrabbitUserTransaction ut = new JackrabbitUserTransaction(session); try { ut.begin(); Node folder = getFolder(session); folder.checkout(); folder.checkin(); success = true; log.info("SUCCESS id:" + id + ", i=" + i); } catch (Exception e) { log.warn("FAIL:" + id + ", i=" + i, e); } finally { try { if (success) { ut.commit(); } else { ut.rollback(); } } catch (Exception e) { log.fatal(e); } } } session.logout(); } catch (RepositoryException e) { e.printStackTrace(); } } } 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:0, i=0 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=0 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:0, i=0 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:1, i=0 13:46 ERROR org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:156) - org.apache.jackrabbit.core.state.StaleItemStateException: 233e656f-79f8-414d-9e37-3fce865b492d/{http://www.jcp.org/jcr/1.0 }isCheckedOut has been modified externally 13:46 FATAL JrTestDeadlock.run(JrTestDeadlock.java:104) - javax.transaction.RollbackException: Transaction rolled back: XA_ERR=104 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=1 13:46 WARN JrTestDeadlock.run(JrTestDeadlock.java:92) - FAIL:1, i=1 ax.jcr.InvalidItemStateException: f83a830b-abbf-4ab2-8625-b9e2c4802316: the item does not exist anymore at org.apache.jackrabbit.core.version.XAVersion.sanityCheck(XAV ersion.java:81) at org.apache.jackrabbit.core.version.XAVersion.getInternalVers ion(XAVersion.java:70) at org.apache.jackrabbit.core.version.AbstractVersion.getUUID(A bstractVersion.java:107) at org.apache.jackrabbit.core.NodeImpl.checkout(NodeImpl.java:2 759) at JrTestDeadlock.run(JrTestDeadlock.java:85) 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=2 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:1, i=2 13:51 WARN org.apache.jackrabbit.core.TransactionContext.run(Transactio nContext.java:239) - Transaction rolled back because timeout expired. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://issues.apache.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atl assian.com/software/jira

Assigned: (JCR-335) Deadlock caused by versioning operations within transaction
	2006-03-07 17:17:41
[ http://issues.apache.org/jira/browse/JCR-335?page=all ] Dominique Pfister reassigned JCR-335: ------------------------------------- Assign To: Dominique Pfister > Deadlock caused by versioning operations within transaction > ----------------------------------------------------------- > > Key: JCR-335 > URL: http://i ssues.apache.org/jira/browse/JCR-335 > Project: Jackrabbit > Type: Bug > Components: versioning > Versions: 0.9 > Environment: r383887 > Reporter: Tobias Bocanegra > Assignee: Dominique Pfister > Fix For: 1.1 > > Deadlock occurs, while running a very simple test, which is just trying > to checkout/checkin node within transaction concurrently from 2 threads. > Find enclosed thread dump, log and simple Java program. > I'm using UserTransaction implementation from jackrabbit test suite. > Regards > Przemo Pakulski > www.cognifide.com > Full thread dump Java HotSpot(TM) Client VM (1.4.2_08-b03 mixed mode): > "Thread-5" prio=5 tid=0x03054c48 nid=0x180c in Object.wait() [355f000..355fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at java.lang.Object.wait(Object.java:429) > at EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock.acquire(Unknown Source) > - locked <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acqu ireWriteLock(SharedItemStateManager.java:1137) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acce ss$200(SharedItemStateManager.java:110) > at org.apache.jackrabbit.core.state.SharedItemStateManager$Upda te.begin(SharedItemStateManager.java:456) > at org.apache.jackrabbit.core.state.SharedItemStateManager.begi nUpdate(SharedItemStateManager.java:651) > at org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:150) > at org.apache.jackrabbit.core.TransactionContext.prepare(Transa ctionContext.java:128) > - locked <0x11565ac8> (a org.apache.jackrabbit.core.TransactionContext) > at org.apache.jackrabbit.core.XASessionImpl.prepare(XASessionIm pl.java:300) > at com.oyster.mom.contentserver.jcr.transaction.JackrabbitUserT ransaction.commit(JackrabbitUserTransaction.java:102) > at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. run(JrTestDeadlock.java:97) > "Thread-4" prio=5 tid=0x0303b348 nid=0x9d0 in Object.wait() [351f000..351fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at java.lang.Object.wait(Object.java:429) > at EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock.acquire(Unknown Source) > - locked <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acqu ireWriteLock(SharedItemStateManager.java:1137) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acce ss$200(SharedItemStateManager.java:110) > at org.apache.jackrabbit.core.state.SharedItemStateManager$Upda te.begin(SharedItemStateManager.java:456) > at org.apache.jackrabbit.core.state.SharedItemStateManager.begi nUpdate(SharedItemStateManager.java:651) > at org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:150) > at org.apache.jackrabbit.core.TransactionContext.prepare(Transa ctionContext.java:128) > - locked <0x1156f558> (a org.apache.jackrabbit.core.TransactionContext) > at org.apache.jackrabbit.core.XASessionImpl.prepare(XASessionIm pl.java:300) > at com.oyster.mom.contentserver.jcr.transaction.JackrabbitUserT ransaction.commit(JackrabbitUserTransaction.java:102) > at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. run(JrTestDeadlock.java:97) > "IndexMerger" daemon prio=5 tid=0x030388b8 nid=0x1858 in Object.wait() [34df000..34dfd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114fd280> (a org.apache.commons.collections.buffer.BlockingBuffer) > at java.lang.Object.wait(Object.java:429) > at org.apache.commons.collections.buffer.BlockingBuffer.remove( BlockingBuffer.java:107) > - locked <0x114fd280> (a org.apache.commons.collections.buffer.BlockingBuffer) > at org.apache.jackrabbit.core.query.lucene.IndexMerger.run(Inde xMerger.java:235) > "Thread-2" daemon prio=5 tid=0x0303a230 nid=0xe4c in Object.wait() [349f000..349fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114fd2e0> (a java.util.TaskQueue) > at java.util.TimerThread.mainLoop(Timer.java:429) > - locked <0x114fd2e0> (a java.util.TaskQueue) > at java.util.TimerThread.run(Timer.java:382) > "Thread-1" daemon prio=5 tid=0x0301b7a0 nid=0x1a00 in Object.wait() [345f000..345fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114f9058> (a java.util.TaskQueue) > at java.lang.Object.wait(Object.java:429) > at java.util.TimerThread.mainLoop(Timer.java:403) > - locked <0x114f9058> (a java.util.TaskQueue) > at java.util.TimerThread.run(Timer.java:382) > "ObservationManager" daemon prio=5 tid=0x02ef6c50 nid=0x10d8 in Object.wait() [341f000..341fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114f38e0> (a org.apache.commons.collections.buffer.BlockingBuffer) > at java.lang.Object.wait(Object.java:429) > at org.apache.commons.collections.buffer.BlockingBuffer.remove( BlockingBuffer.java:107) > - locked <0x114f38e0> (a org.apache.commons.collections.buffer.BlockingBuffer) > at org.apache.jackrabbit.core.observation.ObservationManagerFac tory.run(ObservationManagerFactory.java:155) > at java.lang.Thread.run(Thread.java:534) > "Signal Dispatcher" daemon prio=10 tid=0x00a05590 nid=0x1914 waiting on condition [0..0] > "Finalizer" daemon prio=9 tid=0x00a027f8 nid=0x17a4 in Object.wait() [2c9f000..2c9fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x113db118> (a java.lang.ref.ReferenceQueue$Lock) > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111) > - locked <0x113db118> (a java.lang.ref.ReferenceQueue$Lock) > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127) > at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:1 59) > "Reference Handler" daemon prio=10 tid=0x00a01478 nid=0x16d4 in Object.wait() [2c5f000..2c5fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x113db180> (a java.lang.ref.Reference$Lock) > at java.lang.Object.wait(Object.java:429) > at java.lang.ref.Reference$ReferenceHandler.run(Reference.java: 115) > - locked <0x113db180> (a java.lang.ref.Reference$Lock) > "main" prio=5 tid=0x0003e6f0 nid=0x1470 in Object.wait() [7f000..7fc38] > at java.lang.Object.wait(Native Method) > - waiting on <0x11524f10> (a com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock) > at java.lang.Thread.join(Thread.java:1001) > - locked <0x11524f10> (a com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock) > at java.lang.Thread.join(Thread.java:1054) > at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. main(JrTestDeadlock.java:33) > "VM Thread" prio=5 tid=0x00a42730 nid=0x17d0 runnable > "VM Periodic Task Thread" prio=10 tid=0x00a45540 nid=0x1928 waiting on condition > "Suspend Checker Thread" prio=10 tid=0x00a04af8 nid=0x17ac runnable > import javax.jcr.Node; > import javax.jcr.RepositoryException; > import javax.jcr.Session; > import javax.jcr.SimpleCredentials; > import org.apache.jackrabbit.core.RepositoryImpl; > import org.apache.jackrabbit.core.config.RepositoryConfig; > public class JrTestDeadlock extends Thread { > private static final org.apache.commons.logging.Log log = org.apache.commons.logging.LogFactory.getLog(JrTestDeadlock. class); > public static String REPOSITORY_HOME = "d:/repo/jackrabbit/"; > public static String REPOSITORY_CONFIG = REPOSITORY_HOME + "repository.xml"; > public static void main(String[] args) throws Exception { > JrTestDeadlock test = new JrTestDeadlock(-1); > test.startup(); > JrTestDeadlock tests[] = new JrTestDeadlock[2]; > for (int i = 0; i < tests.length; i++) { > JrTestDeadlock x = new JrTestDeadlock(i); > x.start(); > tests[i] = x; > } > for (int i = 0; i < tests.length; i++) { > tests[i].join(); > } > test.shutdown(); > } > private static RepositoryImpl repository; > private int id; > public JrTestDeadlock(int i) { > this.id = i; > } > public void startup() throws Exception { > System.setProperty("java.security.auth.login.config&q uot;, "c:/jaas.config"); > RepositoryConfig config = RepositoryConfig.create(REPOSITORY_CONFIG, REPOSITORY_HOME); > repository = RepositoryImpl.create(config); > Session session = repository.login(new SimpleCredentials("admin", "admin".toCharArray())); > Node rootNode = session.getRootNode(); > if (!rootNode.hasNode("folder")) { > Node folder = rootNode.addNode("folder"); > folder.addMixin("mix:versionable"); > folder.addMixin("mix:lockable"); > rootNode.save(); > } > session.logout(); > } > public void shutdown() throws RepositoryException { > repository.shutdown(); > } > public Node getFolder(Session session) throws RepositoryException { > return session.getRootNode().getNode("folder"); > } > public void run() { > try { > Session session = repository.login(new SimpleCredentials("admin", "admin".toCharArray())); > for (int i = 0; i < 100; i++) { > log.error("START id:" + id + ", i=" + i); > boolean success = false; > JackrabbitUserTransaction ut = new JackrabbitUserTransaction(session); > try { > ut.begin(); > Node folder = getFolder(session); > folder.checkout(); > folder.checkin(); > success = true; > log.info("SUCCESS id:" + id + ", i=" + i); > } > catch (Exception e) { > log.warn("FAIL:" + id + ", i=" + i, e); > } > finally { > try { > if (success) { > ut.commit(); > } > else { > ut.rollback(); > } > } > catch (Exception e) { > log.fatal(e); > } > } > } > session.logout(); > } > catch (RepositoryException e) { > e.printStackTrace(); > } > } > } > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:0, i=0 > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=0 > 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:0, i=0 > 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:1, i=0 > 13:46 ERROR org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:156) - org.apache.jackrabbit.core.state.StaleItemStateException: 233e656f-79f8-414d-9e37-3fce865b492d/{http://www.jcp.org/jcr/1.0 }isCheckedOut has been modified externally > 13:46 FATAL JrTestDeadlock.run(JrTestDeadlock.java:104) - javax.transaction.RollbackException: Transaction rolled back: XA_ERR=104 > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=1 > 13:46 WARN JrTestDeadlock.run(JrTestDeadlock.java:92) - FAIL:1, i=1 > ax.jcr.InvalidItemStateException: f83a830b-abbf-4ab2-8625-b9e2c4802316: the item does not exist anymore > at org.apache.jackrabbit.core.version.XAVersion.sanityCheck(XAV ersion.java:81) > at org.apache.jackrabbit.core.version.XAVersion.getInternalVers ion(XAVersion.java:70) > at org.apache.jackrabbit.core.version.AbstractVersion.getUUID(A bstractVersion.java:107) > at org.apache.jackrabbit.core.NodeImpl.checkout(NodeImpl.java:2 759) > at JrTestDeadlock.run(JrTestDeadlock.java:85) > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=2 > 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:1, i=2 > 13:51 WARN org.apache.jackrabbit.core.TransactionContext.run(Transactio nContext.java:239) - Transaction rolled back because timeout expired. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://issues.apache.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atl assian.com/software/jira

Closed: (JCR-335) Deadlock caused by versioning operations within transaction
	2006-03-07 17:17:40
[ http://issues.apache.org/jira/browse/JCR-335?page=all ] Dominique Pfister closed JCR-335: --------------------------------- > Deadlock caused by versioning operations within transaction > ----------------------------------------------------------- > > Key: JCR-335 > URL: http://i ssues.apache.org/jira/browse/JCR-335 > Project: Jackrabbit > Type: Bug > Components: versioning > Versions: 0.9 > Environment: r383887 > Reporter: Tobias Bocanegra > Fix For: 1.1 > > Deadlock occurs, while running a very simple test, which is just trying > to checkout/checkin node within transaction concurrently from 2 threads. > Find enclosed thread dump, log and simple Java program. > I'm using UserTransaction implementation from jackrabbit test suite. > Regards > Przemo Pakulski > www.cognifide.com > Full thread dump Java HotSpot(TM) Client VM (1.4.2_08-b03 mixed mode): > "Thread-5" prio=5 tid=0x03054c48 nid=0x180c in Object.wait() [355f000..355fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at java.lang.Object.wait(Object.java:429) > at EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock.acquire(Unknown Source) > - locked <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acqu ireWriteLock(SharedItemStateManager.java:1137) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acce ss$200(SharedItemStateManager.java:110) > at org.apache.jackrabbit.core.state.SharedItemStateManager$Upda te.begin(SharedItemStateManager.java:456) > at org.apache.jackrabbit.core.state.SharedItemStateManager.begi nUpdate(SharedItemStateManager.java:651) > at org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:150) > at org.apache.jackrabbit.core.TransactionContext.prepare(Transa ctionContext.java:128) > - locked <0x11565ac8> (a org.apache.jackrabbit.core.TransactionContext) > at org.apache.jackrabbit.core.XASessionImpl.prepare(XASessionIm pl.java:300) > at com.oyster.mom.contentserver.jcr.transaction.JackrabbitUserT ransaction.commit(JackrabbitUserTransaction.java:102) > at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. run(JrTestDeadlock.java:97) > "Thread-4" prio=5 tid=0x0303b348 nid=0x9d0 in Object.wait() [351f000..351fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at java.lang.Object.wait(Object.java:429) > at EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock.acquire(Unknown Source) > - locked <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acqu ireWriteLock(SharedItemStateManager.java:1137) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acce ss$200(SharedItemStateManager.java:110) > at org.apache.jackrabbit.core.state.SharedItemStateManager$Upda te.begin(SharedItemStateManager.java:456) > at org.apache.jackrabbit.core.state.SharedItemStateManager.begi nUpdate(SharedItemStateManager.java:651) > at org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:150) > at org.apache.jackrabbit.core.TransactionContext.prepare(Transa ctionContext.java:128) > - locked <0x1156f558> (a org.apache.jackrabbit.core.TransactionContext) > at org.apache.jackrabbit.core.XASessionImpl.prepare(XASessionIm pl.java:300) > at com.oyster.mom.contentserver.jcr.transaction.JackrabbitUserT ransaction.commit(JackrabbitUserTransaction.java:102) > at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. run(JrTestDeadlock.java:97) > "IndexMerger" daemon prio=5 tid=0x030388b8 nid=0x1858 in Object.wait() [34df000..34dfd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114fd280> (a org.apache.commons.collections.buffer.BlockingBuffer) > at java.lang.Object.wait(Object.java:429) > at org.apache.commons.collections.buffer.BlockingBuffer.remove( BlockingBuffer.java:107) > - locked <0x114fd280> (a org.apache.commons.collections.buffer.BlockingBuffer) > at org.apache.jackrabbit.core.query.lucene.IndexMerger.run(Inde xMerger.java:235) > "Thread-2" daemon prio=5 tid=0x0303a230 nid=0xe4c in Object.wait() [349f000..349fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114fd2e0> (a java.util.TaskQueue) > at java.util.TimerThread.mainLoop(Timer.java:429) > - locked <0x114fd2e0> (a java.util.TaskQueue) > at java.util.TimerThread.run(Timer.java:382) > "Thread-1" daemon prio=5 tid=0x0301b7a0 nid=0x1a00 in Object.wait() [345f000..345fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114f9058> (a java.util.TaskQueue) > at java.lang.Object.wait(Object.java:429) > at java.util.TimerThread.mainLoop(Timer.java:403) > - locked <0x114f9058> (a java.util.TaskQueue) > at java.util.TimerThread.run(Timer.java:382) > "ObservationManager" daemon prio=5 tid=0x02ef6c50 nid=0x10d8 in Object.wait() [341f000..341fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114f38e0> (a org.apache.commons.collections.buffer.BlockingBuffer) > at java.lang.Object.wait(Object.java:429) > at org.apache.commons.collections.buffer.BlockingBuffer.remove( BlockingBuffer.java:107) > - locked <0x114f38e0> (a org.apache.commons.collections.buffer.BlockingBuffer) > at org.apache.jackrabbit.core.observation.ObservationManagerFac tory.run(ObservationManagerFactory.java:155) > at java.lang.Thread.run(Thread.java:534) > "Signal Dispatcher" daemon prio=10 tid=0x00a05590 nid=0x1914 waiting on condition [0..0] > "Finalizer" daemon prio=9 tid=0x00a027f8 nid=0x17a4 in Object.wait() [2c9f000..2c9fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x113db118> (a java.lang.ref.ReferenceQueue$Lock) > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111) > - locked <0x113db118> (a java.lang.ref.ReferenceQueue$Lock) > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127) > at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:1 59) > "Reference Handler" daemon prio=10 tid=0x00a01478 nid=0x16d4 in Object.wait() [2c5f000..2c5fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x113db180> (a java.lang.ref.Reference$Lock) > at java.lang.Object.wait(Object.java:429) > at java.lang.ref.Reference$ReferenceHandler.run(Reference.java: 115) > - locked <0x113db180> (a java.lang.ref.Reference$Lock) > "main" prio=5 tid=0x0003e6f0 nid=0x1470 in Object.wait() [7f000..7fc38] > at java.lang.Object.wait(Native Method) > - waiting on <0x11524f10> (a com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock) > at java.lang.Thread.join(Thread.java:1001) > - locked <0x11524f10> (a com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock) > at java.lang.Thread.join(Thread.java:1054) > at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. main(JrTestDeadlock.java:33) > "VM Thread" prio=5 tid=0x00a42730 nid=0x17d0 runnable > "VM Periodic Task Thread" prio=10 tid=0x00a45540 nid=0x1928 waiting on condition > "Suspend Checker Thread" prio=10 tid=0x00a04af8 nid=0x17ac runnable > import javax.jcr.Node; > import javax.jcr.RepositoryException; > import javax.jcr.Session; > import javax.jcr.SimpleCredentials; > import org.apache.jackrabbit.core.RepositoryImpl; > import org.apache.jackrabbit.core.config.RepositoryConfig; > public class JrTestDeadlock extends Thread { > private static final org.apache.commons.logging.Log log = org.apache.commons.logging.LogFactory.getLog(JrTestDeadlock. class); > public static String REPOSITORY_HOME = "d:/repo/jackrabbit/"; > public static String REPOSITORY_CONFIG = REPOSITORY_HOME + "repository.xml"; > public static void main(String[] args) throws Exception { > JrTestDeadlock test = new JrTestDeadlock(-1); > test.startup(); > JrTestDeadlock tests[] = new JrTestDeadlock[2]; > for (int i = 0; i < tests.length; i++) { > JrTestDeadlock x = new JrTestDeadlock(i); > x.start(); > tests[i] = x; > } > for (int i = 0; i < tests.length; i++) { > tests[i].join(); > } > test.shutdown(); > } > private static RepositoryImpl repository; > private int id; > public JrTestDeadlock(int i) { > this.id = i; > } > public void startup() throws Exception { > System.setProperty("java.security.auth.login.config&q uot;, "c:/jaas.config"); > RepositoryConfig config = RepositoryConfig.create(REPOSITORY_CONFIG, REPOSITORY_HOME); > repository = RepositoryImpl.create(config); > Session session = repository.login(new SimpleCredentials("admin", "admin".toCharArray())); > Node rootNode = session.getRootNode(); > if (!rootNode.hasNode("folder")) { > Node folder = rootNode.addNode("folder"); > folder.addMixin("mix:versionable"); > folder.addMixin("mix:lockable"); > rootNode.save(); > } > session.logout(); > } > public void shutdown() throws RepositoryException { > repository.shutdown(); > } > public Node getFolder(Session session) throws RepositoryException { > return session.getRootNode().getNode("folder"); > } > public void run() { > try { > Session session = repository.login(new SimpleCredentials("admin", "admin".toCharArray())); > for (int i = 0; i < 100; i++) { > log.error("START id:" + id + ", i=" + i); > boolean success = false; > JackrabbitUserTransaction ut = new JackrabbitUserTransaction(session); > try { > ut.begin(); > Node folder = getFolder(session); > folder.checkout(); > folder.checkin(); > success = true; > log.info("SUCCESS id:" + id + ", i=" + i); > } > catch (Exception e) { > log.warn("FAIL:" + id + ", i=" + i, e); > } > finally { > try { > if (success) { > ut.commit(); > } > else { > ut.rollback(); > } > } > catch (Exception e) { > log.fatal(e); > } > } > } > session.logout(); > } > catch (RepositoryException e) { > e.printStackTrace(); > } > } > } > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:0, i=0 > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=0 > 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:0, i=0 > 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:1, i=0 > 13:46 ERROR org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:156) - org.apache.jackrabbit.core.state.StaleItemStateException: 233e656f-79f8-414d-9e37-3fce865b492d/{http://www.jcp.org/jcr/1.0 }isCheckedOut has been modified externally > 13:46 FATAL JrTestDeadlock.run(JrTestDeadlock.java:104) - javax.transaction.RollbackException: Transaction rolled back: XA_ERR=104 > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=1 > 13:46 WARN JrTestDeadlock.run(JrTestDeadlock.java:92) - FAIL:1, i=1 > ax.jcr.InvalidItemStateException: f83a830b-abbf-4ab2-8625-b9e2c4802316: the item does not exist anymore > at org.apache.jackrabbit.core.version.XAVersion.sanityCheck(XAV ersion.java:81) > at org.apache.jackrabbit.core.version.XAVersion.getInternalVers ion(XAVersion.java:70) > at org.apache.jackrabbit.core.version.AbstractVersion.getUUID(A bstractVersion.java:107) > at org.apache.jackrabbit.core.NodeImpl.checkout(NodeImpl.java:2 759) > at JrTestDeadlock.run(JrTestDeadlock.java:85) > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=2 > 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:1, i=2 > 13:51 WARN org.apache.jackrabbit.core.TransactionContext.run(Transactio nContext.java:239) - Transaction rolled back because timeout expired. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://issues.apache.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atl assian.com/software/jira

Resolved: (JCR-335) Deadlock caused by versioning operations within transaction
	2006-03-07 17:17:39
[ http://issues.apache.org/jira/browse/JCR-335?page=all ] Dominique Pfister resolved JCR-335: ----------------------------------- Resolution: Fixed Local SharedItemStateManager.Update object released write lock too often when being rolled back by background thread. Fixed in: r383935 > Deadlock caused by versioning operations within transaction > ----------------------------------------------------------- > > Key: JCR-335 > URL: http://i ssues.apache.org/jira/browse/JCR-335 > Project: Jackrabbit > Type: Bug > Components: versioning > Versions: 0.9 > Environment: r383887 > Reporter: Tobias Bocanegra > Fix For: 1.1 > > Deadlock occurs, while running a very simple test, which is just trying > to checkout/checkin node within transaction concurrently from 2 threads. > Find enclosed thread dump, log and simple Java program. > I'm using UserTransaction implementation from jackrabbit test suite. > Regards > Przemo Pakulski > www.cognifide.com > Full thread dump Java HotSpot(TM) Client VM (1.4.2_08-b03 mixed mode): > "Thread-5" prio=5 tid=0x03054c48 nid=0x180c in Object.wait() [355f000..355fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at java.lang.Object.wait(Object.java:429) > at EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock.acquire(Unknown Source) > - locked <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acqu ireWriteLock(SharedItemStateManager.java:1137) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acce ss$200(SharedItemStateManager.java:110) > at org.apache.jackrabbit.core.state.SharedItemStateManager$Upda te.begin(SharedItemStateManager.java:456) > at org.apache.jackrabbit.core.state.SharedItemStateManager.begi nUpdate(SharedItemStateManager.java:651) > at org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:150) > at org.apache.jackrabbit.core.TransactionContext.prepare(Transa ctionContext.java:128) > - locked <0x11565ac8> (a org.apache.jackrabbit.core.TransactionContext) > at org.apache.jackrabbit.core.XASessionImpl.prepare(XASessionIm pl.java:300) > at com.oyster.mom.contentserver.jcr.transaction.JackrabbitUserT ransaction.commit(JackrabbitUserTransaction.java:102) > at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. run(JrTestDeadlock.java:97) > "Thread-4" prio=5 tid=0x0303b348 nid=0x9d0 in Object.wait() [351f000..351fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at java.lang.Object.wait(Object.java:429) > at EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock.acquire(Unknown Source) > - locked <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acqu ireWriteLock(SharedItemStateManager.java:1137) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acce ss$200(SharedItemStateManager.java:110) > at org.apache.jackrabbit.core.state.SharedItemStateManager$Upda te.begin(SharedItemStateManager.java:456) > at org.apache.jackrabbit.core.state.SharedItemStateManager.begi nUpdate(SharedItemStateManager.java:651) > at org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:150) > at org.apache.jackrabbit.core.TransactionContext.prepare(Transa ctionContext.java:128) > - locked <0x1156f558> (a org.apache.jackrabbit.core.TransactionContext) > at org.apache.jackrabbit.core.XASessionImpl.prepare(XASessionIm pl.java:300) > at com.oyster.mom.contentserver.jcr.transaction.JackrabbitUserT ransaction.commit(JackrabbitUserTransaction.java:102) > at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. run(JrTestDeadlock.java:97) > "IndexMerger" daemon prio=5 tid=0x030388b8 nid=0x1858 in Object.wait() [34df000..34dfd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114fd280> (a org.apache.commons.collections.buffer.BlockingBuffer) > at java.lang.Object.wait(Object.java:429) > at org.apache.commons.collections.buffer.BlockingBuffer.remove( BlockingBuffer.java:107) > - locked <0x114fd280> (a org.apache.commons.collections.buffer.BlockingBuffer) > at org.apache.jackrabbit.core.query.lucene.IndexMerger.run(Inde xMerger.java:235) > "Thread-2" daemon prio=5 tid=0x0303a230 nid=0xe4c in Object.wait() [349f000..349fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114fd2e0> (a java.util.TaskQueue) > at java.util.TimerThread.mainLoop(Timer.java:429) > - locked <0x114fd2e0> (a java.util.TaskQueue) > at java.util.TimerThread.run(Timer.java:382) > "Thread-1" daemon prio=5 tid=0x0301b7a0 nid=0x1a00 in Object.wait() [345f000..345fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114f9058> (a java.util.TaskQueue) > at java.lang.Object.wait(Object.java:429) > at java.util.TimerThread.mainLoop(Timer.java:403) > - locked <0x114f9058> (a java.util.TaskQueue) > at java.util.TimerThread.run(Timer.java:382) > "ObservationManager" daemon prio=5 tid=0x02ef6c50 nid=0x10d8 in Object.wait() [341f000..341fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114f38e0> (a org.apache.commons.collections.buffer.BlockingBuffer) > at java.lang.Object.wait(Object.java:429) > at org.apache.commons.collections.buffer.BlockingBuffer.remove( BlockingBuffer.java:107) > - locked <0x114f38e0> (a org.apache.commons.collections.buffer.BlockingBuffer) > at org.apache.jackrabbit.core.observation.ObservationManagerFac tory.run(ObservationManagerFactory.java:155) > at java.lang.Thread.run(Thread.java:534) > "Signal Dispatcher" daemon prio=10 tid=0x00a05590 nid=0x1914 waiting on condition [0..0] > "Finalizer" daemon prio=9 tid=0x00a027f8 nid=0x17a4 in Object.wait() [2c9f000..2c9fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x113db118> (a java.lang.ref.ReferenceQueue$Lock) > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111) > - locked <0x113db118> (a java.lang.ref.ReferenceQueue$Lock) > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127) > at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:1 59) > "Reference Handler" daemon prio=10 tid=0x00a01478 nid=0x16d4 in Object.wait() [2c5f000..2c5fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x113db180> (a java.lang.ref.Reference$Lock) > at java.lang.Object.wait(Object.java:429) > at java.lang.ref.Reference$ReferenceHandler.run(Reference.java: 115) > - locked <0x113db180> (a java.lang.ref.Reference$Lock) > "main" prio=5 tid=0x0003e6f0 nid=0x1470 in Object.wait() [7f000..7fc38] > at java.lang.Object.wait(Native Method) > - waiting on <0x11524f10> (a com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock) > at java.lang.Thread.join(Thread.java:1001) > - locked <0x11524f10> (a com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock) > at java.lang.Thread.join(Thread.java:1054) > at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. main(JrTestDeadlock.java:33) > "VM Thread" prio=5 tid=0x00a42730 nid=0x17d0 runnable > "VM Periodic Task Thread" prio=10 tid=0x00a45540 nid=0x1928 waiting on condition > "Suspend Checker Thread" prio=10 tid=0x00a04af8 nid=0x17ac runnable > import javax.jcr.Node; > import javax.jcr.RepositoryException; > import javax.jcr.Session; > import javax.jcr.SimpleCredentials; > import org.apache.jackrabbit.core.RepositoryImpl; > import org.apache.jackrabbit.core.config.RepositoryConfig; > public class JrTestDeadlock extends Thread { > private static final org.apache.commons.logging.Log log = org.apache.commons.logging.LogFactory.getLog(JrTestDeadlock. class); > public static String REPOSITORY_HOME = "d:/repo/jackrabbit/"; > public static String REPOSITORY_CONFIG = REPOSITORY_HOME + "repository.xml"; > public static void main(String[] args) throws Exception { > JrTestDeadlock test = new JrTestDeadlock(-1); > test.startup(); > JrTestDeadlock tests[] = new JrTestDeadlock[2]; > for (int i = 0; i < tests.length; i++) { > JrTestDeadlock x = new JrTestDeadlock(i); > x.start(); > tests[i] = x; > } > for (int i = 0; i < tests.length; i++) { > tests[i].join(); > } > test.shutdown(); > } > private static RepositoryImpl repository; > private int id; > public JrTestDeadlock(int i) { > this.id = i; > } > public void startup() throws Exception { > System.setProperty("java.security.auth.login.config&q uot;, "c:/jaas.config"); > RepositoryConfig config = RepositoryConfig.create(REPOSITORY_CONFIG, REPOSITORY_HOME); > repository = RepositoryImpl.create(config); > Session session = repository.login(new SimpleCredentials("admin", "admin".toCharArray())); > Node rootNode = session.getRootNode(); > if (!rootNode.hasNode("folder")) { > Node folder = rootNode.addNode("folder"); > folder.addMixin("mix:versionable"); > folder.addMixin("mix:lockable"); > rootNode.save(); > } > session.logout(); > } > public void shutdown() throws RepositoryException { > repository.shutdown(); > } > public Node getFolder(Session session) throws RepositoryException { > return session.getRootNode().getNode("folder"); > } > public void run() { > try { > Session session = repository.login(new SimpleCredentials("admin", "admin".toCharArray())); > for (int i = 0; i < 100; i++) { > log.error("START id:" + id + ", i=" + i); > boolean success = false; > JackrabbitUserTransaction ut = new JackrabbitUserTransaction(session); > try { > ut.begin(); > Node folder = getFolder(session); > folder.checkout(); > folder.checkin(); > success = true; > log.info("SUCCESS id:" + id + ", i=" + i); > } > catch (Exception e) { > log.warn("FAIL:" + id + ", i=" + i, e); > } > finally { > try { > if (success) { > ut.commit(); > } > else { > ut.rollback(); > } > } > catch (Exception e) { > log.fatal(e); > } > } > } > session.logout(); > } > catch (RepositoryException e) { > e.printStackTrace(); > } > } > } > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:0, i=0 > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=0 > 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:0, i=0 > 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:1, i=0 > 13:46 ERROR org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:156) - org.apache.jackrabbit.core.state.StaleItemStateException: 233e656f-79f8-414d-9e37-3fce865b492d/{http://www.jcp.org/jcr/1.0 }isCheckedOut has been modified externally > 13:46 FATAL JrTestDeadlock.run(JrTestDeadlock.java:104) - javax.transaction.RollbackException: Transaction rolled back: XA_ERR=104 > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=1 > 13:46 WARN JrTestDeadlock.run(JrTestDeadlock.java:92) - FAIL:1, i=1 > ax.jcr.InvalidItemStateException: f83a830b-abbf-4ab2-8625-b9e2c4802316: the item does not exist anymore > at org.apache.jackrabbit.core.version.XAVersion.sanityCheck(XAV ersion.java:81) > at org.apache.jackrabbit.core.version.XAVersion.getInternalVers ion(XAVersion.java:70) > at org.apache.jackrabbit.core.version.AbstractVersion.getUUID(A bstractVersion.java:107) > at org.apache.jackrabbit.core.NodeImpl.checkout(NodeImpl.java:2 759) > at JrTestDeadlock.run(JrTestDeadlock.java:85) > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=2 > 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:1, i=2 > 13:51 WARN org.apache.jackrabbit.core.TransactionContext.run(Transactio nContext.java:239) - Transaction rolled back because timeout expired. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://issues.apache.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atl assian.com/software/jira

Commented: (JCR-335) Deadlock caused by versioning operations within transaction
	2006-03-07 17:27:39
[ http://issues.apache.org/jira/browse/J CR-335?page=comments#action_12369270 ] Jukka Zitting commented on JCR-335: ----------------------------------- This seems serious enough to warrant inclusion in the Jackrabbit 1.0 release. Do you think it would be safe to apply the change also to the 1.0 branch as a last-minute fix, or could this case unexpected regressions? > Deadlock caused by versioning operations within transaction > ----------------------------------------------------------- > > Key: JCR-335 > URL: http://i ssues.apache.org/jira/browse/JCR-335 > Project: Jackrabbit > Type: Bug > Components: versioning > Versions: 0.9 > Environment: r383887 > Reporter: Tobias Bocanegra > Assignee: Dominique Pfister > Fix For: 1.1 > > Deadlock occurs, while running a very simple test, which is just trying > to checkout/checkin node within transaction concurrently from 2 threads. > Find enclosed thread dump, log and simple Java program. > I'm using UserTransaction implementation from jackrabbit test suite. > Regards > Przemo Pakulski > www.cognifide.com > Full thread dump Java HotSpot(TM) Client VM (1.4.2_08-b03 mixed mode): > "Thread-5" prio=5 tid=0x03054c48 nid=0x180c in Object.wait() [355f000..355fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at java.lang.Object.wait(Object.java:429) > at EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock.acquire(Unknown Source) > - locked <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acqu ireWriteLock(SharedItemStateManager.java:1137) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acce ss$200(SharedItemStateManager.java:110) > at org.apache.jackrabbit.core.state.SharedItemStateManager$Upda te.begin(SharedItemStateManager.java:456) > at org.apache.jackrabbit.core.state.SharedItemStateManager.begi nUpdate(SharedItemStateManager.java:651) > at org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:150) > at org.apache.jackrabbit.core.TransactionContext.prepare(Transa ctionContext.java:128) > - locked <0x11565ac8> (a org.apache.jackrabbit.core.TransactionContext) > at org.apache.jackrabbit.core.XASessionImpl.prepare(XASessionIm pl.java:300) > at com.oyster.mom.contentserver.jcr.transaction.JackrabbitUserT ransaction.commit(JackrabbitUserTransaction.java:102) > at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. run(JrTestDeadlock.java:97) > "Thread-4" prio=5 tid=0x0303b348 nid=0x9d0 in Object.wait() [351f000..351fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at java.lang.Object.wait(Object.java:429) > at EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock.acquire(Unknown Source) > - locked <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acqu ireWriteLock(SharedItemStateManager.java:1137) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acce ss$200(SharedItemStateManager.java:110) > at org.apache.jackrabbit.core.state.SharedItemStateManager$Upda te.begin(SharedItemStateManager.java:456) > at org.apache.jackrabbit.core.state.SharedItemStateManager.begi nUpdate(SharedItemStateManager.java:651) > at org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:150) > at org.apache.jackrabbit.core.TransactionContext.prepare(Transa ctionContext.java:128) > - locked <0x1156f558> (a org.apache.jackrabbit.core.TransactionContext) > at org.apache.jackrabbit.core.XASessionImpl.prepare(XASessionIm pl.java:300) > at com.oyster.mom.contentserver.jcr.transaction.JackrabbitUserT ransaction.commit(JackrabbitUserTransaction.java:102) > at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. run(JrTestDeadlock.java:97) > "IndexMerger" daemon prio=5 tid=0x030388b8 nid=0x1858 in Object.wait() [34df000..34dfd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114fd280> (a org.apache.commons.collections.buffer.BlockingBuffer) > at java.lang.Object.wait(Object.java:429) > at org.apache.commons.collections.buffer.BlockingBuffer.remove( BlockingBuffer.java:107) > - locked <0x114fd280> (a org.apache.commons.collections.buffer.BlockingBuffer) > at org.apache.jackrabbit.core.query.lucene.IndexMerger.run(Inde xMerger.java:235) > "Thread-2" daemon prio=5 tid=0x0303a230 nid=0xe4c in Object.wait() [349f000..349fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114fd2e0> (a java.util.TaskQueue) > at java.util.TimerThread.mainLoop(Timer.java:429) > - locked <0x114fd2e0> (a java.util.TaskQueue) > at java.util.TimerThread.run(Timer.java:382) > "Thread-1" daemon prio=5 tid=0x0301b7a0 nid=0x1a00 in Object.wait() [345f000..345fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114f9058> (a java.util.TaskQueue) > at java.lang.Object.wait(Object.java:429) > at java.util.TimerThread.mainLoop(Timer.java:403) > - locked <0x114f9058> (a java.util.TaskQueue) > at java.util.TimerThread.run(Timer.java:382) > "ObservationManager" daemon prio=5 tid=0x02ef6c50 nid=0x10d8 in Object.wait() [341f000..341fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114f38e0> (a org.apache.commons.collections.buffer.BlockingBuffer) > at java.lang.Object.wait(Object.java:429) > at org.apache.commons.collections.buffer.BlockingBuffer.remove( BlockingBuffer.java:107) > - locked <0x114f38e0> (a org.apache.commons.collections.buffer.BlockingBuffer) > at org.apache.jackrabbit.core.observation.ObservationManagerFac tory.run(ObservationManagerFactory.java:155) > at java.lang.Thread.run(Thread.java:534) > "Signal Dispatcher" daemon prio=10 tid=0x00a05590 nid=0x1914 waiting on condition [0..0] > "Finalizer" daemon prio=9 tid=0x00a027f8 nid=0x17a4 in Object.wait() [2c9f000..2c9fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x113db118> (a java.lang.ref.ReferenceQueue$Lock) > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111) > - locked <0x113db118> (a java.lang.ref.ReferenceQueue$Lock) > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127) > at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:1 59) > "Reference Handler" daemon prio=10 tid=0x00a01478 nid=0x16d4 in Object.wait() [2c5f000..2c5fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x113db180> (a java.lang.ref.Reference$Lock) > at java.lang.Object.wait(Object.java:429) > at java.lang.ref.Reference$ReferenceHandler.run(Reference.java: 115) > - locked <0x113db180> (a java.lang.ref.Reference$Lock) > "main" prio=5 tid=0x0003e6f0 nid=0x1470 in Object.wait() [7f000..7fc38] > at java.lang.Object.wait(Native Method) > - waiting on <0x11524f10> (a com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock) > at java.lang.Thread.join(Thread.java:1001) > - locked <0x11524f10> (a com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock) > at java.lang.Thread.join(Thread.java:1054) > at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. main(JrTestDeadlock.java:33) > "VM Thread" prio=5 tid=0x00a42730 nid=0x17d0 runnable > "VM Periodic Task Thread" prio=10 tid=0x00a45540 nid=0x1928 waiting on condition > "Suspend Checker Thread" prio=10 tid=0x00a04af8 nid=0x17ac runnable > import javax.jcr.Node; > import javax.jcr.RepositoryException; > import javax.jcr.Session; > import javax.jcr.SimpleCredentials; > import org.apache.jackrabbit.core.RepositoryImpl; > import org.apache.jackrabbit.core.config.RepositoryConfig; > public class JrTestDeadlock extends Thread { > private static final org.apache.commons.logging.Log log = org.apache.commons.logging.LogFactory.getLog(JrTestDeadlock. class); > public static String REPOSITORY_HOME = "d:/repo/jackrabbit/"; > public static String REPOSITORY_CONFIG = REPOSITORY_HOME + "repository.xml"; > public static void main(String[] args) throws Exception { > JrTestDeadlock test = new JrTestDeadlock(-1); > test.startup(); > JrTestDeadlock tests[] = new JrTestDeadlock[2]; > for (int i = 0; i < tests.length; i++) { > JrTestDeadlock x = new JrTestDeadlock(i); > x.start(); > tests[i] = x; > } > for (int i = 0; i < tests.length; i++) { > tests[i].join(); > } > test.shutdown(); > } > private static RepositoryImpl repository; > private int id; > public JrTestDeadlock(int i) { > this.id = i; > } > public void startup() throws Exception { > System.setProperty("java.security.auth.login.config&q uot;, "c:/jaas.config"); > RepositoryConfig config = RepositoryConfig.create(REPOSITORY_CONFIG, REPOSITORY_HOME); > repository = RepositoryImpl.create(config); > Session session = repository.login(new SimpleCredentials("admin", "admin".toCharArray())); > Node rootNode = session.getRootNode(); > if (!rootNode.hasNode("folder")) { > Node folder = rootNode.addNode("folder"); > folder.addMixin("mix:versionable"); > folder.addMixin("mix:lockable"); > rootNode.save(); > } > session.logout(); > } > public void shutdown() throws RepositoryException { > repository.shutdown(); > } > public Node getFolder(Session session) throws RepositoryException { > return session.getRootNode().getNode("folder"); > } > public void run() { > try { > Session session = repository.login(new SimpleCredentials("admin", "admin".toCharArray())); > for (int i = 0; i < 100; i++) { > log.error("START id:" + id + ", i=" + i); > boolean success = false; > JackrabbitUserTransaction ut = new JackrabbitUserTransaction(session); > try { > ut.begin(); > Node folder = getFolder(session); > folder.checkout(); > folder.checkin(); > success = true; > log.info("SUCCESS id:" + id + ", i=" + i); > } > catch (Exception e) { > log.warn("FAIL:" + id + ", i=" + i, e); > } > finally { > try { > if (success) { > ut.commit(); > } > else { > ut.rollback(); > } > } > catch (Exception e) { > log.fatal(e); > } > } > } > session.logout(); > } > catch (RepositoryException e) { > e.printStackTrace(); > } > } > } > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:0, i=0 > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=0 > 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:0, i=0 > 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:1, i=0 > 13:46 ERROR org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:156) - org.apache.jackrabbit.core.state.StaleItemStateException: 233e656f-79f8-414d-9e37-3fce865b492d/{http://www.jcp.org/jcr/1.0 }isCheckedOut has been modified externally > 13:46 FATAL JrTestDeadlock.run(JrTestDeadlock.java:104) - javax.transaction.RollbackException: Transaction rolled back: XA_ERR=104 > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=1 > 13:46 WARN JrTestDeadlock.run(JrTestDeadlock.java:92) - FAIL:1, i=1 > ax.jcr.InvalidItemStateException: f83a830b-abbf-4ab2-8625-b9e2c4802316: the item does not exist anymore > at org.apache.jackrabbit.core.version.XAVersion.sanityCheck(XAV ersion.java:81) > at org.apache.jackrabbit.core.version.XAVersion.getInternalVers ion(XAVersion.java:70) > at org.apache.jackrabbit.core.version.AbstractVersion.getUUID(A bstractVersion.java:107) > at org.apache.jackrabbit.core.NodeImpl.checkout(NodeImpl.java:2 759) > at JrTestDeadlock.run(JrTestDeadlock.java:85) > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=2 > 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:1, i=2 > 13:51 WARN org.apache.jackrabbit.core.TransactionContext.run(Transactio nContext.java:239) - Transaction rolled back because timeout expired. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://issues.apache.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atl assian.com/software/jira

Commented: (JCR-335) Deadlock caused by versioning operations within transaction
	2006-03-08 07:17:56
[ http://issues.apache.org/jira/browse/J CR-335?page=comments#action_12369406 ] Dominique Pfister commented on JCR-335: --------------------------------------- Yes, I think this would be safe, since code related to transactions did not change for some time. > Deadlock caused by versioning operations within transaction > ----------------------------------------------------------- > > Key: JCR-335 > URL: http://i ssues.apache.org/jira/browse/JCR-335 > Project: Jackrabbit > Type: Bug > Components: versioning > Versions: 0.9 > Environment: r383887 > Reporter: Tobias Bocanegra > Assignee: Dominique Pfister > Fix For: 1.1 > > Deadlock occurs, while running a very simple test, which is just trying > to checkout/checkin node within transaction concurrently from 2 threads. > Find enclosed thread dump, log and simple Java program. > I'm using UserTransaction implementation from jackrabbit test suite. > Regards > Przemo Pakulski > www.cognifide.com > Full thread dump Java HotSpot(TM) Client VM (1.4.2_08-b03 mixed mode): > "Thread-5" prio=5 tid=0x03054c48 nid=0x180c in Object.wait() [355f000..355fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at java.lang.Object.wait(Object.java:429) > at EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock.acquire(Unknown Source) > - locked <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acqu ireWriteLock(SharedItemStateManager.java:1137) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acce ss$200(SharedItemStateManager.java:110) > at org.apache.jackrabbit.core.state.SharedItemStateManager$Upda te.begin(SharedItemStateManager.java:456) > at org.apache.jackrabbit.core.state.SharedItemStateManager.begi nUpdate(SharedItemStateManager.java:651) > at org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:150) > at org.apache.jackrabbit.core.TransactionContext.prepare(Transa ctionContext.java:128) > - locked <0x11565ac8> (a org.apache.jackrabbit.core.TransactionContext) > at org.apache.jackrabbit.core.XASessionImpl.prepare(XASessionIm pl.java:300) > at com.oyster.mom.contentserver.jcr.transaction.JackrabbitUserT ransaction.commit(JackrabbitUserTransaction.java:102) > at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. run(JrTestDeadlock.java:97) > "Thread-4" prio=5 tid=0x0303b348 nid=0x9d0 in Object.wait() [351f000..351fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at java.lang.Object.wait(Object.java:429) > at EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock.acquire(Unknown Source) > - locked <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acqu ireWriteLock(SharedItemStateManager.java:1137) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acce ss$200(SharedItemStateManager.java:110) > at org.apache.jackrabbit.core.state.SharedItemStateManager$Upda te.begin(SharedItemStateManager.java:456) > at org.apache.jackrabbit.core.state.SharedItemStateManager.begi nUpdate(SharedItemStateManager.java:651) > at org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:150) > at org.apache.jackrabbit.core.TransactionContext.prepare(Transa ctionContext.java:128) > - locked <0x1156f558> (a org.apache.jackrabbit.core.TransactionContext) > at org.apache.jackrabbit.core.XASessionImpl.prepare(XASessionIm pl.java:300) > at com.oyster.mom.contentserver.jcr.transaction.JackrabbitUserT ransaction.commit(JackrabbitUserTransaction.java:102) > at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. run(JrTestDeadlock.java:97) > "IndexMerger" daemon prio=5 tid=0x030388b8 nid=0x1858 in Object.wait() [34df000..34dfd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114fd280> (a org.apache.commons.collections.buffer.BlockingBuffer) > at java.lang.Object.wait(Object.java:429) > at org.apache.commons.collections.buffer.BlockingBuffer.remove( BlockingBuffer.java:107) > - locked <0x114fd280> (a org.apache.commons.collections.buffer.BlockingBuffer) > at org.apache.jackrabbit.core.query.lucene.IndexMerger.run(Inde xMerger.java:235) > "Thread-2" daemon prio=5 tid=0x0303a230 nid=0xe4c in Object.wait() [349f000..349fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114fd2e0> (a java.util.TaskQueue) > at java.util.TimerThread.mainLoop(Timer.java:429) > - locked <0x114fd2e0> (a java.util.TaskQueue) > at java.util.TimerThread.run(Timer.java:382) > "Thread-1" daemon prio=5 tid=0x0301b7a0 nid=0x1a00 in Object.wait() [345f000..345fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114f9058> (a java.util.TaskQueue) > at java.lang.Object.wait(Object.java:429) > at java.util.TimerThread.mainLoop(Timer.java:403) > - locked <0x114f9058> (a java.util.TaskQueue) > at java.util.TimerThread.run(Timer.java:382) > "ObservationManager" daemon prio=5 tid=0x02ef6c50 nid=0x10d8 in Object.wait() [341f000..341fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114f38e0> (a org.apache.commons.collections.buffer.BlockingBuffer) > at java.lang.Object.wait(Object.java:429) > at org.apache.commons.collections.buffer.BlockingBuffer.remove( BlockingBuffer.java:107) > - locked <0x114f38e0> (a org.apache.commons.collections.buffer.BlockingBuffer) > at org.apache.jackrabbit.core.observation.ObservationManagerFac tory.run(ObservationManagerFactory.java:155) > at java.lang.Thread.run(Thread.java:534) > "Signal Dispatcher" daemon prio=10 tid=0x00a05590 nid=0x1914 waiting on condition [0..0] > "Finalizer" daemon prio=9 tid=0x00a027f8 nid=0x17a4 in Object.wait() [2c9f000..2c9fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x113db118> (a java.lang.ref.ReferenceQueue$Lock) > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111) > - locked <0x113db118> (a java.lang.ref.ReferenceQueue$Lock) > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127) > at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:1 59) > "Reference Handler" daemon prio=10 tid=0x00a01478 nid=0x16d4 in Object.wait() [2c5f000..2c5fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x113db180> (a java.lang.ref.Reference$Lock) > at java.lang.Object.wait(Object.java:429) > at java.lang.ref.Reference$ReferenceHandler.run(Reference.java: 115) > - locked <0x113db180> (a java.lang.ref.Reference$Lock) > "main" prio=5 tid=0x0003e6f0 nid=0x1470 in Object.wait() [7f000..7fc38] > at java.lang.Object.wait(Native Method) > - waiting on <0x11524f10> (a com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock) > at java.lang.Thread.join(Thread.java:1001) > - locked <0x11524f10> (a com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock) > at java.lang.Thread.join(Thread.java:1054) > at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. main(JrTestDeadlock.java:33) > "VM Thread" prio=5 tid=0x00a42730 nid=0x17d0 runnable > "VM Periodic Task Thread" prio=10 tid=0x00a45540 nid=0x1928 waiting on condition > "Suspend Checker Thread" prio=10 tid=0x00a04af8 nid=0x17ac runnable > import javax.jcr.Node; > import javax.jcr.RepositoryException; > import javax.jcr.Session; > import javax.jcr.SimpleCredentials; > import org.apache.jackrabbit.core.RepositoryImpl; > import org.apache.jackrabbit.core.config.RepositoryConfig; > public class JrTestDeadlock extends Thread { > private static final org.apache.commons.logging.Log log = org.apache.commons.logging.LogFactory.getLog(JrTestDeadlock. class); > public static String REPOSITORY_HOME = "d:/repo/jackrabbit/"; > public static String REPOSITORY_CONFIG = REPOSITORY_HOME + "repository.xml"; > public static void main(String[] args) throws Exception { > JrTestDeadlock test = new JrTestDeadlock(-1); > test.startup(); > JrTestDeadlock tests[] = new JrTestDeadlock[2]; > for (int i = 0; i < tests.length; i++) { > JrTestDeadlock x = new JrTestDeadlock(i); > x.start(); > tests[i] = x; > } > for (int i = 0; i < tests.length; i++) { > tests[i].join(); > } > test.shutdown(); > } > private static RepositoryImpl repository; > private int id; > public JrTestDeadlock(int i) { > this.id = i; > } > public void startup() throws Exception { > System.setProperty("java.security.auth.login.config&q uot;, "c:/jaas.config"); > RepositoryConfig config = RepositoryConfig.create(REPOSITORY_CONFIG, REPOSITORY_HOME); > repository = RepositoryImpl.create(config); > Session session = repository.login(new SimpleCredentials("admin", "admin".toCharArray())); > Node rootNode = session.getRootNode(); > if (!rootNode.hasNode("folder")) { > Node folder = rootNode.addNode("folder"); > folder.addMixin("mix:versionable"); > folder.addMixin("mix:lockable"); > rootNode.save(); > } > session.logout(); > } > public void shutdown() throws RepositoryException { > repository.shutdown(); > } > public Node getFolder(Session session) throws RepositoryException { > return session.getRootNode().getNode("folder"); > } > public void run() { > try { > Session session = repository.login(new SimpleCredentials("admin", "admin".toCharArray())); > for (int i = 0; i < 100; i++) { > log.error("START id:" + id + ", i=" + i); > boolean success = false; > JackrabbitUserTransaction ut = new JackrabbitUserTransaction(session); > try { > ut.begin(); > Node folder = getFolder(session); > folder.checkout(); > folder.checkin(); > success = true; > log.info("SUCCESS id:" + id + ", i=" + i); > } > catch (Exception e) { > log.warn("FAIL:" + id + ", i=" + i, e); > } > finally { > try { > if (success) { > ut.commit(); > } > else { > ut.rollback(); > } > } > catch (Exception e) { > log.fatal(e); > } > } > } > session.logout(); > } > catch (RepositoryException e) { > e.printStackTrace(); > } > } > } > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:0, i=0 > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=0 > 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:0, i=0 > 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:1, i=0 > 13:46 ERROR org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:156) - org.apache.jackrabbit.core.state.StaleItemStateException: 233e656f-79f8-414d-9e37-3fce865b492d/{http://www.jcp.org/jcr/1.0 }isCheckedOut has been modified externally > 13:46 FATAL JrTestDeadlock.run(JrTestDeadlock.java:104) - javax.transaction.RollbackException: Transaction rolled back: XA_ERR=104 > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=1 > 13:46 WARN JrTestDeadlock.run(JrTestDeadlock.java:92) - FAIL:1, i=1 > ax.jcr.InvalidItemStateException: f83a830b-abbf-4ab2-8625-b9e2c4802316: the item does not exist anymore > at org.apache.jackrabbit.core.version.XAVersion.sanityCheck(XAV ersion.java:81) > at org.apache.jackrabbit.core.version.XAVersion.getInternalVers ion(XAVersion.java:70) > at org.apache.jackrabbit.core.version.AbstractVersion.getUUID(A bstractVersion.java:107) > at org.apache.jackrabbit.core.NodeImpl.checkout(NodeImpl.java:2 759) > at JrTestDeadlock.run(JrTestDeadlock.java:85) > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=2 > 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:1, i=2 > 13:51 WARN org.apache.jackrabbit.core.TransactionContext.run(Transactio nContext.java:239) - Transaction rolled back because timeout expired. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://issues.apache.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atl assian.com/software/jira

Reopened: (JCR-335) Deadlock caused by versioning operations within transaction
	2006-03-08 20:35:39
[ http://issues.apache.org/jira/browse/JCR-335?page=all ] Jukka Zitting reopened JCR-335: ------------------------------- > Deadlock caused by versioning operations within transaction > ----------------------------------------------------------- > > Key: JCR-335 > URL: http://i ssues.apache.org/jira/browse/JCR-335 > Project: Jackrabbit > Type: Bug > Components: versioning > Versions: 0.9 > Environment: r383887 > Reporter: Tobias Bocanegra > Assignee: Dominique Pfister > Fix For: 1.0 > > Deadlock occurs, while running a very simple test, which is just trying > to checkout/checkin node within transaction concurrently from 2 threads. > Find enclosed thread dump, log and simple Java program. > I'm using UserTransaction implementation from jackrabbit test suite. > Regards > Przemo Pakulski > www.cognifide.com > Full thread dump Java HotSpot(TM) Client VM (1.4.2_08-b03 mixed mode): > "Thread-5" prio=5 tid=0x03054c48 nid=0x180c in Object.wait() [355f000..355fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at java.lang.Object.wait(Object.java:429) > at EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock.acquire(Unknown Source) > - locked <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acqu ireWriteLock(SharedItemStateManager.java:1137) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acce ss$200(SharedItemStateManager.java:110) > at org.apache.jackrabbit.core.state.SharedItemStateManager$Upda te.begin(SharedItemStateManager.java:456) > at org.apache.jackrabbit.core.state.SharedItemStateManager.begi nUpdate(SharedItemStateManager.java:651) > at org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:150) > at org.apache.jackrabbit.core.TransactionContext.prepare(Transa ctionContext.java:128) > - locked <0x11565ac8> (a org.apache.jackrabbit.core.TransactionContext) > at org.apache.jackrabbit.core.XASessionImpl.prepare(XASessionIm pl.java:300) > at com.oyster.mom.contentserver.jcr.transaction.JackrabbitUserT ransaction.commit(JackrabbitUserTransaction.java:102) > at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. run(JrTestDeadlock.java:97) > "Thread-4" prio=5 tid=0x0303b348 nid=0x9d0 in Object.wait() [351f000..351fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at java.lang.Object.wait(Object.java:429) > at EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock.acquire(Unknown Source) > - locked <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acqu ireWriteLock(SharedItemStateManager.java:1137) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acce ss$200(SharedItemStateManager.java:110) > at org.apache.jackrabbit.core.state.SharedItemStateManager$Upda te.begin(SharedItemStateManager.java:456) > at org.apache.jackrabbit.core.state.SharedItemStateManager.begi nUpdate(SharedItemStateManager.java:651) > at org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:150) > at org.apache.jackrabbit.core.TransactionContext.prepare(Transa ctionContext.java:128) > - locked <0x1156f558> (a org.apache.jackrabbit.core.TransactionContext) > at org.apache.jackrabbit.core.XASessionImpl.prepare(XASessionIm pl.java:300) > at com.oyster.mom.contentserver.jcr.transaction.JackrabbitUserT ransaction.commit(JackrabbitUserTransaction.java:102) > at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. run(JrTestDeadlock.java:97) > "IndexMerger" daemon prio=5 tid=0x030388b8 nid=0x1858 in Object.wait() [34df000..34dfd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114fd280> (a org.apache.commons.collections.buffer.BlockingBuffer) > at java.lang.Object.wait(Object.java:429) > at org.apache.commons.collections.buffer.BlockingBuffer.remove( BlockingBuffer.java:107) > - locked <0x114fd280> (a org.apache.commons.collections.buffer.BlockingBuffer) > at org.apache.jackrabbit.core.query.lucene.IndexMerger.run(Inde xMerger.java:235) > "Thread-2" daemon prio=5 tid=0x0303a230 nid=0xe4c in Object.wait() [349f000..349fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114fd2e0> (a java.util.TaskQueue) > at java.util.TimerThread.mainLoop(Timer.java:429) > - locked <0x114fd2e0> (a java.util.TaskQueue) > at java.util.TimerThread.run(Timer.java:382) > "Thread-1" daemon prio=5 tid=0x0301b7a0 nid=0x1a00 in Object.wait() [345f000..345fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114f9058> (a java.util.TaskQueue) > at java.lang.Object.wait(Object.java:429) > at java.util.TimerThread.mainLoop(Timer.java:403) > - locked <0x114f9058> (a java.util.TaskQueue) > at java.util.TimerThread.run(Timer.java:382) > "ObservationManager" daemon prio=5 tid=0x02ef6c50 nid=0x10d8 in Object.wait() [341f000..341fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114f38e0> (a org.apache.commons.collections.buffer.BlockingBuffer) > at java.lang.Object.wait(Object.java:429) > at org.apache.commons.collections.buffer.BlockingBuffer.remove( BlockingBuffer.java:107) > - locked <0x114f38e0> (a org.apache.commons.collections.buffer.BlockingBuffer) > at org.apache.jackrabbit.core.observation.ObservationManagerFac tory.run(ObservationManagerFactory.java:155) > at java.lang.Thread.run(Thread.java:534) > "Signal Dispatcher" daemon prio=10 tid=0x00a05590 nid=0x1914 waiting on condition [0..0] > "Finalizer" daemon prio=9 tid=0x00a027f8 nid=0x17a4 in Object.wait() [2c9f000..2c9fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x113db118> (a java.lang.ref.ReferenceQueue$Lock) > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111) > - locked <0x113db118> (a java.lang.ref.ReferenceQueue$Lock) > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127) > at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:1 59) > "Reference Handler" daemon prio=10 tid=0x00a01478 nid=0x16d4 in Object.wait() [2c5f000..2c5fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x113db180> (a java.lang.ref.Reference$Lock) > at java.lang.Object.wait(Object.java:429) > at java.lang.ref.Reference$ReferenceHandler.run(Reference.java: 115) > - locked <0x113db180> (a java.lang.ref.Reference$Lock) > "main" prio=5 tid=0x0003e6f0 nid=0x1470 in Object.wait() [7f000..7fc38] > at java.lang.Object.wait(Native Method) > - waiting on <0x11524f10> (a com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock) > at java.lang.Thread.join(Thread.java:1001) > - locked <0x11524f10> (a com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock) > at java.lang.Thread.join(Thread.java:1054) > at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. main(JrTestDeadlock.java:33) > "VM Thread" prio=5 tid=0x00a42730 nid=0x17d0 runnable > "VM Periodic Task Thread" prio=10 tid=0x00a45540 nid=0x1928 waiting on condition > "Suspend Checker Thread" prio=10 tid=0x00a04af8 nid=0x17ac runnable > import javax.jcr.Node; > import javax.jcr.RepositoryException; > import javax.jcr.Session; > import javax.jcr.SimpleCredentials; > import org.apache.jackrabbit.core.RepositoryImpl; > import org.apache.jackrabbit.core.config.RepositoryConfig; > public class JrTestDeadlock extends Thread { > private static final org.apache.commons.logging.Log log = org.apache.commons.logging.LogFactory.getLog(JrTestDeadlock. class); > public static String REPOSITORY_HOME = "d:/repo/jackrabbit/"; > public static String REPOSITORY_CONFIG = REPOSITORY_HOME + "repository.xml"; > public static void main(String[] args) throws Exception { > JrTestDeadlock test = new JrTestDeadlock(-1); > test.startup(); > JrTestDeadlock tests[] = new JrTestDeadlock[2]; > for (int i = 0; i < tests.length; i++) { > JrTestDeadlock x = new JrTestDeadlock(i); > x.start(); > tests[i] = x; > } > for (int i = 0; i < tests.length; i++) { > tests[i].join(); > } > test.shutdown(); > } > private static RepositoryImpl repository; > private int id; > public JrTestDeadlock(int i) { > this.id = i; > } > public void startup() throws Exception { > System.setProperty("java.security.auth.login.config&q uot;, "c:/jaas.config"); > RepositoryConfig config = RepositoryConfig.create(REPOSITORY_CONFIG, REPOSITORY_HOME); > repository = RepositoryImpl.create(config); > Session session = repository.login(new SimpleCredentials("admin", "admin".toCharArray())); > Node rootNode = session.getRootNode(); > if (!rootNode.hasNode("folder")) { > Node folder = rootNode.addNode("folder"); > folder.addMixin("mix:versionable"); > folder.addMixin("mix:lockable"); > rootNode.save(); > } > session.logout(); > } > public void shutdown() throws RepositoryException { > repository.shutdown(); > } > public Node getFolder(Session session) throws RepositoryException { > return session.getRootNode().getNode("folder"); > } > public void run() { > try { > Session session = repository.login(new SimpleCredentials("admin", "admin".toCharArray())); > for (int i = 0; i < 100; i++) { > log.error("START id:" + id + ", i=" + i); > boolean success = false; > JackrabbitUserTransaction ut = new JackrabbitUserTransaction(session); > try { > ut.begin(); > Node folder = getFolder(session); > folder.checkout(); > folder.checkin(); > success = true; > log.info("SUCCESS id:" + id + ", i=" + i); > } > catch (Exception e) { > log.warn("FAIL:" + id + ", i=" + i, e); > } > finally { > try { > if (success) { > ut.commit(); > } > else { > ut.rollback(); > } > } > catch (Exception e) { > log.fatal(e); > } > } > } > session.logout(); > } > catch (RepositoryException e) { > e.printStackTrace(); > } > } > } > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:0, i=0 > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=0 > 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:0, i=0 > 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:1, i=0 > 13:46 ERROR org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:156) - org.apache.jackrabbit.core.state.StaleItemStateException: 233e656f-79f8-414d-9e37-3fce865b492d/{http://www.jcp.org/jcr/1.0 }isCheckedOut has been modified externally > 13:46 FATAL JrTestDeadlock.run(JrTestDeadlock.java:104) - javax.transaction.RollbackException: Transaction rolled back: XA_ERR=104 > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=1 > 13:46 WARN JrTestDeadlock.run(JrTestDeadlock.java:92) - FAIL:1, i=1 > ax.jcr.InvalidItemStateException: f83a830b-abbf-4ab2-8625-b9e2c4802316: the item does not exist anymore > at org.apache.jackrabbit.core.version.XAVersion.sanityCheck(XAV ersion.java:81) > at org.apache.jackrabbit.core.version.XAVersion.getInternalVers ion(XAVersion.java:70) > at org.apache.jackrabbit.core.version.AbstractVersion.getUUID(A bstractVersion.java:107) > at org.apache.jackrabbit.core.NodeImpl.checkout(NodeImpl.java:2 759) > at JrTestDeadlock.run(JrTestDeadlock.java:85) > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=2 > 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:1, i=2 > 13:51 WARN org.apache.jackrabbit.core.TransactionContext.run(Transactio nContext.java:239) - Transaction rolled back because timeout expired. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://issues.apache.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atl assian.com/software/jira

Resolved: (JCR-335) Deadlock caused by versioning operations within transaction
	2006-03-08 20:35:41
[ http://issues.apache.org/jira/browse/JCR-335?page=all ] Jukka Zitting resolved JCR-335: ------------------------------- Fix Version: 1.0 (was: 1.1) Resolution: Fixed Applied the fix to the 1.0 branch in revision 384322. Changing fix version to 1.0. > Deadlock caused by versioning operations within transaction > ----------------------------------------------------------- > > Key: JCR-335 > URL: http://i ssues.apache.org/jira/browse/JCR-335 > Project: Jackrabbit > Type: Bug > Components: versioning > Versions: 0.9 > Environment: r383887 > Reporter: Tobias Bocanegra > Assignee: Dominique Pfister > Fix For: 1.0 > > Deadlock occurs, while running a very simple test, which is just trying > to checkout/checkin node within transaction concurrently from 2 threads. > Find enclosed thread dump, log and simple Java program. > I'm using UserTransaction implementation from jackrabbit test suite. > Regards > Przemo Pakulski > www.cognifide.com > Full thread dump Java HotSpot(TM) Client VM (1.4.2_08-b03 mixed mode): > "Thread-5" prio=5 tid=0x03054c48 nid=0x180c in Object.wait() [355f000..355fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at java.lang.Object.wait(Object.java:429) > at EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock.acquire(Unknown Source) > - locked <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acqu ireWriteLock(SharedItemStateManager.java:1137) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acce ss$200(SharedItemStateManager.java:110) > at org.apache.jackrabbit.core.state.SharedItemStateManager$Upda te.begin(SharedItemStateManager.java:456) > at org.apache.jackrabbit.core.state.SharedItemStateManager.begi nUpdate(SharedItemStateManager.java:651) > at org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:150) > at org.apache.jackrabbit.core.TransactionContext.prepare(Transa ctionContext.java:128) > - locked <0x11565ac8> (a org.apache.jackrabbit.core.TransactionContext) > at org.apache.jackrabbit.core.XASessionImpl.prepare(XASessionIm pl.java:300) > at com.oyster.mom.contentserver.jcr.transaction.JackrabbitUserT ransaction.commit(JackrabbitUserTransaction.java:102) > at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. run(JrTestDeadlock.java:97) > "Thread-4" prio=5 tid=0x0303b348 nid=0x9d0 in Object.wait() [351f000..351fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at java.lang.Object.wait(Object.java:429) > at EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock.acquire(Unknown Source) > - locked <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acqu ireWriteLock(SharedItemStateManager.java:1137) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acce ss$200(SharedItemStateManager.java:110) > at org.apache.jackrabbit.core.state.SharedItemStateManager$Upda te.begin(SharedItemStateManager.java:456) > at org.apache.jackrabbit.core.state.SharedItemStateManager.begi nUpdate(SharedItemStateManager.java:651) > at org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:150) > at org.apache.jackrabbit.core.TransactionContext.prepare(Transa ctionContext.java:128) > - locked <0x1156f558> (a org.apache.jackrabbit.core.TransactionContext) > at org.apache.jackrabbit.core.XASessionImpl.prepare(XASessionIm pl.java:300) > at com.oyster.mom.contentserver.jcr.transaction.JackrabbitUserT ransaction.commit(JackrabbitUserTransaction.java:102) > at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. run(JrTestDeadlock.java:97) > "IndexMerger" daemon prio=5 tid=0x030388b8 nid=0x1858 in Object.wait() [34df000..34dfd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114fd280> (a org.apache.commons.collections.buffer.BlockingBuffer) > at java.lang.Object.wait(Object.java:429) > at org.apache.commons.collections.buffer.BlockingBuffer.remove( BlockingBuffer.java:107) > - locked <0x114fd280> (a org.apache.commons.collections.buffer.BlockingBuffer) > at org.apache.jackrabbit.core.query.lucene.IndexMerger.run(Inde xMerger.java:235) > "Thread-2" daemon prio=5 tid=0x0303a230 nid=0xe4c in Object.wait() [349f000..349fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114fd2e0> (a java.util.TaskQueue) > at java.util.TimerThread.mainLoop(Timer.java:429) > - locked <0x114fd2e0> (a java.util.TaskQueue) > at java.util.TimerThread.run(Timer.java:382) > "Thread-1" daemon prio=5 tid=0x0301b7a0 nid=0x1a00 in Object.wait() [345f000..345fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114f9058> (a java.util.TaskQueue) > at java.lang.Object.wait(Object.java:429) > at java.util.TimerThread.mainLoop(Timer.java:403) > - locked <0x114f9058> (a java.util.TaskQueue) > at java.util.TimerThread.run(Timer.java:382) > "ObservationManager" daemon prio=5 tid=0x02ef6c50 nid=0x10d8 in Object.wait() [341f000..341fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114f38e0> (a org.apache.commons.collections.buffer.BlockingBuffer) > at java.lang.Object.wait(Object.java:429) > at org.apache.commons.collections.buffer.BlockingBuffer.remove( BlockingBuffer.java:107) > - locked <0x114f38e0> (a org.apache.commons.collections.buffer.BlockingBuffer) > at org.apache.jackrabbit.core.observation.ObservationManagerFac tory.run(ObservationManagerFactory.java:155) > at java.lang.Thread.run(Thread.java:534) > "Signal Dispatcher" daemon prio=10 tid=0x00a05590 nid=0x1914 waiting on condition [0..0] > "Finalizer" daemon prio=9 tid=0x00a027f8 nid=0x17a4 in Object.wait() [2c9f000..2c9fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x113db118> (a java.lang.ref.ReferenceQueue$Lock) > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111) > - locked <0x113db118> (a java.lang.ref.ReferenceQueue$Lock) > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127) > at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:1 59) > "Reference Handler" daemon prio=10 tid=0x00a01478 nid=0x16d4 in Object.wait() [2c5f000..2c5fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x113db180> (a java.lang.ref.Reference$Lock) > at java.lang.Object.wait(Object.java:429) > at java.lang.ref.Reference$ReferenceHandler.run(Reference.java: 115) > - locked <0x113db180> (a java.lang.ref.Reference$Lock) > "main" prio=5 tid=0x0003e6f0 nid=0x1470 in Object.wait() [7f000..7fc38] > at java.lang.Object.wait(Native Method) > - waiting on <0x11524f10> (a com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock) > at java.lang.Thread.join(Thread.java:1001) > - locked <0x11524f10> (a com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock) > at java.lang.Thread.join(Thread.java:1054) > at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. main(JrTestDeadlock.java:33) > "VM Thread" prio=5 tid=0x00a42730 nid=0x17d0 runnable > "VM Periodic Task Thread" prio=10 tid=0x00a45540 nid=0x1928 waiting on condition > "Suspend Checker Thread" prio=10 tid=0x00a04af8 nid=0x17ac runnable > import javax.jcr.Node; > import javax.jcr.RepositoryException; > import javax.jcr.Session; > import javax.jcr.SimpleCredentials; > import org.apache.jackrabbit.core.RepositoryImpl; > import org.apache.jackrabbit.core.config.RepositoryConfig; > public class JrTestDeadlock extends Thread { > private static final org.apache.commons.logging.Log log = org.apache.commons.logging.LogFactory.getLog(JrTestDeadlock. class); > public static String REPOSITORY_HOME = "d:/repo/jackrabbit/"; > public static String REPOSITORY_CONFIG = REPOSITORY_HOME + "repository.xml"; > public static void main(String[] args) throws Exception { > JrTestDeadlock test = new JrTestDeadlock(-1); > test.startup(); > JrTestDeadlock tests[] = new JrTestDeadlock[2]; > for (int i = 0; i < tests.length; i++) { > JrTestDeadlock x = new JrTestDeadlock(i); > x.start(); > tests[i] = x; > } > for (int i = 0; i < tests.length; i++) { > tests[i].join(); > } > test.shutdown(); > } > private static RepositoryImpl repository; > private int id; > public JrTestDeadlock(int i) { > this.id = i; > } > public void startup() throws Exception { > System.setProperty("java.security.auth.login.config&q uot;, "c:/jaas.config"); > RepositoryConfig config = RepositoryConfig.create(REPOSITORY_CONFIG, REPOSITORY_HOME); > repository = RepositoryImpl.create(config); > Session session = repository.login(new SimpleCredentials("admin", "admin".toCharArray())); > Node rootNode = session.getRootNode(); > if (!rootNode.hasNode("folder")) { > Node folder = rootNode.addNode("folder"); > folder.addMixin("mix:versionable"); > folder.addMixin("mix:lockable"); > rootNode.save(); > } > session.logout(); > } > public void shutdown() throws RepositoryException { > repository.shutdown(); > } > public Node getFolder(Session session) throws RepositoryException { > return session.getRootNode().getNode("folder"); > } > public void run() { > try { > Session session = repository.login(new SimpleCredentials("admin", "admin".toCharArray())); > for (int i = 0; i < 100; i++) { > log.error("START id:" + id + ", i=" + i); > boolean success = false; > JackrabbitUserTransaction ut = new JackrabbitUserTransaction(session); > try { > ut.begin(); > Node folder = getFolder(session); > folder.checkout(); > folder.checkin(); > success = true; > log.info("SUCCESS id:" + id + ", i=" + i); > } > catch (Exception e) { > log.warn("FAIL:" + id + ", i=" + i, e); > } > finally { > try { > if (success) { > ut.commit(); > } > else { > ut.rollback(); > } > } > catch (Exception e) { > log.fatal(e); > } > } > } > session.logout(); > } > catch (RepositoryException e) { > e.printStackTrace(); > } > } > } > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:0, i=0 > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=0 > 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:0, i=0 > 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:1, i=0 > 13:46 ERROR org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:156) - org.apache.jackrabbit.core.state.StaleItemStateException: 233e656f-79f8-414d-9e37-3fce865b492d/{http://www.jcp.org/jcr/1.0 }isCheckedOut has been modified externally > 13:46 FATAL JrTestDeadlock.run(JrTestDeadlock.java:104) - javax.transaction.RollbackException: Transaction rolled back: XA_ERR=104 > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=1 > 13:46 WARN JrTestDeadlock.run(JrTestDeadlock.java:92) - FAIL:1, i=1 > ax.jcr.InvalidItemStateException: f83a830b-abbf-4ab2-8625-b9e2c4802316: the item does not exist anymore > at org.apache.jackrabbit.core.version.XAVersion.sanityCheck(XAV ersion.java:81) > at org.apache.jackrabbit.core.version.XAVersion.getInternalVers ion(XAVersion.java:70) > at org.apache.jackrabbit.core.version.AbstractVersion.getUUID(A bstractVersion.java:107) > at org.apache.jackrabbit.core.NodeImpl.checkout(NodeImpl.java:2 759) > at JrTestDeadlock.run(JrTestDeadlock.java:85) > 13:46 ERROR JrTestDeadlock.run(JrTestDeadlock.java:76) - START id:1, i=2 > 13:46 INFO JrTestDeadlock.run(JrTestDeadlock.java:89) - SUCCESS id:1, i=2 > 13:51 WARN org.apache.jackrabbit.core.TransactionContext.run(Transactio nContext.java:239) - Transaction rolled back because timeout expired. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://issues.apache.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atl assian.com/software/jira

Updated: (JCR-335) Deadlock caused by versioning operations within transaction
	2006-03-09 16:38:16
[ http://issues.apache.org/jira/browse/JCR-335?page=all ] Przemysław Pakulski updated JCR-335: ------------------------------------ Attachment: threaddump-385412.txt Deadlock still occurs in r385412 > Deadlock caused by versioning operations within transaction > ----------------------------------------------------------- > > Key: JCR-335 > URL: http://i ssues.apache.org/jira/browse/JCR-335 > Project: Jackrabbit > Type: Bug > Components: versioning > Versions: 0.9 > Environment: r383887 > Reporter: Tobias Bocanegra > Assignee: Dominique Pfister > Fix For: 1.0 > Attachments: threaddump-385412.txt > > Deadlock occurs, while running a very simple test, which is just trying > to checkout/checkin node within transaction concurrently from 2 threads. > Find enclosed thread dump, log and simple Java program. > I'm using UserTransaction implementation from jackrabbit test suite. > Regards > Przemo Pakulski > www.cognifide.com > Full thread dump Java HotSpot(TM) Client VM (1.4.2_08-b03 mixed mode): > "Thread-5" prio=5 tid=0x03054c48 nid=0x180c in Object.wait() [355f000..355fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at java.lang.Object.wait(Object.java:429) > at EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock.acquire(Unknown Source) > - locked <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acqu ireWriteLock(SharedItemStateManager.java:1137) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acce ss$200(SharedItemStateManager.java:110) > at org.apache.jackrabbit.core.state.SharedItemStateManager$Upda te.begin(SharedItemStateManager.java:456) > at org.apache.jackrabbit.core.state.SharedItemStateManager.begi nUpdate(SharedItemStateManager.java:651) > at org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:150) > at org.apache.jackrabbit.core.TransactionContext.prepare(Transa ctionContext.java:128) > - locked <0x11565ac8> (a org.apache.jackrabbit.core.TransactionContext) > at org.apache.jackrabbit.core.XASessionImpl.prepare(XASessionIm pl.java:300) > at com.oyster.mom.contentserver.jcr.transaction.JackrabbitUserT ransaction.commit(JackrabbitUserTransaction.java:102) > at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. run(JrTestDeadlock.java:97) > "Thread-4" prio=5 tid=0x0303b348 nid=0x9d0 in Object.wait() [351f000..351fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at java.lang.Object.wait(Object.java:429) > at EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock.acquire(Unknown Source) > - locked <0x1148ef20> (a EDU.oswego.cs.dl.util.concurrent.WriterPreferenceReadWriteLo ck$WriterLock) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acqu ireWriteLock(SharedItemStateManager.java:1137) > at org.apache.jackrabbit.core.state.SharedItemStateManager.acce ss$200(SharedItemStateManager.java:110) > at org.apache.jackrabbit.core.state.SharedItemStateManager$Upda te.begin(SharedItemStateManager.java:456) > at org.apache.jackrabbit.core.state.SharedItemStateManager.begi nUpdate(SharedItemStateManager.java:651) > at org.apache.jackrabbit.core.state.XAItemStateManager.prepare( XAItemStateManager.java:150) > at org.apache.jackrabbit.core.TransactionContext.prepare(Transa ctionContext.java:128) > - locked <0x1156f558> (a org.apache.jackrabbit.core.TransactionContext) > at org.apache.jackrabbit.core.XASessionImpl.prepare(XASessionIm pl.java:300) > at com.oyster.mom.contentserver.jcr.transaction.JackrabbitUserT ransaction.commit(JackrabbitUserTransaction.java:102) > at com.oyster.mom.contentserver.jcr.transaction.JrTestDeadlock. run(JrTestDeadlock.java:97) > "IndexMerger" daemon prio=5 tid=0x030388b8 nid=0x1858 in Object.wait() [34df000..34dfd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114fd280> (a org.apache.commons.collections.buffer.BlockingBuffer) > at java.lang.Object.wait(Object.java:429) > at org.apache.commons.collections.buffer.BlockingBuffer.remove( BlockingBuffer.java:107) > - locked <0x114fd280> (a org.apache.commons.collections.buffer.BlockingBuffer) > at org.apache.jackrabbit.core.query.lucene.IndexMerger.run(Inde xMerger.java:235) > "Thread-2" daemon prio=5 tid=0x0303a230 nid=0xe4c in Object.wait() [349f000..349fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114fd2e0> (a java.util.TaskQueue) > at java.util.TimerThread.mainLoop(Timer.java:429) > - locked <0x114fd2e0> (a java.util.TaskQueue) > at java.util.TimerThread.run(Timer.java:382) > "Thread-1" daemon prio=5 tid=0x0301b7a0 nid=0x1a00 in Object.wait() [345f000..345fd8c] > at java.lang.Object.wait(Native Method) > - waiting on <0x114f9058> (a java.util.TaskQueue) > at java.lang.Object.wait(Object.java:429) > at java.util.TimerThread.mainLoop(Timer.java:403) > - locked <0x114f9058> (a java.util.TaskQueue) >