Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Sequence of exceptions following database connection issue #2310

Closed
marcreichman opened this issue Jan 22, 2018 · 6 comments
Closed

Sequence of exceptions following database connection issue #2310

marcreichman opened this issue Jan 22, 2018 · 6 comments
Labels
PR: TESTS REQUIRED PR Requires Tests to be merged

Comments

@marcreichman
Copy link

Description


We are seeing a situation (possibly an Eclipselink bug?), in which if a JDBC connection pool connection runs into an issue, various uses of JDBC in the future will run into assorted exceptions (PoolingException, NullPointerException, etc.) until the domain is restarted.

Expected Outcome

It's expected that after a transient connection issue, that connection will be marked bad and recycled next time. If that already IS happening, then a bug may just need to be fixed in the area which deals with validation and recycling connections.

Current Outcome

First exception from initial transient connection loss:

[2018-01-19T17:30:00.091-0500] [Payara 4.1] [INFO] [] [org.eclipse.persistence.session./file:/C:/payara-4.1.2.174/payara41/glassfish/domains/domain1/applications/TrexEnterprise-5.15.0.4211/WEB-INF/classes/_TREXJPA.query] [tid: _ThreadID=276 _ThreadName=__ejb-thread-pool6] [timeMillis: 1516401000091] [levelValue: 800] [[
  Communication failure detected when attempting to perform read query outside of a transaction. Attempting to retry query. Error was: Exception [EclipseLink-4002] (Eclipse Persistence Services - 2.6.4.qualifier): org.eclipse.persistence.exceptions.DatabaseException
Internal Exception: java.sql.SQLException: Connection closed
Error Code: 0
Call: SELECT * FROM (SELECT a.*, ROWNUM rnum  FROM (SELECT USERTOKENID AS a1, CREATED AS a2, EXPIRES AS a3, TOKEN AS a4, USER_USERID AS a5 FROM USERTOKEN WHERE (EXPIRES < ?)) a WHERE ROWNUM <= ?) WHERE rnum > ?
	bind => [2018-01-19 17:30:00.0, 500, 0]
Query: ReadAllQuery(name="UserToken.findExpired" referenceClass=UserToken sql="SELECT * FROM (SELECT a.*, ROWNUM rnum  FROM (SELECT USERTOKENID AS a1, CREATED AS a2, EXPIRES AS a3, TOKEN AS a4, USER_USERID AS a5 FROM USERTOKEN WHERE (EXPIRES < ?)) a WHERE ROWNUM <= ?) WHERE rnum > ?").]]

Next set of exceptions (several hours in the future):

