Hi Marc,

I have filed WFLY-4014 as I'm experiencing the same problem with a completely different database and setup. It only happened once to me. You mentioned you experienced it repeatedly. Would you care to share your findings?

Hi guys,

It looks like JCA can't lock the internal XAR implementation, probably it is wedged in completing some SQL for the one-phase resource. Please can you supply a thread dump?

There are quite a few forums and not all developers are able to monitor them all, hence the delay in responding. If you have future transaction queries I suggest creating the query over here: Space: JBoss Transactions | JBoss Developer

Thanks,

Tom

/cc jesper.pedersen

I am responding to comments made on the WFLY issue.

arcivanov - thanks for the logs. As you say we can see that postgres has got wedged doing an insert from thread "default task-1". Do you have any ideas why this is the case? I know that the transaction manager will not interrupt threads that are wedged in queries as we have seen some resource managers that have unexpected behavior in this scenario. As the undertow threads are not daemon threads it is likely that the server is not shutting down due to this. We should ask the project lead swd847 about that.

Stuart: the user's server is not shutting down. However, the user is executing an operation that never returns (from an undertow thread), is it therefore likely that the server is not shutting down due to this operation not returning?

[Server:node1] "default task-1" prio=5 tid=0x00007fa3dc8d9800 nid=0xfb0b runnable [0x00000001213c8000]

[Server:node1]    java.lang.Thread.State: RUNNABLE

[Server:node1] at java.net.SocketInputStream.socketRead0(Native Method)

[Server:node1] at java.net.SocketInputStream.read(SocketInputStream.java:152)

[Server:node1] at java.net.SocketInputStream.read(SocketInputStream.java:122)

[Server:node1] at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:143)

[Server:node1] at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:112)

[Server:node1] at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:71)

[Server:node1] at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:282)

[Server:node1] at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1741)

[Server:node1] at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:255)

[Server:node1] - locked <0x00000007bad29d08> (a org.postgresql.core.v3.QueryExecutorImpl)

[Server:node1] at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:561)

[Server:node1] at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:419)

[Server:node1] at org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate(AbstractJdbc2Statement.java:365)

[Server:node1] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

[Server:node1] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)

[Server:node1] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

[Server:node1] at java.lang.reflect.Method.invoke(Method.java:606)

[Server:node1] at net.sf.hajdbc.util.reflect.Methods.invoke(Methods.java:49)

[Server:node1] at net.sf.hajdbc.invocation.SimpleInvoker.invoke(SimpleInvoker.java:53)

[Server:node1] at net.sf.hajdbc.invocation.AllResultsCollector$Invocation.call(AllResultsCollector.java:143)

[Server:node1] at net.sf.hajdbc.util.concurrent.SynchronousExecutor$EagerFuture.<init>(SynchronousExecutor.java:406)

[Server:node1] at net.sf.hajdbc.util.concurrent.SynchronousExecutor.invokeAll(SynchronousExecutor.java:175)

[Server:node1] at net.sf.hajdbc.util.concurrent.SynchronousExecutor.invokeAll(SynchronousExecutor.java:152)

[Server:node1] at net.sf.hajdbc.invocation.AllResultsCollector.collectResults(AllResultsCollector.java:81)

[Server:node1] at net.sf.hajdbc.invocation.InvokeOnManyInvocationStrategy.invoke(InvokeOnManyInvocationStrategy.java:62)

[Server:node1] at net.sf.hajdbc.invocation.InvocationStrategies.invoke(InvocationStrategies.java:35)

[Server:node1] at net.sf.hajdbc.invocation.LockingInvocationStrategy.invoke(LockingInvocationStrategy.java:59)

[Server:node1] at net.sf.hajdbc.sql.LocalTransactionContext$2.invoke(LocalTransactionContext.java:96)

[Server:node1] at net.sf.hajdbc.sql.AbstractInvocationHandler.invokeOnProxy(AbstractInvocationHandler.java:95)

[Server:node1] at net.sf.hajdbc.sql.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:85)

[Server:node1] at net.sf.hajdbc.sql.ChildInvocationHandler.invoke(ChildInvocationHandler.java:44)

[Server:node1] at com.sun.proxy.$Proxy121.executeUpdate(Unknown Source)

[Server:node1] at org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeUpdate(WrappedPreparedStatement.java:493)

[Server:node1] at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:187)

[Server:node1] at org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:62)

