You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@ode.apache.org by Matthieu Riou <ma...@offthelip.org> on 2008/06/05 20:11:06 UTC

Re: [Fwd: Re: SCA BPEL - Problems with ODE - Help requested]

Okay, this took a while because it was actually far trickier than I
expected. Here were the two problems (the first being the serious one):

 * When OpenJPA first connects to the DB it initializes its sequence table
and does it using a different connection. It's fine when it's done in
isolation (like at startup) but with Derby, when a transaction that creates
stuff gets executed, it causes a lock timeout because the two connections
are competing to set a value. To fix this I've set a little parameters (all
that time for a single line fix...) that forces the initialization when we
start the engine.

 * The HelloWorld process assignment was actually setting a variable that
wasn't structured properly when checking the message schema. I updated the
assignment.

So now we get the proper message in and out. I still have one last problem,
when the message gets back to Tuscany I get:

org.apache.tuscany.sca.databinding.TransformationException:
java.lang.IllegalArgumentException: local part cannot be "null" when
creating a QName
        at
org.apache.tuscany.sca.core.databinding.transformers.Output2OutputTransformer.transform(Output2OutputTransformer.java:215)
        at
org.apache.tuscany.sca.databinding.impl.MediatorImpl.mediate(MediatorImpl.java:79)
        at
org.apache.tuscany.sca.core.databinding.wire.DataTransformationInterceptor.transform(DataTransformationInterceptor.java:186)
        at
org.apache.tuscany.sca.core.databinding.wire.DataTransformationInterceptor.invoke(DataTransformationInterceptor.java:169)
        at
org.apache.tuscany.sca.binding.sca.impl.SCABindingInvoker.invoke(SCABindingInvoker.java:61)
        at
org.apache.tuscany.sca.core.databinding.wire.PassByValueInterceptor.invoke(PassByValueInterceptor.java:103)
        at
org.apache.tuscany.sca.core.invocation.JDKInvocationHandler.invoke(JDKInvocationHandler.java:286)
        at
org.apache.tuscany.sca.core.invocation.JDKInvocationHandler.invoke(JDKInvocationHandler.java:154)
        at $Proxy5.hello(Unknown Source)
        at
helloworld.BPELHelloWorldTestCase.testInvoke(BPELHelloWorldTestCase.java:56)

The message looks fine to me, any idea what this could be? I've committed my
fixes so you should be able to reproduce it.

Cheers,
Matthieu

On Fri, May 30, 2008 at 11:39 PM, Matthieu Riou <ma...@offthelip.org>
wrote:

> I've started looking at the DbError issue and reproduced it. Digging deeper
> it seems it's caused by a lock timeout in Derby on the
> OPENJPA_SEQUENCE_TABLE when ODE tries to create a record for the new
> deployed process. Here is an excerpt from the logs:
>
> DEBUG - GeronimoLog.debug(66) | Creating process DAO for {
> http://tuscany.apache.org/implementation/bpel/example/helloworld}HelloWorld-1<http://tuscany.apache.org/implementation/bpel/example/helloworld%7DHelloWorld-1>(guid=hqejbhcnphr3beiwcxrx88)
> DEBUG - GeronimoLog.debug(66) | getConnection (tx=2)
> DEBUG - GeronimoLog.debug(66) | prepareStmt: SELECT t0.ID, t0.GUID,
> t0.PROCESS_ID, t0.PROCESS_TYPE, t0.VERSION FROM ODE_PROCESS t0 WHERE
> (t0.PROCESS_ID = ?)
> DEBUG - GeronimoLog.debug(66) | bound (1,{
> http://tuscany.apache.org/implementation/bpel/example/helloworld}HelloWorld-1<http://tuscany.apache.org/implementation/bpel/example/helloworld%7DHelloWorld-1>
> )
> DEBUG - GeronimoLog.debug(66) | close
> DEBUG - GeronimoLog.debug(66) | getConnection (tx=2)
> DEBUG - GeronimoLog.debug(66) | prepareStmt: SELECT SEQUENCE_VALUE FROM
> OPENJPA_SEQUENCE_TABLE WHERE ID = ? FOR UPDATE WITH RR
> DEBUG - GeronimoLog.debug(66) | bound (1,0)
> DEBUG - GeronimoLog.debug(66) | close
> DEBUG - GeronimoLog.debug(66) | getConnection (tx=2)
> DEBUG - GeronimoLog.debug(66) | prepareStmt: INSERT INTO
> OPENJPA_SEQUENCE_TABLE (ID, SEQUENCE_VALUE) VALUES (?, ?)
> DEBUG - GeronimoLog.debug(66) | bound (2,1) (1,0)
> DEBUG - GeronimoLog.debug(66) | close
> DEBUG - GeronimoLog.debug(66) | getConnection (tx=2)
> DEBUG - GeronimoLog.debug(66) | prepareStmt: SELECT SEQUENCE_VALUE FROM
> OPENJPA_SEQUENCE_TABLE WHERE ID = ? FOR UPDATE WITH RR
> DEBUG - GeronimoLog.debug(66) | bound (1,0)
> WARN - GeronimoLog.warn(96) | connectionErrorOccurred called with null
> java.sql.SQLException: A lock could not be obtained within the time
> requested
>
> Right now I really have no clue why this is happening, there's no reason
> why a lock would get stuck on the OpenJPA sequence table. I have to dig
> deeper but it's getting late, I'll try to find more time during the week-end
> or Monday.
>
> Cheers,
> Matthieu
>
>
> On Fri, May 30, 2008 at 1:42 PM, Mike Edwards <
> mike.edwards.inglenook@gmail.com> wrote:
>
>>
>>
>> -------- Original Message --------
>> Subject: Re: SCA BPEL - Problems with ODE - Help requested
>> Date: Fri, 30 May 2008 17:51:12 +0100
>> From: Mike Edwards <mi...@gmail.com>
>> To: tuscany-dev@ws.apache.org
>> References: <48...@gmail.com> <
>> fbdc6a970805291930v1dbb0e59hfc1b5f4a6e9809c1@mail.gmail.com>
>>
>> Matthieu Riou wrote:
>>
>>> On Thu, May 29, 2008 at 11:41 AM, Mike Edwards <
>>> mike.edwards.inglenook@gmail.com> wrote:
>>>
>>>  Folks,
>>>>
>>>> I've run into problems with the SCA BPEL implementation and the way it
>>>> interacts with the ODE engine - and I need help from some ODE experts,
>>>> please.
>>>>
>>>> OK, the SCA code is using the ODE engine in an embedded mode - and the
>>>> Tuscany code is trying to supply all the information and interfaces for
>>>> each
>>>> BPEL process to the ODE Engine - and in particular it aims to bypass the
>>>> ODE
>>>> database store so far as the BPEL process and its configuration are
>>>> concerned.
>>>>
>>>> So - Tuscany now has its own version of the ProcessConfImpl (I sent a
>>>> version of this out in a previous email).  One thing I discovered is
>>>> that it
>>>> is necessary for the Tuscany ProcessConfImpl to return "true" to the
>>>> isTransient() method. Otherwise, the ODE engine seems to try to find
>>>> information about the process in the database with nasty consequences
>>>> (failed transactions).
>>>>
>>>>
>>> Normally that shouldn't be a problem. Transient tells ODE to execute the
>>> process in memory but that only applies to short living processes, for
>>> most
>>> scenarios you'll want to have persistent executions. So we should try to
>>> see
>>> why these transactions fail.
>>>
>>>
>>>  HOWEVER, this has a side effect that is both curious and problematic.
>>>>
>>>> Using the ODE ProcessConfImpl (and by implication the database store for
>>>> the process itself), for a trivial "Hello World" BPEL process, when the
>>>> "hello" operation is invoked on the BPEL process, the ODE engine returns
>>>> the
>>>> result message as a "DeferredElementNSImpl" class with the name
>>>> "TestPart" -
>>>> which on inspection contains a child element "message" containing the
>>>> expected "Hello World" string.
>>>> (I attach the relevant part of the WSDL at the bottom)
>>>>
>>>>
>>>> When we switch to using the Tuscany ProcessConfImpl - with its
>>>> "transient"
>>>> setting, when we invoke the same process, we get back a different type
>>>> of
>>>> object - an "ElementImpl" named "TestPart".  This contains an
>>>> ElementNSImpl
>>>> object named "hello" containing a TextImpl child holding "Hello World".
>>>> This
>>>> structural layout is clearly different to the previous case - and is
>>>> wrong -
>>>> it isn't what is expected.
>>>>
>>>> Can anyone explain the difference in the two cases?  Any assistance
>>>> gratefully received.
>>>>
>>>>
>>> I don't see what could create this difference. The deferred element vs.
>>> normal element is nothing to worry about, it's just that the structure
>>> has
>>> already been traversed in one case because of the storage different, but
>>> the
>>> content itself should be identical. Usually the switch from transient to
>>> persistent doesn't bring that kind of differences but there's nothing I
>>> can
>>> think of off the top of my head that could create this behavior. The
>>> structural difference kind of reminds the difference between rpc and
>>> document style part wrappers but that shouldn't show here.
>>>
>>> So I'd like to reproduce this and see what's going wrong. Is all your
>>> code
>>> committed? Which test case are you using?
>>>
>>> Thanks,
>>> Matthieu
>>>
>>
>> Matthieu,
>>
>> Thanks for responding - let me try and pick my way through it for you:
>>
>> 1) All the code is committed and in the current Tuscany SVN.
>>
>> 2) The runtime code that is relevant is all in the implementation-bpel-ode
>> module
>>
>> 3) There are 3 sets of test/samples you can use to try things out:
>>
>> a) In Samples - helloworld-bpel  and   helloworld-bpel-ws
>> b) In Itest - there are 4 Itests under BPEL - helloworld
>>                                            - helloworld-reference
>>                                            - helloworld-ws
>>                                            - ping-pong
>>
>> I tend to use the 2 samples.  The second one uses web services and catches
>> the problems with the
>> data format returned by the BPEL process, for example. (You get an
>> exception in the databinding code
>> when it tries to transform it)
>>
>>
>> Now, I've fixed up the code in implementation-bpel-ode so that it works -
>> so the problems are all
>> masked.  But some simple commenting and uncommenting of lines of code can
>> reproduce all the problems.
>>
>> The 2 main classes to deal with are:
>>
>> - EmbeddedODEServer
>> - TuscanyProcessConfImpl
>>
>>
>> Currently, EmbeddedODEServer is set up to use the ODE Store and Persisted
>> BPEL Processes - the trick
>> I've done is that the code itself WRITES the deploy.xml file on the fly -
>> so that the programmer
>> does not need to write it.  This is handled by the BPELODEDeployFile
>> class.
>>
>> To change things, all you need to do is to go to the deploy(....) method
>> in EmbeddedOdeServer.  You
>> will find 2 blocks of code inside a try{} block - one for using the ODE
>> Store, the other for using
>> the Tuscany stuff without the store.  Simply comment out one an uncomment
>> the other to flip between
>> them.
>>
>> Only one other thing needs changing to work through all the problems - and
>> that is the response to
>> the isTransient() method of the TuscanyProcessConfImpl - currently it's
>> set to "true" - simply flip
>> it to return "false" to see the other behaviour.
>>
>>
>> One significant thing I discovered is that there is a "memory effect" in
>> the database.  IF the
>> database has been used ONCE by the ODE Store code then if the code is run
>> afterwards in "non Store"
>> mode, it works ok, with no transaction errors.  The transaction errors
>> only occur with a "virgin"
>> database that has never been used by the Store code.  If that ain't
>> confusing, nothing is...
>>
>> Note - running the Samples and Itests above using mvn usually cleans out
>> the DB - I've been able to
>> preserve the DB when running from Eclipse.
>>
>> When getting the transaction problem, my tracing showed that is happening
>> in:
>>
>> BpelProcess$HydrationLatch.doHydrate() line 755
>> "DbError"
>> "Unable to Commit"
>>
>>
>> Yours,  Mike.
>>
>>
>

Re: [Fwd: Re: SCA BPEL - Problems with ODE - Help requested]

Posted by Mike Edwards <mi...@gmail.com>.
Matthieu Riou wrote:
> On Thu, Jun 5, 2008 at 12:38 PM, Mike Edwards <
> mike.edwards.inglenook@gmail.com> wrote:
> 
>> Matthieu,
>>
>> First - many thanks for your hard work on this.
>>
>> I take no pleasure in saying this, but I am glad that the DB problem was
>> ODE's problem rather than Tuscany's - it looks like you are far more
>> experienced in handling that area of code!
>>
>> Regarding that remaining error, which is generated by Tuscany.  I am
>> assuming that this is the same error that I examined previously when using
>> the TuscanyProcessConfImpl rather than the ODE ProcessConfImpl - namely that
>> the returned data structure from ODE is simply different - and I believe it
>> is in error - as the top level element is of a different type: - quoting
>> from my previous email, in the case of using the TuscanyProcessConfImpl:
>>
> 
> Actually I think it's a different problem even if the symptom looks
> identical (as I mentioned, I fixed the process). First, it always break in
> the same way, whether the process is transient or not (which is reassuring).
> Second, the message looks good to me this time:
> 
>>>> Response:
> <?xml version="1.0" encoding="UTF-8"?>
> <message><TestPart><hello xmlns="
> http://tuscany.apache.org/implementation/bpel/example/helloworld.wsdl"><message>Hello
> World</message></hello></TestPart></message>
> 
> The namespaces of the <hello> and the <message> elements seem correct. Don't
> you think?
> 
> Cheers,
> Matthieu
> 
Matthieu,

Many thanks...

the Tuscany archaeology is underway....


Yours,  Mike.


Re: [Fwd: Re: SCA BPEL - Problems with ODE - Help requested]

Posted by Matthieu Riou <ma...@offthelip.org>.
On Thu, Jun 5, 2008 at 12:38 PM, Mike Edwards <
mike.edwards.inglenook@gmail.com> wrote:

> Matthieu,
>
> First - many thanks for your hard work on this.
>
> I take no pleasure in saying this, but I am glad that the DB problem was
> ODE's problem rather than Tuscany's - it looks like you are far more
> experienced in handling that area of code!
>
> Regarding that remaining error, which is generated by Tuscany.  I am
> assuming that this is the same error that I examined previously when using
> the TuscanyProcessConfImpl rather than the ODE ProcessConfImpl - namely that
> the returned data structure from ODE is simply different - and I believe it
> is in error - as the top level element is of a different type: - quoting
> from my previous email, in the case of using the TuscanyProcessConfImpl:
>

Actually I think it's a different problem even if the symptom looks
identical (as I mentioned, I fixed the process). First, it always break in
the same way, whether the process is transient or not (which is reassuring).
Second, the message looks good to me this time:

>>>Response:
<?xml version="1.0" encoding="UTF-8"?>
<message><TestPart><hello xmlns="
http://tuscany.apache.org/implementation/bpel/example/helloworld.wsdl"><message>Hello
World</message></hello></TestPart></message>

The namespaces of the <hello> and the <message> elements seem correct. Don't
you think?

Cheers,
Matthieu