[2018-01-19T21:20:00.091-0500] [Payara 4.1] [SEVERE] [] [javax.enterprise.resource.resourceadapter.com.sun.enterprise.resource] [tid: _ThreadID=284 _ThreadName=__ejb-thread-pool13] [timeMillis: 1516414800091] [levelValue: 1000] [[
  RAR5031:System Exception
com.sun.appserv.connectors.internal.api.PoolingException: java.lang.NullPointerException
	at com.sun.enterprise.resource.ConnectorXAResource.getResourceHandle(ConnectorXAResource.java:264)
	at com.sun.enterprise.resource.ConnectorXAResource.getResourceHandleAndBeginTxIfNeeded(ConnectorXAResource.java:232)
	at com.sun.enterprise.resource.ConnectorXAResource.end(ConnectorXAResource.java:160)
	at com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.delistResource(JavaEETransactionManagerSimplified.java:545)
	at com.sun.enterprise.resource.rm.SystemResourceManagerImpl.delistResource(SystemResourceManagerImpl.java:145)
	at com.sun.enterprise.resource.pool.PoolManagerImpl.resourceClosed(PoolManagerImpl.java:378)
	at com.sun.enterprise.resource.listener.LocalTxConnectionEventListener.connectionClosed(LocalTxConnectionEventListener.java:77)
	at com.sun.gjc.spi.ManagedConnectionImpl.connectionClosed(ManagedConnectionImpl.java:860)
	at com.sun.gjc.spi.base.ConnectionHolder.close(ConnectionHolder.java:214)
	at com.sun.gjc.spi.jdbc40.ConnectionHolder40.close(ConnectionHolder40.java:606)
	at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.closeDatasourceConnection(DatabaseAccessor.java:495)
	at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.closeConnection(DatasourceAccessor.java:520)
	at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.closeConnection(DatabaseAccessor.java:520)
	at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.decrementCallCount(DatasourceAccessor.java:290)
	at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.closeStatement(DatabaseAccessor.java:413)
	at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.releaseStatement(DatabaseAccessor.java:1674)
	at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:705)
	at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(DatabaseAccessor.java:560)
	at org.eclipse.persistence.internal.sessions.AbstractSession.basicExecuteCall(AbstractSession.java:2056)
	at org.eclipse.persistence.sessions.server.ServerSession.executeCall(ServerSession.java:570)
	at org.eclipse.persistence.sessions.server.ClientSession.executeCall(ClientSession.java:258)
	at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:242)
	at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:228)
	at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeSelectCall(DatasourceCallQueryMechanism.java:299)
	at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.selectAllRows(DatasourceCallQueryMechanism.java:694)
	at org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllRowsFromTable(ExpressionQueryMechanism.java:2740)
	at org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllReportQueryRows(ExpressionQueryMechanism.java:2677)
	at org.eclipse.persistence.queries.ReportQuery.executeDatabaseQuery(ReportQuery.java:852)
	at org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:904)
	at org.eclipse.persistence.queries.ObjectLevelReadQuery.execute(ObjectLevelReadQuery.java:1134)
	at org.eclipse.persistence.queries.ReadAllQuery.execute(ReadAllQuery.java:460)
	at org.eclipse.persistence.queries.ObjectLevelReadQuery.executeInUnitOfWork(ObjectLevelReadQuery.java:1222)
	at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.internalExecuteQuery(UnitOfWorkImpl.java:2896)
	at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1857)
	at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1839)
	at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1804)
	at org.eclipse.persistence.internal.jpa.QueryImpl.executeReadQuery(QueryImpl.java:258)
	at org.eclipse.persistence.internal.jpa.QueryImpl.getSingleResult(QueryImpl.java:521)
	at org.eclipse.persistence.internal.jpa.EJBQueryImpl.getSingleResult(EJBQueryImpl.java:400)
	at com.myorg.trex.enterprisemanager.controller.EMMd5Bean.findMinimumESIndexVersionByIndexingStatus(EMMd5Bean.java:1360)
	at sun.reflect.GeneratedMethodAccessor769.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.glassfish.ejb.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1081)
	at org.glassfish.ejb.security.application.EJBSecurityManager.invoke(EJBSecurityManager.java:1153)
	at com.sun.ejb.containers.BaseContainer.invokeBeanMethod(BaseContainer.java:4836)
	at com.sun.ejb.EjbInvocation.invokeBeanMethod(EjbInvocation.java:656)
	at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:836)
	at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:608)
	at org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:64)
	at org.jboss.weld.ejb.SessionBeanInterceptor.aroundInvoke(SessionBeanInterceptor.java:52)
	at sun.reflect.GeneratedMethodAccessor110.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:895)
	at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:835)
	at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:608)
	at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.doCall(SystemInterceptorProxy.java:163)
	at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.aroundInvoke(SystemInterceptorProxy.java:140)
	at sun.reflect.GeneratedMethodAccessor111.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:895)
	at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:835)
	at com.sun.ejb.containers.interceptors.InterceptorManager.intercept(InterceptorManager.java:374)
	at com.sun.ejb.containers.BaseContainer.__intercept(BaseContainer.java:4808)
	at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:4796)
	at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:212)
	at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:90)
	at com.sun.proxy.$Proxy404.findMinimumESIndexVersionByIndexingStatus(Unknown Source)
	at com.myorg.trex.enterprisemanager.controller.__EJB31_Generated__EMMd5Bean__Intf____Bean__.findMinimumESIndexVersionByIndexingStatus(Unknown Source)
	at com.myorg.trex.enterprisemanager.search.es.control.ESIndexManager.removeOldIndices(ESIndexManager.java:313)
	at sun.reflect.GeneratedMethodAccessor767.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.glassfish.ejb.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1081)
	at org.glassfish.ejb.security.application.EJBSecurityManager.invoke(EJBSecurityManager.java:1153)
	at com.sun.ejb.containers.BaseContainer.invokeBeanMethod(BaseContainer.java:4836)
	at com.sun.ejb.EjbInvocation.invokeBeanMethod(EjbInvocation.java:656)
	at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:836)
	at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:608)
	at org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:73)
	at org.jboss.weld.ejb.SessionBeanInterceptor.aroundInvoke(SessionBeanInterceptor.java:52)
	at sun.reflect.GeneratedMethodAccessor110.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:895)
	at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:835)
	at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:608)
	at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.doCall(SystemInterceptorProxy.java:163)
	at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.aroundTimeout(SystemInterceptorProxy.java:145)
	at sun.reflect.GeneratedMethodAccessor148.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:895)
	at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:835)
	at com.sun.ejb.containers.interceptors.InterceptorManager.intercept(InterceptorManager.java:374)
	at com.sun.ejb.containers.BaseContainer.__intercept(BaseContainer.java:4808)
	at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:4796)
	at com.sun.ejb.containers.BaseContainer.callEJBTimeout(BaseContainer.java:4074)
	at com.sun.ejb.containers.EJBTimerService.deliverTimeout(EJBTimerService.java:1228)
	at com.sun.ejb.containers.EJBTimerService.access$000(EJBTimerService.java:93)
	at com.sun.ejb.containers.EJBTimerService$TaskExpiredWork.run(EJBTimerService.java:1963)
	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:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.NullPointerException
	at com.sun.enterprise.resource.ConnectorXAResource.getResourceHandle(ConnectorXAResource.java:255)
	... 107 more
]]

[2018-01-19T21:20:00.092-0500] [Payara 4.1] [WARNING] [] [org.eclipse.persistence.session./file:/C:/payara-4.1.2.174/payara41/glassfish/domains/domain1/applications/TrexEnterprise-5.15.0.4211/WEB-INF/classes/_TREXJPA] [tid: _ThreadID=284 _ThreadName=__ejb-thread-pool13] [timeMillis: 1516414800092] [levelValue: 900] [[
  
java.lang.RuntimeException: Got exception during XAResource.end: javax.transaction.xa.XAException: com.sun.appserv.connectors.internal.api.PoolingException: java.lang.NullPointerException
	at com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.delistResource(JavaEETransactionManagerSimplified.java:547)
	at com.sun.enterprise.resource.rm.SystemResourceManagerImpl.delistResource(SystemResourceManagerImpl.java:145)
	at com.sun.enterprise.resource.pool.PoolManagerImpl.resourceClosed(PoolManagerImpl.java:378)
	at com.sun.enterprise.resource.listener.LocalTxConnectionEventListener.connectionClosed(LocalTxConnectionEventListener.java:77)
	at com.sun.gjc.spi.ManagedConnectionImpl.connectionClosed(ManagedConnectionImpl.java:860)
	at com.sun.gjc.spi.base.ConnectionHolder.close(ConnectionHolder.java:214)
	at com.sun.gjc.spi.jdbc40.ConnectionHolder40.close(ConnectionHolder40.java:606)
	at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.closeDatasourceConnection(DatabaseAccessor.java:495)
	at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.closeConnection(DatasourceAccessor.java:520)
	at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.closeConnection(DatabaseAccessor.java:520)
	at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.decrementCallCount(DatasourceAccessor.java:290)
	at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.closeStatement(DatabaseAccessor.java:413)
	at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.releaseStatement(DatabaseAccessor.java:1674)
	at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:705)
	at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(DatabaseAccessor.java:560)
	at org.eclipse.persistence.internal.sessions.AbstractSession.basicExecuteCall(AbstractSession.java:2056)
	at org.eclipse.persistence.sessions.server.ServerSession.executeCall(ServerSession.java:570)
	at org.eclipse.persistence.sessions.server.ClientSession.executeCall(ClientSession.java:258)
	at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:242)
	at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:228)
	at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeSelectCall(DatasourceCallQueryMechanism.java:299)
	at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.selectAllRows(DatasourceCallQueryMechanism.java:694)
	at org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllRowsFromTable(ExpressionQueryMechanism.java:2740)
	at org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllReportQueryRows(ExpressionQueryMechanism.java:2677)
	at org.eclipse.persistence.queries.ReportQuery.executeDatabaseQuery(ReportQuery.java:852)
	at org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:904)
	at org.eclipse.persistence.queries.ObjectLevelReadQuery.execute(ObjectLevelReadQuery.java:1134)
	at org.eclipse.persistence.queries.ReadAllQuery.execute(ReadAllQuery.java:460)
	at org.eclipse.persistence.queries.ObjectLevelReadQuery.executeInUnitOfWork(ObjectLevelReadQuery.java:1222)
	at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.internalExecuteQuery(UnitOfWorkImpl.java:2896)
	at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1857)
	at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1839)
	at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1804)
	at org.eclipse.persistence.internal.jpa.QueryImpl.executeReadQuery(QueryImpl.java:258)
	at org.eclipse.persistence.internal.jpa.QueryImpl.getSingleResult(QueryImpl.java:521)
	at org.eclipse.persistence.internal.jpa.EJBQueryImpl.getSingleResult(EJBQueryImpl.java:400)
	at com.myorg.trex.enterprisemanager.controller.EMMd5Bean.findMinimumESIndexVersionByIndexingStatus(EMMd5Bean.java:1360)
	at sun.reflect.GeneratedMethodAccessor769.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.glassfish.ejb.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1081)
	at org.glassfish.ejb.security.application.EJBSecurityManager.invoke(EJBSecurityManager.java:1153)
	at com.sun.ejb.containers.BaseContainer.invokeBeanMethod(BaseContainer.java:4836)
	at com.sun.ejb.EjbInvocation.invokeBeanMethod(EjbInvocation.java:656)
	at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:836)
	at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:608)
	at org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:64)
	at org.jboss.weld.ejb.SessionBeanInterceptor.aroundInvoke(SessionBeanInterceptor.java:52)
	at sun.reflect.GeneratedMethodAccessor110.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:895)
	at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:835)
	at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:608)
	at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.doCall(SystemInterceptorProxy.java:163)
	at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.aroundInvoke(SystemInterceptorProxy.java:140)
	at sun.reflect.GeneratedMethodAccessor111.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:895)
	at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:835)
	at com.sun.ejb.containers.interceptors.InterceptorManager.intercept(InterceptorManager.java:374)
	at com.sun.ejb.containers.BaseContainer.__intercept(BaseContainer.java:4808)
	at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:4796)
	at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:212)
	at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:90)
	at com.sun.proxy.$Proxy404.findMinimumESIndexVersionByIndexingStatus(Unknown Source)
	at com.myorg.trex.enterprisemanager.controller.__EJB31_Generated__EMMd5Bean__Intf____Bean__.findMinimumESIndexVersionByIndexingStatus(Unknown Source)
	at com.myorg.trex.enterprisemanager.search.es.control.ESIndexManager.removeOldIndices(ESIndexManager.java:313)
	at sun.reflect.GeneratedMethodAccessor767.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.glassfish.ejb.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1081)
	at org.glassfish.ejb.security.application.EJBSecurityManager.invoke(EJBSecurityManager.java:1153)
	at com.sun.ejb.containers.BaseContainer.invokeBeanMethod(BaseContainer.java:4836)
	at com.sun.ejb.EjbInvocation.invokeBeanMethod(EjbInvocation.java:656)
	at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:836)
	at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:608)
	at org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:73)
	at org.jboss.weld.ejb.SessionBeanInterceptor.aroundInvoke(SessionBeanInterceptor.java:52)
	at sun.reflect.GeneratedMethodAccessor110.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:895)
	at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:835)
	at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:608)
	at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.doCall(SystemInterceptorProxy.java:163)
	at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.aroundTimeout(SystemInterceptorProxy.java:145)
	at sun.reflect.GeneratedMethodAccessor148.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:895)
	at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:835)
	at com.sun.ejb.containers.interceptors.InterceptorManager.intercept(InterceptorManager.java:374)
	at com.sun.ejb.containers.BaseContainer.__intercept(BaseContainer.java:4808)
	at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:4796)
	at com.sun.ejb.containers.BaseContainer.callEJBTimeout(BaseContainer.java:4074)
	at com.sun.ejb.containers.EJBTimerService.deliverTimeout(EJBTimerService.java:1228)
	at com.sun.ejb.containers.EJBTimerService.access$000(EJBTimerService.java:93)
	at com.sun.ejb.containers.EJBTimerService$TaskExpiredWork.run(EJBTimerService.java:1963)
	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:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
