We've an application deployed on WAS 9 (JSF, in case it matters) and noticed that, randomly, the application stops working properly after a redeployment (all POST requests fail and we're always redirected to the homepage).
The log shows the same error happening everytime we click a button in the application, that, in a nutshell, is an Oracle error complaining about an insertion using a duplicate key (every action performed on the application is audited and that's the insertion that is failing and causing the error). After some digging, I also noticed that the problem was occurring only on some browsers and that deleting the cookies and restaring the browser "solved" the problem.
The same application is running without any issue on GlassFish, so this is cleary a problem with WebSphere.
My layman's conclusion is that the server is caching something it shouldn't and running the same insert over and over again, hence the exception.
Is this a known issue? Any suggestions on how to solve this?
This is probably related to other problem I reported here, but I'm just guessing.
Here's the relevant part of the log:
Error Code: 1
Call: INSERT INTO AUDIT (EVENT_ACTION_TYPE, EVENT_DESCRIPTION, EVENT_LOGICAL_NAME, EVENT_ORIGIN, EVENT_RESULT, EVENT_USERNAME, EVENT_TIMESTAMP, EVENT_MODULE) VALUES (?, ?, ?, ?, ?, ?, ?, ?)
bind => [LOGOUT, john.doe, N/A, localhost, S, system, 2016-12-21 16:35:19.821, ECC]
Query: InsertObjectQuery(x.EccAudit[ eccAuditPK=x.EccAuditPK[ eventUsername=system, eventTimestamp=Wed Dec 21 16:35:19 WET 2016, eventModule=ECC ] ])
at org.eclipse.persistence.exceptions.DatabaseException.sqlException(DatabaseException.java:331) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeDirectNoSelect(DatabaseAccessor.java:902) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeNoSelect(DatabaseAccessor.java:964) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:633) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(DatabaseAccessor.java:560) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.sessions.AbstractSession.basicExecuteCall(AbstractSession.java:2061) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.sessions.server.ClientSession.executeCall(ClientSession.java:309) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:242) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:228) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.insertObject(DatasourceCallQueryMechanism.java:377) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.queries.StatementQueryMechanism.insertObject(StatementQueryMechanism.java:165) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.queries.StatementQueryMechanism.insertObject(StatementQueryMechanism.java:180) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.queries.DatabaseQueryMechanism.insertObjectForWrite(DatabaseQueryMechanism.java:489) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.queries.InsertObjectQuery.executeCommit(InsertObjectQuery.java:80) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.queries.InsertObjectQuery.executeCommitWithChangeSet(InsertObjectQuery.java:90) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.queries.DatabaseQueryMechanism.executeWriteWithChangeSet(DatabaseQueryMechanism.java:301) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.queries.WriteObjectQuery.executeDatabaseQuery(WriteObjectQuery.java:58) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:911) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.queries.DatabaseQuery.executeInUnitOfWork(DatabaseQuery.java:810) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.queries.ObjectLevelModifyQuery.executeInUnitOfWorkObjectLevelModifyQuery(ObjectLevelModifyQuery.java:108) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.queries.ObjectLevelModifyQuery.executeInUnitOfWork(ObjectLevelModifyQuery.java:85) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.internalExecuteQuery(UnitOfWorkImpl.java:2899) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1863) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1845) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1796) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.sessions.CommitManager.commitNewObjectsForClassWithChangeSet(CommitManager.java:227) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.sessions.CommitManager.commitAllObjectsWithChangeSet(CommitManager.java:126) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.sessions.AbstractSession.writeAllObjectsWithChangeSet(AbstractSession.java:4275) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.commitToDatabase(UnitOfWorkImpl.java:1444) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.commitToDatabaseWithChangeSet(UnitOfWorkImpl.java:1534) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.sessions.RepeatableWriteUnitOfWork.commitRootUnitOfWork(RepeatableWriteUnitOfWork.java:278) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.commit(UnitOfWorkImpl.java:1116) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at org.eclipse.persistence.internal.jpa.transaction.EntityTransactionImpl.commit(EntityTransactionImpl.java:137) ~[com.ibm.ws.jpa.eclipselink.jar:na]
... 45 common frames omitted
Caused by: com.ibm.websphere.ce.cm.DuplicateKeyException: ORA-00001: unique constraint (EPMS_CL1.ECC_AUDIT_PK) violated
at sun.reflect.GeneratedConstructorAccessor150.newInstance(Unknown Source) ~[na:na]
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:57) ~[na:1.8.0-internal]
at java.lang.reflect.Constructor.newInstance(Constructor.java:437) ~[na:2.6 (04-27-2016)]
at com.ibm.websphere.rsadapter.GenericDataStoreHelper.mapExceptionHelper(GenericDataStoreHelper.java:628) ~[rsahelpers.jar:WAS90.SERV1 [cf011635.01]]
at com.ibm.websphere.rsadapter.GenericDataStoreHelper.mapException(GenericDataStoreHelper.java:687) ~[rsahelpers.jar:WAS90.SERV1 [cf011635.01]]
at com.ibm.ws.rsadapter.AdapterUtil.mapException(AdapterUtil.java:2273) ~[com.ibm.ws.runtime.jar:na]
at com.ibm.ws.rsadapter.jdbc.WSJdbcUtil.mapException(WSJdbcUtil.java:1191) ~[com.ibm.ws.runtime.jar:na]
at com.ibm.ws.rsadapter.jdbc.WSJdbcPreparedStatement.executeUpdate(WSJdbcPreparedStatement.java:822) ~[com.ibm.ws.runtime.jar:na]
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeDirectNoSelect(DatabaseAccessor.java:892) ~[com.ibm.ws.jpa.eclipselink.jar:na]
... 76 common frames omitted
[12/21/16 16:35:19:837 WET] 0000018f SystemOut O [ERROR] -
Exception Description: No transaction is currently active
java.lang.IllegalStateException:
Exception Description: No transaction is currently active
at org.eclipse.persistence.internal.jpa.transaction.EntityTransactionImpl.rollback(EntityTransactionImpl.java:178) ~[com.ibm.ws.jpa.eclipselink.jar:na]
at pt.sibs.epms.persistence.facade.AbstractFacade.execute(AbstractFacade.java:102) [epms-persistence.jar:EPMS V11120002L]
at pt.sibs.epms.persistence.facade.AbstractFacade.create(AbstractFacade.java:51) [epms-persistence.jar:EPMS V11120002L]
at pt.sibs.epms.ecc.audit.AuditController.audit(AuditController.java:139) [classes/:na]
at pt.sibs.epms.ecc.audit.AuditController.audit(AuditController.java:74) [classes/:na]
at pt.sibs.epms.ecc.audit.AuditController.auditSuccess(AuditController.java:173) [classes/:na]
at pt.sibs.epms.ecc.listener.SessionAttributeListener.attributeRemoved(SessionAttributeListener.java:58) [classes/:na]
at com.ibm.ws.session.http.HttpSessionAttributeObserver.sessionAttributeRemoved(HttpSessionAttributeObserver.java:157) [com.ibm.ws.webcontainer.jar:na]
at com.ibm.ws.session.SessionStateEventDispatcher.sessionAttributeRemoved(SessionStateEventDispatcher.java:137) [com.ibm.ws.webcontainer.jar:na]
at com.ibm.ws.session.StoreCallback.sessionAttributeRemoved(StoreCallback.java:191) [com.ibm.ws.webcontainer.jar:na]
at com.ibm.ws.session.store.memory.MemorySession.removeAttribute(MemorySession.java:496) [com.ibm.ws.webcontainer.jar:na]
at com.ibm.ws.session.store.memory.MemorySession.invalidate(MemorySession.java:243) [com.ibm.ws.webcontainer.jar:na]
at com.ibm.ws.session.http.HttpSessionImpl.invalidate(HttpSessionImpl.java:303) [com.ibm.ws.webcontainer.jar:na]
at com.ibm.ws.session.SessionData.invalidate(SessionData.java:247) [com.ibm.ws.webcontainer.jar:na]
at pt.sibs.epms.ecc.security.LiveSessionsObserver.addLiveSession(LiveSessionsObserver.java:39) [classes/:na]
at pt.sibs.epms.ecc.listener.SessionAttributeListener.attributeAdded(SessionAttributeListener.java:47) [classes/:na]
at com.ibm.ws.session.http.HttpSessionAttributeObserver.sessionAttributeSet(HttpSessionAttributeObserver.java:132) [com.ibm.ws.webcontainer.jar:na]
at com.ibm.ws.session.SessionStateEventDispatcher.sessionAttributeSet(SessionStateEventDispatcher.java:110) [com.ibm.ws.webcontainer.jar:na]
at com.ibm.ws.session.StoreCallback.sessionAttributeSet(StoreCallback.java:178) [com.ibm.ws.webcontainer.jar:na]
at com.ibm.ws.session.store.memory.MemorySession.setAttribute(MemorySession.java:474) [com.ibm.ws.webcontainer.jar:na]
at com.ibm.ws.session.http.HttpSessionImpl.setAttribute(HttpSessionImpl.java:251) [com.ibm.ws.webcontainer.jar:na]
at com.ibm.ws.session.SessionData.putSessionValue(SessionData.java:293) [com.ibm.ws.webcontainer.jar:na]
at com.ibm.ws.session.SessionData.setAttribute(SessionData.java:217) [com.ibm.ws.webcontainer.jar:na]
at com.ibm.ws.session.HttpSessionFacade.setAttribute(HttpSessionFacade.java:169) [com.ibm.ws.webcontainer.jar:na]
at pt.sibs.epms.ecc.filter.AuthenticationFilter.doBeforeProcessing(AuthenticationFilter.java:52) [classes/:na]
at pt.sibs.epms.ecc.filter.AuthenticationFilter.doFilter(AuthenticationFilter.java:82) [classes/:na]
at com.ibm.ws.webcontainer.filter.FilterInstanceWrapper.doFilter(FilterInstanceWrapper.java:197) [com.ibm.ws.webcontainer.jar:na]
at com.ibm.ws.webcontainer.filter.WebAppFilterChain.doFilter(WebAppFilterChain.java:90) [com.ibm.ws.webcontainer.jar:na]
at com.ibm.ws.webcontainer.filter.WebAppFilterManager.doFilter(WebAppFilterManager.java:969) [com.ibm.ws.webcontainer.jar:na]
at com.ibm.ws.webcontainer.filter.WebAppFilterManager.invokeFilters(WebAppFilterManager.java:1109) [com.ibm.ws.webcontainer.jar:na]
at com.ibm.ws.webcontainer.servlet.CacheServletWrapper.handleRequest(CacheServletWrapper.java:82) [com.ibm.ws.webcontainer.jar:na]
at com.ibm.ws.webcontainer.WebContainer.handleRequest(WebContainer.java:961) [com.ibm.ws.webcontainer.jar:na]
at com.ibm.ws.webcontainer.WSWebContainer.handleRequest(WSWebContainer.java:1817) [com.ibm.ws.webcontainer.jar:na]
at com.ibm.ws.webcontainer.channel.WCChannelLink.ready(WCChannelLink.java:382) [com.ibm.ws.webcontainer.jar:na]
at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleDiscrimination(HttpInboundLink.java:465) [com.ibm.ws.runtime.jar:na]
at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleNewRequest(HttpInboundLink.java:532) [com.ibm.ws.runtime.jar:na]
at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.processRequest(HttpInboundLink.java:318) [com.ibm.ws.runtime.jar:na]
at com.ibm.ws.http.channel.inbound.impl.HttpICLReadCallback.complete(HttpICLReadCallback.java:88) [com.ibm.ws.runtime.jar:na]
at com.ibm.ws.tcp.channel.impl.AioReadCompletionListener.futureCompleted(AioReadCompletionListener.java:175) [com.ibm.ws.runtime.jar:na]
at com.ibm.io.async.AbstractAsyncFuture.invokeCallback(AbstractAsyncFuture.java:217) [com.ibm.ws.runtime.jar:na]
at com.ibm.io.async.AsyncChannelFuture.fireCompletionActions(AsyncChannelFuture.java:161) [com.ibm.ws.runtime.jar:na]
at com.ibm.io.async.AsyncFuture.completed(AsyncFuture.java:138) [com.ibm.ws.runtime.jar:na]
at com.ibm.io.async.ResultHandler.complete(ResultHandler.java:204) [com.ibm.ws.runtime.jar:na]
at com.ibm.io.async.ResultHandler.runEventProcessingLoop(ResultHandler.java:775) [com.ibm.ws.runtime.jar:na]
at com.ibm.io.async.ResultHandler$2.run(ResultHandler.java:905) [com.ibm.ws.runtime.jar:na]
at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1892) [com.ibm.ws.runtime.jar:na]
EDIT #1
The log also starts showing the following warning message:
000000f2 WASSessionCor W SessionAffinityManager setNextId Detected JSESSIONID with invalid length; expected length of 23, found 24, setting: 6a559228ee4bcdc3c90f58ac to null.
EDIT #2
I've also noticed that my logout method is not working correctly because the call if( request.isRequestedSessionIdValid() ) is always returning false, but it shouldn't.