Ok, i'll will try this but I really need Hibernate as a persistence layer because I need some ODE functionnality (I mean the possibility to invoke the "listInstance" service with $prodOrderId in filter) that are not working with OpenJPA...
On Wed, Aug 10, 2011 at 2:02 PM, Waruna Ranasinghe <[email protected]>wrote: > 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 <[email protected] > >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@a0c486forerror: > [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* > > > > [email protected] > > > > *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 >