Caused by: javax.transaction.xa.XAException: com.sun.appserv.connectors.internal.api.PoolingException: java.lang.NullPointerException
	at com.sun.enterprise.resource.ConnectorXAResource.handleResourceException(ConnectorXAResource.java:116)
	at com.sun.enterprise.resource.ConnectorXAResource.end(ConnectorXAResource.java:175)
	at com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.delistResource(JavaEETransactionManagerSimplified.java:545)
	... 104 more
]]

[2018-01-19T21:20:00.095-0500] [Payara 4.1] [WARNING] [AS-EJB-00056] [javax.enterprise.ejb.container] [tid: _ThreadID=284 _ThreadName=__ejb-thread-pool13] [timeMillis: 1516414800095] [levelValue: 900] [[
  A system exception occurred during an invocation on EJB EMMd5Bean, method: public java.lang.Integer com.myorg.trex.enterprisemanager.controller.EMMd5Bean.findMinimumESIndexVersionByIndexingStatus(com.myorg.trex.enterprisemanager.controller.EMMd5ESIndexStatus)]]

[2018-01-19T21:20:00.096-0500] [Payara 4.1] [WARNING] [] [javax.enterprise.ejb.container] [tid: _ThreadID=284 _ThreadName=__ejb-thread-pool13] [timeMillis: 1516414800096] [levelValue: 900] [[
  
javax.ejb.TransactionRolledbackLocalException: Exception thrown from bean
	at com.sun.ejb.containers.EJBContainerTransactionManager.checkExceptionClientTx(EJBContainerTransactionManager.java:664)
	at com.sun.ejb.containers.EJBContainerTransactionManager.postInvokeTx(EJBContainerTransactionManager.java:509)
	at com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:4616)
	at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:2089)
	at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:2060)
	at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:220)
	at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:90)
	at com.sun.proxy.$Proxy404.findMinimumESIndexVersionByIndexingStatus(Unknown Source)
	at com.myorg.trex.enterprisemanager.controller.__EJB31_Generated__EMMd5Bean__Intf____Bean__.findMinimumESIndexVersionByIndexingStatus(Unknown Source)
	at com.myorg.trex.enterprisemanager.search.es.control.ESIndexManager.removeOldIndices(ESIndexManager.java:313)
	at sun.reflect.GeneratedMethodAccessor767.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.glassfish.ejb.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1081)
	at org.glassfish.ejb.security.application.EJBSecurityManager.invoke(EJBSecurityManager.java:1153)
	at com.sun.ejb.containers.BaseContainer.invokeBeanMethod(BaseContainer.java:4836)
	at com.sun.ejb.EjbInvocation.invokeBeanMethod(EjbInvocation.java:656)
	at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:836)
	at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:608)
	at org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:73)
	at org.jboss.weld.ejb.SessionBeanInterceptor.aroundInvoke(SessionBeanInterceptor.java:52)
	at sun.reflect.GeneratedMethodAccessor110.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:895)
	at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:835)
	at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:608)
	at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.doCall(SystemInterceptorProxy.java:163)
	at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.aroundTimeout(SystemInterceptorProxy.java:145)
	at sun.reflect.GeneratedMethodAccessor148.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:895)
	at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:835)
	at com.sun.ejb.containers.interceptors.InterceptorManager.intercept(InterceptorManager.java:374)
	at com.sun.ejb.containers.BaseContainer.__intercept(BaseContainer.java:4808)
	at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:4796)
	at com.sun.ejb.containers.BaseContainer.callEJBTimeout(BaseContainer.java:4074)
	at com.sun.ejb.containers.EJBTimerService.deliverTimeout(EJBTimerService.java:1228)
	at com.sun.ejb.containers.EJBTimerService.access$000(EJBTimerService.java:93)
	at com.sun.ejb.containers.EJBTimerService$TaskExpiredWork.run(EJBTimerService.java:1963)
	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:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
Caused by: javax.persistence.PersistenceException: java.lang.RuntimeException: Got exception during XAResource.end: javax.transaction.xa.XAException: com.sun.appserv.connectors.internal.api.PoolingException: java.lang.NullPointerException
	at org.eclipse.persistence.internal.jpa.QueryImpl.getSingleResult(QueryImpl.java:551)
	at org.eclipse.persistence.internal.jpa.EJBQueryImpl.getSingleResult(EJBQueryImpl.java:400)
	at com.myorg.trex.enterprisemanager.controller.EMMd5Bean.findMinimumESIndexVersionByIndexingStatus(EMMd5Bean.java:1360)
	at sun.reflect.GeneratedMethodAccessor769.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.glassfish.ejb.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1081)
	at org.glassfish.ejb.security.application.EJBSecurityManager.invoke(EJBSecurityManager.java:1153)
	at com.sun.ejb.containers.BaseContainer.invokeBeanMethod(BaseContainer.java:4836)
	at com.sun.ejb.EjbInvocation.invokeBeanMethod(EjbInvocation.java:656)
	at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:836)
	at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:608)
	at org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:64)
	at org.jboss.weld.ejb.SessionBeanInterceptor.aroundInvoke(SessionBeanInterceptor.java:52)
	at sun.reflect.GeneratedMethodAccessor110.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:895)
	at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:835)
	at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:608)
	at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.doCall(SystemInterceptorProxy.java:163)
	at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.aroundInvoke(SystemInterceptorProxy.java:140)
	at sun.reflect.GeneratedMethodAccessor111.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:895)
	at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:835)
	at com.sun.ejb.containers.interceptors.InterceptorManager.intercept(InterceptorManager.java:374)
	at com.sun.ejb.containers.BaseContainer.__intercept(BaseContainer.java:4808)
	at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:4796)
	at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:212)
	... 40 more
