search



Oracle Service Bus: thread blocking evidences, transport level

The common case scenario for a service exposed by Service Bus is to receive a message, validate or enrich or transform it, call a service provider passing the incoming payload, and then do some additional work with the response from the provider before returning it to the caller. The initial steps are grouped inside a request pipeline. Then the payload goes thru a route to the provider, and the final processing is done at a response pipeline before sending the final response back to the caller:

Common OSB service


The threading model used by Oracle Service Bus states that the request pipeline must execute on a thread (the Inbound Request Message Thread), and the response pipeline must use another thread to process the response (properly named the Outbound Response Message Thread). The route is done by a transport provider, which can or cannot use the request thread to wait for the provider's response.

When the transport holds the request thread until it gets a response, it is called a blocking transport. Conversely, if the transport puts the call and release the thread, it's called a non-blocking transport. Some of the transports are listed below, with info about their non-blocking support:

Support for Asynchrony by Oracle Service Bus 10g Transport Providers


So, as per documentation, the HTTP transport is non-blocking, meaning it doesn't keep a thread blocked while it waits for a response from the service provider. In order to check if this is true, I tried a couple scenarios, described below.

  • 1. Testing HTTP transport with a "Route" action

    This is the most common use for a proxy, so I tried it first. I created a syncronous BPEL with just a wait time inside it:

    Delayed response BPEL

    Then, I mapped the endpoint with a Business Service inside OSB, and then created a Proxy Service referencing the Business. This sequence creates the proxy with the same WSDL and automatically puts a Route action inside the proxy flow.

    Everything in place, I started a few instances and went to SOA's Enterprise Manager. Sure enough, the instances were running:

    Running instances

    Then, I checked the executing threads from OSB's Weblogic Adminstration Console, and found no activity (no threads running), as expected. I also put a few hundred instances to spin using JMeter, and the behaviour didn't change - a lot of instances running at BPEL, and no threads locked at OSB. I watched this from Weblogic's Admin Console: go to Server --> Monitoring --> Threads, then sort the Self-Tuning Thread Pool Threads by the Current Request column. No requests executing means no threads being used.

    So, non-blocking transport indeed.

  • 2. Testing HTTP transport with a "Service Callout" action

    Even though the HTTP transport is non-blocking, if you use it inside a Service Callout, the behaviour is somewhat different, as stated by the documentation:
    Service Callout: The pipeline processor will block the thread until the response arrives asynchronously. The blocked thread would then resume execution of the pipeline. The purpose is to bind variables that can later be used in pipeline actions to perform business logic. Therefore, these actions must block so that the business logic can be performed before the response comes back.

    To test this, I removed the Route from the Proxy Service and added a Service Callout inside a Request Pipeline:

    Service Callout

    Then, started 10 instances with JMeter (loop = 1, threads = 10), and watched the execution threads from the admin console. There they were.

    Threads waiting for response from the service provider

    A thread dump from one of them shows that it is indeed locked, waiting for a response:
     "[ACTIVE] ExecuteThread: '5' for queue: 'weblogic.kernel.Default (self-tuning)'" id=79 idx=0x118 tid=1476 prio=5 alive, waiting, native_blocked, daemon
    	-- Waiting for notification on: java/lang/Object@0xaefe1c50[fat lock]
    	at jrockit/vm/Threads.waitForNotifySignal(JLjava/lang/Object;)Z(Native Method)
    	at java/lang/Object.wait(J)V(Native Method)
    	at java/lang/Object.wait(Object.java:485)
    	at com/bea/wli/sb/pipeline/PipelineContextImpl$SynchronousListener.waitForResponse(PipelineContextImpl.java:1569)
    	^-- Lock released while waiting: java/lang/Object@0xaefe1c50[fat lock]
    	at com/bea/wli/sb/pipeline/PipelineContextImpl.dispatchSync(PipelineContextImpl.java:553)
    	at stages/transform/runtime/WsCalloutRuntimeStep$WsCalloutDispatcher.dispatch(WsCalloutRuntimeStep.java:1391)
    	at stages/transform/runtime/WsCalloutRuntimeStep.processMessage(WsCalloutRuntimeStep.java:236)
    	at com/bea/wli/sb/pipeline/debug/DebuggerRuntimeStep.processMessage(DebuggerRuntimeStep.java:74)
    	at com/bea/wli/sb/stages/StageMetadataImpl$WrapperRuntimeStep.processMessage(StageMetadataImpl.java:346)
    	at com/bea/wli/sb/pipeline/PipelineStage.processMessage(PipelineStage.java:84)
    	at com/bea/wli/sb/pipeline/PipelineContextImpl.execute(PipelineContextImpl.java:1055)
    	at com/bea/wli/sb/pipeline/Pipeline.processMessage(Pipeline.java:141)
    	at com/bea/wli/sb/pipeline/PipelineContextImpl.execute(PipelineContextImpl.java:1055)
    	at com/bea/wli/sb/pipeline/PipelineNode.doRequest(PipelineNode.java:55)
    	at com/bea/wli/sb/pipeline/Node.processMessage(Node.java:67)
    	at com/bea/wli/sb/pipeline/PipelineContextImpl.execute(PipelineContextImpl.java:1055)
    	at com/bea/wli/sb/pipeline/Router.processMessage(Router.java:214)
    	at com/bea/wli/sb/pipeline/MessageProcessor.processRequest(MessageProcessor.java:96)
    	at com/bea/wli/sb/pipeline/RouterManager$1.run(RouterManager.java:593)
    	at com/bea/wli/sb/pipeline/RouterManager$1.run(RouterManager.java:591)
    	at weblogic/security/acl/internal/AuthenticatedSubject.doAs(AuthenticatedSubject.java:363)
    	at weblogic/security/service/SecurityManager.runAs(SecurityManager.java:146)
    	at com/bea/wli/sb/security/WLSSecurityContextService.runAs(WLSSecurityContextService.java:55)
    	at com/bea/wli/sb/pipeline/RouterManager.processMessage(RouterManager.java:590)
    	at com/bea/wli/sb/transports/TransportManagerImpl.receiveMessage(TransportManagerImpl.java:375)
    	at com/bea/wli/sb/transports/http/generic/RequestHelperBase.invokePipeline(RequestHelperBase.java:179)
    	at com/bea/wli/sb/transports/http/wls/HttpTransportServlet$RequestHelperWLS.invokePipeline(HttpTransportServlet.java:227)
    	at com/bea/wli/sb/transports/http/generic/RequestHelperBase$1.run(RequestHelperBase.java:154)
    	at com/bea/wli/sb/transports/http/generic/RequestHelperBase$1.run(RequestHelperBase.java:152)
    	at weblogic/security/acl/internal/AuthenticatedSubject.doAs(AuthenticatedSubject.java:363)
    	at weblogic/security/service/SecurityManager.runAs(SecurityManager.java:146)
    	at com/bea/wli/sb/transports/http/generic/RequestHelperBase.securedInvoke(RequestHelperBase.java:151)
    	at com/bea/wli/sb/transports/http/generic/RequestHelperBase.service(RequestHelperBase.java:107)
    	at com/bea/wli/sb/transports/http/wls/HttpTransportServlet.service(HttpTransportServlet.java:129)
    	at weblogic/servlet/FutureResponseServlet.service(FutureResponseServlet.java:24)
    	at javax/servlet/http/HttpServlet.service(HttpServlet.java:820)
    	at weblogic/servlet/internal/StubSecurityHelper$ServletServiceAction.run(StubSecurityHelper.java:227)
    	at weblogic/servlet/internal/StubSecurityHelper.invokeServlet(StubSecurityHelper.java:125)
    	at weblogic/servlet/internal/ServletStubImpl.execute(ServletStubImpl.java:300)
    	at weblogic/servlet/internal/ServletStubImpl.execute(ServletStubImpl.java:183)
    	at weblogic/servlet/internal/WebAppServletContext$ServletInvocationAction.wrapRun(WebAppServletContext.java:3717)
    	at weblogic/servlet/internal/WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:3681)
    	at weblogic/security/acl/internal/AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)
    	at weblogic/security/service/SecurityManager.runAs(SecurityManager.java:120)
    	at weblogic/servlet/internal/WebAppServletContext.securedExecute(WebAppServletContext.java:2277)
    	at weblogic/servlet/internal/WebAppServletContext.execute(WebAppServletContext.java:2183)
    	at weblogic/servlet/internal/ServletRequestImpl.run(ServletRequestImpl.java:1454)
    	at weblogic/work/ExecuteThread.execute(ExecuteThread.java:209)
    	at weblogic/work/ExecuteThread.run(ExecuteThread.java:178)
    	at jrockit/vm/RNI.c2java(IIIII)V(Native Method)
    	-- end of trace
    

    I left the complete stack so we can see that the thread starts at the incoming request, goes thru the pipeline (Pipeline.processMessage), places the call to the service provider (WsCalloutRuntimeStep) and then waits for a response, as the documentation says.

    So, if you don't want to lock your threads while waiting for an HTTP response, do not use Service Callout when you don't have to. I saw a couple of developers doing this instead of using the more logical Route construct, and when confronted with this "architectural decision", the answer was "well, it works that way, so we did that way". A really strong argument, indeed...

  • 3. DB Adapter (JCA) synchronous calls

    One pattern that emerged in later versions of OSB is to execute queries and commands against databases directly from OSB, courtesy of the JCA Adapter for Database, or DB Adapter. I'm not going into details about this kind of usage, since there are a lot of arguments and variables to take into account when deciding to adopt it - the idea is just to test if this is a non-blocking transport.

    In order to check this, I created a procedure that just waited for 30 seconds, without any parameters:
    CREATE OR REPLACE
    PROCEDURE PROC_SLOW_RESPONSE AS 
    BEGIN
      DBMS_LOCK.SLEEP(30);
    END;
    
    By the looks of the provider above, you can think of it as an one-way request, AKA fire-and-forget. So, from a consumer point-of-view, after successfully reaching the provider and delivering the message, there's no need to wait for a response.

    After creating the .jca and .wsdl files using JDeveloper's Adapter Wizard, importing them at OSB and creating the corresponding Business and Proxy services, I started 10 instances. And they showed up at the thread monitoring, consistently waiting for a response from the database connector:
    "[ACTIVE] ExecuteThread: '13' for queue: 'weblogic.kernel.Default (self-tuning)'" id=112 idx=0x198 tid=1662 prio=5 alive, in native, daemon
        at jrockit/net/SocketNativeIO.readBytesPinned(Ljava/io/FileDescriptor;[BIII)I(Native Method)
        at jrockit/net/SocketNativeIO.socketRead(SocketNativeIO.java:32)
        at java/net/SocketInputStream.socketRead0(Ljava/io/FileDescriptor;[BIII)I(SocketInputStream.java)
        at java/net/SocketInputStream.read(SocketInputStream.java:129)
        at oracle/net/nt/MetricsEnabledInputStream.read(TcpNTAdapter.java:718)
        at oracle/net/ns/Packet.receive(Packet.java:295)
        at oracle/net/ns/DataPacket.receive(DataPacket.java:106)
        at oracle/net/ns/NetInputStream.getNextPacket(NetInputStream.java:317)
        at oracle/net/ns/NetInputStream.read(NetInputStream.java:262)
        ...
        at oracle/tip/adapter/db/DBInteraction.executeStoredProcedure(DBInteraction.java:1102)
        at oracle/tip/adapter/db/DBInteraction.execute(DBInteraction.java:247)
        ...
        at com/bea/wli/sb/transports/TransportManagerImpl.sendMessageToService(TransportManagerImpl.java:558)
        at com/bea/wli/sb/transports/TransportManagerImpl.sendMessageAsync(TransportManagerImpl.java:426)
        at com/bea/wli/sb/pipeline/PipelineContextImpl.doDispatch(PipelineContextImpl.java:670)
        at com/bea/wli/sb/pipeline/PipelineContextImpl.dispatch(PipelineContextImpl.java:585)
        ...
        at com/bea/wli/sb/transports/http/wls/HttpTransportServlet.service(HttpTransportServlet.java:129)
        at weblogic/servlet/FutureResponseServlet.service(FutureResponseServlet.java:24)
        at javax/servlet/http/HttpServlet.service(HttpServlet.java:820)
        at weblogic/servlet/internal/StubSecurityHelper$ServletServiceAction.run(StubSecurityHelper.java:227)
        at weblogic/servlet/internal/StubSecurityHelper.invokeServlet(StubSecurityHelper.java:125)
        at weblogic/servlet/internal/ServletStubImpl.execute(ServletStubImpl.java:300)
        at weblogic/servlet/internal/ServletStubImpl.execute(ServletStubImpl.java:183)
        at weblogic/servlet/internal/WebAppServletContext$ServletInvocationAction.wrapRun(WebAppServletContext.java:3717)
        at weblogic/servlet/internal/WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:3681)
        at weblogic/security/acl/internal/AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)
        at weblogic/security/service/SecurityManager.runAs(SecurityManager.java:120)
        at weblogic/servlet/internal/WebAppServletContext.securedExecute(WebAppServletContext.java:2277)
        at weblogic/servlet/internal/WebAppServletContext.execute(WebAppServletContext.java:2183)
        at weblogic/servlet/internal/ServletRequestImpl.run(ServletRequestImpl.java:1454)
        at weblogic/work/ExecuteThread.execute(ExecuteThread.java:209)
        at weblogic/work/ExecuteThread.run(ExecuteThread.java:178)
        at jrockit/vm/RNI.c2java(IIIII)V(Native Method)
        -- end of trace
    
    This stack trace was shortened - there's a lot of info that we don't need in order to see that the same thread that received the request is blocked waiting for the response. I captured the threads from the console, to illustrate the finding:

    Threads waiting DB response

    So, even if you're calling some package or procedure that doesn't have a response, or executing an update command (no return by nature), keep in mind that you're blocking threads that could be serving other income requests. By doing this, you're dropping the throughput of your OSB.


References:



Cheers!
Posted by Fabio Mazanatti at Jan 28, 2012 - 20:54
Tags: , , ,


The author does not allow comments to this entry