Unable to complete container-managed transaction with app scoped resources

[glassfishrobot]

The EJB container cannot complete a transaction after a method annotated with @Asynchronous was invoked. It claims that the JDBC managed connection is not valid:

Caused by: javax.ejb.EJBException: Unable to complete container-managed transaction. at com.sun.ejb.containers.BaseContainer.completeNewTx(BaseContainer.java:5126) 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:222) at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:88) at $Proxy168.getSamples(Unknown Source) at com.mycroftmind.samples.win.asynctest.__EJB31_GeneratedAsyncTestBeanIntf__Bean.getSamples(Unknown Source) at com.mycroftmind.samples.win.asynctest.frontend.AsyncTestFormBean.refresh(AsyncTestFormBean.java:39) at sun.reflect.GeneratedMethodAccessor115.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at javax.el.BeanELResolver.invokeMethod(BeanELResolver.java:737) at javax.el.BeanELResolver.invoke(BeanELResolver.java:467) at javax.el.CompositeELResolver.invoke(CompositeELResolver.java:254) at com.sun.el.parser.AstValue.invoke(AstValue.java:228) at com.sun.el.MethodExpressionImpl.invoke(MethodExpressionImpl.java:297) at org.jboss.weld.util.el.ForwardingMethodExpression.invoke(ForwardingMethodExpression.java:43) at org.jboss.weld.el.WeldMethodExpression.invoke(WeldMethodExpression.java:56) at com.sun.faces.facelets.el.TagMethodExpression.invoke(TagMethodExpression.java:105) at javax.faces.component.MethodBindingMethodExpressionAdapter.invoke(MethodBindingMethodExpressionAdapter.java:88) ... 33 more Caused by: javax.transaction.SystemException at com.sun.enterprise.transaction.JavaEETransactionImpl.commit(JavaEETransactionImpl.java:520) at com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.commit(JavaEETransactionManagerSimplified.java:867) at com.sun.ejb.containers.BaseContainer.completeNewTx(BaseContainer.java:5115) ... 53 more Caused by: javax.transaction.xa.XAException: com.sun.appserv.connectors.internal.api.PoolingException: javax.resource.ResourceException: This Managed Connection is not valid as the physical connection is not usable at com.sun.enterprise.resource.ConnectorXAResource.handleResourceException(ConnectorXAResource.java:115) at com.sun.enterprise.resource.ConnectorXAResource.resetAssociation(ConnectorXAResource.java:287) at com.sun.enterprise.resource.ConnectorXAResource.commit(ConnectorXAResource.java:128) at com.sun.enterprise.transaction.JavaEETransactionImpl.commit(JavaEETransactionImpl.java:503) ... 55 more

The database used is Derby. The complete exception stack trace can be found among the attachments, as well as a sample web application illustrating this issue. The configuration of JDBC connection pool is among the attachments as well. However, the error does not occur at all times.

The scenario description is the following (however, it may take some time to reproduce the issue):

• the test application is deployed
• in the web form of the test application:
  • click Run method button - the method executes asynchronously, it waits for one minute and then persists a sample JPA entity
  • click Get results button - in roughly 1 of 10 cases the exception is thrown; if the exception does not appear, wait for some time before clicking the Get results button.

The exception is often thrown after some (not regular) time period. It seems that it is the most likely to happen when the first action after deployment is hitting the Run method button (i.e. not getting the results from database before calling the asynchronous method).

In real application, when the user started some asynchronous process and after some time (e.g. 5 minutes) the user wants to retrieve the results from the database. It looks like a JDBC connection has timed-out. We have run into this only when using @Asynchronous methods with the default TransactionAttribute (REQUIRED which should behave as REQUIRES_NEW with asynchronous methods) settings.

The EJB used in the test looks as follows:

@Singleton @LocalBean public class AsyncTestBean {

private static final long DELAY = 60000;

@EJB private AsyncTestCRUDBean crudBean;

@Asynchronous @Lock(LockType.READ) public Future testMethod() { System.out.println("Asynchronous method started.");

final SampleEntity sampleEntity = new SampleEntity(); try { Thread.sleep(DELAY); } catch (InterruptedException ex) { ex.printStackTrace(); }

this.crudBean.persist(sampleEntity);

System.out.println("Asynchronous method done."); return new AsyncResult("test"); }

@Lock(LockType.READ) public List getSamples() { return this.crudBean.getSamples(); } }

Are there any limitations when using transactional access to JPA entities in @Asynchronous methods?

Environment

MacOS

Affected Versions

[3.1]

[glassfishrobot]

• Issue Imported From: https://github.com/javaee/glassfish/issues/16784
• Original Issue Raised By:@glassfishrobot
• Original Issue Assigned To: @h2002044
• Original Issue Closed By:@glassfishrobot

[glassfishrobot]

@glassfishrobot Commented sm157516 said: Need to evaluate the @Asynchronous method behavior for JPA entities in a transaction. Marking it as 3_1-next.

[glassfishrobot]

@glassfishrobot Commented sm157516 said: Could you please attach the source files of this app?

[glassfishrobot]

@glassfishrobot Commented marek.winkler said: Added source files for the example app (async-test.zip).

[glassfishrobot]

@glassfishrobot Commented mvatkina said: Marek,

The exception is thrown from a non-async method.

Do you see the same problem if you have 2 beans - one that inserts and another that gets the result? Did you try your test with the jdbc/__default resource?

[glassfishrobot]

@glassfishrobot Commented marek.winkler said: Marina,

I will test the two beans scenario. In the test, I have used an application-specific JDBC resource defined in glassfish-resources.xml. I will try to use jdbc/__default as well and let you know.

Regarding the fact, that the exception is thrown from a non-async method - it is true, but we have witnessed behaviour when the exception was thrown by the async method as well. It seems that the connection gets broken and the exception is thrown by the first method which tries to access the connection. We have not run into this kind of trouble when an async method was not used.

I will try the test cases you described and let you know. Thanks for the hints!

[glassfishrobot]

@glassfishrobot Commented marek.winkler said: I have made the test with two EJBs, one providing only method for reading entites, and the other EJB only a method for persisting entities. The exception still occurs.

However, I have identified the steps for replicating this issue: it is sufficient to deploy the application, start the asynchronous method, then wait until it finishes (see the log), and then invoke the asynchronous method again. When it tries to commit, the exception occurs.

You have the exception stack trace, as well as another variant of the test application containing the two EJBs in the attachment.

[glassfishrobot]

@glassfishrobot Commented marek.winkler said: I have made another observation: when I annotate the method AsyncTestWriteBean.persist with @TransactionAttribute(TransactionAttributeType.REQUIRES_NEW), then a different exception is thrown (a transaction cannot be started because of the unusability of the physical connection).

You can find the stack trace in the attachment.

[glassfishrobot]

@glassfishrobot Commented marek.winkler said: Another observation, making it rather more complicated: when the method AsyncTestBean.testMethod is not asynchronous, the same exception is thrown. Therefore, it seems the problem is, in fact, not related to the use of asynchronous methods. Sorry for any misleading in the previous comments.

Were you able to reproduce the problem?

[glassfishrobot]