Caused by: java.lang.RuntimeException: Got exception during XAResource.end: javax.transaction.xa.XAException: com.sun.appserv.connectors.internal.api.PoolingException: java.lang.NullPointerException
	at com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.delistResource(JavaEETransactionManagerSimplified.java:547)
	at com.sun.enterprise.resource.rm.SystemResourceManagerImpl.delistResource(SystemResourceManagerImpl.java:145)
	at com.sun.enterprise.resource.pool.PoolManagerImpl.resourceClosed(PoolManagerImpl.java:378)
	at com.sun.enterprise.resource.listener.LocalTxConnectionEventListener.connectionClosed(LocalTxConnectionEventListener.java:77)
	at com.sun.gjc.spi.ManagedConnectionImpl.connectionClosed(ManagedConnectionImpl.java:860)
	at com.sun.gjc.spi.base.ConnectionHolder.close(ConnectionHolder.java:214)
	at com.sun.gjc.spi.jdbc40.ConnectionHolder40.close(ConnectionHolder40.java:606)
	at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.closeDatasourceConnection(DatabaseAccessor.java:495)
	at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.closeConnection(DatasourceAccessor.java:520)
	at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.closeConnection(DatabaseAccessor.java:520)
	at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.decrementCallCount(DatasourceAccessor.java:290)
	at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.closeStatement(DatabaseAccessor.java:413)
	at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.releaseStatement(DatabaseAccessor.java:1674)
	at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:705)
	at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(DatabaseAccessor.java:560)
	at org.eclipse.persistence.internal.sessions.AbstractSession.basicExecuteCall(AbstractSession.java:2056)
	at org.eclipse.persistence.sessions.server.ServerSession.executeCall(ServerSession.java:570)
	at org.eclipse.persistence.sessions.server.ClientSession.executeCall(ClientSession.java:258)
	at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:242)
	at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:228)
	at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeSelectCall(DatasourceCallQueryMechanism.java:299)
	at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.selectAllRows(DatasourceCallQueryMechanism.java:694)
	at org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllRowsFromTable(ExpressionQueryMechanism.java:2740)
	at org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllReportQueryRows(ExpressionQueryMechanism.java:2677)
	at org.eclipse.persistence.queries.ReportQuery.executeDatabaseQuery(ReportQuery.java:852)
	at org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:904)
	at org.eclipse.persistence.queries.ObjectLevelReadQuery.execute(ObjectLevelReadQuery.java:1134)
	at org.eclipse.persistence.queries.ReadAllQuery.execute(ReadAllQuery.java:460)
	at org.eclipse.persistence.queries.ObjectLevelReadQuery.executeInUnitOfWork(ObjectLevelReadQuery.java:1222)
	at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.internalExecuteQuery(UnitOfWorkImpl.java:2896)
	at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1857)
	at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1839)
	at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1804)
	at org.eclipse.persistence.internal.jpa.QueryImpl.executeReadQuery(QueryImpl.java:258)
	at org.eclipse.persistence.internal.jpa.QueryImpl.getSingleResult(QueryImpl.java:521)
	... 70 more
