jBPM persistency problem| JBoss.org Content Archive (Read Only)

15. Re: jBPM persistency problem

lvdberg Sep 15, 2009 5:22 PM (in response to lvdberg)

Hi Ronald,

I've added the logging category to the Jboss-setting and everything looks nice now, although it keeps buzzing in my hide where this Optimistic locking error comes from, because I am still testing so its basically single-user, one-database.

I was wrong in assuming there is a double DB-request. They are different, but only in the where clause.

2009-09-15 17:08:02,956 INFO  [STDOUT] (JbpmJobExecutor@192.168.1.100:1) Hibernate: 
    select
        job0_.ID_ as ID1_285_,
        job0_.VERSION_ as VERSION3_285_,
        job0_.DUEDATE_ as DUEDATE4_285_,
        job0_.PROCESSINSTANCE_ as PROCESSI5_285_,
        job0_.TOKEN_ as TOKEN6_285_,
        job0_.TASKINSTANCE_ as TASKINST7_285_,
        job0_.ISSUSPENDED_ as ISSUSPEN8_285_,
        job0_.ISEXCLUSIVE_ as ISEXCLUS9_285_,
        job0_.LOCKOWNER_ as LOCKOWNER10_285_,
        job0_.LOCKTIME_ as LOCKTIME11_285_,
        job0_.EXCEPTION_ as EXCEPTION12_285_,
        job0_.RETRIES_ as RETRIES13_285_,
        job0_.NAME_ as NAME14_285_,
        job0_.REPEAT_ as REPEAT15_285_,
        job0_.TRANSITIONNAME_ as TRANSIT16_285_,
        job0_.ACTION_ as ACTION17_285_,
        job0_.GRAPHELEMENTTYPE_ as GRAPHEL18_285_,
        job0_.GRAPHELEMENT_ as GRAPHEL19_285_,
        job0_.NODE_ as NODE20_285_,
        job0_.CLASS_ as CLASS2_285_ 
    from
        JBPM_JOB job0_ 
    where
        (
            job0_.LOCKOWNER_ is null 
            or job0_.LOCKOWNER_=?
        ) 
        and job0_.RETRIES_>0 
        and job0_.DUEDATE_<=? 
        and job0_.ISSUSPENDED_=0 
    order by
        job0_.DUEDATE_ asc limit ?
2009-09-15 17:08:02,987 INFO  [STDOUT] (JbpmJobExecutor@192.168.1.100:1) Hibernate: 
    select
        job0_.ID_ as ID1_285_,
        job0_.VERSION_ as VERSION3_285_,
        job0_.DUEDATE_ as DUEDATE4_285_,
        job0_.PROCESSINSTANCE_ as PROCESSI5_285_,
        job0_.TOKEN_ as TOKEN6_285_,
        job0_.TASKINSTANCE_ as TASKINST7_285_,
        job0_.ISSUSPENDED_ as ISSUSPEN8_285_,
        job0_.ISEXCLUSIVE_ as ISEXCLUS9_285_,
        job0_.LOCKOWNER_ as LOCKOWNER10_285_,
        job0_.LOCKTIME_ as LOCKTIME11_285_,
        job0_.EXCEPTION_ as EXCEPTION12_285_,
        job0_.RETRIES_ as RETRIES13_285_,
        job0_.NAME_ as NAME14_285_,
        job0_.REPEAT_ as REPEAT15_285_,
        job0_.TRANSITIONNAME_ as TRANSIT16_285_,
        job0_.ACTION_ as ACTION17_285_,
        job0_.GRAPHELEMENTTYPE_ as GRAPHEL18_285_,
        job0_.GRAPHELEMENT_ as GRAPHEL19_285_,
        job0_.NODE_ as NODE20_285_,
        job0_.CLASS_ as CLASS2_285_ 
    from
        JBPM_JOB job0_ 
    where
        (
            job0_.LOCKOWNER_ is null 
            or job0_.LOCKOWNER_=?
        ) 
        and job0_.RETRIES_>0 
        and job0_.ISSUSPENDED_=0 
    order by
        job0_.DUEDATE_ asc limit ?

Sorry for the confusion,

Leo

16. Re: jBPM persistency problem

tamas.tamas.blummers.hu Sep 15, 2009 9:46 PM (in response to lvdberg)

I was bugged by the same problem today and muted the exception as advised.

It seems to me that the equals operation in the Set holding the saved processInstances is broken, in CascadeSaveOperation that is why the same instance is saved again and again. I also got

2009-09-15 21:32:36,690 WARN  [org.hibernate.engine.StatefulPersistenceContext.ProxyWarnLog] (ajp-127.0.0.1-8009-5) Narrowing proxy to class org.jbpm.graph.node.TaskNode - this operation breaks ==

on the way up, that may be related.

A similar process with timer works for me too but am unconfortable with the above ...

Leo van den Berg wrote on Sep 15, 2009 11:48:

I've switched on debug for JBPM and found the following in the log, this is just a small part. The same block of logs is repeated hundreds of times. So there is definitely something really wrong with persistency of the process instance.

