search

eclipse-ee4j / glassfish

Eclipse GlassFish
https://eclipse-ee4j.github.io/glassfish/
378 stars 144 forks source link

tx recovery issue with a derby restart or crash #14830

Closed glassfishrobot closed 13 years ago

glassfishrobot commented 13 years ago

glassfish-3.1-b29.zip Unable to complete container-managed transaction with a derby restart.

appserver-sqe/pe/transaction/recovery/cliapp2

1) setup app, do jdbc and jms operation, and verify the results cd appserver-sqe/pe/transaction/recovery/cliapp2 ant ee setup build deploy ant ee run_operate_xa_i2 ant ee run_verify_xa_t4 see expected results, e.g. [java] got expectedResult=RESULTS:9

2) restart Derby, e.g. cd appserver-sqe ant stopTxDerby ant startTxDerby

3) verify db results again. cd appserver-sqe/pe/transaction/recovery/cliapp2 ant ee run_verify_xa_t4 client output shows: [java] Processing line: javax.ejb.EJBException: Unable to complete container-managed transaction.

server.log shows: [#|2010-11-20T18:00:47.006-0800|INFO|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| VerifyServlet,type=xa|#]

[#|2010-11-20T18:00:47.028-0800|INFO|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| Found: BAA48080DB_A1 : BBB480801|#]

[#|2010-11-20T18:00:47.029-0800|INFO|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| Found: BAA48080DB_A2 : BBB480802|#]

[#|2010-11-20T18:00:47.031-0800|INFO|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| Found: BAA48080DB_A3 : BBB480803|#]

[#|2010-11-20T18:01:47.773-0800|WARNING|glassfish3.1| javax.enterprise.system.core.transaction.com.sun.jts.jta|_ThreadID=15;_ThreadName=Thread-1;|JTS5064: Unexpected exception occurred while delisting the resource org.apache.derby.client.am.XaException: XAER_RMFAIL : No current connection. at org.apache.derby.client.net.NetXAResource.throwXAException(Unknown Source) at org.apache.derby.client.net.NetXAResource.throwXAException(Unknown Source) at org.apache.derby.client.net.NetXAResource.connectionClosedFailure(Unknown Source) at org.apache.derby.client.net.NetXAResource.end(Unknown Source) at com.sun.gjc.spi.XAResourceImpl.end(XAResourceImpl.java:102) at com.sun.jts.jta.TransactionState.beforeCompletion(TransactionState.java:160) at com.sun.jts.jta.SynchronizationImpl.before_completion(SynchronizationImpl.java:135) at com.sun.jts.CosTransactions.RegisteredSyncs.distributeBefore(RegisteredSyncs.java:158) at com.sun.jts.CosTransactions.TopCoordinator.beforeCompletion(TopCoordinator.java:2552) at com.sun.jts.CosTransactions.CoordinatorTerm.commit(CoordinatorTerm.java:279) at com.sun.jts.CosTransactions.TerminatorImpl.commit(TerminatorImpl.java:250) at com.sun.jts.CosTransactions.CurrentImpl.commit(CurrentImpl.java:623) at com.sun.jts.jta.TransactionManagerImpl.commit(TransactionManagerImpl.java:319) at com.sun.enterprise.transaction.jts.JavaEETransactionManagerJTSDelegate.commitDistributedTransaction(JavaEETransactionManagerJTSDelegate.java:183) at com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.commit(JavaEETransactionManagerSimplified.java:871) at com.sun.ejb.containers.BaseContainer.completeNewTx(BaseContainer.java:5115) at com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:4880) at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:2039) at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1990) at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:203) at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:88) at $Proxy213.verifyxa(Unknown Source) at tx.recovery.cliapp2.VerifyServlet.doGet(VerifyServlet.java:42) at javax.servlet.http.HttpServlet.service(HttpServlet.java:735) at javax.servlet.http.HttpServlet.service(HttpServlet.java:848) at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1534) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:281) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175) at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:655) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:595) at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:98) at com.sun.enterprise.web.PESessionLockingStandardPipeline.invoke(PESessionLockingStandardPipeline.java:91) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:162) at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:326) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:227) at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:170) at com.sun.grizzly.http.ProcessorTask.invokeAdapter(ProcessorTask.java:817) at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:718) at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:1007) at com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:225) at com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:137) at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:104) at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:90) at com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:79) at com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:54) at com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:59) at com.sun.grizzly.ContextTask.run(ContextTask.java:71) at com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:532) at com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:513) at java.lang.Thread.run(Thread.java:662) Caused by: org.apache.derby.client.am.SqlException: No current connection. ... 48 more

| #] |

[#|2010-11-20T18:01:47.814-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| javax.ejb.EJBException: Unable to complete container-managed transaction.|#]

[#|2010-11-20T18:01:47.815-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;|

at com.sun.ejb.containers.BaseContainer.completeNewTx(BaseContainer.java:5126)|#]

[#|2010-11-20T18:01:47.816-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;|

at com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:4880)|#]

[#|2010-11-20T18:01:47.817-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:2039)|#]

[#|2010-11-20T18:01:47.817-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1990)|#]

[#|2010-11-20T18:01:47.818-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:203)|#]

[#|2010-11-20T18:01:47.819-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:88)|#]

[#|2010-11-20T18:01:47.820-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at $Proxy213.verifyxa(Unknown Source)|#]

[#|2010-11-20T18:01:47.820-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at tx.recovery.cliapp2.VerifyServlet.doGet(VerifyServlet.java:42)|#]

[#|2010-11-20T18:01:47.821-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at javax.servlet.http.HttpServlet.service(HttpServlet.java:735)|#]

[#|2010-11-20T18:01:47.821-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at javax.servlet.http.HttpServlet.service(HttpServlet.java:848)|#]

[#|2010-11-20T18:01:47.822-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1534)|#]

[#|2010-11-20T18:01:47.822-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:281)|#]

[#|2010-11-20T18:01:47.823-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)|#]

[#|2010-11-20T18:01:47.823-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:655)|#]

[#|2010-11-20T18:01:47.824-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:595)|#]

[#|2010-11-20T18:01:47.824-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:98)|#]

[#|2010-11-20T18:01:47.825-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at com.sun.enterprise.web.PESessionLockingStandardPipeline.invoke(PESessionLockingStandardPipeline.java:91)|#]

[#|2010-11-20T18:01:47.825-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:162)|#]

[#|2010-11-20T18:01:47.826-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:326)|#]

[#|2010-11-20T18:01:47.826-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:227)|#]

[#|2010-11-20T18:01:47.827-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:170)|#]

[#|2010-11-20T18:01:47.827-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at com.sun.grizzly.http.ProcessorTask.invokeAdapter(ProcessorTask.java:817)|#]

[#|2010-11-20T18:01:47.832-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:718)|#]

[#|2010-11-20T18:01:47.868-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:1007)|#]

[#|2010-11-20T18:01:47.870-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:225)|#]

[#|2010-11-20T18:01:47.871-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:137)|#]

[#|2010-11-20T18:01:47.872-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:104)|#]

[#|2010-11-20T18:01:47.872-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:90)|#]

[#|2010-11-20T18:01:47.873-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:79)|#]

[#|2010-11-20T18:01:47.874-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:54)|#]

[#|2010-11-20T18:01:47.875-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:59)|#]

[#|2010-11-20T18:01:47.876-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at com.sun.grizzly.ContextTask.run(ContextTask.java:71)|#]

[#|2010-11-20T18:01:47.876-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:532)|#]

[#|2010-11-20T18:01:47.877-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:513)|#]

[#|2010-11-20T18:01:47.878-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at java.lang.Thread.run(Thread.java:662)|#]

[#|2010-11-20T18:01:47.879-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;|Caused by: javax.transaction.SystemException: org.omg.CORBA.INTERNAL: JTS5031: Exception [org.omg.CORBA.INTERNAL: vmcid: 0x0 minor code: 0 completed: Maybe] on Resource [rollback] operation. vmcid: 0x0 minor code: 0 completed: No|#]

[#|2010-11-20T18:01:47.880-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;|

at com.sun.jts.jta.TransactionManagerImpl.commit(TransactionManagerImpl.java:331)|#]

[#|2010-11-20T18:01:47.881-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;|

at com.sun.enterprise.transaction.jts.JavaEETransactionManagerJTSDelegate.commitDistributedTransaction(JavaEETransactionManagerJTSDelegate.java:183)|#]

[#|2010-11-20T18:01:47.881-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;| at com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.commit(JavaEETransactionManagerSimplified.java:871)|#]

[#|2010-11-20T18:01:47.882-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;|

at com.sun.ejb.containers.BaseContainer.completeNewTx(BaseContainer.java:5115)|#]

[#|2010-11-20T18:01:47.883-0800|SEVERE|glassfish3.1|null|_ThreadID=15;_ThreadName=Thread-1;|

... 34 more|#]

Environment

Operating System: All Platform: All

Affected Versions

[3.1]

glassfishrobot commented 6 years ago
glassfishrobot commented 13 years ago

@glassfishrobot Commented sherryshen said: Without jms, the similar operatins are OK with 2JDBC resources, e.g. cd appserver-sqe/pe/transaction/recovery/cliweb2 ant ee setup build deploy ant ee run_insert_two ant ee run_verify_two_t5 [java] got expectedResult=RESULTS:6

cd appserver-sqe ant stopTxDerby ant startTxDerby

cd appserver-sqe/pe/transaction/recovery/cliweb2 ant ee run_verify_two_t5 [java] got expectedResult=RESULTS:6

glassfishrobot commented 13 years ago

@glassfishrobot Commented mvatkina said: Probably some setup error. With connection validation on, there is no problem with restarting derby

glassfishrobot commented 13 years ago

@glassfishrobot Commented sherryshen said: http://java.net/jira/browse/GLASSFISH-14830 I discussed 14830 with Marina. Test 1) kill 1 Derby with 2 jdbc resources and 1 jms resource, tests failed. Test 2) stop 1 Derby with 2 jdbc resources and 1 jms resource, test failed. Test 3) stop 1 Derby with 2 jdbc resources, test passed. Test 4) kill 2 Derby with 2 jdbc resources, test failed with bug 14836. http://java.net/jira/browse/GLASSFISH-14836

I report 14830 for Test 2 in order to simplify the failure analysis. From Marina's feedback, it is a low priority to consider Test 2). I will use 14830 for Test 1) and revisit it after 14836 is resolved.

glassfishrobot commented 13 years ago

@glassfishrobot Commented sherryshen said: add case for kill derby

glassfishrobot commented 13 years ago

@glassfishrobot Commented mvatkina said: I'll close this bug as a duplicate of 15063 and 14836. Please reopen if there is something beyond non-transactional delivery of JMS messages (15063) and a rollback of inserts on a crushed/restarted Derby instance (14836)

glassfishrobot commented 13 years ago

@glassfishrobot Commented Was assigned to mvatkina

glassfishrobot commented 7 years ago

@glassfishrobot Commented This issue was imported from java.net JIRA GLASSFISH-14830

glassfishrobot commented 13 years ago

@glassfishrobot Commented Reported by sherryshen

glassfishrobot commented 13 years ago

@glassfishrobot Commented Marked as duplicate on Tuesday, December 21st 2010, 6:17:23 am