ode-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Waruna Ranasinghe <waruna...@gmail.com>
Subject Re: Transaction problem in parallel foreach (Apache ODE 1.3.5)
Date Wed, 10 Aug 2011 12:02:46 GMT
Hi,

WSO2 BPS 2.1.0 also use Apache ODE but with OpenJPA as the persistent layer
(not Hibernate).
Can you try this process with Apache ODE with OpenJPA as the persistent
layer instead of Hibernate.

Thanks,
Waruna
On 2 August 2011 00:05, Alexandre SAPANEL <alexandre.sapanel@photobox.com>wrote:

>  *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
>
>
>



-- 
-----------------------------------------------------
Regards,
Waruna Ranasinghe

blog: http://warunapw.blogspot.com
twitter: http://twitter.com/warunapww
http://lk.linkedin.com/in/waruna
www.facebook.com/waruna.ranasinghe

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