Caused by: javax.transaction.xa.XAException: com.sun.appserv.connectors.internal.api.PoolingException: java.lang.NullPointerException
	at com.sun.enterprise.resource.ConnectorXAResource.handleResourceException(ConnectorXAResource.java:116)
	at com.sun.enterprise.resource.ConnectorXAResource.end(ConnectorXAResource.java:175)
	at com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.delistResource(JavaEETransactionManagerSimplified.java:545)
	... 104 more
]]

Steps to reproduce (Only for bug reports)

I haven't found a clear set of ways to reproduce this, I'm hoping the traces provide some ability to dig into the code and see if any logic issues persist.

If this cannot proceed without real steps, I can try to conjure some up but this is an existing stable application otherwise, and nothing new has been introduced to change this aside from the Payara updates.

Context (Optional)

This is an existing enterprise application which was ported from GF 3.1.2 to Payara 4.1.1.171.1, and then most recently to 4.1.2.174. It runs for weeks/months at a time, and there is generally no issue, but if this kind of transient connection issue happens, it's hard to pull out of it without a restart.

I've seen other bugs on related issues (e.g. #769) , but it doesn't seem like they've fixed this problem all the way.

Environment

  • Payara Version: 4.1.2.174
  • Edition: Full
  • JDK Version: Oracle 8u144 (Windows x64)
  • Operating System: Windows Server 2008 R2
  • Database: Oracle 11gR2 on Linux

Using pool settings:

<jdbc-connection-pool validation-table-name="TABLEVALIDATION" connection-validation-method="custom-validation"
						  allow-non-component-callers="true"
						  statement-cache-size="200" associate-with-thread="true" statement-timeout-in-seconds="-1"
						  idle-timeout-in-seconds="0" lazy-connection-association="true" max-wait-time-in-millis="0"
						  connection-creation-retry-attempts="90" validate-atmost-once-period-in-seconds="120"
						  lazy-connection-enlistment="true" max-pool-size="96"
						  validation-classname="org.glassfish.api.jdbc.validation.OracleConnectionValidation"
						  datasource-classname="oracle.jdbc.xa.client.OracleXADataSource"
						  res-type="javax.sql.DataSource" name="MYPool" is-connection-validation-required="true">

Happy to try settings changes (like turning off statement cache, or using max connection usage, but it's hard to prove this out as it happens infrequently.

@smillidge
Copy link
Contributor

try without

associate-with-thread="true"

as that setting effectively removes pooling and just creates a connection per request thread.

@marcreichman
Copy link
Author

marcreichman commented Feb 16, 2018 via email

@marcreichman
Copy link
Author

@smillidge I apologize for the ping, but can you answer my last question?

Thanks,
Marc

@smillidge
Copy link
Contributor

The connection will be associated with a specific thread and will remain with that thread. It will only be removed from the thread if the thread is idle and another thread requires a connection.

It can reduce the overhead of pooling but requires careful tuning of connection pool size to request threadpool size so if web requests the http thread pool. Ideally both would be equal size.

The old docs have more information https://docs.oracle.com/cd/E19798-01/821-1752/giydr/index.html

@smillidge
Copy link
Contributor

Closing due to inactivity

@marcreichman
Copy link
Author

Hi @smillidge

I apologize but I wasn't aware there was a request for more information. We have put in changes to use more of the default connection pool settings, not knowing from history why some were changed from defaults. If this issue persists with the changed settings, I'll re-open the ticket.

Thanks!

Marc

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
PR: TESTS REQUIRED PR Requires Tests to be merged
Projects
None yet
Development

No branches or pull requests

3 participants