Completed process instances' records are not removed from ProcessInstanceLog table in jBPM 5
Issue
- While executing a process instance in
Business Centralthrows the following exception on the console.
org.jboss.resteasy.spi.UnhandledException: java.lang.RuntimeException: Could not commit session or rollback
org.jboss.resteasy.core.SynchronousDispatcher.unwrapException(SynchronousDispatcher.java:345)
org.jboss.resteasy.core.SynchronousDispatcher.handleApplicationException(SynchronousDispatcher.java:321)
org.jboss.resteasy.core.SynchronousDispatcher.handleException(SynchronousDispatcher.java:214)
org.jboss.resteasy.core.SynchronousDispatcher.handleInvokerException(SynchronousDispatcher.java:190)
org.jboss.resteasy.core.SynchronousDispatcher.getResponse(SynchronousDispatcher.java:534)
org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:496)
org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:119)
org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:208)
org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:55)
org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:50)
javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
org.jboss.bpm.console.server.util.GWTJsonFilter.doFilter(GWTJsonFilter.java:59)
org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
...
- The issue is taking place when a process instance is completed and it's record is removed from
processinstanceinfotable but insideprocessinstancelogtable the entry remains without having any value forend_datecolumn. That results in the entry for the process instance still visible inprocess overviewsection ofBusiness Centralconsole. Now, if it is attempted to create another process instance, sometimes it doesn't allow to do so. The following log entries reveals the chain of actions taking place during such an event.
2014-02-03 14:00:06,360 DEBUG [org.hibernate.pretty.Printer] (http-127.0.0.1-8080-3) listing entities:
2014-02-03 14:00:06,360 DEBUG [org.hibernate.pretty.Printer] (http-127.0.0.1-8080-3) org.jbpm.process.audit.NodeInstanceLog{id=5, nodeId=1, processInstanceId=2, processId=defaultPackage.Test, nodeName=Start, type=1, nodeInstanceId=0, date=2014-02-03 14:00:06}
2014-02-03 14:00:06,361 DEBUG [org.hibernate.pretty.Printer] (http-127.0.0.1-8080-3) org.jbpm.process.audit.NodeInstanceLog{id=6, nodeId=2, processInstanceId=2, processId=defaultPackage.Test, nodeName=Script, type=0, nodeInstanceId=1, date=2014-02-03 14:00:06}
2014-02-03 14:00:06,361 DEBUG [org.hibernate.pretty.Printer] (http-127.0.0.1-8080-3) org.jbpm.process.audit.NodeInstanceLog{id=4, nodeId=1, processInstanceId=2, processId=defaultPackage.Test, nodeName=Start, type=0, nodeInstanceId=0, date=2014-02-03 14:00:06}
2014-02-03 14:00:06,361 DEBUG [org.hibernate.pretty.Printer] (http-127.0.0.1-8080-3) org.jbpm.process.audit.NodeInstanceLog{id=9, nodeId=3, processInstanceId=2, processId=defaultPackage.Test, nodeName=End, type=1, nodeInstanceId=2, date=2014-02-03 14:00:06}
2014-02-03 14:00:06,361 DEBUG [org.hibernate.pretty.Printer] (http-127.0.0.1-8080-3) org.jbpm.process.audit.NodeInstanceLog{id=7, nodeId=2, processInstanceId=2, processId=defaultPackage.Test, nodeName=Script, type=1, nodeInstanceId=1, date=2014-02-03 14:00:06}
2014-02-03 14:00:06,361 DEBUG [org.hibernate.pretty.Printer] (http-127.0.0.1-8080-3) org.jbpm.process.audit.NodeInstanceLog{id=8, nodeId=3, processInstanceId=2, processId=defaultPackage.Test, nodeName=End, type=0, nodeInstanceId=2, date=2014-02-03 14:00:06}
2014-02-03 14:00:06,361 DEBUG [org.hibernate.pretty.Printer] (http-127.0.0.1-8080-3) org.jbpm.process.audit.ProcessInstanceLog{id=3, processInstanceId=2, start=2014-02-03 14:00:06, processId=defaultPackage.Test, end=null}
2014-02-03 14:00:06,362 DEBUG [org.hibernate.pretty.Printer] (http-127.0.0.1-8080-3) org.jbpm.persistence.processinstance.ProcessInstanceInfo{startDate=2014-02-03 14:00:06, processInstanceId=2, processId=defaultPackage.Test, processInstanceByteArray=null, state=0, lastModificationDate=null, eventTypes=[], lastReadDate=2014-02-03 14:00:06, version=0}
2014-02-03 14:00:06,362 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-127.0.0.1-8080-3) about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2014-02-03 14:00:06,362 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-127.0.0.1-8080-3) opening JDBC connection
2014-02-03 14:00:06,362 DEBUG [org.hibernate.SQL] (http-127.0.0.1-8080-3) insert into ProcessInstanceInfo (OPTLOCK, processId, startDate, lastReadDate, lastModificationDate, state, processInstanceByteArray, InstanceId) values (?, ?, ?, ?, ?, ?, ?, ?)
2014-02-03 14:00:06,362 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-127.0.0.1-8080-3) Executing batch size: 1
2014-02-03 14:00:06,363 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-127.0.0.1-8080-3) about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2014-02-03 14:00:06,363 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-127.0.0.1-8080-3) skipping aggressive-release due to flush cycle
2014-02-03 14:00:06,363 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-127.0.0.1-8080-3) about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2014-02-03 14:00:06,363 DEBUG [org.hibernate.SQL] (http-127.0.0.1-8080-3) insert into ProcessInstanceLog (end_date, processId, processInstanceId, start_date, id) values (?, ?, ?, ?, ?)
2014-02-03 14:00:06,363 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-127.0.0.1-8080-3) Executing batch size: 1
2014-02-03 14:00:06,365 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-127.0.0.1-8080-3) about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2014-02-03 14:00:06,365 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-127.0.0.1-8080-3) skipping aggressive-release due to flush cycle
2014-02-03 14:00:06,365 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-127.0.0.1-8080-3) about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2014-02-03 14:00:06,365 DEBUG [org.hibernate.SQL] (http-127.0.0.1-8080-3) insert into NodeInstanceLog (log_date, nodeId, nodeInstanceId, nodeName, processId, processInstanceId, type, id) values (?, ?, ?, ?, ?, ?, ?, ?)
2014-02-03 14:00:06,365 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-127.0.0.1-8080-3) reusing prepared statement
2014-02-03 14:00:06,365 DEBUG [org.hibernate.SQL] (http-127.0.0.1-8080-3) insert into NodeInstanceLog (log_date, nodeId, nodeInstanceId, nodeName, processId, processInstanceId, type, id) values (?, ?, ?, ?, ?, ?, ?, ?)
2014-02-03 14:00:06,365 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-127.0.0.1-8080-3) reusing prepared statement
2014-02-03 14:00:06,365 DEBUG [org.hibernate.SQL] (http-127.0.0.1-8080-3) insert into NodeInstanceLog (log_date, nodeId, nodeInstanceId, nodeName, processId, processInstanceId, type, id) values (?, ?, ?, ?, ?, ?, ?, ?)
2014-02-03 14:00:06,365 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-127.0.0.1-8080-3) reusing prepared statement
2014-02-03 14:00:06,365 DEBUG [org.hibernate.SQL] (http-127.0.0.1-8080-3) insert into NodeInstanceLog (log_date, nodeId, nodeInstanceId, nodeName, processId, processInstanceId, type, id) values (?, ?, ?, ?, ?, ?, ?, ?)
2014-02-03 14:00:06,366 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-127.0.0.1-8080-3) reusing prepared statement
2014-02-03 14:00:06,366 DEBUG [org.hibernate.SQL] (http-127.0.0.1-8080-3) insert into NodeInstanceLog (log_date, nodeId, nodeInstanceId, nodeName, processId, processInstanceId, type, id) values (?, ?, ?, ?, ?, ?, ?, ?)
2014-02-03 14:00:06,366 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-127.0.0.1-8080-3) reusing prepared statement
2014-02-03 14:00:06,366 DEBUG [org.hibernate.SQL] (http-127.0.0.1-8080-3) insert into NodeInstanceLog (log_date, nodeId, nodeInstanceId, nodeName, processId, processInstanceId, type, id) values (?, ?, ?, ?, ?, ?, ?, ?)
2014-02-03 14:00:06,366 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-127.0.0.1-8080-3) Executing batch size: 6
2014-02-03 14:00:06,369 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-127.0.0.1-8080-3) about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2014-02-03 14:00:06,369 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-127.0.0.1-8080-3) skipping aggressive-release due to flush cycle
2014-02-03 14:00:06,369 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-127.0.0.1-8080-3) about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2014-02-03 14:00:06,369 DEBUG [org.hibernate.SQL] (http-127.0.0.1-8080-3) delete from ProcessInstanceInfo where InstanceId=? and OPTLOCK=?
Environment
- Red Hat JBoss BRMS (BRMS)
- 5.3.x
- Red Hat JBoss SOA Platform (SOA-P)
- 5.3.1
- PostgreSQL
- 9.7
Subscriber exclusive content
A Red Hat subscription provides unlimited access to our knowledgebase of over 48,000 articles and solutions.
Welcome! Check out the Getting Started with Red Hat page for quick tours and guides for common tasks.
