Hasitha's Tech Blessings

WSO2 ESB supports many transports such as HTTP, JMS, FIX, VFS etc. HTTP protocol is one of main transports used (maybe most used).

Every message flow does not want to touch the payload of the message. Some messages flows which includes message manipulation etc need that but a in a great deal of scenarios there is no such requirement. WSO2 ESB has a special transport called Passthrough HTTP transport which intelligently decides whether to build the message or not depending on the mediators involved and share internal read/write buffer to speed up message writing out while it is being read.

Following post discusses about code path followed when a HTTP message is sent out using "send mediator" of ESB.

Threads inside ESB

There is a several thread pools inside ESB to do message mediation and sending. Out of these following are two important thread groups.

1. IO Reactor Threads - these reads messages coming into ESB from socket buffers. They do not have heavy jobs, just message dispatching is done. At message sender side also these involve to send messages out (to back-ends, back to client).

SourceHandler and TargetHandler

These two classes are the implementations of NHTTPServerEventHandler and NHTTPClientEventHandler interfaces provided by HTTPcore library to handle HTTP events. Both are implemented as a part of passThrough HTTP transport.

Both classes maintain a state model while receiving events related to messages from HTTP core (REQUEST_READY, REQUEST_DONE etc). SourceHandler has a container called source context to gather events belonging to a particular message and similarly TargetHandler uses target context.

Debugging these two handlers are the entry point where message is received/sent out by ESB

Code path when sending a message out

Done by server Worker thread.

When "send mediator" is used, FlexibleMEPClient send out the message from synapse layer down to Axis2 layer.

This call lands onto the HTTP sender mentioned in axis2.xml - by defalut PasthrougHTTPSender. It has invike() method. It is hit.

PasthrougHTTPSender passes the messageContext to deliveryAgent to send message.

Message is added to a queue here until a connection is free to send this up.

/**
* This Map holds the messages that need to be delivered. But at the moment maximum
* number of connections to the host:pair is being used. So these messages has to wait
* until a new connection is available.
*/
private Map<HttpRoute, Queue<MessageContext>> waitingMessages =
new ConcurrentHashMap<HttpRoute, Queue<MessageContext>>();
serverHandler Thread returns here to pick up next one.
msgContext.getOperationContext().setProperty(
Constants.RESPONSE_WRITTEN, Constants.VALUE_TRUE);
return InvocationResponse.CONTINUE;

Done by IO Reactor threads

Above messages in waiting queue is written to the wire using IO Reactoer threads. Target handler’s outputReady method is called.

Get a connection from pool otherwise IORactor(host,port) thread ends here. There is no limit to num of connections here. If queue is flushed suddenly here BE rate can go high.

Then CONNECT is called on newly created connection.

When response is coming back TargetHandler's following method is hit.

public void responseReceived(NHttpClientConnection conn) {..}

PS:

While debug saw these two issues. This is due to callback timeout when response lands to ESB.

2017-05-31 23:23:10,131] WARN - TargetHandler http-outgoing-1: Connection time out while in state: REQUEST_DONE

[2017-05-31 23:23:10,172] WARN - SynapseCallbackReceiver Synapse received a response for the request with message Id : urn:uuid:743bea80-fd1e-47ba-9bef-ab2d518c5fa8 But a callback is not registered (anymore) to process this response

WSO2 ESB uses Apache Synapse as its mediation engine. Synapse has a layered architecture to mediate messages through it.

Following is a high level component diagram of Synapse design.

This post walks you through main steps done in synapse to mediate messages. It is more of a code reference that gives a high level understanding of message flow so that one can debug the code and understand.

Contents

Where is the code?

Proxy Configuration Used for Debugging

Inflow of a message

Entry point

Creating synapse mc out of axis2 mc

Check if message is coming from Inbound Endpoint

Set service level log (per proxy logs)

Honour isSoapConversionRequired parameter

Execute synapse handlers

Check for mandatory sequence

Start mediating message with SequenceMediator

Building the message

Iterate through mediators and exit where necessary

Forwarding message to the Back-end in in-sequence

Send message to endpoint (send mediator debug)

Axis2SynapseEnvironment.send() Method (to send out any message from synapse)

Check for mandatory sequence

Start mediating message with SequenceMediator

/**
* If this mediator refers to another named Sequence, execute that. Else
* execute the list of mediators (children) contained within this. If a referenced
* named sequence mediator instance cannot be found at runtime, an exception is
* thrown. This may occur due to invalid configuration of an erroneous runtime
* change of the synapse configuration. It is the responsibility of the
* SynapseConfiguration builder to ensure that dead references are not present.
*
* @param synCtx the synapse message
* @return as per standard mediator result
*/
public boolean mediate(MessageContext synCtx) {..}

We keep a stack to trace which sequence is being executed. This is done by ContinuationStackManager.

set all the details of the endpoint only to the cloned message context so that we can use the original message context for resending through different endpoints. Following is the outline of the method.

Write to wire so that message goes to BE service

mepClient.execute(true);

Following diagram depicts above flow in summery (Thanks Pamod Silvester for the diagram!)

Outflow of a message

When a message is sent to an endpoint using send mediator or call mediator, if ESB expects a response it registers a callback when it is sent out (please refer "Register the callback for response" section above). When response comes into ESB it is handled by this callback.

SynapseCallbackReceiver

When response comes from the BE, it is handled by SynapseCallbackReceiver.

/**

* This is the message receiver that receives the responses for outgoing messages sent out

* by Synapse. It holds a callbackStore that maps the [unique] messageID of each message to

* a callback object that gets executed on timeout or when a response is received (before timeout)

*

* The AnonymousServiceFactory uses this MessageReceiver for all Anonymous services created by it.

Inject message to synapse environment (Axis2SynapseEnvironment)

if isContinuationCall - in call() mediator responses, execute mediators after the call mediator

else if receivingSequence - if there is a receive sequence, dispatch message there

else if outSequence - if out sequence execute mediators there

else if - just send back using info in synCtx

}

Using send mediator in out sequence

Just assume we have a send mediator in out seq. Then call stack would be

Ultimately it hits following section in send mediator

// if no endpoints are defined, send where implicitly stated

if (endpoint == null) {

synCtx.getEnvironment().send(null, synCtx);

}

Here is it is response for inbound transport message, it uses InboundResponseSender to send back (looked up using synapseContext)

Dispatching message to Axis2 to send back

If the request arrives through a conventional transport listener

AxisEngine.send(messageContext);

Following diagram depicts above flow in summery (Thanks Pamod Silvester for the diagram!)

An MBean is a managed Java object. They are generally used to expose monitoring statistics of a java application, management capability on it. JDK itself has a default set of MBeans to monitor JVM statistics etc.

It follows the JMX specification. You can use JMX protocol to invoke MBeans. It is possible to connect to MBeans from same machine insecurely, but if you access from a different machine, credentials needs to be provided.

It is often a requirement to receive and view several properties of a set of objects (objects are rows and properties are columns if you put it to a table). This can be achieved using CompositeData under Open MBeans.

This tutorial shows how to define MBean with CompositeData as well as how to access and receive information.

Scenario

Expose a set of customer objects. A customer has following properties those need to be exposed.

Running the client you will see customer information is printed to the console. This way, complex object information can be transferred using MBeans using CompositeData.

Another type of out of memory errors in java is - "java lang outofmemoryerror gc overhead limit exceeded". This is NOT talking about that your machine has no enough memory (heap memory) to run the application, but rather a symptom of a different issue.

According to Oracle here is the description about on what situations this error is thrown."The parallel collector will throw an OutOfMemoryError if too much time is being spent in garbage collection: if more than 98% of the total time is spent in garbage collection and less than 2% of the heap is recovered, an OutOfMemoryError will be thrown. This feature is designed to prevent applications from running for an extended period of time while making little or no progress because the heap is too small. If necessary, this feature can be disabled by adding the option -XX:-UseGCOverheadLimit to the command line."

If you are hit with this issue for a java application (i.e a WSO2 Server), it can be a GC tuning issue, or not enough memory issue or else it can be a program level bug. In order to decide, we need to set up some monitoring for the application.

What causes gc overhead limit exceeded issue?

As Oracle states, this issue surface when automatic GC runs too frequently to free up memory in your Java application. After a garbage collection, if the Java process is spending more than approximately 98% of its time doing garbage collection and if it is recovering less than 2% of the heap and has been doing so far the last 5 (compile time constant) consecutive garbage collections, java throws this error to prevent your application from soaking up CPU time without getting anything done so that you have a chance of diagnosing the problem.

What programming issues can cause this?

If Java application creates a tons of temporary objects in memory and loose all the references to them frequently and tons of weakly-referenced objects in an already very memory-constrained environment this issue will surface. The program might need to re-written with a different algorithm reusing created objects as much as possible.

But wait, this can be normal, if memory is not very constrained...!! If there is no obvious programming issue like above, we need to setup monitoring and decide.

Below let us discuss how to monitor GC. For obvious reasons, we need to monitor Heap memory behavior as well.

How to monitor WSO2 Sever application for GC

Jconsole

1. Run wso2 server by [HOME]/bin wso2server.sh script.

2. Find process id by using command ps -ef | grep wso2

3. Run jconsole by typing jconsole in commandline

4. Attach process and monitor. You can attach jconsole to a remotely running sever as well. (Refer to server startup log)

Here we can see how much time server has taken for GC. You can calculate, out of total up time, GC time should be less than 2% for a healthy running application. The saw tooth memory variation pattern is normal, as Java will do a automatic GC once PS Eden Space is filled.

Above grep was for WSO2 Message Broker 3.1.0 with 2GB Heap allocated. Now I created a memory constrained environment by reducing heap memory size to 500MB. Still application ran, but with more frequent GC happening to gain memory. Here, memory could re-gain by GC process (more than 2%), so there is no OOM error.

Likewise, if application retained objects permanently in memory over long run, and always keep to occupy a memory near to heap limit, GC happens frequently.

As objects keep memory (due to some memory leak, or a cache not cleared for a longer time by application), the amount of memory GC can recover keeps getting low in every GC cycle.

There, if load (usually a high load) put to the server creates temporary objects in memory so fast that GC operations cannot sweep them out, GC overhead limit exceeded error will be thrown.

(Java) VisualVM + Visual GC

Java Visual VM is a GUI profiling/monitoring tool provided by Oracle JDK. Instead of the version that is included with JDK, you can download Visual VM directly from its website as well.

Same as Jconsole above you can monitor attaching to the process or monitor remotely (File >> add JMX connection).

You can get the basic information about GC and Heap from Monitoring tab. But it does not give you detailed information.

running "jstat –gc 1000 10" will display the GC monitoring information once every 1 second for 10 times in total.

There are many options other than -gc, among which GC related ones are listed below.

Option Name

Description

gc

It shows the current size for each heap area and its current usage (Ede, survivor, old, etc.), total number of GC performed, and the accumulated time for GC operations.

gccapactiy

It shows the minimum size (ms) and maximum size (mx) of each heap area, current size, and the number of GC performed for each area. (Does not show current usage and accumulated time for GC operations.)

gccause

It shows the "information provided by -gcutil" + reason for the last GC and the reason for the current GC.

gcnew

Shows the GC performance data for the new area.

gcnewcapacity

Shows statistics for the size of new area.

gcold

Shows the GC performance data for the old area.

gcoldcapacity

Shows statistics for the size of old area.

gcpermcapacity

Shows statistics for the permanent area.

gcutil

Shows the usage for each heap area in percentage. Also shows the total number of GC performed and the accumulated time for GC operations.

From above options -gcutil and -gccapacity are most helpful.

-gcutil is used to check the usage of heap areas, the number of GC performed, and the total accumulated time for GC operations.

while -gccapacity option and others can be used to check the actual size allocated.

For details about the stats denoted by each column please refer to post here.

-verbosegc

Unlike Jstat, this is a JVM option that you can run with. Meaning, it should be passed as a parameter to JVM at the startup. However, as -verbosegc displays easy to understand output results whenever a GC occurs, it is very helpful for monitoring rough GC information.

The followings are other options that can be used with -verbosegc.

-XX:+PrintGCDetails (enabled by default)

-XX:+PrintGCTimeStamps

-XX:+PrintHeapAtGC

-XX:+PrintGCDateStamps (from JDK 6 update 4)

Here is the format that information is printed when a minor GC occurs.

There is a Software called HPJMeterwhich can be used to analyze -verbosegc output results graphically.

Solutions to the problem

If above monitoring tools tells you that there is not enough memory to handle the load put to the server, there is an actual resource limitation. In that case you need to increase heap memory size allocated to JVM. The load might be creating too many temporary objects. And in long run some objects are kept in memory by application for some time, making the situation worse. Following is how we can update memory allocation using JVM parameters. Xms- for minimum limit. Xmx - for maximum limit

If monitoring tells you that there is a memory leak keeping objects in memory in long run, preventing GC to recover memory (even running frequently when memory brim is reaching), need to fix the memory leak on the first place.

If load is considerably low and there is enough memory allocated, need to revisit the code how temporary objects are created and used by the application. Choosing to reuse objects instead of creating new ones can reduce the number of times the garbage collector gets in the way.

GC tuning might be an option as well. Frequent GC from beginning might solve this particular problem given that there is no memory leak (-XX:-UseConcMarkSweepGC will be an option).

About Me

Hi all, I am Hasitha Abeykoon. I schooled to Wariyapola Sri Sumangala college and Dharmaraja college. I was graduated from University of Moratuwa, Sri Lanka and I am currently working at WSO2 as a software Engineer. My home town is Kandy. I like to be with my friends and to read books and Internet. My hobbies are Travelling and Photography....