[jboss-jira] [JBoss JIRA] Commented: (JBPM-627) Cancel timer problem
Derek Chen-Becker (JIRA)
jira-events at jboss.com
Mon Jul 31 12:57:11 EDT 2006
[ http://jira.jboss.com/jira/browse/JBPM-627?page=comments#action_12340281 ]
Derek Chen-Becker commented on JBPM-627:
----------------------------------------
I've been trying to step through this and I've found something interesting with the SchedulerSession. On my system, the scheduler session appears to be using a PersistenceContext for its hibernate session with flushMode set to AUTO. I'm wondering if setting the repeat to null is causing it to update automatically. If so, then something is wrong with the session.delete() that gets called, because the timer is not actually being detached from the session. I've gone through the code manually several times and I can't find any place where the timer would be saved or updated, so while this may be a shot in the dark, it's the only thing I've been able to come up with so far.
> Cancel timer problem
> --------------------
>
> Key: JBPM-627
> URL: http://jira.jboss.com/jira/browse/JBPM-627
> Project: JBoss jBPM
> Issue Type: Bug
> Components: Core Engine
> Affects Versions: jBPM 3.1
> Environment: Windows XP Pro
> Database: DB2/400 v5r3, HSQLDB
> Reporter: Mark Shotton
> Assigned To: Tom Baeyens
> Attachments: JBPM-627-screenshots.doc
>
>
> As reported in issue JBPM-594, timers do not get deleted on the cancel-timer event. This is because in SchedulerSession.cancelTimersByName(String, Token), the timer is deleted by a call to SchedulerSession.deleteTimer:
> public void deleteTimer(Timer timer) {
> if (! deletedTimers.contains(timer)) {
> try {
> session.delete(timer);
> deletedTimers.add(timer);
> } catch (Exception e) {
> log.error(e);
> jbpmSession.handleException();
> throw new JbpmException("couldn't delete timer '"+timer+"' from the database", e);
> }
> }
> }
> but in SchedulerThread, the timer is saved again if timer.getRepeat() is not null:
> public long executeTimers() {
> long millisTillNextTimerIsDue = -1;
> boolean isDueDateInPast = true;
>
> JbpmContext jbpmContext = jbpmConfiguration.createJbpmContext(jbpmContextName);
> try {
> SchedulerSession schedulerSession = jbpmContext.getSchedulerSession();
>
> log.debug("checking for timers");
> Iterator iter = schedulerSession.findTimersByDueDate();
> while( (iter.hasNext())
> && (isDueDateInPast)
> ) {
> Timer timer = (Timer) iter.next();
> log.debug("found timer "+timer);
>
> // if this timer is due
> if (timer.isDue()) {
> log.debug("executing timer '"+timer+"'");
>
> // execute
> timer.execute();
>
> // save the process instance
> jbpmContext.save(timer.getProcessInstance());
>
> // notify the listeners (e.g. the scheduler servlet)
> notifyListeners(timer);
>
> // if there was an exception, just save the timer
> if (timer.getException()!=null) {
> schedulerSession.saveTimer(timer);
>
> // if repeat is specified
> } else if (timer.getRepeat()!=null) {
> // update timer by adding the repeat duration
> Date dueDate = timer.getDueDate();
>
> // suppose that it took the timer runner thread a
> // very long time to execute the timers.
> // then the repeat action dueDate could already have passed.
> while (dueDate.getTime()<=System.currentTimeMillis()) {
> dueDate = businessCalendar
> .add(dueDate,
> new Duration(timer.getRepeat()));
> }
> timer.setDueDate( dueDate );
> // save the updated timer in the database
> log.debug("saving updated timer for repetition '"+timer+"' in '"+(dueDate.getTime()-System.currentTimeMillis())+"' millis");
> schedulerSession.saveTimer(timer);
>
> } else {
> // delete this timer
> log.debug("deleting timer '"+timer+"'");
> schedulerSession.deleteTimer(timer);
> }
> } else { // this is the first timer that is not yet due
> isDueDateInPast = false;
> millisTillNextTimerIsDue = timer.getDueDate().getTime() - System.currentTimeMillis();
> }
> }
>
> } finally {
> jbpmContext.close();
> }
> A work-around was suggested in JBPM-594:
> "As workaround now I do remove timer myself in action just before calling signal():
> if(flag) {
> //need to remove scheduler session as it is not removed during event with
> //cancel-timer element
> SchedulerSession schsession = ctx.getJbpmContext().getSchedulerSession();
> Timer timer=(Timer) schsession.findTimersByName("aaa",ctx.getToken()).get(0);
> log.info("found timer:"+timer.getName());
> timer.setRepeat(null);
> timer.setSuspended(true);
> schsession.saveTimer(timer);
>
> ctx.getToken().signal("tonode1");
> }
> "
> However, this does not seem to be thread-safe as the call to findTimersByName sometimes returns a zero-length array and sometimes an exception if the work-around code to cancel the timer executes before the timer is available from the SchedulerSession (and this does happen even when the code to cancel the timer is within the ActionHandler of the timer) As a different work-around, I set the timer repeat to null in the SchedulerSession.deleteTimer method to ensure that it will not be saved again in the SchedulerThread.executeTimers method:
> public void deleteTimer(Timer timer) {
> if (! deletedTimers.contains(timer)) {
> try {
> session.delete(timer);
> deletedTimers.add(timer);
> //MWS 06/04/06 workaround to ensure that timer is deleted
> timer.setRepeat(null);
> } catch (Exception e) {
> log.error(e);
> jbpmSession.handleException();
> throw new JbpmException("couldn't delete timer '"+timer+"' from the database", e);
> }
> }
> }
> However, this causes an occasional exception to be thrown:
> org.jbpm.persistence.JbpmPersistenceException: couldn't commit hibernate session
> at org.jbpm.persistence.db.DbPersistenceService.close(DbPersistenceService.java:171)
> at org.jbpm.svc.Services.close(Services.java:211)
> at org.jbpm.JbpmContext.close(JbpmContext.java:138)
> at org.jbpm.scheduler.impl.SchedulerThread.executeTimers(SchedulerThread.java:161)
> at org.jbpm.scheduler.impl.SchedulerThread.run(SchedulerThread.java:70)
> Caused by: org.hibernate.StaleStateException: Unexpected row count: 0 expected: 1
> at org.hibernate.jdbc.NonBatchingBatcher.addToBatch(NonBatchingBatcher.java:27)
> at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2204)
> at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2118)
> at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2374)
> at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:84)
> at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:243)
> at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:227)
> at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:141)
> at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:296)
> at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
> at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:980)
> at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:353)
> On further investigation, it appears that on some occasions, when deleting a timer on a cancel-timer event, the call to session.getNamedQuery("SchedulerSession.findTimersByName") causes a hibernate flush to occur which attempts to update a timer that has already been deleted:
> public void cancelTimersByName(String timerName, Token token) {
> try {
> Query query = session.getNamedQuery("SchedulerSession.findTimersByName");
> query.setString("timerName", timerName);
> query.setEntity("token", token);
> Iterator iter = query.list().iterator();
> while(iter.hasNext()) {
> deleteTimer((Timer) iter.next());
> }
>
> } catch (Exception e) {
> log.error(e);
> jbpmSession.handleException();
> throw new JbpmException("couldn't delete timer '"+timerName+"' on '"+token+"' from the database", e);
> }
> }
> I have some screenshots below to illustrate this but cannot include them in this form. The attempt to cancel the timer ?processing_error_task_timer? causes the following query to be issued:
> <query name="SchedulerSession.findTimersByName">
> <![CDATA[
> select t
> from org.jbpm.scheduler.exe.Timer t
> where t.name = :timerName
> and t.token = :token
> ]]>
> </query>
> which in turn causes hibernate to flush and attempt to issue the SQL statement:
> update JBPM_TIMER set NAME_=?, DUEDATE_=?, REPEAT_=?, TRANSITIONNAME_=?, EXCEPTION_=?, ISSUSPENDED_=?, ACTION_=?, TOKEN_=?, PROCESSINSTANCE_=?, TASKINSTANCE_=?, GRAPHELEMENTTYPE_=?, GRAPHELEMENT_=? where ID_=?
> where the ID_ of the timer is that of a previous timer that has already been deleted from the database called ?credit_referral_task_timer? (I confirmed this by inspection of the JBPM_TIMER table).
> I am at a loss to explain how the hibernate cache contains a timer that has already been deleted from the database.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://jira.jboss.com/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
More information about the jboss-jira
mailing list