[ https://issues.apache.org/jira/browse/JCR-4174?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16153237#comment-16153237 ]
modelrepoistory edited comment on JCR-4174 at 9/5/17 7:56 AM: -------------------------------------------------------------- I can reproduce this issue now. That is, say bundle table has one row, and then start two thread, one thread to delete it, and another to load it, it's very easy to reproduce the deadlock In cluster environment, it's possible that the quick node is trying to delete one existing node, while another node is just trying to load it within the sync process. public class MSSQLDeadlockTest { final static String URL = "jdbc:sqlserver://10.111.3.152:1433;DatabaseName=lcheng"; final static String USER = "sa"; final static String PASSWORD = "Asdf!234"; public static void main(String[] args) throws Exception { new MSSQLDeadlockTest().deleteBundle(); Connection conn4Delete = DriverManager.getConnection(URL, USER, PASSWORD); Connection conn4Get = DriverManager.getConnection(URL, USER, PASSWORD); for (int i = 0; i < 10000; i++) { new MSSQLDeadlockTest().insertBundle(); CountDownLatch start = new CountDownLatch(1); CountDownLatch end = new CountDownLatch(2); new Thread(new DeleteRunner(start, end, conn4Delete)).start(); new Thread(new GetRunner(start, end, conn4Get)).start(); start.countDown(); end.await(); System.out.println("loop " + i + " is completed"); } } static class DeleteRunner implements Runnable { private CountDownLatch start_; private CountDownLatch end_; private Connection conn_; public DeleteRunner(CountDownLatch start, CountDownLatch end, Connection conn) { this.start_ = start; this.end_ = end; this.conn_ = conn; } @Override public void run() { try { start_.await(); } catch (InterruptedException e1) { e1.printStackTrace(); } NodeId nodeId = NodeId.valueOf("09fa9c9b-ef26-4a26-ba21-a883ab908e29"); PreparedStatement stmt = null; ResultSet rs = null; try { stmt = conn_.prepareStatement("delete from vtjp_def_bundle2 where NODE_ID = ?"); stmt.setObject(1, nodeId.getRawBytes()); stmt.executeUpdate(); end_.countDown(); } catch (SQLException e) { e.printStackTrace(); } finally { if (rs != null) { try { rs.close(); } catch (SQLException e) { e.printStackTrace(); } } if (stmt != null) { try { stmt.close(); } catch (SQLException e) { e.printStackTrace(); } } } } } static class GetRunner implements Runnable { private CountDownLatch start_; private CountDownLatch end_; private Connection conn_; public GetRunner(CountDownLatch start, CountDownLatch end, Connection conn) { this.start_ = start; this.end_ = end; this.conn_ = conn; } @Override public void run() { try { start_.await(); } catch (InterruptedException e1) { e1.printStackTrace(); } NodeId nodeId = NodeId.valueOf("09fa9c9b-ef26-4a26-ba21-a883ab908e29"); PreparedStatement stmt = null; ResultSet rs = null; try { stmt = conn_.prepareStatement("select BUNDLE_DATA from vtjp_def_bundle2 where NODE_ID = ?"); stmt.setObject(1, nodeId.getRawBytes()); rs = stmt.executeQuery(); if (rs.next()) { byte[] content = (byte[]) rs.getObject(1); System.out.println(new String(content)); } else { System.out.println("no node"); } end_.countDown(); } catch (SQLException e) { e.printStackTrace(); } finally { if (rs != null) { try { rs.close(); } catch (SQLException e) { e.printStackTrace(); } } if (stmt != null) { try { stmt.close(); } catch (SQLException e) { e.printStackTrace(); } } } } } public void deleteBundle() throws Exception { NodeId nodeId = NodeId.valueOf("09fa9c9b-ef26-4a26-ba21-a883ab908e29"); Connection conn = null; PreparedStatement stmt = null; ResultSet rs = null; try { conn = DriverManager.getConnection(URL, USER, PASSWORD); stmt = conn.prepareStatement("delete from vtjp_def_bundle2 where NODE_ID = ?"); stmt.setObject(1, nodeId.getRawBytes()); stmt.executeUpdate(); } finally { if (rs != null) { rs.close(); } if (stmt != null) { stmt.close(); } if (conn != null) { conn.close(); } } } public void insertBundle() throws Exception { NodeId nodeId = NodeId.valueOf("09fa9c9b-ef26-4a26-ba21-a883ab908e29"); Connection conn = null; PreparedStatement stmt = null; ResultSet rs = null; try { conn = DriverManager.getConnection(URL, USER, PASSWORD); stmt = conn.prepareStatement("insert into vtjp_def_bundle2 (NODE_ID, BUNDLE_DATA) values(?, ?)"); stmt.setObject(1, nodeId.getRawBytes()); String content = "hello world"; stmt.setObject(2, content.getBytes()); stmt.executeUpdate(); } finally { if (rs != null) { rs.close(); } if (stmt != null) { stmt.close(); } if (conn != null) { conn.close(); } } } } was (Author: modelrepository): I can reproduce this issue now. public class MSSQLDeadlockTest { final static String URL = "jdbc:sqlserver://10.111.3.152:1433;DatabaseName=lcheng"; final static String USER = "sa"; final static String PASSWORD = "Asdf!234"; public static void main(String[] args) throws Exception { new MSSQLDeadlockTest().deleteBundle(); Connection conn4Delete = DriverManager.getConnection(URL, USER, PASSWORD); Connection conn4Get = DriverManager.getConnection(URL, USER, PASSWORD); for (int i = 0; i < 10000; i++) { new MSSQLDeadlockTest().insertBundle(); CountDownLatch start = new CountDownLatch(1); CountDownLatch end = new CountDownLatch(2); new Thread(new DeleteRunner(start, end, conn4Delete)).start(); new Thread(new GetRunner(start, end, conn4Get)).start(); start.countDown(); end.await(); System.out.println("loop " + i + " is completed"); } } static class DeleteRunner implements Runnable { private CountDownLatch start_; private CountDownLatch end_; private Connection conn_; public DeleteRunner(CountDownLatch start, CountDownLatch end, Connection conn) { this.start_ = start; this.end_ = end; this.conn_ = conn; } @Override public void run() { try { start_.await(); } catch (InterruptedException e1) { e1.printStackTrace(); } NodeId nodeId = NodeId.valueOf("09fa9c9b-ef26-4a26-ba21-a883ab908e29"); PreparedStatement stmt = null; ResultSet rs = null; try { stmt = conn_.prepareStatement("delete from vtjp_def_bundle2 where NODE_ID = ?"); stmt.setObject(1, nodeId.getRawBytes()); stmt.executeUpdate(); end_.countDown(); } catch (SQLException e) { e.printStackTrace(); } finally { if (rs != null) { try { rs.close(); } catch (SQLException e) { e.printStackTrace(); } } if (stmt != null) { try { stmt.close(); } catch (SQLException e) { e.printStackTrace(); } } } } } static class GetRunner implements Runnable { private CountDownLatch start_; private CountDownLatch end_; private Connection conn_; public GetRunner(CountDownLatch start, CountDownLatch end, Connection conn) { this.start_ = start; this.end_ = end; this.conn_ = conn; } @Override public void run() { try { start_.await(); } catch (InterruptedException e1) { e1.printStackTrace(); } NodeId nodeId = NodeId.valueOf("09fa9c9b-ef26-4a26-ba21-a883ab908e29"); PreparedStatement stmt = null; ResultSet rs = null; try { stmt = conn_.prepareStatement("select BUNDLE_DATA from vtjp_def_bundle2 where NODE_ID = ?"); stmt.setObject(1, nodeId.getRawBytes()); rs = stmt.executeQuery(); if (rs.next()) { byte[] content = (byte[]) rs.getObject(1); System.out.println(new String(content)); } else { System.out.println("no node"); } end_.countDown(); } catch (SQLException e) { e.printStackTrace(); } finally { if (rs != null) { try { rs.close(); } catch (SQLException e) { e.printStackTrace(); } } if (stmt != null) { try { stmt.close(); } catch (SQLException e) { e.printStackTrace(); } } } } } public void deleteBundle() throws Exception { NodeId nodeId = NodeId.valueOf("09fa9c9b-ef26-4a26-ba21-a883ab908e29"); Connection conn = null; PreparedStatement stmt = null; ResultSet rs = null; try { conn = DriverManager.getConnection(URL, USER, PASSWORD); stmt = conn.prepareStatement("delete from vtjp_def_bundle2 where NODE_ID = ?"); stmt.setObject(1, nodeId.getRawBytes()); stmt.executeUpdate(); } finally { if (rs != null) { rs.close(); } if (stmt != null) { stmt.close(); } if (conn != null) { conn.close(); } } } public void insertBundle() throws Exception { NodeId nodeId = NodeId.valueOf("09fa9c9b-ef26-4a26-ba21-a883ab908e29"); Connection conn = null; PreparedStatement stmt = null; ResultSet rs = null; try { conn = DriverManager.getConnection(URL, USER, PASSWORD); stmt = conn.prepareStatement("insert into vtjp_def_bundle2 (NODE_ID, BUNDLE_DATA) values(?, ?)"); stmt.setObject(1, nodeId.getRawBytes()); String content = "hello world"; stmt.setObject(2, content.getBytes()); stmt.executeUpdate(); } finally { if (rs != null) { rs.close(); } if (stmt != null) { stmt.close(); } if (conn != null) { conn.close(); } } } } > lock resource deadlock when using mssql2016 > ------------------------------------------- > > Key: JCR-4174 > URL: https://issues.apache.org/jira/browse/JCR-4174 > Project: Jackrabbit Content Repository > Issue Type: Bug > Components: jackrabbit-core > Environment: cluster JR + mssql2016 > Reporter: modelrepoistory > Labels: cluster, deadlock > > Recently, we need to support MSSQL2016. After running some test in one > cluster environment, we meet following dead lock issue. I have two questions > 1. Based on what I know, synchronizing repository doesn't need acquire > write lock, so why deadlock happened > 2. The exception handling looks not good on > SharedItemStateManager.externalUpdate. In my case, some unexpected exception, > i.e. UndeclaredThrowableException, is throw out, that's because some > reflection is used when executing sql. As this non-ItemStateException is > thrown, SharedItemStateManager will not release the global writer lock, make > repository in this VM not working. > {noformat} > 2017-08-18 19:01:00,296 ERROR [org.jboss.as.ejb3.invocation] WFLYEJB0034: EJB > Invocation failed on component ...: javax.ejb.EJBException: > java.lang.reflect.UndeclaredThrowableException > at > org.jboss.as.ejb3.tx.BMTInterceptor.handleException(BMTInterceptor.java:83) > at > org.jboss.as.ejb3.tx.EjbBMTInterceptor.checkStatelessDone(EjbBMTInterceptor.java:91) > > at > org.jboss.as.ejb3.tx.EjbBMTInterceptor.handleInvocation(EjbBMTInterceptor.java:106) > > at > org.jboss.as.ejb3.tx.BMTInterceptor.processInvocation(BMTInterceptor.java:58) > at > org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) > at > org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:437) > > at > org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:73) > > at > org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:83) > > at > org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) > at > org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:45) > > at > org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) > at > org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:21) > > at > org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) > at > org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) > > at > org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:52) > > at > org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) > at > org.jboss.as.ejb3.component.interceptors.NonPooledEJBComponentInstanceAssociatingInterceptor.processInvocation(NonPooledEJBComponentInstanceAssociatingInterceptor.java:59) > at > org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) > at > org.jboss.as.ejb3.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:79) > > at > org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) > at > org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) > > at > org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) > at > org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:43) > > at > org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) > at > org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100) > > at > org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) > at > org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) > > at > org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) > at > org.jboss.as.ejb3.deployment.processors.EjbSuspendInterceptor.processInvocation(EjbSuspendInterceptor.java:53) > > at > org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) > at > org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67) > > at > org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) > at > org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) > > at > org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) > at > org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54) > > at > org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) > at > org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:64) > > at > org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) > at > org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356) > at > org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:634) > > at > org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:61) > > at > org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) > at > org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356) > at > org.jboss.invocation.PrivilegedWithCombinerInterceptor.processInvocation(PrivilegedWithCombinerInterceptor.java:80) > > at > org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) > at > org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) > > at > org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:195) > at > org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.invokeMethod(MethodInvocationMessageHandler.java:331) > > at > org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.access$100(MethodInvocationMessageHandler.java:69) > > at > org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler$1.run(MethodInvocationMessageHandler.java:202) > > at > java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) > at java.util.concurrent.FutureTask.run(FutureTask.java:266) > at > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) > > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) > > at java.lang.Thread.run(Thread.java:748) > at org.jboss.threads.JBossThread.run(JBossThread.java:320) > Caused by: java.lang.reflect.UndeclaredThrowableException > at com.sun.proxy.$Proxy62.next(Unknown Source) > at > org.apache.jackrabbit.core.persistence.pool.BundleDbPersistenceManager.loadBundle(BundleDbPersistenceManager.java:1028) > > at > org.apache.jackrabbit.core.persistence.bundle.AbstractBundlePersistenceManager.getBundle(AbstractBundlePersistenceManager.java:654) > > at > org.apache.jackrabbit.core.persistence.bundle.AbstractBundlePersistenceManager.load(AbstractBundlePersistenceManager.java:400) > > at > org.apache.jackrabbit.core.state.SharedItemStateManager.loadItemState(SharedItemStateManager.java:1819) > > at > org.apache.jackrabbit.core.state.SharedItemStateManager.doExternalUpdate(SharedItemStateManager.java:1552) > > at > org.apache.jackrabbit.core.state.SharedItemStateManager.externalUpdate(SharedItemStateManager.java:1504) > > at > org.apache.jackrabbit.core.RepositoryImpl$WorkspaceInfo.externalUpdate(RepositoryImpl.java:2269) > > at > org.apache.jackrabbit.core.cluster.ClusterNode.process(ClusterNode.java:814) > at > org.apache.jackrabbit.core.cluster.ChangeLogRecord.process(ChangeLogRecord.java:498) > > at > org.apache.jackrabbit.core.cluster.ClusterNode.consume(ClusterNode.java:760) > at > org.apache.jackrabbit.core.journal.AbstractJournal.doSync(AbstractJournal.java:235) > > at > org.apache.jackrabbit.core.journal.AbstractJournal.internalSync(AbstractJournal.java:209) > > at > org.apache.jackrabbit.core.journal.AbstractJournal.sync(AbstractJournal.java:189) > > at > org.apache.jackrabbit.core.cluster.ClusterNode.sync(ClusterNode.java:308) > at > org.apache.jackrabbit.core.session.SessionRefreshOperation.perform(SessionRefreshOperation.java:58) > > at > org.apache.jackrabbit.core.session.SessionState.perform(SessionState.java:200) > > at > org.apache.jackrabbit.core.SessionImpl.perform(SessionImpl.java:355) > at > org.apache.jackrabbit.core.SessionImpl.refresh(SessionImpl.java:765) > at > org.apache.jackrabbit.jca.JCASessionHandle.refresh(JCASessionHandle.java:193) > .... > at > org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52) > > at > org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) > at > org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:437) > > at > org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.doMethodInterception(Jsr299BindingsInterceptor.java:82) > > at > org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.processInvocation(Jsr299BindingsInterceptor.java:93) > > at > org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63) > > at > org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) > at > org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43) > > at > org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) > at > org.jboss.as.jpa.interceptor.SBInvocationInterceptor.processInvocation(SBInvocationInterceptor.java:47) > > at > org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) > at > org.jboss.as.ejb3.tx.EjbBMTInterceptor.handleInvocation(EjbBMTInterceptor.java:103) > > ... 53 more > Caused by: java.lang.reflect.InvocationTargetException > at sun.reflect.GeneratedMethodAccessor8.invoke(Unknown Source) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > > at java.lang.reflect.Method.invoke(Method.java:498) > at > org.apache.jackrabbit.core.util.db.ResultSetWrapper.invoke(ResultSetWrapper.java:66) > > ... 100 more > Caused by: com.microsoft.sqlserver.jdbc.SQLServerException: Transaction > (Process ID 55) was deadlocked on lock resources with another process and has > been chosen as the deadlock victim. Rerun the transaction. > at > com.microsoft.sqlserver.jdbc.SQLServerException.makeFromDatabaseError(SQLServerException.java:197) > > at > com.microsoft.sqlserver.jdbc.SQLServerResultSet$FetchBuffer.nextRow(SQLServerResultSet.java:4762) > > at > com.microsoft.sqlserver.jdbc.SQLServerResultSet.fetchBufferNext(SQLServerResultSet.java:1682) > > at > com.microsoft.sqlserver.jdbc.SQLServerResultSet.next(SQLServerResultSet.java:955) > > at > org.apache.commons.dbcp.DelegatingResultSet.next(DelegatingResultSet.java:169) > > at > org.apache.commons.dbcp.DelegatingResultSet.next(DelegatingResultSet.java:169) > > ... 104 more > > {noformat} -- This message was sent by Atlassian JIRA (v6.4.14#64029)