....
2009-09-15 11:31:19,044 DEBUG [org.jbpm.svc.save.HibernateSaveOperation] (http-127.0.0.1-80-1) saving process instance
2009-09-15 11:31:19,044 DEBUG [org.jbpm.svc.save.SaveLogsOperation] (http-127.0.0.1-80-1) posting logs to logging service.
2009-09-15 11:31:19,044 DEBUG [org.jbpm.svc.save.CascadeSaveOperation] (http-127.0.0.1-80-1) cascading save of 'ProcessInstance(1)'
2009-09-15 11:31:19,044 DEBUG [org.jbpm.svc.Services] (http-127.0.0.1-80-1) executing default save operations
2009-09-15 11:31:19,044 DEBUG [org.jbpm.svc.save.HibernateSaveOperation] (http-127.0.0.1-80-1) saving process instance
2009-09-15 11:31:19,059 DEBUG [org.jbpm.svc.save.SaveLogsOperation] (http-127.0.0.1-80-1) posting logs to logging service.
2009-09-15 11:31:19,059 DEBUG [org.jbpm.svc.save.CascadeSaveOperation] (http-127.0.0.1-80-1) cascading save of 'ProcessInstance(1)'
2009-09-15 11:31:19,059 DEBUG [org.jbpm.svc.Services] (http-127.0.0.1-80-1) executing default save operations
2009-09-15 11:31:19,059 DEBUG [org.jbpm.svc.save.HibernateSaveOperation] (http-127.0.0.1-80-1) saving process instance
2009-09-15 11:31:19,059 DEBUG [org.jbpm.svc.save.SaveLogsOperation] (http-127.0.0.1-80-1) posting logs to logging service.
2009-09-15 11:31:19,059 DEBUG [org.jbpm.svc.save.CascadeSaveOperation] (http-127.0.0.1-80-1) cascading save of 'ProcessInstance(1)'
2009-09-15 11:31:19,059 DEBUG [org.jbpm.svc.Services] (http-127.0.0.1-80-1) executing default save operations
2009-09-15 11:31:19,059 DEBUG [org.jbpm.svc.save.HibernateSaveOperation] (http-127.0.0.1-80-1) saving process instance
2009-09-15 11:31:19,075 DEBUG [org.jbpm.svc.save.SaveLogsOperation] (http-127.0.0.1-80-1) posting logs to logging service.
2009-09-15 11:31:19,075 DEBUG [org.jbpm.svc.save.CascadeSaveOperation] (http-127.0.0.1-80-1) cascading save of 'ProcessInstance(1)'
2009-09-15 11:31:19,075 DEBUG [org.jbpm.svc.Services] (http-127.0.0.1-80-1) executing default save operations
And a lot more lines follow....

Click HELP for text formatting instructions. Then edit this text and check the preview.

17. Re: jBPM persistency problem

kukeltje.ronald.jbpm.org Sep 15, 2009 11:04 PM (in response to lvdberg)

@Leo:

I've added the logging category to the Jboss-setting and everything looks nice now, although it keeps buzzing in my hide where this Optimistic locking error comes from, because I am still testing so its basically single-user, one-database.

This part is simple. You have a task, that task has a timer on it. When the timer fires, you end the task, which in turn ends all timers on that task. Surprise, surprise, that is the timer cancelling the task. Get it? I think you do ;-). jBPM before 3.2.5 did it wrong (actually deleting the timer) in subsequent release, the timer is just set to not fire again.

Regarding the double, slightly different queries, I have no clue (yet). I'll try to find some more info the next days.

@Tamás:

It seems to me that the equals operation in the Set holding the saved processInstances is broken, in CascadeSaveOperation that is why the same instance is saved again and again. I also got
2009-09-15 21:32:36,690 WARN  [org.hibernate.engine.StatefulPersistenceContext.ProxyWarnLog] (ajp-127.0.0.1-8009-5) Narrowing proxy to class org.jbpm.graph.node.TaskNode - this operation breaks ==
on the way up, that may be related.

This warn happens all the time, nothing to worry about (at least it normally isn't in 'pure' jBPM, but not sure if it does influence in Seam). Though the number of saves does intrigue me. Maybe I'll try to simulate with Leo's example this week.

18. Re: jBPM persistency problem

kukeltje.ronald.jbpm.org Sep 15, 2009 11:58 PM (in response to lvdberg)

I was wrong in assuming there is a double DB-request. They are different, but only in the where clause.

Found the plausible cause: One query acquires jobs, but those jobs have to monitored to prevent them getting stuck. That is what the second query does. Checking and if stuck 'release' them. Details are in the jBPM source (and partly in the docs)

19. Re: jBPM persistency problem

kukeltje.ronald.jbpm.org Sep 16, 2009 1:34 PM (in response to lvdberg)

Leo van den Berg wrote on Sep 15, 2009 17:22:

Hi Ronald,

I've added the logging category to the Jboss-setting and everything looks nice now, although it keeps buzzing in my hide where this Optimistic locking error comes from, because I am still testing so its basically single-user, one-database.

Does this mean the multiple (100's) of saves for the processinstance are gone to or are they still there?

20. Re: jBPM persistency problem

lvdberg Sep 16, 2009 1:52 PM (in response to lvdberg)

Hi Ronald,

I owe you a couple of beers by now...

The 100-plus lines are still there, but there is no DB-interaction (which I was really afraid of). So it has to be something in the interaction between Seam/jBPM, problably somthing to do with configuration. I am preparing a demo for the end of this month, so its basically adding a note to the TODOlist and come back to it in october (I had another issue in relation to jBPM and REst) We need to solve these iaauea because a demo is something different than a fully deployed app in december.

I am becoming more and more enthousiast about its possiblities in combination with Seam. Our application is demonstrated in Delft 29 sept.

Maybe interested ? We are looking for Dutch support. You can find my contact details here: