Thursday 12 July 2018

SOASuite12c - BPEL: JTA transaction is not in active state

Yesterday I ran into this pretty weird problem.

A bit of context...

I have two BPEL services to generate documents using BIP. One I created earlier that is based on a generic XML used by BIP to generate multiple letters. Now I had to create another one that is a report, so uses another XML. I generated an XSD for both XML's but since they haven't got a namespace, but same element names, I can't have them in the same composite. So, I duplicated the code.

I created a WSDL with two operations, one for the letters and one for the report, so I wanted to call the report from the service that created the letters. The first service is called 'GenerateDocument', but with an operation 'GenerateLetter', but with an added operation 'GenerateReport'.

So I changed the BPEL and replaced the 'Receive' by a Pick:
In the invoke it calls the 'GenerateReport' BPEL service, that does basically exact the same as in the scope under the 'Generate Letter' OnMessage.

In the 'GenerateReport' BPEL service (and from the 'Generate Letter' scope) I call a Base64Encoding service. It gets an XML in, and it will encode it to string using ora:getContentAsString() and encode that using a Spring bean, based on a quite simple java bean:


But now the problem...


So, called seperately, the 'Generate Report' service functioned just fine. Also the 'Generate Letter' operation of the 'Generate Document' service, thus the 'Generate Lettter' OnMessage from the Pick above, function just fine. But, when I call the 'Generate Document' service using the 'Generate Report' operation, resulting in the other OnMessage I'll get the following message on return from the Base64Encoding service:
<exception class="com.collaxa.cube.engine.EngineException">JTA transaction is not in active state.
The transaction became inactive when executing activity "" for instance "60,004", bpel engine can not proceed further without an active transaction. please debug the invoked subsystem on why the transaction is not in active status. the transaction status is "MARKED_ROLLBACK".
The reason was The execution of this instance "60004" for process "MyFancyProcess" is supposed to be in an active jta transaction, the current transaction status is "MARKED_ROLLBACK", the underlying exception is "EJB Exception: " .
Consult the system administrator regarding this error.
<stack>
            <f>com.oracle.bpel.client.util.TransactionUtils.throwExceptionIfTxnNotActive#126</f>
            <f>com.collaxa.cube.ws.WSInvocationManager.invoke#398</f>
            <f>com.collaxa.cube.engine.ext.common.InvokeHandler.__invoke#1460</f>
            <f>com.collaxa.cube.engine.ext.common.InvokeHandler.handleNormalWSDLInvoke#806</f>
            <f>com.collaxa.cube.engine.ext.common.InvokeHandler.handleNormalInvoke#497</f>
            <f>com.collaxa.cube.engine.ext.common.InvokeHandler.handle#158</f>
            <f>com.collaxa.cube.engine.ext.bpel.common.wmp.BPELInvokeWMP.__executeStatements#78</f>
            <f>com.collaxa.cube.engine.ext.bpel.common.wmp.BaseBPELActivityWMP$1.call#197</f>
            <f>com.collaxa.cube.engine.ext.bpel.common.wmp.BaseBPELActivityWMP$1.call#195</f>
            <f>com.collaxa.bpel.sws.SWSComponentProcessActivityWrapper$1.call#74</f>
            <f>com.collaxa.bpel.sws.SWSCallableActivityWrapper.execute#89</f>
            <f>com.collaxa.bpel.sws.SWSComponentProcessActivityWrapper.execute#82</f>
            <f>com.collaxa.cube.engine.ext.bpel.common.wmp.BaseBPELActivityWMP.perform#205</f>
            <f>com.collaxa.cube.engine.CubeEngine.performActivity#2922</f>
            <f>com.collaxa.cube.engine.CubeEngine._handleWorkItem#1289</f>
            <f>com.collaxa.cube.engine.CubeEngine.handleWorkItem#1178</f>
            <f>...</f>
         </stack>
      </exception>
<root class="oracle.fabric.common.FabricInvocationException">EJB Exception: <stack>
            <f>oracle.fabric.CubeServiceEngine.handleRequestResponseServerException#3920</f>
            <f>oracle.fabric.CubeServiceEngine.request#653</f>
            <f>oracle.integration.platform.blocks.mesh.SynchronousMessageHandler.doRequest#151</f>
            <f>oracle.integration.platform.blocks.mesh.MessageRouter.request#217</f>
            <f>oracle.integration.platform.blocks.mesh.MeshImpl.request#283</f>
            <f>sun.reflect.NativeMethodAccessorImpl.invoke0</f>
            <f>sun.reflect.NativeMethodAccessorImpl.invoke#62</f>
            <f>sun.reflect.DelegatingMethodAccessorImpl.invoke#43</f>
            <f>java.lang.reflect.Method.invoke#498</f>
            <f>org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection#318</f>
            <f>org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint#183</f>
            <f>org.springframework.aop.framework.ReflectiveMethodInvocation.proceed#150</f>
            <f>oracle.integration.platform.metrics.PhaseEventAspect.invoke#57</f>
            <f>org.springframework.aop.framework.ReflectiveMethodInvocation.proceed#172</f>
            <f>org.springframework.aop.framework.JdkDynamicAopProxy.invoke#202</f>
            <f>com.sun.proxy.$Proxy428.request</f>
            <f>...</f>
         </stack>
      </root>
   </fault>
</messages>

Most blogs or forums I found suggest increasing the JTA time out, as this one. However, in those cases also the time out is mentioned as a cause in the exception.
In my case though, there's no mention of a time-out. Nevertheless I did try the suggestion, but as expected, with no luck.

The investigation

How to proceed? Well, in those cases, I just 'undress' or 'strip-down' my code. Cut out all code to the point it works again. Then, piece by piece, I dress it again, until the point it breaks again. That way you can narrow to the exact point where it goes wrong.

It turns out it indeed just breaks again when I add the scope with the call to the Base64Encoding service. So, I had to investigate that a bit further. I fiddled with the transaction properties of the Exposed Service:
I don't want transaction support in this service actually: it doesn't do anything that needs to be transacted. But this wasn't it either.

A closer look to the composite then:
...
  <component name="Base64Process" version="2.0">
    <implementation.bpel src="BPEL/Base64Process.bpel"/>
    <componentType>
      <service name="base64process_client_ep" ui:wsdlLocation="WSDLs/Base64ServiceWrapper.wsdl">
        <interface.wsdl interface="http://nl.darwin-it.service/wsdl/Base64Service/1.0#wsdl.interface(Base64ServicePortType)"/>
      </service>
      <reference name="Based64EncoderDecoder.Base64EncoderDecoder"
                 ui:wsdlLocation="WSDLs/IBase64EncoderDecoderWrapper.wsdl">
        <interface.wsdl interface="http://base64.utils.darwin-it.nl/#wsdl.interface(IBase64EncoderDecoder)"/>
      </reference>
    </componentType>
    <property name="bpel.config.transaction" type="xs:string" many="false">required</property>
    <property name="bpel.config.completionPersistPolicy" type="xs:string" many="false">deferred</property>
  </component>
  <component name="Based64EncoderDecoder">
    <implementation.spring src="Spring/Based64EncoderDecoder.xml"/>
    <componentType>
      <service name="Base64EncoderDecoder">
        <interface.java interface="nl.darwin-it.utils.base64.IBase64EncoderDecoder"/>
      </service>
    </componentType>
  </component>
...

And there my the following caught my eye:
...
  <component name="Base64Process" version="2.0">
...
    <property name="bpel.config.transaction" type="xs:string" many="false">required</property>
    <property name="bpel.config.completionPersistPolicy" type="xs:string" many="false">deferred</property>
  </component>

...

As said, I don't want a transaction, and I'm not interested in deferred persistence. So, I commented this out, and all worked.

What did I learn?

I'm not sure. But apparently, when called from the main-flow directly, these properties don't hurt. The BPEL Engine doesn't feel the need to do a persist directly and therefor a transaction. But with one level deeper, called from another flow, on return from the Base64Encoding flow, it just felt the need to do a persist and thus needed a transaction. That was not there.

All the services in the composition of the 3 composites (GenerateDocument -> GenerateReport -> Base64Encoding) are synchronous, created with default settings. And therefor I did not expect this behavior.



1 comment :

Prabha Ande said...

When you see transaction is Rolled_back in the logs,JTA is being effective. I too ran into exact situation with one of my composites.

When you have any dependent service longer than expected time,Some how instance wont run into error state ,it will keep showing running state. You would want to add httptimeout settings to the invoke and which is taking longer and kill the long running invoke call