[CAUSEWAY-760] IllegalStateException when commands/audit enabled in Estatio and failing to persist the Oid of a view model.

• Type: Bug
• Status: Closed
• Priority: Critical
• Resolution: Fixed
• Affects Version/s: core-1.4.0
• Fix Version/s: core-1.5.0
• Component/s: Core
• Assignee: Daniel Keir Haywood
• Reporter: Jeroen van der Wal
• Created: 02/Apr/14 15:54
• Updated: 09/Jun/14 23:25
• Resolved: 03/Apr/14 12:21

Description

There are two separate issues here:

• first is that the auditing service's column for storing OIDs isn't long enough for view models.
• the second is that, given this then causes the xactn to be aborted, that it throws an IllegalStateException for any subsequent interaction with the system. The only fix is to restart the server. See details below

The reason for the second issue is that the previous session does not close correctly. This is because of an exception being thrown in PersistenceSession#close:

PersistenceSession.completeCommandIfConfigured() line: 418
PersistenceSession.closeServices() line: 399
PersistenceSession.close() line: 372
IsisSessionDefault.close() line: 119
IsisContextThreadLocal(IsisContext).closeSessionInstance() line: 219
WebRequestCycleForIsis.onEndRequest(RequestCycle) line: 134

This in turn is because of an attempt to complete any pending command (per the CommandJdo service) on a xactn that has already been aborted....

private void completeCommandIfConfigured() {
final CommandContext commandContext = getServiceOrNull(CommandContext.class);
if(commandContext != null) {
final CommandService commandService = getServiceOrNull(CommandService.class);
if(commandService != null)

{ final Command command = commandContext.getCommand(); commandService.complete(command); }

}
}

So, when closing the session, need to take this into account. Should propogate exception if any arises, but still ensure that the persistence session is closed for next-time around.

~~~~~~~~~~
to reproduce:
with estatio demo data

> find invoices for status new
> choose oxford
> approve all.

A server restart was required.

java.lang.IllegalStateException
Session already open and context not configured for autoclose
 org.apache.isis.core.runtime.system.context.IsisContext#applySessionClosePolicy(IsisContext.java:186)
 org.apache.isis.core.runtime.system.context.IsisContextThreadLocal#openSessionInstance(IsisContextThreadLocal.java:148)
 org.apache.isis.viewer.wicket.viewer.integration.wicket.WebRequestCycleForIsis#onBeginRequest(WebRequestCycleForIsis.java:81)
 org.apache.wicket.request.cycle.RequestCycleListenerCollection$1#notify(RequestCycleListenerCollection.java:65)
 org.apache.wicket.request.cycle.RequestCycleListenerCollection$1#notify(RequestCycleListenerCollection.java:61)
 org.apache.wicket.util.listener.ListenerCollection#notify(ListenerCollection.java:80)
 org.apache.wicket.request.cycle.RequestCycleListenerCollection#onBeginRequest(RequestCycleListenerCollection.java:60)
 org.apache.wicket.request.cycle.RequestCycleListenerCollection$1#notify(RequestCycleListenerCollection.java:65)
 org.apache.wicket.request.cycle.RequestCycleListenerCollection$1#notify(RequestCycleListenerCollection.java:61)
 org.apache.wicket.util.listener.ListenerCollection#notify(ListenerCollection.java:80)
 org.apache.wicket.request.cycle.RequestCycleListenerCollection#onBeginRequest(RequestCycleListenerCollection.java:60)
 org.apache.wicket.request.cycle.RequestCycle#processRequest(RequestCycle.java:213)
 org.apache.wicket.request.cycle.RequestCycle#processRequestAndDetach(RequestCycle.java:289)
 org.apache.wicket.protocol.http.WicketFilter#processRequestCycle(WicketFilter.java:259)
 org.apache.wicket.protocol.http.WicketFilter#processRequest(WicketFilter.java:201)
 org.apache.wicket.protocol.http.WicketFilter#doFilter(WicketFilter.java:282) 
org.apache.catalina.core.ApplicationFilterChain#internalDoFilter(ApplicationFilterChain.java:243)
 org.apache.catalina.core.ApplicationFilterChain#doFilter(ApplicationFilterChain.java:210)
 org.apache.shiro.web.servlet.AbstractShiroFilter#executeChain(AbstractShiroFilter.java:449)
 org.apache.shiro.web.servlet.AbstractShiroFilter$1#call(AbstractShiroFilter.java:365)
 org.apache.shiro.subject.support.SubjectCallable#doCall(SubjectCallable.java:90)
 org.apache.shiro.subject.support.SubjectCallable#call(SubjectCallable.java:83) 
