Wildfly 12 - hibernate/infinispan doesn't evict entity from level 2 cache
florin.spatar Jun 19, 2018 6:20 AMContext
We are in the process of migrating our app from WildFly 10.1 to WildFly 12. While testing one of our client apps, we randomly encountered an OptimisticLockException. Our client app does a sequence (nothing parallel or concurrent here) of Session Bean calls to WildFly. We use JPA over hibernate and inifinispan as level 2 cache.
2018-06-11 06:48:36,265 WARNING Thread-131 [com.opsware.locality.ejb.session.CustomerServiceBean] [setCustAttr] setCustAttr() called with the following params: self.id = 15, key = __OPSW_core_recert_new_opsware_ca
2018-06-11 06:48:36,266 WARNING Thread-131 [com.opsware.locality.impl.CustomerCustAttrImpl] [setCustAttr] Retrieved Accounts instance. modified_dt = 2018-06-11 06:48:35.0
2018-06-11 06:48:36,267 DEBUG Thread-131 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] select acctconfig0_.ACCT_ID as ACCT_ID2_1_0_, acctconfig0_.ACCT_CONFIG_ID as ACCT_CONFIG_ID1_1_0_, acctconfig0_.ACCT_CONFIG_ID as ACCT_CONFIG_ID1_1_1_, acctconfig0_.ACCT_ID as ACCT_ID2_1_1_, acctconfig0_.CONFLICTING as CONFLICTING3_1_1_, acctconfig0_.KEY_NAME as KEY_NAME4_1_1_, acctconfig0_.NAMESPACE_LUS_ID as NAMESPACE_LUS_ID5_1_1_, acctconfig0_.TRAN_ID as TRAN_ID6_1_1_ from TRUTH.ACCT_CONFIG acctconfig0_ where acctconfig0_.ACCT_ID=?
2018-06-11 06:48:36,278 WARNING Thread-131 [com.opsware.shared.helper.CustomAttributeImpl] [updateEntityModifiedTime] Setting modified_dt to 2018-06-11 06:48:36.0
2018-06-11 06:48:36,280 DEBUG Thread-131 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] insert into TRUTH.ACCT_CONFIG (ACCT_ID, KEY_NAME, NAMESPACE_LUS_ID, ACCT_CONFIG_ID) values (?, ?, ?, ?)
2018-06-11 06:48:36,286 DEBUG Thread-131 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] insert into TRUTH.ACCT_CONFIG_VALUES (CONFIG_VALUE, ACCT_CONFIG_ID, TEXT_ORDER) values (?, ?, ?)
2018-06-11 06:48:36,290 DEBUG Thread-131 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] update TRUTH.ACCOUNTS set MODIFIED_DT=? where ACCT_ID=? and MODIFIED_DT=?
2018-06-11 06:48:36,300 DEBUG Thread-90 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] select distinct virtualcol0_.VIRTUAL_COLUMN_ID as VIRTUAL_COLUMN_ID1_76_, virtualcol0_.CONFLICTING as CONFLICTING2_76_, virtualcol0_.DISPLAY_NAME as DISPLAY_NAME3_76_, virtualcol0_.TRAN_ID as TRAN_ID4_76_, virtualcol0_.VIRTUAL_COLUMN_DATATYPE as VIRTUAL_COLUMN_DAT5_76_, virtualcol0_.VIRTUAL_COLUMN_NAME as VIRTUAL_COLUMN_NAM6_76_, virtualcol0_.VIRTUAL_COLUMN_NAMESPACE as VIRTUAL_COLUMN_NAM7_76_ from AAA.VIRTUAL_COLUMN virtualcol0_ where virtualcol0_.VIRTUAL_COLUMN_NAME='full_name' and virtualcol0_.VIRTUAL_COLUMN_NAMESPACE='base'
2018-06-11 06:48:36,305 DEBUG Thread-90 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] select distinct virtualcol0_.VIRTUAL_COLUMN_ID as VIRTUAL_COLUMN_ID1_76_, virtualcol0_.CONFLICTING as CONFLICTING2_76_, virtualcol0_.DISPLAY_NAME as DISPLAY_NAME3_76_, virtualcol0_.TRAN_ID as TRAN_ID4_76_, virtualcol0_.VIRTUAL_COLUMN_DATATYPE as VIRTUAL_COLUMN_DAT5_76_, virtualcol0_.VIRTUAL_COLUMN_NAME as VIRTUAL_COLUMN_NAM6_76_, virtualcol0_.VIRTUAL_COLUMN_NAMESPACE as VIRTUAL_COLUMN_NAM7_76_ from AAA.VIRTUAL_COLUMN virtualcol0_ where virtualcol0_.VIRTUAL_COLUMN_NAME='internal' and virtualcol0_.VIRTUAL_COLUMN_NAMESPACE='base'
2018-06-11 06:48:36,328 INFO Thread-131 [org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl] [release] HHH000010: On release of batch it still contained JDBC statements
2018-06-11 06:48:36,335 INFO Thread-131 [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] [connectionClosed] IJ000311: Throwable from unregister connection
java.lang.IllegalStateException: IJ000152: Trying to return an unknown connection: org.jboss.jca.adapters.jdbc.jdk8.WrappedConnectionJDK8@68c8a039
at org.jboss.jca.core.connectionmanager.ccm.CachedConnectionManagerImpl.unregisterConnection(CachedConnectionManagerImpl.java:408)
at org.jboss.jca.core.connectionmanager.listener.TxConnectionListener.connectionClosed(TxConnectionListener.java:645)
at org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.returnHandle(BaseWrapperManagedConnection.java:596)
at org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.closeHandle(BaseWrapperManagedConnection.java:541)
at org.jboss.jca.adapters.jdbc.WrappedConnection.returnConnection(WrappedConnection.java:298)
at org.jboss.jca.adapters.jdbc.WrappedConnection.close(WrappedConnection.java:256)
at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.closeConnection(DatasourceConnectionProviderImpl.java:127)
at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.releaseConnection(AbstractSessionImpl.java:397)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.releaseConnection(LogicalConnectionManagedImpl.java:169)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.afterStatement(LogicalConnectionManagedImpl.java:122)
at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.afterStatementExecution(JdbcCoordinatorImpl.java:287)
at org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.releaseStatements(AbstractBatchImpl.java:158)
at org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.release(AbstractBatchImpl.java:195)
at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.close(JdbcCoordinatorImpl.java:192)
at org.hibernate.internal.SessionImpl.close(SessionImpl.java:424)
at org.hibernate.jpa.internal.EntityManagerImpl.close(EntityManagerImpl.java:145)
at org.jboss.as.jpa.transaction.TransactionUtil$SessionSynchronization.safeCloseEntityManager(TransactionUtil.java:181)
at org.jboss.as.jpa.transaction.TransactionUtil$SessionSynchronization.afterCompletion(TransactionUtil.java:163)
at org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList.afterCompletion(JCAOrderedLastSynchronizationList.java:147)
at org.wildfly.transaction.client.AbstractTransaction.performConsumer(AbstractTransaction.java:196)
at org.wildfly.transaction.client.AbstractTransaction$AssociatingSynchronization.afterCompletion(AbstractTransaction.java:279)
at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.afterCompletion(SynchronizationImple.java:96)
at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.afterCompletion(TwoPhaseCoordinator.java:542)
at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.afterCompletion(TwoPhaseCoordinator.java:473)
at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.cancel(TwoPhaseCoordinator.java:127)
at com.arjuna.ats.arjuna.AtomicAction.abort(AtomicAction.java:186)
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.rollbackAndDisassociate(TransactionImple.java:1371)
at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.rollback(BaseTransaction.java:143)
at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.rollback(BaseTransactionManagerDelegate.java:134)
at org.wildfly.transaction.client.LocalTransaction.rollbackAndDissociate(LocalTransaction.java:104)
at org.wildfly.transaction.client.ContextTransactionManager.rollback(ContextTransactionManager.java:83)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:92)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:277)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:330)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:238)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:89)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.interceptors.EjbExceptionTransformingInterceptorFactories$1.processInvocation(EjbExceptionTransformingInterceptorFactories.java:80)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438)
at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:619)
at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:198)
at org.jboss.as.ejb3.remote.LocalEjbReceiver.processInvocation(LocalEjbReceiver.java:266)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:454)
at org.jboss.ejb.protocol.remote.RemotingEJBClientInterceptor.handleInvocation(RemotingEJBClientInterceptor.java:51)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:466)
at org.jboss.ejb.client.TransactionPostDiscoveryInterceptor.handleInvocation(TransactionPostDiscoveryInterceptor.java:79)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:466)
at org.jboss.ejb.client.DiscoveryEJBClientInterceptor.handleInvocation(DiscoveryEJBClientInterceptor.java:94)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:466)
at org.jboss.ejb.client.NamingEJBClientInterceptor.handleInvocation(NamingEJBClientInterceptor.java:63)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:466)
at org.jboss.ejb.client.TransactionInterceptor.handleInvocation(TransactionInterceptor.java:165)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:466)
at org.wildfly.common.context.Contextual.runExConsumer(Contextual.java:203)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequestInitial(EJBClientInvocationContext.java:302)
at org.jboss.ejb.client.EJBInvocationHandler.invoke(EJBInvocationHandler.java:173)
at org.jboss.ejb.client.EJBInvocationHandler.invoke(EJBInvocationHandler.java:112)
at com.sun.proxy.$Proxy156._opsw__setCustAttr(Unknown Source)
at com.opsware._gen.client.locality._CustomerServiceStub._opsw__setCustAttr(_CustomerServiceStub.java:105)
at com.opsware._gen.client.locality._CustomerServiceStub.setCustAttr(_CustomerServiceStub.java:97)
at sun.reflect.GeneratedMethodAccessor184.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.opsware.serialization.TwistRefMethod.invoke(TwistRefMethod.java:59)
at com.opsware.webapp.externalaccess.ExternalTwistInvoker.invoke(ExternalTwistInvoker.java:95)
at com.opsware.webapp.externalaccess.ExternalAccessServlet.process(ExternalAccessServlet.java:176)
at com.opsware.webapp.externalaccess.ExternalAccessServlet.doPost(ExternalAccessServlet.java:95)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74)
at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
at io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:67)
at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131)
at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
at io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)
at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:292)
at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)
at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)
at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
at org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1526)
at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1526)
at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1526)
at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1526)
at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)
at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
at io.undertow.servlet.handlers.ServletInitialHandler$1$1.run(ServletInitialHandler.java:110)
at java.security.AccessController.doPrivileged(Native Method)
at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:107)
at io.undertow.server.Connectors.executeRootHandler(Connectors.java:360)
at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1985)
at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1487)
at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1378)
at java.lang.Thread.run(Thread.java:748)
2018-06-11 06:48:36,337 DEBUG Thread-143 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] select devicerebo0_.DVC_ID as DVC_ID1_138_0_, devicerebo0_.CONFLICTING as CONFLICTING2_138_0_, devicerebo0_.CREATE_DT as CREATE_DT3_138_0_, devicerebo0_.TRAN_ID as TRAN_ID4_138_0_ from TRUTH.DEVICE_REBOOT_REQUIRED devicerebo0_ where devicerebo0_.DVC_ID=?
2018-06-11 06:48:36,340 DEBUG Thread-143 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] select accounts0_.ACCT_ID as ACCT_ID1_0_0_, accounts0_.ACCT_NAME as ACCT_NAME2_0_0_, accounts0_.AUTH_DOMAIN as AUTH_DOMAIN3_0_0_, accounts0_.BUSINESS_ACCT_ID as BUSINESS_ACCT_ID4_0_0_, accounts0_.CONFLICTING as CONFLICTING5_0_0_, accounts0_.CREATED_BY as CREATED_BY6_0_0_, accounts0_.CREATED_DT as CREATED_DT7_0_0_, accounts0_.DISPLAY_NAME as DISPLAY_NAME8_0_0_, accounts0_.INTERNAL_ACCT_FLG as INTERNAL_ACCT_FLG9_0_0_, accounts0_.MODIFIED_BY as MODIFIED_BY10_0_0_, accounts0_.MODIFIED_DT as MODIFIED_DT11_0_0_, accounts0_.STATUS as STATUS12_0_0_, accounts0_.TRAN_ID as TRAN_ID13_0_0_, accounts0_.USE_ROLE_CLASSES_FLG as USE_ROLE_CLASSES_14_0_0_ from TRUTH.ACCOUNTS accounts0_ where accounts0_.ACCT_ID=?
2018-06-11 06:48:36,355 DEBUG Thread-90 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] select distinct virtualcol0_.VIRTUAL_COLUMN_ID as VIRTUAL_COLUMN_ID1_76_, virtualcol0_.CONFLICTING as CONFLICTING2_76_, virtualcol0_.DISPLAY_NAME as DISPLAY_NAME3_76_, virtualcol0_.TRAN_ID as TRAN_ID4_76_, virtualcol0_.VIRTUAL_COLUMN_DATATYPE as VIRTUAL_COLUMN_DAT5_76_, virtualcol0_.VIRTUAL_COLUMN_NAME as VIRTUAL_COLUMN_NAM6_76_, virtualcol0_.VIRTUAL_COLUMN_NAMESPACE as VIRTUAL_COLUMN_NAM7_76_ from AAA.VIRTUAL_COLUMN virtualcol0_ where virtualcol0_.VIRTUAL_COLUMN_NAME='full_name' and virtualcol0_.VIRTUAL_COLUMN_NAMESPACE='base'
2018-06-11 06:48:36,360 DEBUG Thread-90 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] select distinct virtualcol0_.VIRTUAL_COLUMN_ID as VIRTUAL_COLUMN_ID1_76_, virtualcol0_.CONFLICTING as CONFLICTING2_76_, virtualcol0_.DISPLAY_NAME as DISPLAY_NAME3_76_, virtualcol0_.TRAN_ID as TRAN_ID4_76_, virtualcol0_.VIRTUAL_COLUMN_DATATYPE as VIRTUAL_COLUMN_DAT5_76_, virtualcol0_.VIRTUAL_COLUMN_NAME as VIRTUAL_COLUMN_NAM6_76_, virtualcol0_.VIRTUAL_COLUMN_NAMESPACE as VIRTUAL_COLUMN_NAM7_76_ from AAA.VIRTUAL_COLUMN virtualcol0_ where virtualcol0_.VIRTUAL_COLUMN_NAME='internal' and virtualcol0_.VIRTUAL_COLUMN_NAMESPACE='base'
2018-06-11 06:48:36,398 SEVERE Thread-131 [com.opsware.webapp.externalaccess.ExternalAccessServlet] [process] Exception while invoking facade
java.lang.reflect.InvocationTargetException
at sun.reflect.GeneratedMethodAccessor184.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.opsware.serialization.TwistRefMethod.invoke(TwistRefMethod.java:59)
at com.opsware.webapp.externalaccess.ExternalTwistInvoker.invoke(ExternalTwistInvoker.java:95)
at com.opsware.webapp.externalaccess.ExternalAccessServlet.process(ExternalAccessServlet.java:176)
at com.opsware.webapp.externalaccess.ExternalAccessServlet.doPost(ExternalAccessServlet.java:95)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74)
at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
at io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:67)
at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131)
at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
at io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)
at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:292)
at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)
at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)
at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
at org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1526)
at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1526)
at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1526)
at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1526)
at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)
at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
at io.undertow.servlet.handlers.ServletInitialHandler$1$1.run(ServletInitialHandler.java:110)
at java.security.AccessController.doPrivileged(Native Method)
at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:107)
at io.undertow.server.Connectors.executeRootHandler(Connectors.java:360)
at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1985)
at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1487)
at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1378)
at java.lang.Thread.run(Thread.java:748)
Caused by: com.opsware.common.WriteException: ID: HPSA-013
Code: com.opsware.common.MessageSpec.WRITE_PERSISTENCE_ERROR
Details: A Persistence layer error occurred while trying to write an object.
at com.opsware.shared.ejb.session.WriterBean.end(WriterBean.java:90)
at com.opsware._gen.sejb.locality._CustomerServiceBean._opsw__setCustAttr(_CustomerServiceBean.java:1992)
at sun.reflect.GeneratedMethodAccessor185.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.jpa.interceptor.SBInvocationInterceptor.processInvocation(SBInvocationInterceptor.java:47)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:45)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:40)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
at org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:52)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.pool.PooledInstanceInterceptor.processInvocation(PooledInstanceInterceptor.java:51)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:273)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:330)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:238)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:89)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.interceptors.EjbExceptionTransformingInterceptorFactories$1.processInvocation(EjbExceptionTransformingInterceptorFactories.java:80)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438)
at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:619)
at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:198)
at org.jboss.as.ejb3.remote.LocalEjbReceiver.processInvocation(LocalEjbReceiver.java:266)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:454)
at org.jboss.ejb.protocol.remote.RemotingEJBClientInterceptor.handleInvocation(RemotingEJBClientInterceptor.java:51)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:466)
at org.jboss.ejb.client.TransactionPostDiscoveryInterceptor.handleInvocation(TransactionPostDiscoveryInterceptor.java:79)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:466)
at org.jboss.ejb.client.DiscoveryEJBClientInterceptor.handleInvocation(DiscoveryEJBClientInterceptor.java:94)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:466)
at org.jboss.ejb.client.NamingEJBClientInterceptor.handleInvocation(NamingEJBClientInterceptor.java:63)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:466)
at org.jboss.ejb.client.TransactionInterceptor.handleInvocation(TransactionInterceptor.java:165)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:466)
at org.wildfly.common.context.Contextual.runExConsumer(Contextual.java:203)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequestInitial(EJBClientInvocationContext.java:302)
at org.jboss.ejb.client.EJBInvocationHandler.invoke(EJBInvocationHandler.java:173)
at org.jboss.ejb.client.EJBInvocationHandler.invoke(EJBInvocationHandler.java:112)
at com.sun.proxy.$Proxy156._opsw__setCustAttr(Unknown Source)
at com.opsware._gen.client.locality._CustomerServiceStub._opsw__setCustAttr(_CustomerServiceStub.java:105)
at com.opsware._gen.client.locality._CustomerServiceStub.setCustAttr(_CustomerServiceStub.java:97)
... 51 more
Caused by: com.opsware.common.ProxySystemException: ID: HPSA-019
Code: com.opsware.common.MessageSpec.PROXY_EXCEPTION
Details: An internal exception of type javax.persistence.OptimisticLockException with message Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1 was caught.
at org.hibernate.jpa.spi.AbstractEntityManagerImpl.wrapStaleStateException(AbstractEntityManagerImpl.java:1729)
at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1634)
at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1602)
at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1608)
at org.hibernate.jpa.spi.AbstractEntityManagerImpl.flush(AbstractEntityManagerImpl.java:1303)
at org.jboss.as.jpa.container.AbstractEntityManager.flush(AbstractEntityManager.java:459)
at com.opsware.shared.ejb.session.TxObserverBean.flushUpdates(TxObserverBean.java:86)
at sun.reflect.GeneratedMethodAccessor96.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.jpa.interceptor.SBInvocationInterceptor.processInvocation(SBInvocationInterceptor.java:47)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.jpa.interceptor.SFSBInvocationInterceptor.processInvocation(SFSBInvocationInterceptor.java:57)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor.processInvocation(StatefulSessionSynchronizationInterceptor.java:135)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:45)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:40)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
at org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:52)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.stateful.StatefulComponentInstanceInterceptor.processInvocation(StatefulComponentInstanceInterceptor.java:59)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInCallerTx(CMTTxInterceptor.java:253)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:332)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:238)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:84)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.interceptors.EjbExceptionTransformingInterceptorFactories$1.processInvocation(EjbExceptionTransformingInterceptorFactories.java:80)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438)
at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:619)
at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:198)
at org.jboss.as.ejb3.remote.LocalEjbReceiver.processInvocation(LocalEjbReceiver.java:266)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:454)
at org.jboss.ejb.protocol.remote.RemotingEJBClientInterceptor.handleInvocation(RemotingEJBClientInterceptor.java:51)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:466)
at org.jboss.ejb.client.TransactionPostDiscoveryInterceptor.handleInvocation(TransactionPostDiscoveryInterceptor.java:79)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:466)
at org.jboss.ejb.client.DiscoveryEJBClientInterceptor.handleInvocation(DiscoveryEJBClientInterceptor.java:89)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:466)
at org.jboss.ejb.client.NamingEJBClientInterceptor.handleInvocation(NamingEJBClientInterceptor.java:63)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:466)
at org.jboss.ejb.client.TransactionInterceptor.handleInvocation(TransactionInterceptor.java:165)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:466)
at org.wildfly.common.context.Contextual.runExConsumer(Contextual.java:203)
at org.jboss.ejb.client.EJBClientInvocationContext.sendRequestInitial(EJBClientInvocationContext.java:302)
at org.jboss.ejb.client.EJBInvocationHandler.invoke(EJBInvocationHandler.java:173)
at org.jboss.ejb.client.EJBInvocationHandler.invoke(EJBInvocationHandler.java:112)
at com.sun.proxy.$Proxy109.flushUpdates(Unknown Source)
at com.opsware.shared.ejb.session.WriterBean.end(WriterBean.java:88)
... 121 more
Caused by: com.opsware.common.ProxySystemException: ID: HPSA-019
Code: com.opsware.common.MessageSpec.PROXY_EXCEPTION
Details: An internal exception of type org.hibernate.StaleStateException with message Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1 was caught.
at org.hibernate.jdbc.Expectations$BasicExpectation.checkBatched(Expectations.java:67)
at org.hibernate.jdbc.Expectations$BasicExpectation.verifyOutcome(Expectations.java:54)
at org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:46)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3184)
at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:3063)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3443)
at org.hibernate.action.internal.EntityUpdateAction.execute(EntityUpdateAction.java:145)
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:589)
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:463)
at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:337)
at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39)
at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1295)
at org.hibernate.jpa.spi.AbstractEntityManagerImpl.flush(AbstractEntityManagerImpl.java:1300)
... 195 more
Investigation
The problem is difficult to investigate as it happens randomly.
I enabled org.hibernate.SQL logs and it seams like after an SQL update the corresponding entity is not evicted from hibernate level 2 cache.
2018-06-11 06:48:36,174 WARNING Thread-90 [com.opsware.locality.ejb.session.CustomerServiceBean] [setCustAttr] setCustAttr() called with the following params: self.id = 15, key = __OPSW_core_recert_new_agent_ca
2018-06-11 06:48:36,175 WARNING Thread-90 [com.opsware.locality.impl.CustomerCustAttrImpl] [setCustAttr] Retrieved Accounts instance. modified_dt = 2018-06-11 06:48:35.0
2018-06-11 06:48:36,186 DEBUG Thread-90 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] select customercl0_.ACCT_ID as ACCT_ID2_118_0_, customercl0_.CUST_CLD_ID as CUST_CLD_ID1_118_0_, customercl0_.CUST_CLD_ID as CUST_CLD_ID1_118_1_, customercl0_.ACCT_ID as ACCT_ID2_118_1_, customercl0_.CONFLICTING as CONFLICTING3_118_1_, customercl0_.DATA_CENTER_ID as DATA_CENTER_ID4_118_1_, customercl0_.LOG_HOST as LOG_HOST5_118_1_, customercl0_.MONITOR_FLG as MONITOR_FLG6_118_1_, customercl0_.TRAN_ID as TRAN_ID7_118_1_ from TRUTH.CUSTOMER_CLOUDS customercl0_ where customercl0_.ACCT_ID=?
2018-06-11 06:48:36,190 DEBUG Thread-90 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] select devicerole0_.CUST_CLD_ID as CUST_CLD_ID6_143_0_, devicerole0_.DVC_ROLE_ID as DVC_ROLE_ID1_143_0_, devicerole0_.DVC_ROLE_ID as DVC_ROLE_ID1_143_1_, devicerole0_.CONFIG_STORE_ENABLED as CONFIG_STORE_ENABL2_143_1_, devicerole0_.CONFLICTING as CONFLICTING3_143_1_, devicerole0_.CREATE_DT as CREATE_DT4_143_1_, devicerole0_.CREATED_BY as CREATED_BY5_143_1_, devicerole0_.CUST_CLD_ID as CUST_CLD_ID6_143_1_, devicerole0_.DVC_ID as DVC_ID7_143_1_, devicerole0_.DVC_ROLE_NAME as DVC_ROLE_NAME8_143_1_, devicerole0_.EFF_BEG_DT as EFF_BEG_DT9_143_1_, devicerole0_.JIVE_TEMPLATE_ID as JIVE_TEMPLATE_ID10_143_1_, devicerole0_.MODIFIED_BY as MODIFIED_BY11_143_1_, devicerole0_.MODIFIED_DT as MODIFIED_DT12_143_1_, devicerole0_.STATUS as STATUS13_143_1_, devicerole0_.TRAN_ID as TRAN_ID14_143_1_ from TRUTH.DEVICE_ROLES devicerole0_ where devicerole0_.CUST_CLD_ID=?
2018-06-11 06:48:36,193 DEBUG Thread-143 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] select distinct virtualcol0_.VIRTUAL_COLUMN_ID as VIRTUAL_COLUMN_ID1_76_, virtualcol0_.CONFLICTING as CONFLICTING2_76_, virtualcol0_.DISPLAY_NAME as DISPLAY_NAME3_76_, virtualcol0_.TRAN_ID as TRAN_ID4_76_, virtualcol0_.VIRTUAL_COLUMN_DATATYPE as VIRTUAL_COLUMN_DAT5_76_, virtualcol0_.VIRTUAL_COLUMN_NAME as VIRTUAL_COLUMN_NAM6_76_, virtualcol0_.VIRTUAL_COLUMN_NAMESPACE as VIRTUAL_COLUMN_NAM7_76_ from AAA.VIRTUAL_COLUMN virtualcol0_ where virtualcol0_.VIRTUAL_COLUMN_NAME='full_name' and virtualcol0_.VIRTUAL_COLUMN_NAMESPACE='base'
2018-06-11 06:48:36,195 WARNING Thread-90 [com.opsware.shared.helper.CustomAttributeImpl] [updateEntityModifiedTime] Setting modified_dt to 2018-06-11 06:48:36.0
2018-06-11 06:48:36,197 DEBUG Thread-90 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] insert into TRUTH.ACCT_CONFIG (ACCT_ID, KEY_NAME, NAMESPACE_LUS_ID, ACCT_CONFIG_ID) values (?, ?, ?, ?)
2018-06-11 06:48:36,197 DEBUG Thread-143 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] select distinct virtualcol0_.VIRTUAL_COLUMN_ID as VIRTUAL_COLUMN_ID1_76_, virtualcol0_.CONFLICTING as CONFLICTING2_76_, virtualcol0_.DISPLAY_NAME as DISPLAY_NAME3_76_, virtualcol0_.TRAN_ID as TRAN_ID4_76_, virtualcol0_.VIRTUAL_COLUMN_DATATYPE as VIRTUAL_COLUMN_DAT5_76_, virtualcol0_.VIRTUAL_COLUMN_NAME as VIRTUAL_COLUMN_NAM6_76_, virtualcol0_.VIRTUAL_COLUMN_NAMESPACE as VIRTUAL_COLUMN_NAM7_76_ from AAA.VIRTUAL_COLUMN virtualcol0_ where virtualcol0_.VIRTUAL_COLUMN_NAME='internal' and virtualcol0_.VIRTUAL_COLUMN_NAMESPACE='base'
2018-06-11 06:48:36,216 DEBUG Thread-90 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] insert into TRUTH.ACCT_CONFIG_VALUES (CONFIG_VALUE, ACCT_CONFIG_ID, TEXT_ORDER) values (?, ?, ?)
2018-06-11 06:48:36,219 DEBUG Thread-90 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] insert into TRUTH.ACCT_CONFIG_VALUES (CONFIG_VALUE, ACCT_CONFIG_ID, TEXT_ORDER) values (?, ?, ?)
2018-06-11 06:48:36,222 DEBUG Thread-90 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] update TRUTH.ACCOUNTS set MODIFIED_DT=? where ACCT_ID=? and MODIFIED_DT=?
2018-06-11 06:48:36,225 DEBUG Thread-131 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] select devicerebo0_.DVC_ID as DVC_ID1_138_0_, devicerebo0_.CONFLICTING as CONFLICTING2_138_0_, devicerebo0_.CREATE_DT as CREATE_DT3_138_0_, devicerebo0_.TRAN_ID as TRAN_ID4_138_0_ from TRUTH.DEVICE_REBOOT_REQUIRED devicerebo0_ where devicerebo0_.DVC_ID=?
2018-06-11 06:48:36,229 DEBUG Thread-131 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] select accounts0_.ACCT_ID as ACCT_ID1_0_0_, accounts0_.ACCT_NAME as ACCT_NAME2_0_0_, accounts0_.AUTH_DOMAIN as AUTH_DOMAIN3_0_0_, accounts0_.BUSINESS_ACCT_ID as BUSINESS_ACCT_ID4_0_0_, accounts0_.CONFLICTING as CONFLICTING5_0_0_, accounts0_.CREATED_BY as CREATED_BY6_0_0_, accounts0_.CREATED_DT as CREATED_DT7_0_0_, accounts0_.DISPLAY_NAME as DISPLAY_NAME8_0_0_, accounts0_.INTERNAL_ACCT_FLG as INTERNAL_ACCT_FLG9_0_0_, accounts0_.MODIFIED_BY as MODIFIED_BY10_0_0_, accounts0_.MODIFIED_DT as MODIFIED_DT11_0_0_, accounts0_.STATUS as STATUS12_0_0_, accounts0_.TRAN_ID as TRAN_ID13_0_0_, accounts0_.USE_ROLE_CLASSES_FLG as USE_ROLE_CLASSES_14_0_0_ from TRUTH.ACCOUNTS accounts0_ where accounts0_.ACCT_ID=?
2018-06-11 06:48:36,250 DEBUG Thread-143 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] select distinct virtualcol0_.VIRTUAL_COLUMN_ID as VIRTUAL_COLUMN_ID1_76_, virtualcol0_.CONFLICTING as CONFLICTING2_76_, virtualcol0_.DISPLAY_NAME as DISPLAY_NAME3_76_, virtualcol0_.TRAN_ID as TRAN_ID4_76_, virtualcol0_.VIRTUAL_COLUMN_DATATYPE as VIRTUAL_COLUMN_DAT5_76_, virtualcol0_.VIRTUAL_COLUMN_NAME as VIRTUAL_COLUMN_NAM6_76_, virtualcol0_.VIRTUAL_COLUMN_NAMESPACE as VIRTUAL_COLUMN_NAM7_76_ from AAA.VIRTUAL_COLUMN virtualcol0_ where virtualcol0_.VIRTUAL_COLUMN_NAME='full_name' and virtualcol0_.VIRTUAL_COLUMN_NAMESPACE='base'
2018-06-11 06:48:36,255 DEBUG Thread-143 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] select distinct virtualcol0_.VIRTUAL_COLUMN_ID as VIRTUAL_COLUMN_ID1_76_, virtualcol0_.CONFLICTING as CONFLICTING2_76_, virtualcol0_.DISPLAY_NAME as DISPLAY_NAME3_76_, virtualcol0_.TRAN_ID as TRAN_ID4_76_, virtualcol0_.VIRTUAL_COLUMN_DATATYPE as VIRTUAL_COLUMN_DAT5_76_, virtualcol0_.VIRTUAL_COLUMN_NAME as VIRTUAL_COLUMN_NAM6_76_, virtualcol0_.VIRTUAL_COLUMN_NAMESPACE as VIRTUAL_COLUMN_NAM7_76_ from AAA.VIRTUAL_COLUMN virtualcol0_ where virtualcol0_.VIRTUAL_COLUMN_NAME='internal' and virtualcol0_.VIRTUAL_COLUMN_NAMESPACE='base'
2018-06-11 06:48:36,265 WARNING Thread-131 [com.opsware.locality.ejb.session.CustomerServiceBean] [setCustAttr] setCustAttr() called with the following params: self.id = 15, key = __OPSW_core_recert_new_opsware_ca
2018-06-11 06:48:36,266 WARNING Thread-131 [com.opsware.locality.impl.CustomerCustAttrImpl] [setCustAttr] Retrieved Accounts instance. modified_dt = 2018-06-11 06:48:35.0
2018-06-11 06:48:36,267 DEBUG Thread-131 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] select acctconfig0_.ACCT_ID as ACCT_ID2_1_0_, acctconfig0_.ACCT_CONFIG_ID as ACCT_CONFIG_ID1_1_0_, acctconfig0_.ACCT_CONFIG_ID as ACCT_CONFIG_ID1_1_1_, acctconfig0_.ACCT_ID as ACCT_ID2_1_1_, acctconfig0_.CONFLICTING as CONFLICTING3_1_1_, acctconfig0_.KEY_NAME as KEY_NAME4_1_1_, acctconfig0_.NAMESPACE_LUS_ID as NAMESPACE_LUS_ID5_1_1_, acctconfig0_.TRAN_ID as TRAN_ID6_1_1_ from TRUTH.ACCT_CONFIG acctconfig0_ where acctconfig0_.ACCT_ID=?
2018-06-11 06:48:36,278 WARNING Thread-131 [com.opsware.shared.helper.CustomAttributeImpl] [updateEntityModifiedTime] Setting modified_dt to 2018-06-11 06:48:36.0
2018-06-11 06:48:36,280 DEBUG Thread-131 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] insert into TRUTH.ACCT_CONFIG (ACCT_ID, KEY_NAME, NAMESPACE_LUS_ID, ACCT_CONFIG_ID) values (?, ?, ?, ?)
2018-06-11 06:48:36,286 DEBUG Thread-131 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] insert into TRUTH.ACCT_CONFIG_VALUES (CONFIG_VALUE, ACCT_CONFIG_ID, TEXT_ORDER) values (?, ?, ?)
2018-06-11 06:48:36,290 DEBUG Thread-131 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] update TRUTH.ACCOUNTS set MODIFIED_DT=? where ACCT_ID=? and MODIFIED_DT=?
2018-06-11 06:48:36,300 DEBUG Thread-90 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] select distinct virtualcol0_.VIRTUAL_COLUMN_ID as VIRTUAL_COLUMN_ID1_76_, virtualcol0_.CONFLICTING as CONFLICTING2_76_, virtualcol0_.DISPLAY_NAME as DISPLAY_NAME3_76_, virtualcol0_.TRAN_ID as TRAN_ID4_76_, virtualcol0_.VIRTUAL_COLUMN_DATATYPE as VIRTUAL_COLUMN_DAT5_76_, virtualcol0_.VIRTUAL_COLUMN_NAME as VIRTUAL_COLUMN_NAM6_76_, virtualcol0_.VIRTUAL_COLUMN_NAMESPACE as VIRTUAL_COLUMN_NAM7_76_ from AAA.VIRTUAL_COLUMN virtualcol0_ where virtualcol0_.VIRTUAL_COLUMN_NAME='full_name' and virtualcol0_.VIRTUAL_COLUMN_NAMESPACE='base'
2018-06-11 06:48:36,305 DEBUG Thread-90 [org.hibernate.engine.jdbc.spi.SqlStatementLogger] [logStatement] select distinct virtualcol0_.VIRTUAL_COLUMN_ID as VIRTUAL_COLUMN_ID1_76_, virtualcol0_.CONFLICTING as CONFLICTING2_76_, virtualcol0_.DISPLAY_NAME as DISPLAY_NAME3_76_, virtualcol0_.TRAN_ID as TRAN_ID4_76_, virtualcol0_.VIRTUAL_COLUMN_DATATYPE as VIRTUAL_COLUMN_DAT5_76_, virtualcol0_.VIRTUAL_COLUMN_NAME as VIRTUAL_COLUMN_NAM6_76_, virtualcol0_.VIRTUAL_COLUMN_NAMESPACE as VIRTUAL_COLUMN_NAM7_76_ from AAA.VIRTUAL_COLUMN virtualcol0_ where virtualcol0_.VIRTUAL_COLUMN_NAME='internal' and virtualcol0_.VIRTUAL_COLUMN_NAMESPACE='base'
2018-06-11 06:48:36,328 INFO Thread-131 [org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl] [release] HHH000010: On release of batch it still contained JDBC statements
2018-06-11 06:48:36,335 INFO Thread-131 [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] [connectionClosed] IJ000311: Throwable from unregister connection
java.lang.IllegalStateException: IJ000152: Trying to return an unknown connection: org.jboss.jca.adapters.jdbc.jdk8.WrappedConnectionJDK8@68c8a039
Each SQL update on the ACCOUNTS table should trigger an eviction from hibernate level 2 cache for the Account entity, and next time the Accounts entity is loaded there should be an SQL select in the logs. The above logs indicate that there is no SQL select when retrieving the Accounts entity, so it must be retrieved from the hibernate level 2 cache. This seams to be a bug in hibernate/infinispan eviction.
The hibernate cache is configured like this in standalone-full.xml
<cache-container name="hibernate" module="org.infinispan.hibernate-cache">
<local-cache name="entity">
<transaction mode="NON_XA" locking="OPTIMISTIC"/>
<locking acquire-timeout="60000" isolation="READ_COMMITTED"/>
<expiration max-idle="180000"/>
<binary-memory size="10000" eviction-type="MEMORY"/>
</local-cache>
<local-cache name="local-query">
<binary-memory size="10000" eviction-type="MEMORY"/>
<expiration max-idle="100000"/>
</local-cache>
<local-cache name="timestamps"/>
</cache-container>
It seams like the error happens more rarely if I change eviction-type to COUNT (which is default in WildFly 12).
Infinispan logs are in attachment.
Any idea on how to further investigate this will be much appreciated.