>
>
> "When we switch to using the Tuscany ProcessConfImpl - with its "transient"
> setting, when we invoke the same process, we get back a different type of
> object - an "ElementImpl" named "TestPart".  This contains an ElementNSImpl
> object named "hello" containing a TextImpl child holding "Hello World". This
> structural layout is clearly different to the previous case - and is wrong -
> it isn't what is expected."
>
> To explain futher, the direct cause of that exception you list is the fact
> that the top level element returned - the ElementImpl - does NOT have a
> namespace declared (I believe that it should be an ElementNSImpl) - and it
> is the lack of the NS that is at the root of the "null" exception that
> Tuscany returns.  I note that this is NOT the same data structure that is
> returned by ODE when the ODE ProcessConfImpl is used - that data structure
> IS headed by a DeferredElementNSImpl (the deferred aspect isn't important,
> but the "NS" aspect very much is important).
>
> I could not determine why there was this difference in the data structure
> returned.  I'll have another check using your fixed version of the code -
> but it would be useful if you could give me a clue about where in the ODE
> code this data element is being generated - it is very hard to trace.
>
>
>
> Yours,  Mike.
>
> PS - I assume that I need to take a latest build from the ODE SVN to get
> your fixes for the DB problem?
>
>
> Matthieu Riou wrote:
>
>> Okay, this took a while because it was actually far trickier than I
>> expected. Here were the two problems (the first being the serious one):
>>
>>  * When OpenJPA first connects to the DB it initializes its sequence table
>> and does it using a different connection. It's fine when it's done in
>> isolation (like at startup) but with Derby, when a transaction that
>> creates
>> stuff gets executed, it causes a lock timeout because the two connections
>> are competing to set a value. To fix this I've set a little parameters
>> (all
>> that time for a single line fix...) that forces the initialization when we
>> start the engine.
>>
>>  * The HelloWorld process assignment was actually setting a variable that
>> wasn't structured properly when checking the message schema. I updated the
>> assignment.
>>
>> So now we get the proper message in and out. I still have one last
>> problem,
>> when the message gets back to Tuscany I get:
>>
>> org.apache.tuscany.sca.databinding.TransformationException:
>> java.lang.IllegalArgumentException: local part cannot be "null" when
>> creating a QName
>>        at
>>
>> org.apache.tuscany.sca.core.databinding.transformers.Output2OutputTransformer.transform(Output2OutputTransformer.java:215)
>>        at
>>
>> org.apache.tuscany.sca.databinding.impl.MediatorImpl.mediate(MediatorImpl.java:79)
>>        at
>>
>> org.apache.tuscany.sca.core.databinding.wire.DataTransformationInterceptor.transform(DataTransformationInterceptor.java:186)
>>        at
>>
>> org.apache.tuscany.sca.core.databinding.wire.DataTransformationInterceptor.invoke(DataTransformationInterceptor.java:169)
>>        at
>>
>> org.apache.tuscany.sca.binding.sca.impl.SCABindingInvoker.invoke(SCABindingInvoker.java:61)
>>        at
>>
>> org.apache.tuscany.sca.core.databinding.wire.PassByValueInterceptor.invoke(PassByValueInterceptor.java:103)
>>        at
>>
>> org.apache.tuscany.sca.core.invocation.JDKInvocationHandler.invoke(JDKInvocationHandler.java:286)
>>        at
>>
>> org.apache.tuscany.sca.core.invocation.JDKInvocationHandler.invoke(JDKInvocationHandler.java:154)
>>        at $Proxy5.hello(Unknown Source)
>>        at
>>
>> helloworld.BPELHelloWorldTestCase.testInvoke(BPELHelloWorldTestCase.java:56)
>>
>> The message looks fine to me, any idea what this could be? I've committed
>> my
>> fixes so you should be able to reproduce it.
>>
>> Cheers,
>> Matthieu
>>
>> On Fri, May 30, 2008 at 11:39 PM, Matthieu Riou <ma...@offthelip.org>
>> wrote:
>>
>>  I've started looking at the DbError issue and reproduced it. Digging
>>> deeper
>>> it seems it's caused by a lock timeout in Derby on the
>>> OPENJPA_SEQUENCE_TABLE when ODE tries to create a record for the new
>>> deployed process. Here is an excerpt from the logs:
>>>
>>> DEBUG - GeronimoLog.debug(66) | Creating process DAO for {
>>>
>>> http://tuscany.apache.org/implementation/bpel/example/helloworld}HelloWorld-1<http://tuscany.apache.org/implementation/bpel/example/helloworld%7DHelloWorld-1>
>>> <
>>> http://tuscany.apache.org/implementation/bpel/example/helloworld%7DHelloWorld-1
>>> >(guid=hqejbhcnphr3beiwcxrx88)
>>> DEBUG - GeronimoLog.debug(66) | getConnection (tx=2)
>>> DEBUG - GeronimoLog.debug(66) | prepareStmt: SELECT t0.ID, t0.GUID,
>>> t0.PROCESS_ID, t0.PROCESS_TYPE, t0.VERSION FROM ODE_PROCESS t0 WHERE
>>> (t0.PROCESS_ID = ?)
>>> DEBUG - GeronimoLog.debug(66) | bound (1,{
>>>
>>> http://tuscany.apache.org/implementation/bpel/example/helloworld}HelloWorld-1<http://tuscany.apache.org/implementation/bpel/example/helloworld%7DHelloWorld-1>
>>> <
>>> http://tuscany.apache.org/implementation/bpel/example/helloworld%7DHelloWorld-1
>>> >
>>>
>>> )
>>> DEBUG - GeronimoLog.debug(66) | close
>>> DEBUG - GeronimoLog.debug(66) | getConnection (tx=2)
>>> DEBUG - GeronimoLog.debug(66) | prepareStmt: SELECT SEQUENCE_VALUE FROM
>>> OPENJPA_SEQUENCE_TABLE WHERE ID = ? FOR UPDATE WITH RR
>>> DEBUG - GeronimoLog.debug(66) | bound (1,0)
>>> DEBUG - GeronimoLog.debug(66) | close
>>> DEBUG - GeronimoLog.debug(66) | getConnection (tx=2)
>>> DEBUG - GeronimoLog.debug(66) | prepareStmt: INSERT INTO
>>> OPENJPA_SEQUENCE_TABLE (ID, SEQUENCE_VALUE) VALUES (?, ?)
>>> DEBUG - GeronimoLog.debug(66) | bound (2,1) (1,0)
>>> DEBUG - GeronimoLog.debug(66) | close
>>> DEBUG - GeronimoLog.debug(66) | getConnection (tx=2)
>>> DEBUG - GeronimoLog.debug(66) | prepareStmt: SELECT SEQUENCE_VALUE FROM
>>> OPENJPA_SEQUENCE_TABLE WHERE ID = ? FOR UPDATE WITH RR
>>> DEBUG - GeronimoLog.debug(66) | bound (1,0)
>>> WARN - GeronimoLog.warn(96) | connectionErrorOccurred called with null
>>> java.sql.SQLException: A lock could not be obtained within the time
>>> requested
>>>
>>> Right now I really have no clue why this is happening, there's no reason
>>> why a lock would get stuck on the OpenJPA sequence table. I have to dig
>>> deeper but it's getting late, I'll try to find more time during the
>>> week-end
>>> or Monday.
>>>
>>> Cheers,
>>> Matthieu
>>>
>>>
>>> On Fri, May 30, 2008 at 1:42 PM, Mike Edwards <
>>> mike.edwards.inglenook@gmail.com> wrote:
>>>
>>>
>>>> -------- Original Message --------
>>>> Subject: Re: SCA BPEL - Problems with ODE - Help requested
>>>> Date: Fri, 30 May 2008 17:51:12 +0100
>>>> From: Mike Edwards <mi...@gmail.com>
>>>> To: tuscany-dev@ws.apache.org
>>>> References: <48...@gmail.com> <
>>>> fbdc6a970805291930v1dbb0e59hfc1b5f4a6e9809c1@mail.gmail.com>
>>>>
>>>> Matthieu Riou wrote:
>>>>
>>>>  On Thu, May 29, 2008 at 11:41 AM, Mike Edwards <
>>>>> mike.edwards.inglenook@gmail.com> wrote:
>>>>>
>>>>>  Folks,
>>>>>
>>>>>> I've run into problems with the SCA BPEL implementation and the way it
>>>>>> interacts with the ODE engine - and I need help from some ODE experts,
>>>>>> please.
>>>>>>
>>>>>> OK, the SCA code is using the ODE engine in an embedded mode - and the
>>>>>> Tuscany code is trying to supply all the information and interfaces
>>>>>> for
>>>>>> each
>>>>>> BPEL process to the ODE Engine - and in particular it aims to bypass
>>>>>> the
>>>>>> ODE
>>>>>> database store so far as the BPEL process and its configuration are
>>>>>> concerned.
>>>>>>
>>>>>> So - Tuscany now has its own version of the ProcessConfImpl (I sent a
>>>>>> version of this out in a previous email).  One thing I discovered is
>>>>>> that it
>>>>>> is necessary for the Tuscany ProcessConfImpl to return "true" to the
>>>>>> isTransient() method. Otherwise, the ODE engine seems to try to find
>>>>>> information about the process in the database with nasty consequences
>>>>>> (failed transactions).
>>>>>>
>>>>>>
>>>>>>  Normally that shouldn't be a problem. Transient tells ODE to execute
>>>>> the
>>>>> process in memory but that only applies to short living processes, for
>>>>> most
>>>>> scenarios you'll want to have persistent executions. So we should try
>>>>> to
>>>>> see
>>>>> why these transactions fail.
>>>>>
>>>>>
>>>>>  HOWEVER, this has a side effect that is both curious and problematic.
>>>>>
>>>>>> Using the ODE ProcessConfImpl (and by implication the database store
>>>>>> for
>>>>>> the process itself), for a trivial "Hello World" BPEL process, when
>>>>>> the
>>>>>> "hello" operation is invoked on the BPEL process, the ODE engine
>>>>>> returns
>>>>>> the
>>>>>> result message as a "DeferredElementNSImpl" class with the name
>>>>>> "TestPart" -
>>>>>> which on inspection contains a child element "message" containing the
>>>>>> expected "Hello World" string.
>>>>>> (I attach the relevant part of the WSDL at the bottom)
>>>>>>
>>>>>>
>>>>>> When we switch to using the Tuscany ProcessConfImpl - with its
>>>>>> "transient"
>>>>>> setting, when we invoke the same process, we get back a different type
>>>>>> of
>>>>>> object - an "ElementImpl" named "TestPart".  This contains an
>>>>>> ElementNSImpl
>>>>>> object named "hello" containing a TextImpl child holding "Hello
>>>>>> World".
>>>>>> This
>>>>>> structural layout is clearly different to the previous case - and is
>>>>>> wrong -
>>>>>> it isn't what is expected.
>>>>>>
>>>>>> Can anyone explain the difference in the two cases?  Any assistance
>>>>>> gratefully received.
>>>>>>
>>>>>>
>>>>>>  I don't see what could create this difference. The deferred element
>>>>> vs.
>>>>> normal element is nothing to worry about, it's just that the structure
>>>>> has
>>>>> already been traversed in one case because of the storage different,
>>>>> but
>>>>> the
>>>>> content itself should be identical. Usually the switch from transient
>>>>> to
>>>>> persistent doesn't bring that kind of differences but there's nothing I
>>>>> can
>>>>> think of off the top of my head that could create this behavior. The
>>>>> structural difference kind of reminds the difference between rpc and
>>>>> document style part wrappers but that shouldn't show here.
>>>>>
>>>>> So I'd like to reproduce this and see what's going wrong. Is all your
>>>>> code
>>>>> committed? Which test case are you using?
>>>>>
>>>>> Thanks,
>>>>> Matthieu
>>>>>
>>>>>  Matthieu,
>>>>
>>>> Thanks for responding - let me try and pick my way through it for you:
>>>>
>>>> 1) All the code is committed and in the current Tuscany SVN.
>>>>
>>>> 2) The runtime code that is relevant is all in the
>>>> implementation-bpel-ode
>>>> module
>>>>
>>>> 3) There are 3 sets of test/samples you can use to try things out:
>>>>
>>>> a) In Samples - helloworld-bpel  and   helloworld-bpel-ws
>>>> b) In Itest - there are 4 Itests under BPEL - helloworld
>>>>                                           - helloworld-reference
>>>>                                           - helloworld-ws
>>>>                                           - ping-pong
>>>>
>>>> I tend to use the 2 samples.  The second one uses web services and
>>>> catches
>>>> the problems with the
>>>> data format returned by the BPEL process, for example. (You get an
>>>> exception in the databinding code
>>>> when it tries to transform it)
>>>>
>>>>
>>>> Now, I've fixed up the code in implementation-bpel-ode so that it works
>>>> -
>>>> so the problems are all
>>>> masked.  But some simple commenting and uncommenting of lines of code
>>>> can
>>>> reproduce all the problems.
>>>>
>>>> The 2 main classes to deal with are:
>>>>
>>>> - EmbeddedODEServer
>>>> - TuscanyProcessConfImpl
>>>>
>>>>
>>>> Currently, EmbeddedODEServer is set up to use the ODE Store and
>>>> Persisted
>>>> BPEL Processes - the trick
>>>> I've done is that the code itself WRITES the deploy.xml file on the fly
>>>> -
>>>> so that the programmer
>>>> does not need to write it.  This is handled by the BPELODEDeployFile
>>>> class.
>>>>
>>>> To change things, all you need to do is to go to the deploy(....) method
>>>> in EmbeddedOdeServer.  You
>>>> will find 2 blocks of code inside a try{} block - one for using the ODE
>>>> Store, the other for using
>>>> the Tuscany stuff without the store.  Simply comment out one an
>>>> uncomment
>>>> the other to flip between
>>>> them.
>>>>
>>>> Only one other thing needs changing to work through all the problems -
>>>> and
>>>> that is the response to
>>>> the isTransient() method of the TuscanyProcessConfImpl - currently it's
>>>> set to "true" - simply flip
>>>> it to return "false" to see the other behaviour.
>>>>
>>>>
>>>> One significant thing I discovered is that there is a "memory effect" in
>>>> the database.  IF the
>>>> database has been used ONCE by the ODE Store code then if the code is
>>>> run
>>>> afterwards in "non Store"
>>>> mode, it works ok, with no transaction errors.  The transaction errors
>>>> only occur with a "virgin"
>>>> database that has never been used by the Store code.  If that ain't
>>>> confusing, nothing is...
>>>>
>>>> Note - running the Samples and Itests above using mvn usually cleans out
>>>> the DB - I've been able to
>>>> preserve the DB when running from Eclipse.
>>>>
>>>> When getting the transaction problem, my tracing showed that is
>>>> happening
>>>> in:
>>>>
>>>> BpelProcess$HydrationLatch.doHydrate() line 755
>>>> "DbError"
>>>> "Unable to Commit"
>>>>
>>>>
>>>> Yours,  Mike.
>>>>
>>>>
>>>>
>>
>

Re: [Fwd: Re: SCA BPEL - Problems with ODE - Help requested]

Posted by Matthieu Riou <ma...@offthelip.org>.
On Thu, Jun 5, 2008 at 12:38 PM, Mike Edwards <
mike.edwards.inglenook@gmail.com> wrote:

> Matthieu,
>
> First - many thanks for your hard work on this.
>
> I take no pleasure in saying this, but I am glad that the DB problem was
> ODE's problem rather than Tuscany's - it looks like you are far more
> experienced in handling that area of code!
>
> Regarding that remaining error, which is generated by Tuscany.  I am
> assuming that this is the same error that I examined previously when using
> the TuscanyProcessConfImpl rather than the ODE ProcessConfImpl - namely that
> the returned data structure from ODE is simply different - and I believe it
> is in error - as the top level element is of a different type: - quoting
> from my previous email, in the case of using the TuscanyProcessConfImpl:
>

Actually I think it's a different problem even if the symptom looks
identical (as I mentioned, I fixed the process). First, it always break in
the same way, whether the process is transient or not (which is reassuring).
Second, the message looks good to me this time:

>>>Response:
<?xml version="1.0" encoding="UTF-8"?>
<message><TestPart><hello xmlns="
http://tuscany.apache.org/implementation/bpel/example/helloworld.wsdl"><message>Hello
World</message></hello></TestPart></message>

The namespaces of the <hello> and the <message> elements seem correct. Don't
you think?

Cheers,
Matthieu



>
>
> "When we switch to using the Tuscany ProcessConfImpl - with its "transient"
> setting, when we invoke the same process, we get back a different type of
> object - an "ElementImpl" named "TestPart".  This contains an ElementNSImpl
> object named "hello" containing a TextImpl child holding "Hello World". This
> structural layout is clearly different to the previous case - and is wrong -
> it isn't what is expected."
>
> To explain futher, the direct cause of that exception you list is the fact
> that the top level element returned - the ElementImpl - does NOT have a
> namespace declared (I believe that it should be an ElementNSImpl) - and it
> is the lack of the NS that is at the root of the "null" exception that
> Tuscany returns.  I note that this is NOT the same data structure that is
> returned by ODE when the ODE ProcessConfImpl is used - that data structure
> IS headed by a DeferredElementNSImpl (the deferred aspect isn't important,
> but the "NS" aspect very much is important).
>
> I could not determine why there was this difference in the data structure
> returned.  I'll have another check using your fixed version of the code -
> but it would be useful if you could give me a clue about where in the ODE
> code this data element is being generated - it is very hard to trace.
>
>
>
> Yours,  Mike.
>
> PS - I assume that I need to take a latest build from the ODE SVN to get
> your fixes for the DB problem?
>
>
> Matthieu Riou wrote:
>
>> Okay, this took a while because it was actually far trickier than I
>> expected. Here were the two problems (the first being the serious one):
>>
>>  * When OpenJPA first connects to the DB it initializes its sequence table
>> and does it using a different connection. It's fine when it's done in
>> isolation (like at startup) but with Derby, when a transaction that
>> creates
>> stuff gets executed, it causes a lock timeout because the two connections
>> are competing to set a value. To fix this I've set a little parameters
>> (all
>> that time for a single line fix...) that forces the initialization when we
>> start the engine.
>>
>>  * The HelloWorld process assignment was actually setting a variable that
>> wasn't structured properly when checking the message schema. I updated the
>> assignment.
>>
>> So now we get the proper message in and out. I still have one last
>> problem,
>> when the message gets back to Tuscany I get:
>>
>> org.apache.tuscany.sca.databinding.TransformationException:
>> java.lang.IllegalArgumentException: local part cannot be "null" when
>> creating a QName
>>        at
>>
>> org.apache.tuscany.sca.core.databinding.transformers.Output2OutputTransformer.transform(Output2OutputTransformer.java:215)
>>        at
>>
>> org.apache.tuscany.sca.databinding.impl.MediatorImpl.mediate(MediatorImpl.java:79)
>>        at
>>
>> org.apache.tuscany.sca.core.databinding.wire.DataTransformationInterceptor.transform(DataTransformationInterceptor.java:186)
>>        at
>>
>> org.apache.tuscany.sca.core.databinding.wire.DataTransformationInterceptor.invoke(DataTransformationInterceptor.java:169)
>>        at
>>
>> org.apache.tuscany.sca.binding.sca.impl.SCABindingInvoker.invoke(SCABindingInvoker.java:61)
>>        at
>>
>> org.apache.tuscany.sca.core.databinding.wire.PassByValueInterceptor.invoke(PassByValueInterceptor.java:103)
>>        at
>>
>> org.apache.tuscany.sca.core.invocation.JDKInvocationHandler.invoke(JDKInvocationHandler.java:286)
>>        at
>>
>> org.apache.tuscany.sca.core.invocation.JDKInvocationHandler.invoke(JDKInvocationHandler.java:154)
>>        at $Proxy5.hello(Unknown Source)
>>        at
>>
>> helloworld.BPELHelloWorldTestCase.testInvoke(BPELHelloWorldTestCase.java:56)
>>
>> The message looks fine to me, any idea what this could be? I've committed
>> my
>> fixes so you should be able to reproduce it.
>>
>> Cheers,
>> Matthieu
>>
>> On Fri, May 30, 2008 at 11:39 PM, Matthieu Riou <ma...@offthelip.org>
>> wrote:
>>
>>  I've started looking at the DbError issue and reproduced it. Digging
>>> deeper
>>> it seems it's caused by a lock timeout in Derby on the
>>> OPENJPA_SEQUENCE_TABLE when ODE tries to create a record for the new
>>> deployed process. Here is an excerpt from the logs:
>>>
>>> DEBUG - GeronimoLog.debug(66) | Creating process DAO for {
>>>
>>> http://tuscany.apache.org/implementation/bpel/example/helloworld}HelloWorld-1<http://tuscany.apache.org/implementation/bpel/example/helloworld%7DHelloWorld-1>
>>> <
>>> http://tuscany.apache.org/implementation/bpel/example/helloworld%7DHelloWorld-1
>>> >(guid=hqejbhcnphr3beiwcxrx88)
>>> DEBUG - GeronimoLog.debug(66) | getConnection (tx=2)
>>> DEBUG - GeronimoLog.debug(66) | prepareStmt: SELECT t0.ID, t0.GUID,
>>> t0.PROCESS_ID, t0.PROCESS_TYPE, t0.VERSION FROM ODE_PROCESS t0 WHERE
>>> (t0.PROCESS_ID = ?)
>>> DEBUG - GeronimoLog.debug(66) | bound (1,{
>>>
>>> http://tuscany.apache.org/implementation/bpel/example/helloworld}HelloWorld-1<http://tuscany.apache.org/implementation/bpel/example/helloworld%7DHelloWorld-1>
>>> <
>>> http://tuscany.apache.org/implementation/bpel/example/helloworld%7DHelloWorld-1
>>> >
>>>
>>> )
>>> DEBUG - GeronimoLog.debug(66) | close
>>> DEBUG - GeronimoLog.debug(66) | getConnection (tx=2)
>>> DEBUG - GeronimoLog.debug(66) | prepareStmt: SELECT SEQUENCE_VALUE FROM
>>> OPENJPA_SEQUENCE_TABLE WHERE ID = ? FOR UPDATE WITH RR
>>> DEBUG - GeronimoLog.debug(66) | bound (1,0)
>>> DEBUG - GeronimoLog.debug(66) | close
>>> DEBUG - GeronimoLog.debug(66) | getConnection (tx=2)
>>> DEBUG - GeronimoLog.debug(66) | prepareStmt: INSERT INTO
>>> OPENJPA_SEQUENCE_TABLE (ID, SEQUENCE_VALUE) VALUES (?, ?)
>>> DEBUG - GeronimoLog.debug(66) | bound (2,1) (1,0)
>>> DEBUG - GeronimoLog.debug(66) | close
>>> DEBUG - GeronimoLog.debug(66) | getConnection (tx=2)
>>> DEBUG - GeronimoLog.debug(66) | prepareStmt: SELECT SEQUENCE_VALUE FROM
>>> OPENJPA_SEQUENCE_TABLE WHERE ID = ? FOR UPDATE WITH RR
>>> DEBUG - GeronimoLog.debug(66) | bound (1,0)
>>> WARN - GeronimoLog.warn(96) | connectionErrorOccurred called with null
>>> java.sql.SQLException: A lock could not be obtained within the time
>>> requested
>>>
>>> Right now I really have no clue why this is happening, there's no reason
>>> why a lock would get stuck on the OpenJPA sequence table. I have to dig
>>> deeper but it's getting late, I'll try to find more time during the
>>> week-end
>>> or Monday.
>>>
>>> Cheers,
>>> Matthieu
>>>
>>>
>>> On Fri, May 30, 2008 at 1:42 PM, Mike Edwards <
>>> mike.edwards.inglenook@gmail.com> wrote:
>>>
>>>
>>>> -------- Original Message --------
>>>> Subject: Re: SCA BPEL - Problems with ODE - Help requested
>>>> Date: Fri, 30 May 2008 17:51:12 +0100
>>>> From: Mike Edwards <mi...@gmail.com>
>>>> To: tuscany-dev@ws.apache.org
>>>> References: <48...@gmail.com> <
>>>> fbdc6a970805291930v1dbb0e59hfc1b5f4a6e9809c1@mail.gmail.com>
>>>>
>>>> Matthieu Riou wrote:
>>>>
>>>>  On Thu, May 29, 2008 at 11:41 AM, Mike Edwards <
>>>>> mike.edwards.inglenook@gmail.com> wrote:
>>>>>
>>>>>  Folks,
>>>>>
>>>>>> I've run into problems with the SCA BPEL implementation and the way it
>>>>>> interacts with the ODE engine - and I need help from some ODE experts,
>>>>>> please.
>>>>>>
>>>>>> OK, the SCA code is using the ODE engine in an embedded mode - and the
>>>>>> Tuscany code is trying to supply all the information and interfaces
>>>>>> for
>>>>>> each
>>>>>> BPEL process to the ODE Engine - and in particular it aims to bypass
>>>>>> the
>>>>>> ODE
>>>>>> database store so far as the BPEL process and its configuration are
>>>>>> concerned.
>>>>>>
>>>>>> So - Tuscany now has its own version of the ProcessConfImpl (I sent a
>>>>>> version of this out in a previous email).  One thing I discovered is
>>>>>> that it
>>>>>> is necessary for the Tuscany ProcessConfImpl to return "true" to the
>>>>>> isTransient() method. Otherwise, the ODE engine seems to try to find
>>>>>> information about the process in the database with nasty consequences
>>>>>> (failed transactions).
>>>>>>
>>>>>>
>>>>>>  Normally that shouldn't be a problem. Transient tells ODE to execute
>>>>> the
>>>>> process in memory but that only applies to short living processes, for
>>>>> most
>>>>> scenarios you'll want to have persistent executions. So we should try
>>>>> to
>>>>> see
>>>>> why these transactions fail.
>>>>>
>>>>>
>>>>>  HOWEVER, this has a side effect that is both curious and problematic.
>>>>>
>>>>>> Using the ODE ProcessConfImpl (and by implication the database store
>>>>>> for
>>>>>> the process itself), for a trivial "Hello World" BPEL process, when
>>>>>> the
>>>>>> "hello" operation is invoked on the BPEL process, the ODE engine
>>>>>> returns
>>>>>> the
>>>>>> result message as a "DeferredElementNSImpl" class with the name
>>>>>> "TestPart" -
>>>>>> which on inspection contains a child element "message" containing the
>>>>>> expected "Hello World" string.
>>>>>> (I attach the relevant part of the WSDL at the bottom)
>>>>>>
>>>>>>
>>>>>> When we switch to using the Tuscany ProcessConfImpl - with its
>>>>>> "transient"
>>>>>> setting, when we invoke the same process, we get back a different type
>>>>>> of
>>>>>> object - an "ElementImpl" named "TestPart".  This contains an
>>>>>> ElementNSImpl
>>>>>> object named "hello" containing a TextImpl child holding "Hello
>>>>>> World".
>>>>>> This
>>>>>> structural layout is clearly different to the previous case - and is
>>>>>> wrong -
>>>>>> it isn't what is expected.
>>>>>>
>>>>>> Can anyone explain the difference in the two cases?  Any assistance
>>>>>> gratefully received.
>>>>>>
>>>>>>
>>>>>>  I don't see what could create this difference. The deferred element
>>>>> vs.
>>>>> normal element is nothing to worry about, it's just that the structure
>>>>> has
>>>>> already been traversed in one case because of the storage different,
>>>>> but
>>>>> the
>>>>> content itself should be identical. Usually the switch from transient
>>>>> to
>>>>> persistent doesn't bring that kind of differences but there's nothing I
>>>>> can
>>>>> think of off the top of my head that could create this behavior. The
>>>>> structural difference kind of reminds the difference between rpc and
>>>>> document style part wrappers but that shouldn't show here.
>>>>>
>>>>> So I'd like to reproduce this and see what's going wrong. Is all your
>>>>> code
>>>>> committed? Which test case are you using?
>>>>>
>>>>> Thanks,
>>>>> Matthieu
>>>>>
>>>>>  Matthieu,
>>>>
>>>> Thanks for responding - let me try and pick my way through it for you:
>>>>
>>>> 1) All the code is committed and in the current Tuscany SVN.
>>>>
>>>> 2) The runtime code that is relevant is all in the
>>>> implementation-bpel-ode
>>>> module
>>>>
>>>> 3) There are 3 sets of test/samples you can use to try things out:
>>>>
>>>> a) In Samples - helloworld-bpel  and   helloworld-bpel-ws
>>>> b) In Itest - there are 4 Itests under BPEL - helloworld
>>>>                                           - helloworld-reference
>>>>                                           - helloworld-ws
>>>>                                           - ping-pong
>>>>
>>>> I tend to use the 2 samples.  The second one uses web services and
>>>> catches
>>>> the problems with the
>>>> data format returned by the BPEL process, for example. (You get an
>>>> exception in the databinding code
>>>> when it tries to transform it)
>>>>
>>>>
>>>> Now, I've fixed up the code in implementation-bpel-ode so that it works
>>>> -
>>>> so the problems are all
>>>> masked.  But some simple commenting and uncommenting of lines of code
>>>> can
>>>> reproduce all the problems.
>>>>
>>>> The 2 main classes to deal with are:
>>>>
>>>> - EmbeddedODEServer
>>>> - TuscanyProcessConfImpl
>>>>
>>>>
>>>> Currently, EmbeddedODEServer is set up to use the ODE Store and
>>>> Persisted
>>>> BPEL Processes - the trick
>>>> I've done is that the code itself WRITES the deploy.xml file on the fly
>>>> -
>>>> so that the programmer
>>>> does not need to write it.  This is handled by the BPELODEDeployFile
>>>> class.
>>>>
>>>> To change things, all you need to do is to go to the deploy(....) method
>>>> in EmbeddedOdeServer.  You
>>>> will find 2 blocks of code inside a try{} block - one for using the ODE
>>>> Store, the other for using
>>>> the Tuscany stuff without the store.  Simply comment out one an
>>>> uncomment
>>>> the other to flip between
>>>> them.
>>>>
>>>> Only one other thing needs changing to work through all the problems -
>>>> and
>>>> that is the response to
>>>> the isTransient() method of the TuscanyProcessConfImpl - currently it's
>>>> set to "true" - simply flip
>>>> it to return "false" to see the other behaviour.
>>>>
>>>>
>>>> One significant thing I discovered is that there is a "memory effect" in
>>>> the database.  IF the
>>>> database has been used ONCE by the ODE Store code then if the code is
>>>> run
>>>> afterwards in "non Store"
>>>> mode, it works ok, with no transaction errors.  The transaction errors
>>>> only occur with a "virgin"
>>>> database that has never been used by the Store code.  If that ain't
>>>> confusing, nothing is...
>>>>
>>>> Note - running the Samples and Itests above using mvn usually cleans out
>>>> the DB - I've been able to
>>>> preserve the DB when running from Eclipse.
>>>>
>>>> When getting the transaction problem, my tracing showed that is
>>>> happening
>>>> in:
>>>>
>>>> BpelProcess$HydrationLatch.doHydrate() line 755
>>>> "DbError"
>>>> "Unable to Commit"
>>>>
>>>>
>>>> Yours,  Mike.
>>>>
>>>>
>>>>
>>
>