[Server:node1] at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3124)

[Server:node1] at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3581)

[Server:node1] at org.hibernate.action.internal.EntityInsertAction.execute(EntityInsertAction.java:104)

[Server:node1] at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:463)

[Server:node1] at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:349)

[Server:node1] at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:350)

[Server:node1] at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:56)

[Server:node1] at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1222)

[Server:node1] at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:425)

[Server:node1] at org.hibernate.engine.transaction.synchronization.internal.SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:110)

[Server:node1] at org.hibernate.engine.transaction.synchronization.internal.RegisteredSynchronization.beforeCompletion(RegisteredSynchronization.java:50)

[Server:node1] at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76)

[Server:node1] at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:358)

[Server:node1] - locked <0x00000007bb867050> (a java.lang.Object)

[Server:node1] at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:91)

[Server:node1] at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)

[Server:node1] at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1166)

[Server:node1] at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)

[Server:node1] at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)

[Server:node1] at org.jboss.tm.usertx.client.ServerVMClientUserTransaction.commit(ServerVMClientUserTransaction.java:173)

[Server:node1] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

[Server:node1] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)

[Server:node1] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

[Server:node1] at java.lang.reflect.Method.invoke(Method.java:606)

[Server:node1] at org.jboss.weld.util.reflection.Reflections.invokeAndUnwrap(Reflections.java:401)

[Server:node1] at org.jboss.weld.bean.builtin.CallableMethodHandler.invoke(CallableMethodHandler.java:42)

[Server:node1] at org.jboss.weld.bean.proxy.EnterpriseTargetBeanInstance.invoke(EnterpriseTargetBeanInstance.java:56)

[Server:node1] at org.jboss.weld.bean.proxy.ProxyMethodHandler.invoke(ProxyMethodHandler.java:100)

[Server:node1] at org.jboss.weldx.transaction.UserTransaction$1266775935$Proxy$_$$_Weld$Proxy$.commit(Unknown Source)

[Server:node1] at com.csc.agility.dialect.PostgreSQL92XLDialectIT.commitTransaction(PostgreSQL92XLDialectIT.java:298)

[Server:node1] at com.csc.agility.dialect.PostgreSQL92XLDialectIT.doTestTemplateName(PostgreSQL92XLDialectIT.java:177)

[Server:node1] at com.csc.agility.dialect.PostgreSQL92XLDialectIT.testTinyString(PostgreSQL92XLDialectIT.java:80)

[Server:node1] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

[Server:node1] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)

[Server:node1] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

[Server:node1] at java.lang.reflect.Method.invoke(Method.java:606)

[Server:node1] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)

[Server:node1] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)

[Server:node1] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44)

[Server:node1] at org.jboss.arquillian.junit.Arquillian$6$1.invoke(Arquillian.java:270)

[Server:node1] at org.jboss.arquillian.container.test.impl.execution.LocalTestExecuter.execute(LocalTestExecuter.java:60)

[Server:node1] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

[Server:node1] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)

[Server:node1] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

[Server:node1] at java.lang.reflect.Method.invoke(Method.java:606)

[Server:node1] at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94)

[Server:node1] at org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:99)

[Server:node1] at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:81)

[Server:node1] at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:135)

[Server:node1] at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:115)

[Server:node1] at org.jboss.arquillian.core.impl.EventImpl.fire(EventImpl.java:67)

[Server:node1] at org.jboss.arquillian.container.test.impl.execution.ContainerTestExecuter.execute(ContainerTestExecuter.java:38)

[Server:node1] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

[Server:node1] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)

[Server:node1] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

[Server:node1] at java.lang.reflect.Method.invoke(Method.java:606)

[Server:node1] at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94)

[Server:node1] at org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:99)

[Server:node1] at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:81)

[Server:node1] at org.jboss.arquillian.test.impl.TestContextHandler.createTestContext(TestContextHandler.java:102)

[Server:node1] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

[Server:node1] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)

[Server:node1] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

[Server:node1] at java.lang.reflect.Method.invoke(Method.java:606)

[Server:node1] at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94)

[Server:node1] at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:88)

[Server:node1] at org.jboss.arquillian.test.impl.TestContextHandler.createClassContext(TestContextHandler.java:84)

[Server:node1] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

[Server:node1] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)

[Server:node1] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

[Server:node1] at java.lang.reflect.Method.invoke(Method.java:606)

