Hi,
I'm running a bpel process with ode-jbi-1.3.5 deployed on servicemix-3.3.1
with jdk 1.5 on linux (same error on win) with ode persistence on mysql
(same error with derby embedded).
When I start running 2 or more processes in parallel quite often I start
getting the following error (full stack below)
org.apache.ode.bpel.iapi.Scheduler$JobProcessorException:
java.lang.RuntimeException: java.lang.IllegalArgumentException: No such
channel; id=20
at
org.apache.ode.bpel.engine.BpelEngineImpl.onScheduledJob(BpelEngineImpl.java:478)
repeated many times. I found almost no reference on the web for this error.
When I run one process at a time it's not common but it happens anyway.
This is the only ERROR I have during the execution of the job.
3:01:15,826 | DEBUG | pool-5-thread-2 | |
sql | e.ode.utils.LoggingInterceptor 163 | Set
isolation level to 2
13:01:15,826 | DEBUG | pool-5-thread-2 | |
sql | e.ode.utils.LoggingInterceptor 163 |
prepareStatement: SELECT t0.CALLEE, t0.CHANNEL, t0.CORRELATION_ID,
t0.CORRELATION_KEYS, t0.CORRELATION_STATUS, t0.CORR_ID, t0.CREATE_TIME,
t0.DIRECTION, t0.EPR, t0.FAULT, t0.FAULT_EXPLANATION, t0.OPERATION,
t0.PARTNER_LINK_ID, t0.PARTNER_LINK_MODEL_ID, t0.PATTERN, t0.PIPED_ID,
t0.PORT_TYPE, t0.PROCESS_ID, t0.PROCESS_INSTANCE_ID, t0.PROPAGATE_TRANS,
t0.REQUEST_MESSAGE_ID, t0.RESPONSE_MESSAGE_ID, t0.STATUS,
t0.SUBSCRIBER_COUNT, t1.MEX_ID, t1.ID, t1.PROP_KEY, t1.PROP_VALUE FROM
ODE_MESSAGE_EXCHANGE t0 LEFT OUTER JOIN ODE_MEX_PROP t1 ON
t0.MESSAGE_EXCHANGE_ID = t1.MEX_ID WHERE t0.MESSAGE_EXCHANGE_ID = ? ORDER BY
t1.MEX_ID ASC
13:01:15,843 | DEBUG | pool-5-thread-2 | |
sql | e.ode.utils.LoggingInterceptor 163 |
executeQuery, bound (1,hqejbhcnphr672vdtegmme)
13:01:15,846 | DEBUG | pool-5-thread-2 | |
sql | e.ode.utils.LoggingInterceptor 163 | close()
13:01:15,846 | DEBUG | pool-5-thread-2 | |
sql | e.ode.utils.LoggingInterceptor 163 | close()
13:01:15,846 | ERROR | pool-5-thread-2 | |
BpelRuntimeContextImpl | .engine.BpelRuntimeContextImpl 1131 | Invalid
response state for mex hqejbhcnphr672vdtegmme: ASYNC
13:01:15,847 | DEBUG | pool-5-thread-2 | |
BpelRuntimeContextImpl | .engine.BpelRuntimeContextImpl 972 | Setting
execution state on instance 1553
13:01:15,848 | DEBUG | pool-5-thread-2 | |
ExecutionQueueImpl | mpl$ExecutionQueueOutputStream 696 |
ReplacmentMap: getReplacement({OScope 'Run transformation' id=79}) =
org.apache.ode.bpel.engine.ReplacementMapImpl$OBaseReplacementImpl@640014df
13:01:15,849 | DEBUG | pool-5-thread-2 | |
ExecutionQueueImpl | mpl$ExecutionQueueOutputStream 696 |
ReplacmentMap: getReplacement({OScope '__PROCESS_SCOPE:covidien-fec-process'
id=3}) =
org.apache.ode.bpel.engine.ReplacementMapImpl$OBaseReplacementImpl@122e8a3c
13:01:15,850 | DEBUG | pool-5-thread-2 | |
ExecutionQueueImpl | mpl$ExecutionQueueOutputStream 696 |
ReplacmentMap: getReplacement(OSequence#65-main) =
org.apache.ode.bpel.engine.ReplacementMapImpl$OBaseReplacementImpl@cf47ba0
13:01:15,851 | DEBUG | pool-5-thread-2 | |
ExecutionQueueImpl | mpl$ExecutionQueueOutputStream 696 |
ReplacmentMap: getReplacement({OAssign : Prepare datapackage request,
joinCondition=null}) =
org.apache.ode.bpel.engine.ReplacementMapImpl$OBaseReplacementImpl@561393bc
13:01:15,851 | DEBUG | pool-5-thread-2 | |
ExecutionQueueImpl | mpl$ExecutionQueueOutputStream 696 |
ReplacmentMap: getReplacement({OScope 'request data-package' id=95}) =
org.apache.ode.bpel.engine.ReplacementMapImpl$OBaseReplacementImpl@1f4847ca
13:01:15,852 | DEBUG | pool-5-thread-2 | |
ExecutionQueueImpl | mpl$ExecutionQueueOutputStream 696 |
ReplacmentMap: getReplacement({OAssign : Preparedocument,
joinCondition=null}) =
org.apache.ode.bpel.engine.ReplacementMapImpl$OBaseReplacementImpl@42612ed1
What could be the cause? How can I fix this?
Thanks in advance, bye
Lorenzo
DEBUG - ExecutionQueueImpl - ReplacementMap:
getOriginal(org.apache.ode.bpel.engine.ReplacementMapImpl$OBaseReplacementImpl@4e647124)
= OPartnerLink#61
DEBUG - BpelRuntimeContextImpl - BpelRuntimeContextImpl created for
instance 1553. INDEXED STATE={{OScope '__PROCESS_SCOPE:covidien-fec-process'
id=3}::0=[SCOPE(...)], {OScope 'Run transformation' id=79}::10=[SCOPE(...)],
{OScope 'Run transformation' id=79}::10=[ACTIVE(...)], OInvoke#80-Run
transformation::12=[INVOKE(...)], OInvoke#80-Run
transformation::11=[ACTIVITYGUARD(...)],
OSequence#65-main::2=[SEQUENCE(self=(OSequence#65-main,TerminationChannel#3,ParentScopeChannel#5),
linkframe=org.apache.ode.bpel.runtime.LinkFrame@24401ab1, remaining=[{OScope
'Run transformation' id=79}, {OAssign : Prepare datapackage request,
joinCondition=null}, {OScope 'request data-package' id=95}, {OAssign :
Preparedocument, joinCondition=null}, {OScope 'Requestdocument' id=115},
OSwitch#122-Verifica errore di firma])],
OSequence#65-main::1=[ACTIVITYGUARD(...)], {OScope
'__PROCESS_SCOPE:covidien-fec-process' id=3}::0=[ACTIVE(...)], {OScope 'Run
transformation' id=79}::9=[ACTIVITYGUARD(...)]}
DEBUG - BpelProcess - InvokeResponse event for iid 1553
DEBUG - BpelRuntimeContextImpl - Invoking message response for mexid
hqejbhcnphr672vdtegmme and channel 20
DEBUG - JacobVPU - injecting (...)
ERROR - JacobVPU - Method "run" in class
"org.apache.ode.bpel.engine.BpelRuntimeContextImpl$7" threw an unexpected
exception.
java.lang.IllegalArgumentException: No such channel; id=20
at
org.apache.ode.jacob.vpu.ExecutionQueueImpl.findChannelFrame(ExecutionQueueImpl.java:205)
at
org.apache.ode.jacob.vpu.ExecutionQueueImpl.consumeExport(ExecutionQueueImpl.java:232)
at
org.apache.ode.jacob.vpu.JacobVPU$JacobThreadImpl.importChannel(JacobVPU.java:369)
at org.apache.ode.jacob.JacobObject.importChannel(JacobObject.java:47)
at
org.apache.ode.bpel.engine.BpelRuntimeContextImpl$7.run(BpelRuntimeContextImpl.java:1094)
at sun.reflect.GeneratedMethodAccessor160.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:592)
at
org.apache.ode.jacob.vpu.JacobVPU$JacobThreadImpl.run(JacobVPU.java:451)
at org.apache.ode.jacob.vpu.JacobVPU.execute(JacobVPU.java:139)
at
org.apache.ode.bpel.engine.BpelRuntimeContextImpl.execute(BpelRuntimeContextImpl.java:968)
at
org.apache.ode.bpel.engine.BpelProcess.handleJobDetails(BpelProcess.java:456)
at
org.apache.ode.bpel.engine.BpelEngineImpl.onScheduledJob(BpelEngineImpl.java:460)
at
org.apache.ode.bpel.engine.BpelServerImpl.onScheduledJob(BpelServerImpl.java:450)
at
org.apache.ode.scheduler.simple.SimpleScheduler$RunJob$1.call(SimpleScheduler.java:518)
at
org.apache.ode.scheduler.simple.SimpleScheduler$RunJob$1.call(SimpleScheduler.java:512)
at
org.apache.ode.scheduler.simple.SimpleScheduler.execTransaction(SimpleScheduler.java:284)
at
org.apache.ode.scheduler.simple.SimpleScheduler.execTransaction(SimpleScheduler.java:239)
at
org.apache.ode.scheduler.simple.SimpleScheduler$RunJob.call(SimpleScheduler.java:512)
at
org.apache.ode.scheduler.simple.SimpleScheduler$RunJob.call(SimpleScheduler.java:496)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269)
at java.util.concurrent.FutureTask.run(FutureTask.java:123)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:651)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:676)
at java.lang.Thread.run(Thread.java:595)
ERROR - BpelEngineImpl - Scheduled job failed;
jobDetail=JobDetails( instanceId: 1553 mexId: hqejbhcnphr672vdtegmme
processId: null type: INVOKE_RESPONSE channel: 20 correlatorId: null
correlationKeySet: null retryCount: 2 inMem: false detailsExt: {})
java.lang.RuntimeException: java.lang.IllegalArgumentException: No such
channel; id=20
at
org.apache.ode.jacob.vpu.JacobVPU$JacobThreadImpl.run(JacobVPU.java:464)
at org.apache.ode.jacob.vpu.JacobVPU.execute(JacobVPU.java:139)
at
org.apache.ode.bpel.engine.BpelRuntimeContextImpl.execute(BpelRuntimeContextImpl.java:968)
at
org.apache.ode.bpel.engine.BpelProcess.handleJobDetails(BpelProcess.java:456)
at
org.apache.ode.bpel.engine.BpelEngineImpl.onScheduledJob(BpelEngineImpl.java:460)
at
org.apache.ode.bpel.engine.BpelServerImpl.onScheduledJob(BpelServerImpl.java:450)
at
org.apache.ode.scheduler.simple.SimpleScheduler$RunJob$1.call(SimpleScheduler.java:518)
at
org.apache.ode.scheduler.simple.SimpleScheduler$RunJob$1.call(SimpleScheduler.java:512)
at
org.apache.ode.scheduler.simple.SimpleScheduler.execTransaction(SimpleScheduler.java:284)
at
org.apache.ode.scheduler.simple.SimpleScheduler.execTransaction(SimpleScheduler.java:239)
at
org.apache.ode.scheduler.simple.SimpleScheduler$RunJob.call(SimpleScheduler.java:512)
at
org.apache.ode.scheduler.simple.SimpleScheduler$RunJob.call(SimpleScheduler.java:496)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269)
at java.util.concurrent.FutureTask.run(FutureTask.java:123)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:651)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:676)
at java.lang.Thread.run(Thread.java:595)
Caused by: java.lang.IllegalArgumentException: No such channel; id=20
at
org.apache.ode.jacob.vpu.ExecutionQueueImpl.findChannelFrame(ExecutionQueueImpl.java:205)
at
org.apache.ode.jacob.vpu.ExecutionQueueImpl.consumeExport(ExecutionQueueImpl.java:232)
at
org.apache.ode.jacob.vpu.JacobVPU$JacobThreadImpl.importChannel(JacobVPU.java:369)
at org.apache.ode.jacob.JacobObject.importChannel(JacobObject.java:47)
at
org.apache.ode.bpel.engine.BpelRuntimeContextImpl$7.run(BpelRuntimeContextImpl.java:1094)
at sun.reflect.GeneratedMethodAccessor160.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:592)
at
org.apache.ode.jacob.vpu.JacobVPU$JacobThreadImpl.run(JacobVPU.java:451)
... 16 more
DEBUG - SimpleScheduler - Rollbacking on
org.jencks.GeronimoPlatformTransactionManager@774cdfcf...
DEBUG - InstanceLockManager - Thread[pool-5-thread-4,5,main]:
unlock(iid=1553)
ERROR - SimpleScheduler - Error while processing a persisted
job: Job hqejbhcnphr672vdtegmmj time: 2011-04-13 13:04:34 CEST transacted:
true persisted: true details: JobDetails( instanceId: 1553 mexId:
hqejbhcnphr672vdtegmme processId: null type: INVOKE_RESPONSE channel: 20
correlatorId: null correlationKeySet: null retryCount: 2 inMem: false
detailsExt: {})
org.apache.ode.bpel.iapi.Scheduler$JobProcessorException:
java.lang.RuntimeException: java.lang.IllegalArgumentException: No such
channel; id=20
at
org.apache.ode.bpel.engine.BpelEngineImpl.onScheduledJob(BpelEngineImpl.java:478)
at
org.apache.ode.bpel.engine.BpelServerImpl.onScheduledJob(BpelServerImpl.java:450)
at
org.apache.ode.scheduler.simple.SimpleScheduler$RunJob$1.call(SimpleScheduler.java:518)
at
org.apache.ode.scheduler.simple.SimpleScheduler$RunJob$1.call(SimpleScheduler.java:512)
at
org.apache.ode.scheduler.simple.SimpleScheduler.execTransaction(SimpleScheduler.java:284)
at
org.apache.ode.scheduler.simple.SimpleScheduler.execTransaction(SimpleScheduler.java:239)
at
org.apache.ode.scheduler.simple.SimpleScheduler$RunJob.call(SimpleScheduler.java:512)
at
org.apache.ode.scheduler.simple.SimpleScheduler$RunJob.call(SimpleScheduler.java:496)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269)
at java.util.concurrent.FutureTask.run(FutureTask.java:123)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:651)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:676)
at java.lang.Thread.run(Thread.java:595)
Caused by: java.lang.RuntimeException: java.lang.IllegalArgumentException:
No such channel; id=20
at
org.apache.ode.jacob.vpu.JacobVPU$JacobThreadImpl.run(JacobVPU.java:464)
at org.apache.ode.jacob.vpu.JacobVPU.execute(JacobVPU.java:139)
at
org.apache.ode.bpel.engine.BpelRuntimeContextImpl.execute(BpelRuntimeContextImpl.java:968)
at
org.apache.ode.bpel.engine.BpelProcess.handleJobDetails(BpelProcess.java:456)
at
org.apache.ode.bpel.engine.BpelEngineImpl.onScheduledJob(BpelEngineImpl.java:460)
... 12 more
Caused by: java.lang.IllegalArgumentException: No such channel; id=20
at
org.apache.ode.jacob.vpu.ExecutionQueueImpl.findChannelFrame(ExecutionQueueImpl.java:205)
at
org.apache.ode.jacob.vpu.ExecutionQueueImpl.consumeExport(ExecutionQueueImpl.java:232)
at
org.apache.ode.jacob.vpu.JacobVPU$JacobThreadImpl.importChannel(JacobVPU.java:369)
at org.apache.ode.jacob.JacobObject.importChannel(JacobObject.java:47)
at
org.apache.ode.bpel.engine.BpelRuntimeContextImpl$7.run(BpelRuntimeContextImpl.java:1094)
at sun.reflect.GeneratedMethodAccessor160.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:592)
at
org.apache.ode.jacob.vpu.JacobVPU$JacobThreadImpl.run(JacobVPU.java:451)
... 16 more
DEBUG - SimpleScheduler - Beginning a new transaction
DEBUG - JdbcDelegate - updateJob hqejbhcnphr672vdtegmmj
retryCount=3
DEBUG - sql - getConnection (tx=2)
DEBUG - sql - prepareStatement: update ODE_JOB
set ts = ?, retryCount = ? where jobid = ?
DEBUG - sql - executeUpdate, bound
(1,1302692838026) (2,3) (3,hqejbhcnphr672vdtegmmj)
DEBUG - sql - close()
DEBUG - sql - close()
ERROR - SimpleScheduler - Error while processing job,
retrying in 125s
DEBUG - SimpleScheduler - Commiting on
org.jencks.GeronimoPlatformTransactionManager@774cdfcf...