On Thu, Jun 5, 2008 at 12:38 PM, Mike Edwards < [EMAIL PROTECTED]> 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 <[EMAIL PROTECTED]> >> 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 < >>> [EMAIL PROTECTED]> wrote: >>> >>> >>>> -------- Original Message -------- >>>> Subject: Re: SCA BPEL - Problems with ODE - Help requested >>>> Date: Fri, 30 May 2008 17:51:12 +0100 >>>> From: Mike Edwards <[EMAIL PROTECTED]> >>>> To: tuscany-dev@ws.apache.org >>>> References: <[EMAIL PROTECTED]> < >>>> [EMAIL PROTECTED]> >>>> >>>> Matthieu Riou wrote: >>>> >>>> On Thu, May 29, 2008 at 11:41 AM, Mike Edwards < >>>>> [EMAIL PROTECTED]> 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. >>>> >>>> >>>> >> >