org.apache.shiro.subject.support.DelegatingSubject#execute(DelegatingSubject.java:383)
 org.apache.shiro.web.servlet.AbstractShiroFilter#doFilterInternal(AbstractShiroFilter.java:362)
 org.apache.shiro.web.servlet.OncePerRequestFilter#doFilter(OncePerRequestFilter.java:125)
 org.apache.catalina.core.ApplicationFilterChain#internalDoFilter(ApplicationFilterChain.java:243)
 org.apache.catalina.core.ApplicationFilterChain#doFilter(ApplicationFilterChain.java:210)
 org.apache.catalina.core.StandardWrapperValve#invoke(StandardWrapperValve.java:225)
 org.apache.catalina.core.StandardContextValve#invoke(StandardContextValve.java:123)
 org.apache.catalina.authenticator.AuthenticatorBase#invoke(AuthenticatorBase.java:472)
 org.apache.catalina.core.StandardHostValve#invoke(StandardHostValve.java:168) 
org.apache.catalina.valves.ErrorReportValve#invoke(ErrorReportValve.java:98) 
org.apache.catalina.valves.AccessLogValve#invoke(AccessLogValve.java:927) 
org.apache.catalina.core.StandardEngineValve#invoke(StandardEngineValve.java:118)
 org.apache.catalina.connector.CoyoteAdapter#service(CoyoteAdapter.java:407) 
org.apache.coyote.http11.AbstractHttp11Processor#process(AbstractHttp11Processor.java:1001)
 org.apache.coyote.AbstractProtocol$AbstractConnectionHandler#process(AbstractProtocol.java:579)
 org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor#run(JIoEndpoint.java:310)
 java.util.concurrent.ThreadPoolExecutor#runWorker(ThreadPoolExecutor.java:1145)
 java.util.concurrent.ThreadPoolExecutor$Worker#run(ThreadPoolExecutor.java:615)
 java.lang.Thread#run(Thread.java:724) 

On the server:

Caused by: javax.jdo.JDOFatalUserException: Attempt to store value "org.estatio.dom.invoice.viewmodel.InvoiceSummaryForPropertyDueDateStatus:PD94bWwgdmVyc2lvbj0iMS4wIiBlbmNvZGluZz0iVVRGLTgiPz4KPG1lbWVudG8-PHJlZmVyZW5jZT5DQVM8L3JlZmVyZW5jZT48ZHVlRGF0ZT4yMDE0LTAzLTMxPC9kdWVEYXRlPjxzdGF0dXM-QVBQUk9WRUQ8L3N0YXR1cz48bmV0QW1vdW50PjE3MTc1LjYwPC9uZXRBbW91bnQ-PHZhdEFtb3VudD4zNzc4LjYzPC92YXRBbW91bnQ-PGdyb3NzQW1vdW50PjIwOTU0LjIzPC9ncm9zc0Ftb3VudD48dG90YWw-MTwvdG90YWw-PC9tZW1lbnRvPg==" in column "target" that has maximum length of 255. Please correct your data!
NestedThrowables:
org.datanucleus.exceptions.NucleusUserException: Attempt to store value "org.estatio.dom.invoice.viewmodel.InvoiceSummaryForPropertyDueDateStatus:PD94bWwgdmVyc2lvbj0iMS4wIiBlbmNvZGluZz0iVVRGLTgiPz4KPG1lbWVudG8-PHJlZmVyZW5jZT5DQVM8L3JlZmVyZW5jZT48ZHVlRGF0ZT4yMDE0LTAzLTMxPC9kdWVEYXRlPjxzdGF0dXM-QVBQUk9WRUQ8L3N0YXR1cz48bmV0QW1vdW50PjE3MTc1LjYwPC9uZXRBbW91bnQ-PHZhdEFtb3VudD4zNzc4LjYzPC92YXRBbW91bnQ-PGdyb3NzQW1vdW50PjIwOTU0LjIzPC9ncm9zc0Ftb3VudD48dG90YWw-MTwvdG90YWw-PC9tZW1lbnRvPg==" in column "target" that has maximum length of 255. Please correct your data!
        at org.datanucleus.api.jdo.NucleusJDOHelper.getJDOExceptionForNucleusException(NucleusJDOHelper.java:528)
        at org.datanucleus.api.jdo.JDOPersistenceManager.jdoMakePersistent(JDOPersistenceManager.java:732)
        at org.datanucleus.api.jdo.JDOPersistenceManager.makePersistent(JDOPersistenceManager.java:752)
        at org.apache.isis.objectstore.jdo.datanucleus.persistence.commands.DataNucleusCreateObjectCommand.execute(DataNucleusCreateObjectCommand.java:54)
        at org.apache.isis.objectstore.jdo.datanucleus.DataNucleusObjectStore.executeCommands(DataNucleusObjectStore.java:368)
        at org.apache.isis.objectstore.jdo.datanucleus.DataNucleusObjectStore.execute(DataNucleusObjectStore.java:362)
        at org.apache.isis.core.runtime.system.transaction.IsisTransaction.doFlush(IsisTransaction.java:425)
        at org.apache.isis.core.runtime.system.transaction.IsisTransaction.commit(IsisTransaction.java:658)
        at org.apache.isis.core.runtime.system.transaction.IsisTransactionManager.endTransaction(IsisTransactionManager.java:396)
        at org.apache.isis.core.runtime.system.transaction.IsisTransactionManager.executeWithinTransaction(IsisTransactionManager.java:184)
        ... 52 more