Re: [Fwd: Re: SCA BPEL - Problems with ODE - Help requested]

Posted by Mike Edwards <mi...@gmail.com>.
Matthieu,

First - many thanks for your hard work on this.

I take no pleasure in saying this, but I am glad that the DB problem was ODE's problem rather than 
Tuscany's - it looks like you are far more experienced in handling that area of code!

Regarding that remaining error, which is generated by Tuscany.  I am assuming that this is the same 
error that I examined previously when using the TuscanyProcessConfImpl rather than the ODE 
ProcessConfImpl - namely that the returned data structure from ODE is simply different - and I 
believe it is in error - as the top level element is of a different type: - quoting from my previous 
email, in the case of using the TuscanyProcessConfImpl:

"When we switch to using the Tuscany ProcessConfImpl - with its "transient" setting, when we invoke 
the same process, we get back a different type of object - an "ElementImpl" named "TestPart".  This 
contains an ElementNSImpl object named "hello" containing a TextImpl child holding "Hello World". 
This structural layout is clearly different to the previous case - and is wrong - it isn't what is 
expected."

To explain futher, the direct cause of that exception you list is the fact that the top level 
element returned - the ElementImpl - does NOT have a namespace declared (I believe that it should be 
an ElementNSImpl) - and it is the lack of the NS that is at the root of the "null" exception that 
Tuscany returns.  I note that this is NOT the same data structure that is returned by ODE when the 
ODE ProcessConfImpl is used - that data structure IS headed by a DeferredElementNSImpl (the deferred 
aspect isn't important, but the "NS" aspect very much is important).

I could not determine why there was this difference in the data structure returned.  I'll have 
another check using your fixed version of the code - but it would be useful if you could give me a 
clue about where in the ODE code this data element is being generated - it is very hard to trace.



Yours,  Mike.

PS - I assume that I need to take a latest build from the ODE SVN to get your fixes for the DB problem?


Matthieu Riou wrote:
> Okay, this took a while because it was actually far trickier than I
> expected. Here were the two problems (the first being the serious one):
> 
>  * When OpenJPA first connects to the DB it initializes its sequence table
> and does it using a different connection. It's fine when it's done in
> isolation (like at startup) but with Derby, when a transaction that creates
> stuff gets executed, it causes a lock timeout because the two connections
> are competing to set a value. To fix this I've set a little parameters (all
> that time for a single line fix...) that forces the initialization when we
> start the engine.
> 
>  * The HelloWorld process assignment was actually setting a variable that
> wasn't structured properly when checking the message schema. I updated the
> assignment.
> 
> So now we get the proper message in and out. I still have one last problem,
> when the message gets back to Tuscany I get:
> 
> org.apache.tuscany.sca.databinding.TransformationException:
> java.lang.IllegalArgumentException: local part cannot be "null" when
> creating a QName
>         at
> org.apache.tuscany.sca.core.databinding.transformers.Output2OutputTransformer.transform(Output2OutputTransformer.java:215)
>         at
> org.apache.tuscany.sca.databinding.impl.MediatorImpl.mediate(MediatorImpl.java:79)
>         at
> org.apache.tuscany.sca.core.databinding.wire.DataTransformationInterceptor.transform(DataTransformationInterceptor.java:186)
>         at
> org.apache.tuscany.sca.core.databinding.wire.DataTransformationInterceptor.invoke(DataTransformationInterceptor.java:169)
>         at
> org.apache.tuscany.sca.binding.sca.impl.SCABindingInvoker.invoke(SCABindingInvoker.java:61)
>         at
> org.apache.tuscany.sca.core.databinding.wire.PassByValueInterceptor.invoke(PassByValueInterceptor.java:103)
>         at
> org.apache.tuscany.sca.core.invocation.JDKInvocationHandler.invoke(JDKInvocationHandler.java:286)
>         at
> org.apache.tuscany.sca.core.invocation.JDKInvocationHandler.invoke(JDKInvocationHandler.java:154)
>         at $Proxy5.hello(Unknown Source)
>         at
> helloworld.BPELHelloWorldTestCase.testInvoke(BPELHelloWorldTestCase.java:56)
> 
> The message looks fine to me, any idea what this could be? I've committed my
> fixes so you should be able to reproduce it.
> 
> Cheers,
> Matthieu
> 
> On Fri, May 30, 2008 at 11:39 PM, Matthieu Riou <ma...@offthelip.org>
> wrote:
> 
>> I've started looking at the DbError issue and reproduced it. Digging deeper
>> it seems it's caused by a lock timeout in Derby on the
>> OPENJPA_SEQUENCE_TABLE when ODE tries to create a record for the new
>> deployed process. Here is an excerpt from the logs:
>>
>> DEBUG - GeronimoLog.debug(66) | Creating process DAO for {
>> http://tuscany.apache.org/implementation/bpel/example/helloworld}HelloWorld-1<http://tuscany.apache.org/implementation/bpel/example/helloworld%7DHelloWorld-1>(guid=hqejbhcnphr3beiwcxrx88)
>> DEBUG - GeronimoLog.debug(66) | getConnection (tx=2)
>> DEBUG - GeronimoLog.debug(66) | prepareStmt: SELECT t0.ID, t0.GUID,
>> t0.PROCESS_ID, t0.PROCESS_TYPE, t0.VERSION FROM ODE_PROCESS t0 WHERE
>> (t0.PROCESS_ID = ?)
>> DEBUG - GeronimoLog.debug(66) | bound (1,{
>> http://tuscany.apache.org/implementation/bpel/example/helloworld}HelloWorld-1<http://tuscany.apache.org/implementation/bpel/example/helloworld%7DHelloWorld-1>
>> )
>> DEBUG - GeronimoLog.debug(66) | close
>> DEBUG - GeronimoLog.debug(66) | getConnection (tx=2)
>> DEBUG - GeronimoLog.debug(66) | prepareStmt: SELECT SEQUENCE_VALUE FROM
>> OPENJPA_SEQUENCE_TABLE WHERE ID = ? FOR UPDATE WITH RR
>> DEBUG - GeronimoLog.debug(66) | bound (1,0)
>> DEBUG - GeronimoLog.debug(66) | close
>> DEBUG - GeronimoLog.debug(66) | getConnection (tx=2)
>> DEBUG - GeronimoLog.debug(66) | prepareStmt: INSERT INTO
>> OPENJPA_SEQUENCE_TABLE (ID, SEQUENCE_VALUE) VALUES (?, ?)
>> DEBUG - GeronimoLog.debug(66) | bound (2,1) (1,0)
>> DEBUG - GeronimoLog.debug(66) | close
>> DEBUG - GeronimoLog.debug(66) | getConnection (tx=2)
>> DEBUG - GeronimoLog.debug(66) | prepareStmt: SELECT SEQUENCE_VALUE FROM
>> OPENJPA_SEQUENCE_TABLE WHERE ID = ? FOR UPDATE WITH RR
>> DEBUG - GeronimoLog.debug(66) | bound (1,0)
>> WARN - GeronimoLog.warn(96) | connectionErrorOccurred called with null
>> java.sql.SQLException: A lock could not be obtained within the time
>> requested
>>
>> Right now I really have no clue why this is happening, there's no reason
>> why a lock would get stuck on the OpenJPA sequence table. I have to dig
>> deeper but it's getting late, I'll try to find more time during the week-end
>> or Monday.
>>
>> Cheers,
>> Matthieu
>>
>>
>> On Fri, May 30, 2008 at 1:42 PM, Mike Edwards <
>> mike.edwards.inglenook@gmail.com> wrote:
>>
>>>
>>> -------- Original Message --------
>>> Subject: Re: SCA BPEL - Problems with ODE - Help requested
>>> Date: Fri, 30 May 2008 17:51:12 +0100
>>> From: Mike Edwards <mi...@gmail.com>
>>> To: tuscany-dev@ws.apache.org
>>> References: <48...@gmail.com> <
>>> fbdc6a970805291930v1dbb0e59hfc1b5f4a6e9809c1@mail.gmail.com>
>>>
>>> Matthieu Riou wrote:
>>>
>>>> On Thu, May 29, 2008 at 11:41 AM, Mike Edwards <
>>>> mike.edwards.inglenook@gmail.com> wrote:
>>>>
>>>>  Folks,
>>>>> I've run into problems with the SCA BPEL implementation and the way it
>>>>> interacts with the ODE engine - and I need help from some ODE experts,
>>>>> please.
>>>>>
>>>>> OK, the SCA code is using the ODE engine in an embedded mode - and the
>>>>> Tuscany code is trying to supply all the information and interfaces for
>>>>> each
>>>>> BPEL process to the ODE Engine - and in particular it aims to bypass the
>>>>> ODE
>>>>> database store so far as the BPEL process and its configuration are
>>>>> concerned.
>>>>>
>>>>> So - Tuscany now has its own version of the ProcessConfImpl (I sent a
>>>>> version of this out in a previous email).  One thing I discovered is
>>>>> that it
>>>>> is necessary for the Tuscany ProcessConfImpl to return "true" to the
>>>>> isTransient() method. Otherwise, the ODE engine seems to try to find
>>>>> information about the process in the database with nasty consequences
>>>>> (failed transactions).
>>>>>
>>>>>
>>>> Normally that shouldn't be a problem. Transient tells ODE to execute the
>>>> process in memory but that only applies to short living processes, for
>>>> most
>>>> scenarios you'll want to have persistent executions. So we should try to
>>>> see
>>>> why these transactions fail.
>>>>
>>>>
>>>>  HOWEVER, this has a side effect that is both curious and problematic.
>>>>> Using the ODE ProcessConfImpl (and by implication the database store for
>>>>> the process itself), for a trivial "Hello World" BPEL process, when the
>>>>> "hello" operation is invoked on the BPEL process, the ODE engine returns
>>>>> the
>>>>> result message as a "DeferredElementNSImpl" class with the name
>>>>> "TestPart" -
>>>>> which on inspection contains a child element "message" containing the
>>>>> expected "Hello World" string.
>>>>> (I attach the relevant part of the WSDL at the bottom)
>>>>>
>>>>>
>>>>> When we switch to using the Tuscany ProcessConfImpl - with its
>>>>> "transient"
>>>>> setting, when we invoke the same process, we get back a different type
>>>>> of
>>>>> object - an "ElementImpl" named "TestPart".  This contains an
>>>>> ElementNSImpl
>>>>> object named "hello" containing a TextImpl child holding "Hello World".
>>>>> This
>>>>> structural layout is clearly different to the previous case - and is
>>>>> wrong -
>>>>> it isn't what is expected.
>>>>>
>>>>> Can anyone explain the difference in the two cases?  Any assistance
>>>>> gratefully received.
>>>>>
>>>>>
>>>> I don't see what could create this difference. The deferred element vs.
>>>> normal element is nothing to worry about, it's just that the structure
>>>> has
>>>> already been traversed in one case because of the storage different, but
>>>> the
>>>> content itself should be identical. Usually the switch from transient to
>>>> persistent doesn't bring that kind of differences but there's nothing I
>>>> can
>>>> think of off the top of my head that could create this behavior. The
>>>> structural difference kind of reminds the difference between rpc and
>>>> document style part wrappers but that shouldn't show here.
>>>>
>>>> So I'd like to reproduce this and see what's going wrong. Is all your
>>>> code
>>>> committed? Which test case are you using?
>>>>
>>>> Thanks,
>>>> Matthieu
>>>>
>>> Matthieu,
>>>
>>> Thanks for responding - let me try and pick my way through it for you:
>>>
>>> 1) All the code is committed and in the current Tuscany SVN.
>>>
>>> 2) The runtime code that is relevant is all in the implementation-bpel-ode
>>> module
>>>
>>> 3) There are 3 sets of test/samples you can use to try things out:
>>>
>>> a) In Samples - helloworld-bpel  and   helloworld-bpel-ws
>>> b) In Itest - there are 4 Itests under BPEL - helloworld
>>>                                            - helloworld-reference
>>>                                            - helloworld-ws
>>>                                            - ping-pong
>>>
>>> I tend to use the 2 samples.  The second one uses web services and catches
>>> the problems with the
>>> data format returned by the BPEL process, for example. (You get an
>>> exception in the databinding code
>>> when it tries to transform it)
>>>
>>>
>>> Now, I've fixed up the code in implementation-bpel-ode so that it works -
>>> so the problems are all
>>> masked.  But some simple commenting and uncommenting of lines of code can
>>> reproduce all the problems.
>>>
>>> The 2 main classes to deal with are:
>>>
>>> - EmbeddedODEServer
>>> - TuscanyProcessConfImpl
>>>
>>>
>>> Currently, EmbeddedODEServer is set up to use the ODE Store and Persisted
>>> BPEL Processes - the trick
>>> I've done is that the code itself WRITES the deploy.xml file on the fly -
>>> so that the programmer
>>> does not need to write it.  This is handled by the BPELODEDeployFile
>>> class.
>>>
>>> To change things, all you need to do is to go to the deploy(....) method
>>> in EmbeddedOdeServer.  You
>>> will find 2 blocks of code inside a try{} block - one for using the ODE
>>> Store, the other for using
>>> the Tuscany stuff without the store.  Simply comment out one an uncomment
>>> the other to flip between
>>> them.
>>>
>>> Only one other thing needs changing to work through all the problems - and
>>> that is the response to
>>> the isTransient() method of the TuscanyProcessConfImpl - currently it's
>>> set to "true" - simply flip
>>> it to return "false" to see the other behaviour.
>>>
>>>
>>> One significant thing I discovered is that there is a "memory effect" in
>>> the database.  IF the
>>> database has been used ONCE by the ODE Store code then if the code is run
>>> afterwards in "non Store"
>>> mode, it works ok, with no transaction errors.  The transaction errors
>>> only occur with a "virgin"
>>> database that has never been used by the Store code.  If that ain't
>>> confusing, nothing is...
>>>
>>> Note - running the Samples and Itests above using mvn usually cleans out
>>> the DB - I've been able to
>>> preserve the DB when running from Eclipse.
>>>
>>> When getting the transaction problem, my tracing showed that is happening
>>> in:
>>>
>>> BpelProcess$HydrationLatch.doHydrate() line 755
>>> "DbError"
>>> "Unable to Commit"
>>>
>>>
>>> Yours,  Mike.
>>>
>>>
>