@glassfishrobot Commented mvatkina said: I was able to replicate the problem with your original test. But it seemed to work correctly when I changed persistence.xml to use jdb/__default (at least I couldn't hit the problem)

[glassfishrobot]

@glassfishrobot Commented marek.winkler said: I tried to use jdbc/__default, as you suggested, and everything worked fine.

However, it seems the culprit has been found. I have investigated the configuration of the application's JDBC connection pool and found out that the jdbc-connection-pool was configured with attribute wrap-jdbc-objects="false". When I removed this setting, the exception no longer occurs.

Is the setting wrap-jdbc-objects="false" expected to cause such exceptions? If this is the intended behaviour, I will test the corrected settings on the real application.

I would then suggest minor correction of the GlassFish online Application Deployment Guide: the web page http://download.oracle.com/docs/cd/E18930_01/html/821-2417/giyil.html does not clearly state, what the default value of wrap-jdbc-objects is (the table column 'default' says 'true', but the textual description says 'false').

[glassfishrobot]

@glassfishrobot Commented mvatkina said: Changed subject to reflect the actual cause

[glassfishrobot]

@glassfishrobot Commented sm157516 said: This has nothing to do with setting the wrap-jdbc-objects=true. The only difference between using DerbyPool and async-test-pool is that async-test-pool is an app scoped resources pool.

After a lot of investigation, it has been figured out that the GlassfishNamingManagerImpl.lookupFromNamespace method does not preseve the passed "env" for connector-runtime usage. The code snippet below

if (o instanceof NamingObjectProxy)

{ NamingObjectProxy namingProxy = (NamingObjectProxy) o; o = namingProxy.create(initialContext); }

omits the passed env argument.

Setting the max-pool-size/steady-pool-size to 1, wrap-jdbc-objects to true/false, idle-timeout to 30 seconds, when the app (using app scoped resources) is deployed, some of the steps to observe are when ConnectorRuntime.lookupPMResource is done, the resourceInfo passed is java:app/async-test/jdbc/async-test__pm, the ConnectorObjectFactory tries to derive a jndi name based on the "env".

The "env" is erroneous in case of app scoped resources and that is the reason why using jdbc/__default as the jdbc resource was passing.

Transferring the issue to Jagadish.

[glassfishrobot]

@glassfishrobot Commented sm157516 said: Changing the summary to reflect that the issue is with app scoped resources.

[glassfishrobot]

@glassfishrobot Commented @h2002044 said: Fix is to make sure Environment is preserved for lookup via namespaces (app/module) also which will provide similar behavior as that of lookup via "(new InitialContext(environment)).lookup()"

Fix reviewed by Cheng.

[glassfishrobot]

@glassfishrobot Commented scatari said: Approved for 3.1.1. The checkin for this fix will miss b09, so target it for b10.

[glassfishrobot]

@glassfishrobot Commented @h2002044 said: FIX INFORMATION :

svn log -v -r 47642 branches/3.1.1/common/glassfish-naming/src/main/java/com/sun/enterprise/naming/impl/GlassfishNamingManagerImpl.java

svn log -v -r 47639 trunk/v3/common/glassfish-naming/src/main/java/com/sun/enterprise/naming/impl/GlassfishNamingManagerImpl.java

[glassfishrobot]

@glassfishrobot Commented maddy_2100 said: Hi Guys,

We have encountered a similar exception in our server with Glassfish version 3.1.2. Is the fix there in this version?

2017-04-04 11:43:03,784 WARN [https-thread-pool-shm-51831(3)] com.ericsson.oss.shm.server.restful.upgrade.ImportUpgradePackageFilter - Exception while importing upgrade package javax.ejb.EJBException: Unable to complete container-managed transaction. at com.sun.ejb.containers.BaseContainer.completeNewTx(BaseContainer.java:5147) at com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:4901) at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:2045) at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1994) at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:222) at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:89) at com.sun.proxy.$Proxy1151.processZip(Unknown Source) at com.ericsson.oss.shm.server.domainservices.upgrade._EJB31_GeneratedUpgradePackageServiceIntf_Bean.processZip(Unknown Source) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.jboss.weld.util.reflection.SecureReflections$13.work(SecureReflections.java:267) at org.jboss.weld.util.reflection.SecureReflectionAccess.run(SecureReflectionAccess.java:52) at org.jboss.weld.util.reflection.SecureReflectionAccess.runAsInvocation(SecureReflectionAccess.java:137) at org.jboss.weld.util.reflection.SecureReflections.invoke(SecureReflections.java:263) at org.jboss.weld.bean.proxy.EnterpriseBeanProxyMethodHandler.invoke(EnterpriseBeanProxyMethodHandler.java:110) at org.jboss.weld.bean.proxy.EnterpriseTargetBeanInstance.invoke(EnterpriseTargetBeanInstance.java:56) at org.jboss.weld.bean.proxy.ProxyMethodHandler.invoke(ProxyMethodHandler.java:105) at com.ericsson.oss.shm.server.domainservices.upgrade.UpgradePackageService$Proxy$$$_Weld$Proxy$.processZip(UpgradePackageService$Proxy$$$_Weld$Proxy$.java) at com.ericsson.oss.shm.server.restful.upgrade.ImportUpgradePackageServlet.doPost(ImportUpgradePackageServlet.java:71) at javax.servlet.http.HttpServlet.service(HttpServlet.java:688) at gwtupload.server.UploadServlet.service(UploadServlet.java:396) at javax.servlet.http.HttpServlet.service(HttpServlet.java:770) at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1550) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:343) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:217) at com.ericsson.oss.shm.server.restful.upgrade.ImportUpgradePackageFilter.doFilter(ImportUpgradePackageFilter.java:55) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:256) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:217) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:279) 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 org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:161) at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:655) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:595) at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:328) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:231) at com.sun.enterprise.v3.services.impl.ContainerMapper$AdapterCallable.call(ContainerMapper.java:317) at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:195) at com.sun.grizzly.http.ProcessorTask.invokeAdapter(ProcessorTask.java:860) at com.sun.grizzly.comet.CometEngine.executeServlet(CometEngine.java:459) at com.sun.grizzly.comet.CometEngine.handle(CometEngine.java:316) at com.sun.grizzly.comet.CometAsyncFilter.doFilter(CometAsyncFilter.java:87) at com.sun.grizzly.arp.DefaultAsyncExecutor.invokeFilters(DefaultAsyncExecutor.java:171) at com.sun.grizzly.arp.DefaultAsyncExecutor.interrupt(DefaultAsyncExecutor.java:143) at com.sun.grizzly.arp.AsyncProcessorTask.doTask(AsyncProcessorTask.java:102) at com.sun.grizzly.http.TaskBase.run(TaskBase.java:193) at com.sun.grizzly.http.TaskBase.execute(TaskBase.java:175) at com.sun.grizzly.arp.DefaultAsyncHandler.handle(DefaultAsyncHandler.java:145) at com.sun.grizzly.arp.AsyncProtocolFilter.execute(AsyncProtocolFilter.java:210) 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:744) Caused by: javax.transaction.SystemException: org.omg.CORBA.INTERNAL: JTS5022: Unexpected exception [com.sun.jts.CosTransactions.LogException: LOG004: Data corrupted. Log exception at point 12. ] from log. vmcid: 0x0 minor code: 0 completed: No at com.sun.jts.jta.TransactionManagerImpl.commit(TransactionManagerImpl.java:345) at com.sun.enterprise.transaction.jts.JavaEETransactionManagerJTSDelegate.commitDistributedTransaction(JavaEETransactionManagerJTSDelegate.java:185) at com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.commit(JavaEETransactionManagerSimplified.java:861) at com.sun.ejb.containers.BaseContainer.completeNewTx(BaseContainer.java:5136) ... 61 more

Regards, Madhan

[glassfishrobot]

@glassfishrobot Commented File: async-test-two-beans.war Attached By: marek.winkler

[glassfishrobot]

@glassfishrobot Commented File: async-test.war Attached By: marek.winkler

[glassfishrobot]

@glassfishrobot Commented File: async-test.zip Attached By: marek.winkler

[glassfishrobot]

@glassfishrobot Commented File: async-test_two_beans.zip Attached By: marek.winkler

[glassfishrobot]

@glassfishrobot Commented File: exception_in_async_method.txt Attached By: marek.winkler

[glassfishrobot]

@glassfishrobot Commented File: exception_with_REQUIRES_NEW.txt Attached By: marek.winkler

[glassfishrobot]

@glassfishrobot Commented File: issue-full-log.txt Attached By: marek.winkler

[glassfishrobot]

@glassfishrobot Commented File: issue-glassfish-resources.xml Attached By: marek.winkler

[glassfishrobot]

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

[glassfishrobot]

@glassfishrobot Commented Reported by marek.winkler

[glassfishrobot]

@glassfishrobot Commented Marked as fixed on Thursday, June 23rd 2011, 3:25:13 am