ode-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Alexandre SAPANEL <alexandre.sapa...@photobox.com>
Subject Transaction problem in parallel foreach (Apache ODE 1.3.5)
Date Mon, 01 Aug 2011 12:05:28 GMT
*CONFIGURATION USED* : Apache ODE 1.3.5, Mysql 5, Tomcat 6.0.29 and
Hibernate





Hi,



I am facing a problem with a parallel foreach (iterating over 2
“orderItems”) and synchronous invoke.



I can see in logs that the call to the setOrderItemStatus operation is
correctly done for the 2 orderItems and the received responses are correct,
but the scope “SetOrderItemStatus_Scope”of the first iteration is never
completed whereas the scope of the second iteration is completed.

In my opinion it seems to be a transaction problem but and I can’t see
anything interesting in logs (see below).





Any help will be greatly appreciated. Also*, I made a test on WSO2 BPS 2.1.0
and my process works well* … Maybe I need to add some configuration
parameters in my ode-axis2.properties …





Thanks



Alexandre



---------- BPEL EXTRACT ------------------

<bpel:forEach parallel="yes" counterName="CounterOrderItem"

          name="ForEach_OrderItem_In_ProductionOrder">

          <bpel:startCounterValue><![CDATA[1]]></bpel:startCounterValue>


<bpel:finalCounterValue><![CDATA[$nbOrderItems]]></bpel:finalCounterValue>

          <bpel:scope name="SplitOrderIntoItems">

                    <bpel:variables>

                              <bpel:variable name="orderItem"
type="dom:orderItem" />

                              <bpel:variable name="nbItemComponent"
type="xs:int" />

                    </bpel:variables>

                    <bpel:partnerLinks>

                              <bpel:partnerLink
name="ProductionOrderServicePartnerBis"


partnerLinkType="process:ProductionOrderServiceLT"
partnerRole="ProductionOrderServiceProvider"></bpel:partnerLink>

                    </bpel:partnerLinks>

                    <bpel:sequence name="Sequence">

                              <bpel:assign validate="no"
name="AssignOrderItem">

                                       <bpel:copy>

                                                 <bpel:from>


<![CDATA[$productionOrder/dom:orderItems/dom:orderItem[position() =
$CounterOrderItem]]]>

                                                 </bpel:from>

                                                 <bpel:to
variable="orderItem"></bpel:to>

                                       </bpel:copy>

                              </bpel:assign>

                              <bpel:assign validate="no"
name="setNbItemComponent">

                                       <bpel:copy>

                                                 <bpel:from>

                                                           <bpel:literal
xml:space="preserve">1</bpel:literal>

                                                 </bpel:from>

                                                 <bpel:to
variable="nbItemComponent"></bpel:to>

                                       </bpel:copy>

                                       <bpel:copy>

                                                 <bpel:from>


<![CDATA[count($orderItem/dom:components/dom:component)]]>

                                                 </bpel:from>

                                                 <bpel:to
variable="nbItemComponent"></bpel:to>

                                       </bpel:copy>

                              </bpel:assign>

                              <!-- Update the order item status -->

                              <bpel:scope name="SetOrderItemStatus_Scope">

                                       <bpel:variables>

                                                 <bpel:variable
name="setOrderItemStatusInput"


messageType="pom:setOrderItemStatus"></bpel:variable>

                                                 <bpel:variable
name="technicalException"


messageType="pom:TechnicalException"></bpel:variable>

                                                 <bpel:variable
name="businessException"


messageType="pom:BusinessException"></bpel:variable>

                                                 <bpel:variable
name="updatedOrderItemStatus"


messageType="pom:setOrderItemStatusResponse">

                                                           <bpel:from>


<bpel:literal xml:space="preserve"><tns:setOrderItemStatusResponse


          xmlns:tns="
http://photobox.com/production/services/pom/ProductionOrderService"


          xmlns:tns1="
http://photobox.com/production/domain/model/schemas/extension"


          xmlns:tns2="http://photobox.com/production/domain/model/schemas"


          xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">



<return>true</return></tns:setOrderItemStatusResponse>




</bpel:literal>

                                                           </bpel:from>

                                                 </bpel:variable>

                                       </bpel:variables>

                                       <bpel:sequence
name="SetOrderItemStatus_Sequence">

                                                 <bpel:assign validate="no"
name="prepareSetOrderItemStatus">

                                                           <bpel:copy>


<bpel:from>


<bpel:literal xml:space="preserve"><tns:setOrderItemStatus


          xmlns:tns="
http://photobox.com/production/services/pom/ProductionOrderService"


          xmlns:tns1="
http://photobox.com/production/domain/model/schemas/extension"


          xmlns:tns2="http://photobox.com/production/domain/model/schemas"


          xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">


          <orderItemId>0</orderItemId>


          <orderItemStatus>INITIALIZED</orderItemStatus>


</tns:setOrderItemStatus>


</bpel:literal>


</bpel:from>


<bpel:to part="parameters" variable="setOrderItemStatusInput"></bpel:to>

                                                           </bpel:copy>

                                                           <bpel:copy>


<bpel:from>


          <bpel:literal><![CDATA[PROCESSING]]></bpel:literal>


</bpel:from>


<bpel:to part="parameters" variable="setOrderItemStatusInput">


<bpel:query queryLanguage="urn:oasis:names:tc:wsbpel:2.0:sublang:xpath1.0">


          <![CDATA[orderItemStatus]]>


</bpel:query>


</bpel:to>

                                                           </bpel:copy>

                                                           <bpel:copy>


<bpel:from> <![CDATA[$orderItem/dom:id]]>


</bpel:from>


<bpel:to part="parameters" variable="setOrderItemStatusInput">


<bpel:query
queryLanguage="urn:oasis:names:tc:wsbpel:2.0:sublang:xpath1.0"><![CDATA[orderItemId]]></bpel:query>


</bpel:to>

                                                           </bpel:copy>

                                                 </bpel:assign>

                                                 <*bpel:invoke
name="setOrderItemStatus"*


partnerLink="ProductionOrderServicePartnerBis"
operation="setOrderItemStatus"


portType="pom:ProductionOrderService"
inputVariable="setOrderItemStatusInput"


outputVariable="updatedOrderItemStatus">

                                                 </bpel:invoke>

                                                 <!-- Update the orderItem
variable with the new status -->

                                                 <bpel:assign validate="no"
name="setOrderItemStatus">

                                                           <bpel:copy>


<bpel:from>


          <bpel:literal><![CDATA[PROCESSING]]></bpel:literal>


</bpel:from>


<bpel:to variable="orderItem">


<bpel:query queryLanguage="urn:oasis:names:tc:wsbpel:2.0:sublang:xpath1.0">


          <![CDATA[dom:status]]>


</bpel:query>


</bpel:to>

                                                           </bpel:copy>

                                                 </bpel:assign>

                                       </bpel:sequence>

                              </bpel:scope>

                    </bpel:scope>

          </bpel:foreach>





---------------- LOGS EXTRACT-----------------

[2011-08-01 11:00:41,640] INFO: Response:

<?xml version="1.0" encoding="UTF-8"?>

<message><parameters><setOrderItemStatusResponse xmlns="
http://photobox.com/production/services/pom/ProductionOrderService"
xmlns:prod="
http://photobox.com/production/services/pom/ProductionOrderService"
xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/">

         <return xmlns="">true</return>

      </setOrderItemStatusResponse></parameters></message>
[org.apache.ode.axis2.ExternalService]

[2011-08-01 11:00:41,656] DEBUG: reply mex=1906
[org.apache.ode.bpel.engine.PartnerRoleMessageExchangeImpl]

[2011-08-01 11:00:41,656] DEBUG: create work event for mex=1906
[org.apache.ode.bpel.engine.PartnerRoleMessageExchangeImpl]

[2011-08-01 11:00:41,656] DEBUG: scheduling JobDetails( instanceId: 2100
mexId: 1906 processId: null type: INVOKE_RESPONSE channel: 125 correlatorId:
null correlationKeySet: null retryCount: null inMem: false detailsExt: {})
for Mon Aug 01 11:00:41 CEST 2011
[org.apache.ode.scheduler.simple.SimpleScheduler]

[2011-08-01 11:00:41,656] DEBUG: insertJob hqejbhcnphr6hbepu99t63 on node
hqejbhcnphr6hbepu99t5e loaded=true
[org.apache.ode.scheduler.simple.JdbcDelegate]

[2011-08-01 11:00:41,656] INFO: Response:

<?xml version="1.0" encoding="UTF-8"?>

<message><parameters><setOrderItemStatusResponse xmlns="
http://photobox.com/production/services/pom/ProductionOrderService"
xmlns:prod="
http://photobox.com/production/services/pom/ProductionOrderService"
xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/">

         <return xmlns="">true</return>

      </setOrderItemStatusResponse></parameters></message>
[org.apache.ode.axis2.ExternalService]

[2011-08-01 11:00:41,656] DEBUG: reply mex=1907
[org.apache.ode.bpel.engine.PartnerRoleMessageExchangeImpl]

[2011-08-01 11:00:41,656] DEBUG: create work event for mex=1907
[org.apache.ode.bpel.engine.PartnerRoleMessageExchangeImpl]

[2011-08-01 11:00:41,656] DEBUG: scheduling JobDetails( instanceId: 2100
mexId: 1907 processId: null type: INVOKE_RESPONSE channel: 144 correlatorId:
null correlationKeySet: null retryCount: null inMem: false detailsExt: {})
for Mon Aug 01 11:00:41 CEST 2011
[org.apache.ode.scheduler.simple.SimpleScheduler]

[2011-08-01 11:00:41,656] DEBUG: insertJob hqejbhcnphr6hbepu99t64 on node
hqejbhcnphr6hbepu99t5e loaded=true
[org.apache.ode.scheduler.simple.JdbcDelegate]

[2011-08-01 11:00:41,656] DEBUG: getConnection (tx=2) [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: getConnection (tx=2) [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: prepareStatement: insert into ODE_JOB
(jobid, nodeid, ts, scheduled, transacted,
instanceId,mexId,processId,type,channel,correlatorId,correlationKeySet,retryCount,inMem,detailsExt)
values(?, ?, ?, ?, ?,?,?,?,?,?,?,?,?,?,?) [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: prepareStatement: insert into ODE_JOB
(jobid, nodeid, ts, scheduled, transacted,
instanceId,mexId,processId,type,channel,correlatorId,correlationKeySet,retryCount,inMem,detailsExt)
values(?, ?, ?, ?, ?,?,?,?,?,?,?,?,?,?,?) [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: executeUpdate, bound
(1,hqejbhcnphr6hbepu99t63) (2,hqejbhcnphr6hbepu99t5e) (3,1312189241656)
(4,1) (5,1) (6,2100) (7,1906) (8,null) (9,INVOKE_RESPONSE) (10,125)
(11,null) (12,null) (13,null) (14,false) (15,null)  [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: executeUpdate, bound
(1,hqejbhcnphr6hbepu99t64) (2,hqejbhcnphr6hbepu99t5e) (3,1312189241656)
(4,1) (5,1) (6,2100) (7,1907) (8,null) (9,INVOKE_RESPONSE) (10,144)
(11,null) (12,null) (13,null) (14,false) (15,null)  [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: close() [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: close() [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: scheduled immediate job:
hqejbhcnphr6hbepu99t63 [org.apache.ode.scheduler.simple.SimpleScheduler]

[2011-08-01 11:00:41,656] DEBUG: Commiting on
org.apache.geronimo.transaction.manager.GeronimoTransactionManager@a0c486...
[org.apache.ode.scheduler.simple.SimpleScheduler]

[2011-08-01 11:00:41,656] DEBUG: getConnection (tx=2) [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: prepareStatement: insert into BPEL_MESSAGE
(MEX, TYPE, MESSAGE_DATA, MESSAGE_HEADER, INSERT_TIME, MLOCK, ID) values (?,
?, ?, ?, ?, ?, ?) [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: executeBatch, bound (1,1906) (2,{
http://photobox.com/production/services/pom/ProductionOrderService}setOrderItemStatusResponse)
(3,null) (4,null) (5,2011-08-01 11:00:41.64) (6,0) (7,2009)
[org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: close() [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: close() [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: scheduled immediate job:
hqejbhcnphr6hbepu99t64 [org.apache.ode.scheduler.simple.SimpleScheduler]

[2011-08-01 11:00:41,656] DEBUG: Commiting on
org.apache.geronimo.transaction.manager.GeronimoTransactionManager@a0c486...
[org.apache.ode.scheduler.simple.SimpleScheduler]

[2011-08-01 11:00:41,656] DEBUG: close() [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: getConnection (tx=2) [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: prepareStatement: update
BPEL_MESSAGE_EXCHANGE set RESPONSE=?, STATE=? where ID=?
[org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: executeBatch, bound (1,2009) (2,RESPONSE)
(3,1906)  [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: prepareStatement: insert into BPEL_MESSAGE
(MEX, TYPE, MESSAGE_DATA, MESSAGE_HEADER, INSERT_TIME, MLOCK, ID) values (?,
?, ?, ?, ?, ?, ?) [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: executeBatch, bound (1,1907) (2,{
http://photobox.com/production/services/pom/ProductionOrderService}setOrderItemStatusResponse)
(3,null) (4,null) (5,2011-08-01 11:00:41.64) (6,0) (7,2010)
[org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: close() [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: prepareStatement: update BPEL_MESSAGE set
MEX=?, TYPE=?, MESSAGE_DATA=?, MESSAGE_HEADER=?, INSERT_TIME=?, MLOCK=?
where ID=? [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: executeBatch, bound (1,1906) (2,{
http://photobox.com/production/services/pom/ProductionOrderService}setOrderItemStatusResponse)
(3,[B@184cdab) (4,null) (5,2011-08-01 11:00:41.64) (6,0) (7,2009)
[org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: close() [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: prepareStatement: update
BPEL_MESSAGE_EXCHANGE set RESPONSE=?, STATE=? where ID=?
[org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: executeBatch, bound (1,2010) (2,RESPONSE)
(3,1907)  [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: close() [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: close() [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: << "[\r]" [httpclient.wire.content]

[2011-08-01 11:00:41,656] DEBUG: Beginning a new transaction
[org.apache.ode.scheduler.simple.SimpleScheduler]

[2011-08-01 11:00:41,656] DEBUG: << "[\n]" [httpclient.wire.content]

[2011-08-01 11:00:41,656] DEBUG: << "0" [httpclient.wire.content]

[2011-08-01 11:00:41,656] DEBUG: deleteJob hqejbhcnphr6hbepu99t63 on node
hqejbhcnphr6hbepu99t5e [org.apache.ode.scheduler.simple.JdbcDelegate]

[2011-08-01 11:00:41,656] DEBUG: << "[\r]" [httpclient.wire.content]

[2011-08-01 11:00:41,656] DEBUG: << "[\n]" [httpclient.wire.content]

[2011-08-01 11:00:41,656] DEBUG: << "[\r]" [httpclient.wire.content]

[2011-08-01 11:00:41,656] DEBUG: close() [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: << "[\n]" [httpclient.wire.content]

[2011-08-01 11:00:41,656] DEBUG: << "[\r][\n]" [httpclient.wire.header]

[2011-08-01 11:00:41,656] DEBUG: prepareStatement: update BPEL_MESSAGE set
MEX=?, TYPE=?, MESSAGE_DATA=?, MESSAGE_HEADER=?, INSERT_TIME=?, MLOCK=?
where ID=? [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: Resorting to protocol version default close
connection policy [org.apache.commons.httpclient.HttpMethodBase]

[2011-08-01 11:00:41,656] DEBUG: getConnection (tx=2) [org.apache.ode.sql]

[2011-08-01 11:00:41,656] DEBUG: Should NOT close connection, using HTTP/1.1
[org.apache.commons.httpclient.HttpMethodBase]

[2011-08-01 11:00:41,656] DEBUG: Releasing connection back to connection
manager. [org.apache.commons.httpclient.HttpConnection]

[2011-08-01 11:00:41,671] DEBUG: Freeing connection,
hostConfig=HostConfiguration[host=http://localhost:8091]
[org.apache.commons.httpclient.MultiThreadedHttpConnectionManager]

[2011-08-01 11:00:41,671] DEBUG: Adding connection at: 1312189241671
[org.apache.commons.httpclient.util.IdleConnectionHandler]

[2011-08-01 11:00:41,671] DEBUG: Notifying no-one, there are no waiting
threads [org.apache.commons.httpclient.MultiThreadedHttpConnectionManager]

[2011-08-01 11:00:41,671] DEBUG: executeBatch, bound (1,1907) (2,{
http://photobox.com/production/services/pom/ProductionOrderService}setOrderItemStatusResponse)
(3,[B@12dd803) (4,null) (5,2011-08-01 11:00:41.64) (6,0) (7,2010)
[org.apache.ode.sql]

[2011-08-01 11:00:41,671] DEBUG: prepareStatement: delete from ODE_JOB where
jobid = ? and nodeid = ? [org.apache.ode.sql]

[2011-08-01 11:00:41,671] DEBUG: executeUpdate, bound
(1,hqejbhcnphr6hbepu99t63) (2,hqejbhcnphr6hbepu99t5e)  [org.apache.ode.sql]

[2011-08-01 11:00:41,671] DEBUG: close() [org.apache.ode.sql]

[2011-08-01 11:00:41,671] DEBUG: close() [org.apache.ode.sql]

[2011-08-01 11:00:41,671] DEBUG: << "[\r]" [httpclient.wire.content]

[2011-08-01 11:00:41,671] DEBUG: Beginning a new transaction
[org.apache.ode.scheduler.simple.SimpleScheduler]

[2011-08-01 11:00:41,671] DEBUG: << "[\n]" [httpclient.wire.content]

[2011-08-01 11:00:41,671] DEBUG: deleteJob hqejbhcnphr6hbepu99t64 on node
hqejbhcnphr6hbepu99t5e [org.apache.ode.scheduler.simple.JdbcDelegate]

[2011-08-01 11:00:41,671] DEBUG: << "0" [httpclient.wire.content]

[2011-08-01 11:00:41,671] DEBUG: << "[\r]" [httpclient.wire.content]

[2011-08-01 11:00:41,671] DEBUG: close() [org.apache.ode.sql]

[2011-08-01 11:00:41,671] DEBUG: << "[\n]" [httpclient.wire.content]

[2011-08-01 11:00:41,671] DEBUG: close() [org.apache.ode.sql]

[2011-08-01 11:00:41,671] DEBUG: << "[\r]" [httpclient.wire.content]

[2011-08-01 11:00:41,671] DEBUG: Thread[ODEServer-63,5,main]: lock(iid=2100,
time=1MICROSECONDS) [org.apache.ode.bpel.engine.InstanceLockManager]

[2011-08-01 11:00:41,671] DEBUG: getConnection (tx=2) [org.apache.ode.sql]

[2011-08-01 11:00:41,671] DEBUG: << "[\n]" [httpclient.wire.content]

[2011-08-01 11:00:41,671] DEBUG: Thread[ODEServer-63,5,main]: lock(iid=2100,
time=1MICROSECONDS)-->GRANTED
[org.apache.ode.bpel.engine.InstanceLockManager]

[2011-08-01 11:00:41,671] DEBUG: << "[\r][\n]" [httpclient.wire.header]

[2011-08-01 11:00:41,671] DEBUG: Resorting to protocol version default close
connection policy [org.apache.commons.httpclient.HttpMethodBase]

[2011-08-01 11:00:41,671] DEBUG: Should NOT close connection, using HTTP/1.1
[org.apache.commons.httpclient.HttpMethodBase]

[2011-08-01 11:00:41,671] DEBUG: Releasing connection back to connection
manager. [org.apache.commons.httpclient.HttpConnection]

[2011-08-01 11:00:41,671] DEBUG: Freeing connection,
hostConfig=HostConfiguration[host=http://localhost:8091]
[org.apache.commons.httpclient.MultiThreadedHttpConnectionManager]

[2011-08-01 11:00:41,671] DEBUG: prepareStatement: delete from ODE_JOB where
jobid = ? and nodeid = ? [org.apache.ode.sql]

[2011-08-01 11:00:41,671] DEBUG: Adding connection at: 1312189241671
[org.apache.commons.httpclient.util.IdleConnectionHandler]

[2011-08-01 11:00:41,671] DEBUG: Notifying no-one, there are no waiting
threads [org.apache.commons.httpclient.MultiThreadedHttpConnectionManager]

[2011-08-01 11:00:41,671] DEBUG: executeUpdate, bound
(1,hqejbhcnphr6hbepu99t64) (2,hqejbhcnphr6hbepu99t5e)  [org.apache.ode.sql]

[2011-08-01 11:00:41,671] DEBUG: getConnection (tx=2) [org.apache.ode.sql]

[2011-08-01 11:00:41,671] DEBUG: prepareStatement: select hprocessin0_.ID as
ID1_1_, hprocessin0_.INSTANTIATING_CORRELATOR as INSTANTI2_1_1_,
hprocessin0_.FAULT as FAULT1_1_, hprocessin0_.JACOB_STATE_DATA as
JACOB4_1_1_, hprocessin0_.PREVIOUS_STATE as PREVIOUS5_1_1_,
hprocessin0_.PROCESS_ID as PROCESS6_1_1_, hprocessin0_.STATE as STATE1_1_,
hprocessin0_.LAST_ACTIVE_DT as LAST8_1_1_, hprocessin0_.SEQUENCE as
SEQUENCE1_1_, hprocessin0_.FAILURE_COUNT as FAILURE10_1_1_,
hprocessin0_.FAILURE_DT as FAILURE11_1_1_, hprocessin0_.INSERT_TIME as
INSERT12_1_1_, hprocessin0_.MLOCK as MLOCK1_1_, hprocess1_.ID as ID0_0_,
hprocess1_.PROCID as PROCID0_0_, hprocess1_.deployer as deployer0_0_,
hprocess1_.deploydate as deploydate0_0_, hprocess1_.type_name as type5_0_0_,
hprocess1_.type_ns as type6_0_0_, hprocess1_.version as version0_0_,
hprocess1_.ACTIVE_ as ACTIVE8_0_0_, hprocess1_.guid as guid0_0_,
hprocess1_.INSERT_TIME as INSERT10_0_0_, hprocess1_.MLOCK as MLOCK0_0_ from
BPEL_INSTANCE hprocessin0_ left outer join BPEL_PROCESS hprocess1_ on
hprocessin0_.PROCESS_ID=hprocess1_.ID where hprocessin0_.ID=?
[org.apache.ode.sql]

[2011-08-01 11:00:41,671] DEBUG: executeQuery, bound (1,2100)
[org.apache.ode.sql]

[2011-08-01 11:00:41,671] DEBUG: close() [org.apache.ode.sql]

[2011-08-01 11:00:41,671] DEBUG: close() [org.apache.ode.sql]

[2011-08-01 11:00:41,671] DEBUG: Thread[ODEServer-64,5,main]: lock(iid=

iuy2100, time=1MICROSECONDS)
[org.apache.ode.bpel.engine.InstanceLockManager]

[2011-08-01 11:00:41,671] DEBUG: Thread[ODEServer-64,5,main]: lock(iid=2100,
time=1MICROSECONDS)-->WAITING(held by Thread[ODEServer-63,5,main])
[org.apache.ode.bpel.engine.InstanceLockManager]

[2011-08-01 11:00:41,671] DEBUG: close() [org.apache.ode.sql]

[2011-08-01 11:00:41,671] DEBUG: close() [org.apache.ode.sql]

[2011-08-01 11:00:41,671] DEBUG: >> handleJobDetails(jobData=JobDetails(
instanceId: 2100 mexId: 1906 processId: null type: INVOKE_RESPONSE channel:
125 correlatorId: null correlationKeySet: null retryCount: null inMem: false
detailsExt: {})) [org.apache.ode.bpel.engine.BpelProcess]

[2011-08-01 11:00:41,671] DEBUG: getConnection (tx=2) [org.apache.ode.sql]

[2011-08-01 11:00:41,671] DEBUG: Thread[ODEServer-64,5,main]: lock(iid=2100,
time=1MICROSECONDS)-->TIMEOUT (held by Thread[ODEServer-63,5,main])
[org.apache.ode.bpel.engine.InstanceLockManager]

[2011-08-01 11:00:41,671] DEBUG: Instance 2100 is busy, rescheduling job.
[org.apache.ode.bpel.engine.BpelEngineImpl]

[2011-08-01 11:00:41,671] DEBUG: Rollbacking on
org.apache.geronimo.transaction.manager.GeronimoTransactionManager@a0c486...
[org.apache.ode.scheduler.simple.SimpleScheduler]

[2011-08-01 11:00:41,671] DEBUG: Will retry the transaction in 1000 msecs on
org.apache.geronimo.transaction.manager.GeronimoTransactionManager@a0c486for
error:  [org.apache.ode.scheduler.simple.SimpleScheduler]

org.apache.ode.bpel.iapi.Scheduler$JobProcessorException

          at
org.apache.ode.bpel.engine.BpelEngineImpl.acquireInstanceLock(BpelEngineImpl.java:394)

          at
org.apache.ode.bpel.engine.BpelEngineImpl.onScheduledJob(BpelEngineImpl.java:403)

          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:303)

          at java.util.concurrent.FutureTask.run(FutureTask.java:138)

          at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)

          at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)

          at java.lang.Thread.run(Thread.java:619)

[2011-08-01 11:00:41,671] DEBUG: prepareStatement: select this_.ID as
ID0_0_, this_.PROCID as PROCID0_0_, this_.deployer as deployer0_0_,
this_.deploydate as deploydate0_0_, this_.type_name as type5_0_0_,
this_.type_ns as type6_0_0_, this_.version as version0_0_, this_.ACTIVE_ as
ACTIVE8_0_0_, this_.guid as guid0_0_, this_.INSERT_TIME as INSERT10_0_0_,
this_.MLOCK as MLOCK0_0_ from BPEL_PROCESS this_ where this_.PROCID=?
[org.apache.ode.sql]

[2011-08-01 11:00:41,671] DEBUG: executeQuery, bound (1,{
http://photobox.com/production/workflow/ProductionOrderProcess}ProductionOrderProcess-2)
[org.apache.ode.sql]

[2011-08-01 11:00:41,671] DEBUG: close() [org.apache.ode.sql]

[2011-08-01 11:00:41,671] DEBUG: close() [org.apache.ode.sql]

  *Alexandre SAPANEL*

 IT Prod Software Architect

*E-mail*

 alexandre.sapanel@photobox.com

*Téléphone*

 01 30 86 80 80

*Fax*

 01 30 86 80 59

Mime
  • Unnamed multipart/related (inline, None, 0 bytes)
View raw message