Friday, September 28, 2012

Oracle BPEL Engine (SOA Suite) Diagnostics - Parsing low level request stats

Parsing Low Level Request Stats



This blog entry is in continuation to Francis blog entry http://thesoaman.blogspot.com/2012/06/using-bpel-performance-statistics-to.html which talks in detail about the use of low level statistics provided by BPEL Engine of Oracle SOA Suite for diagnosing performance related issues for projects involving BPEL processes. As promised to Francis, here are some details that might be useful while parsing the low level request stats. Sorry took some time to put this out – better late than never!
As the request enters bpel engine it is first handled by delivery service. This layer persists all incoming asynchronous requests are in the database. The request is then passed on to BPEL Engine (or generic name Cube Engine) for further processing.
Low level request stats can provide insight into average taken by various engine layers (latency) as it flows through the delivery service and engine. The actual execution of request happens in invoke-method and the individual activity execution can be found by looking for stat with key actual-perform.
Following diagram show the key statistics to watch for as initial analysis. The block marked in red represents database operation.




Further details on Request Stats:

Database latency indicators are marked in red. Other key stats to watch out for are explained with brief description as messages flows through various engine layers. Note the details below shows logical execution and not to be construed as absolute sequence of operations as there are optimizations in place to cache objects and therefore allow loading from memory as opposed to db.

A. The incoming request message is first stored in persistence store
ds-receive-invoke - stats about time taken in storing of incoming request message into db by the delivery service

B. As part of commit of transaction for the stored message, above message proxy is submitted into dispatcher which will be picked by invoke thread pool. This thread pool will dispatch a thread and call the delivery service to load the message from persistence store
ds-handle-invoke - stats will tell you the time taken by the Delivery Service to load this message from database

C. Request then pass to the engine and an instance is created and activities defined for the process are executed till another dehydration point is reached. The nesting blow show s the call stack (outer to inner).
eng-composite-request - top level marker for time taken in this step
    eng-single-request
        create-and-invoke
            lookup-process
            create-instance
            invoke-method - this is workhorse method where the activities defined in the process are executed till the next dehydration point are executed. Notice that after some housekeeping, this would in turn call engine-single-request to handle each of process activities.
                eng-single-request
                    do-perform - time taken to perform the work-items (process activities). Some additional tasks are performed before actual execution of activities. Refer actual-perform for isolating the times (next)
                        actual-perform - actual time taken to execute activities
    glue-requests-store - once the process completes or encounters dehydration point, the instance state is saved in persistence store.

D. If the process defines a callback activity, the callback message is first stored in the database.
ds-receive-callback - stats for time taken to store the callback message in persistence store by the delivery layer.

E. After the engine is dehydrated for waiting for the callback message, the receipt of callback message causes the trigger of rehydration of instance. First, the callback message is loaded then the corresponding instance is loaded into memory
ds-resolve-callback - this indicate the time taken for loading of the callback message
load-instance - indicate the time taken by the engine to load the message from database.

No comments: