Monday, May 4, 2015

Axis2 ConfigurationContext usage and possible memory leak

We are using axis framework in our java application which interacts with external applications using the web service calls.

Along with time, the application performance is getting degraded and after running for few days application is becoming almost non responsive.

The response timings of the application is going beyond the limits and CPU utilization is at almost at 100 %.

The only way to make the application working again is kill the Java process and starting it again. Guess what .. after every restart same story repeats again and again.

After few months, I decided to identify the root cause for the problem we are facing. So started investigated the issue w.r.t. CPU as we are seeing CPU is reaching to 100 %.

I took the thread dump of the application before restart [i.e. application is in un-responsive state] and analysed the thread dumps. Based on the initial analysis I observed that 4 GC threads are using most of the CPU. So got one clue why CPU is going high i.e. due to GC threads.

So, I want analyse the GC behaviour of the application. To start analysing I added required JVM parameters to get the information about the GC behaviour.

-verbose:gc  -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -XX:+PrintGCApplicationStoppedTime -XX:+HeapDumpOnOutOfMemoryError - -Xloggc:gclog -XX:HeapDumpPath=/mtp/app1/ -XX:+PrintTenuringDistribution -XX:+PrintGCCause 

After running the application for few days with the above parameters added, I started analysing the gclog file which was generated.

gclog file gave me the clue of what was happening in the application w.r.t. GC. guess what, application is doing the Full GCs continuously and not able to reclaim any memory.  Below graph shows the GC behaviour of the application. It is clearly evident that heap is getting increased gradually and at some point heap is almost full and application is spending most of its time in doing the Full GCs.


To identify what is occupying the memory, took the heap dump of the application and started analysing the heap dump. By just opening the heap dump, I saw the below in Eclipse MAT dominator tree view.


I.e. org.apache.axis2.context.ConfigurationContext is holding ~ 483MB of heap. I really wonder why ConfigurationContext is taking so much heap??

Based on the further analysis of the heap dump, I noted that for each web service call we are making there is one entry added to the org.apache.axis2.engine.AxisConfiguration allEndPoints HashTable. and size of this HashTable is getting increased along with number of requests we are making to external web services.

At this point I have clue why memory is getting increased along with the time and why CPU utilization is reaching 100%.

  • Memory is getting increased because the number of entries in allEndPoints HashTable is growing.
  • 4 GC threads which are running continuously causing 100% CPU utilization. 
Now, I need to look at the application logic and usage of ConfigurationContext. The below psudo code shows how we are invoking the external web service calls.

public class WebServiceRequestHandler{

    private ConfigurationContext configurationContext;
    private ConfigurationContext prepareConfigurationContext(){
configurationContext =ConfigurationContextFactory.createConfigurationContextFromFileSystem(null, null);
return configurationContext;
}
private ServiceStub initializeStub(HttpClient client) {
        ServiceStub stub = null;
   try {
   if(configurationContext == null){
configurationContext = prepareConfigurationContext();
}
       stub = new ServiceStub(configurationContext, client.getHostConfiguration().getHost());
   return stub;
   } catch (AxisFault e) {
   e.printStackTrace();
   }
   return null;
}
public void externalAPI1(HttpClient client){
ServiceStub stub = initializeStub(client);
try{
stub.externalAPI1();
}catch(Exception e){
e.printStackTrace();
}
}
public void externalAPI2(HttpClient client){
ServiceStub stub = initializeStub(client);
try{
stub.externalAPI2();
}catch(Exception e){
e.printStackTrace();
}
}
}

Does any one tell me what is the issue with above code, everything seems to be perfect right??.
No it is not perfect this peace of the code is causing complete application to stop working....

what is the problem ...... ???

If we observe the code carefully, we are trying to use only one instance of ConfigurationContext in our application i.e. it is singleton [For now don't bother about synchronization of the methods which is required to make ConfigurationContext as a singleton]. 

Nothing wrong with this approach i.e. making ConfigurationContext as singleton. Many people prefer to go with this approach as it saves lot of time in preparing the ConfigurationContext from scratch for each and every request.

So what is the problem ... ???

Have a close look at the api methods [externalAP1 and externalAPI2], we are getting the stub and executing the method on the stub. what is wrong. all seems to be fine.... but finally the problem is..
when ever we make the call on stub, internally it will add entry to allEndPoints HashTable of AxisConfiguration  which we discussed in the beginning of this post. 

But who will be responsible for deleting these entries from allEndPoints, yes the problem is we are not invoking stub._getServiceClient().cleanup(); on stub after invoking the API which is causing pileup in HashTable entries.

We added this cleanup code in the finally block of each APIs method listed in the psudo code and application is started working perfectly without and memory issues...

The method look like below after adding the cleanup code.

public void externalAPI1(HttpClient client) throws Exception{
ServiceStub stub = initializeStub(client);
try{
stub.externalAPI1();
}catch(Exception e){
e.printStackTrace();
}finally{
                       stub._getServiceClient().cleanup();
                }
}

In this post am not saying anything against about axis2 ConfigurationContext, but the way we use and possible memory leaks if we don't use them same properly...











No comments:

Post a Comment