[Server:node1] at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94)

[Server:node1] at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:88)

[Server:node1] at org.jboss.arquillian.test.impl.TestContextHandler.createSuiteContext(TestContextHandler.java:65)

[Server:node1] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

[Server:node1] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)

[Server:node1] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

[Server:node1] at java.lang.reflect.Method.invoke(Method.java:606)

[Server:node1] at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94)

[Server:node1] at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:88)

[Server:node1] at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:135)

[Server:node1] at org.jboss.arquillian.test.impl.EventTestRunnerAdaptor.test(EventTestRunnerAdaptor.java:111)

[Server:node1] at org.jboss.arquillian.junit.Arquillian$6.evaluate(Arquillian.java:263)

[Server:node1] at org.jboss.arquillian.junit.Arquillian$4.evaluate(Arquillian.java:226)

[Server:node1] at org.jboss.arquillian.junit.Arquillian.multiExecute(Arquillian.java:314)

[Server:node1] at org.jboss.arquillian.junit.Arquillian.access$100(Arquillian.java:46)

[Server:node1] at org.jboss.arquillian.junit.Arquillian$5.evaluate(Arquillian.java:240)

[Server:node1] at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271)

[Server:node1] at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70)

[Server:node1] at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)

[Server:node1] at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238)

[Server:node1] at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63)

[Server:node1] at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236)

[Server:node1] at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53)

[Server:node1] at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229)

[Server:node1] at org.jboss.arquillian.junit.Arquillian$2.evaluate(Arquillian.java:185)

[Server:node1] at org.jboss.arquillian.junit.Arquillian.multiExecute(Arquillian.java:314)

[Server:node1] at org.jboss.arquillian.junit.Arquillian.access$100(Arquillian.java:46)

[Server:node1] at org.jboss.arquillian.junit.Arquillian$3.evaluate(Arquillian.java:199)

[Server:node1] at org.junit.runners.ParentRunner.run(ParentRunner.java:309)

[Server:node1] at org.jboss.arquillian.junit.Arquillian.run(Arquillian.java:147)

[Server:node1] at org.junit.runner.JUnitCore.run(JUnitCore.java:160)

[Server:node1] at org.junit.runner.JUnitCore.run(JUnitCore.java:138)

[Server:node1] at org.jboss.arquillian.junit.container.JUnitTestRunner.execute(JUnitTestRunner.java:65)

[Server:node1] at org.jboss.arquillian.protocol.servlet.runner.ServletTestRunner.executeTest(ServletTestRunner.java:160)

[Server:node1] at org.jboss.arquillian.protocol.servlet.runner.ServletTestRunner.execute(ServletTestRunner.java:126)

[Server:node1] at org.jboss.arquillian.protocol.servlet.runner.ServletTestRunner.doGet(ServletTestRunner.java:90)

[Server:node1] at javax.servlet.http.HttpServlet.service(HttpServlet.java:687)

[Server:node1] at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)

[Server:node1] at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85)

[Server:node1] at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:61)

[Server:node1] at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)

[Server:node1] at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)

[Server:node1] at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:25)

[Server:node1] at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:113)

[Server:node1] at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:56)

[Server:node1] at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:25)

[Server:node1] at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:45)

[Server:node1] at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:61)

[Server:node1] at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:58)

[Server:node1] at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:70)

[Server:node1] at io.undertow.security.handlers.SecurityInitialHandler.handleRequest(SecurityInitialHandler.java:76)

[Server:node1] at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:25)

[Server:node1] at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)

[Server:node1] at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:25)

[Server:node1] at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:25)

[Server:node1] at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:240)

[Server:node1] at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:227)

[Server:node1] at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:73)

[Server:node1] at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:146)

[Server:node1] at io.undertow.server.Connectors.executeRootHandler(Connectors.java:177)

[Server:node1] at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:727)

[Server:node1] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)

[Server:node1] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)

[Server:node1] at java.lang.Thread.run(Thread.java:745)

Thanks,

Tom

Correct, we do not use daemon threads for executing user code.  They are only used for certain processes (typically cleanup processes) which can always be terminated without negative consequence.

Thanks for the feedback David, what is your opinion on what should happen here? Arcadiy is reporting that when his SQL deadlocks up he can't shut the server down. I would say it is best that he fix the SQL that is deadlocking, or do you think that the server should be able to force a shutdown somehow?