Monitoring JEE applications

Development of Java enterprise applications had evolved over a period of time, We can say we are in a legacy period now with the help of modern frameworks and packages. I could see lot of developers start talking about Grails, many of them started learning Groovy scripting. It is amazing to feel we can make a Java enterprise web application with all modern libraries and UI frameworks integrated in just 10 minutes!!! Thanks to Grails. Application become less error-prone and development becomes an enjoyable one with the modern frame works. Lazy developers like me are so happy to know he is not going to write javascript for UI, SQL queries for backend access. While we giving importance to rapid component development and integrations, these libraries become inevitable.

On the otherside, one should worry about performance. It is painful to think about the CPU consumption of the browser while loading packed AJAX libraries, the number of SQL queries being fired to complete a simple task, the number of connections opened/closed to execute those queries, the load applied on JVM in terms of high CPU consuming threads or concurrent processing without threads getting blocked. When multiple tiers involved, debugging becomes a pain. While we don’t have sufficient time for development, we can’t afford for the resources to spend much time debugging each and every tier. A simple slow down at my DB backend, slows down my enterprise application. But my developer finds it after 5 working days because, he already spend one day each for user interface, Spring beans, ORM integraton and finally Hibernate tiers!! Monitoring them as silos din’t work out. All our admins tries to prove their box is doing good! It is worth to search for a tool which can monitor all of them as a service.

Here is a case study.
We take a simple web application running in Tomcat 6.
It uses Struts 2 for View, Spring 3.1 for Model, Hibernate 3 for Spring ORM with MySQL backend. We run one Apache web server where Phpmyadmin is running for the same database using by java application.

The application was running without any issue in the beginning. We used to upgrade it as we add new modules. Recently we found the application is not responding for logins. We could see the when we try login, the request is on progress for ever. We could see ‘Waiting for…’ without time-out! As any critical issue, this one also din’t have any trace in application process log, tomcat log. It happens sometimes 🙂 Without waiting for me, the server dies in another 3 or 4 hours!


A good idea is post it in the forums, But where? Java? Struts? Spring? Hibernate? Mysql? I have no trace with me! As a lonely programmer, I need to find out where I shoud start now. I added all the components in my monitoring solution and restarted Tomcat. I got the results when the problem occured again.  All the requests are pending in ‘user login’ block. I have an audit code, which will write success & failure login attempts to database, It is waiting for SQL connection for hours!! All the login requests are pending as ‘Waiting’ threads.

See the graph given for two days. You could see the blocked thread count increased from 10 to 212 on periodic intervals.

  • Red dots indicates the time at which the application stops responding to the users.
  • Yellow dots represent the appliation crash time.
  • The sudden drop shows the manual restart of the application.

Very many threads are in blocking state with the following trace.

Stack Trace     :
java.lang.Object.wait(Native Method)
java.lang.Object.wait(Object.java:485)
org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:810)
org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:96)
org.apache.commons.dbcp.BasicDataSource.getConnection(BasicDataSource.java:880)
org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider.getConnection(LocalDataSourceConnectionProvider.java:81)
org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:423)
org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144)
org.hibernate.jdbc.JDBCContext.connection(JDBCContext.java:119)
org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:57)
org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1326)
org.springframework.orm.hibernate3.HibernateTransactionManager.doBegin(HibernateTransactionManager.java:490)
org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:350)
org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:261)
org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:101)
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
$Proxy17.add(Unknown Source)
org.grassfield.common.interceptor.AuthorizationInterceptor.intercept(AuthorizationInterceptor.java:87)
com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:236)
com.opensymphony.xwork2.interceptor.DefaultWorkflowInterceptor.doIntercept(DefaultWorkflowInterceptor.java:163)
com.opensymphony.xwork2.interceptor.MethodFilterInterceptor.intercept(MethodFilterInterceptor.java:87)
com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:236)
com.opensymphony.xwork2.validator.ValidationInterceptor.doIntercept(ValidationInterceptor.java:249)
org.apache.struts2.interceptor.validation.AnnotationValidationInterceptor.doIntercept(AnnotationValidationInterceptor.java:68)
com.opensymphony.xwork2.interceptor.MethodFilterInterceptor.intercept(MethodFilterInterceptor.java:87)
com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:236)
com.opensymphony.xwork2.interceptor.ConversionErrorInterceptor.intercept(ConversionErrorInterceptor.java:122)
com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:236)
com.opensymphony.xwork2.interceptor.ParametersInterceptor.doIntercept(ParametersInterceptor.java:195)
com.opensymphony.xwork2.interceptor.MethodFilterInterceptor.intercept(MethodFilterInterceptor.java:87)
com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:236)
com.opensymphony.xwork2.interceptor.StaticParametersInterceptor.intercept(StaticParametersInterceptor.java:148)
com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:236)
org.apache.struts2.interceptor.CheckboxInterceptor.intercept(CheckboxInterceptor.java:93)
com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:236)
org.apache.struts2.interceptor.FileUploadInterceptor.intercept(FileUploadInterceptor.java:235)
com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:236)
com.opensymphony.xwork2.interceptor.ModelDrivenInterceptor.intercept(ModelDrivenInterceptor.java:89)
com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:236)
com.opensymphony.xwork2.interceptor.ScopedModelDrivenInterceptor.intercept(ScopedModelDrivenInterceptor.java:128)
com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:236)
org.apache.struts2.interceptor.ProfilingActivationInterceptor.intercept(ProfilingActivationInterceptor.java:104)
com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:236)
org.apache.struts2.interceptor.debugging.DebuggingInterceptor.intercept(DebuggingInterceptor.java:267)
com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:236)
com.opensymphony.xwork2.interceptor.ChainingInterceptor.intercept(ChainingInterceptor.java:126)
com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:236)
com.opensymphony.xwork2.interceptor.I18nInterceptor.intercept(I18nInterceptor.java:148)
com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:236)
com.opensymphony.xwork2.interceptor.PrepareInterceptor.doIntercept(PrepareInterceptor.java:138)
com.opensymphony.xwork2.interceptor.MethodFilterInterceptor.intercept(MethodFilterInterceptor.java:87)
com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:236)
org.apache.struts2.interceptor.ServletConfigInterceptor.intercept(ServletConfigInterceptor.java:164)
com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:236)
com.opensymphony.xwork2.interceptor.AliasInterceptor.intercept(AliasInterceptor.java:128)
com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:236)
com.opensymphony.xwork2.interceptor.ExceptionMappingInterceptor.intercept(ExceptionMappingInterceptor.java:176)
com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:236)
org.apache.struts2.impl.StrutsActionProxy.execute(StrutsActionProxy.java:52)
org.apache.struts2.dispatcher.Dispatcher.serviceAction(Dispatcher.java:468)
org.apache.struts2.dispatcher.ng.ExecuteOperations.executeAction(ExecuteOperations.java:77)
org.apache.struts2.dispatcher.ng.filter.StrutsPrepareAndExecuteFilter.doFilter(StrutsPrepareAndExecuteFilter.java:76)
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:857)
org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:588)
org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
java.lang.Thread.run(Unknown Source)

Now we got a handle from which we need to start.

I got an immediate reply from spring community – it is connection pool
http://forum.springsource.org/showthread.php?p=347479

  • Transactions are not implemented properly. Since DataSource is directly injected, spring dint care about releasing the connections.
  • Need to make all my service methods @transactional, DB retrievals made as read-only in addition to few other changes to DAO configuration which I preferred.
  • I was checking the connections consumed or the session details at MySQL, I dont see any abnormalities.
  • The fault was with my blind guessing about default active/maximum connections of commons-dbcp. I thought default connections will be sufficient for me. But I found I din’t give the minimum, maximum and active SQL connection count where default values 8 connections. But I need 5 ~ 12 connections

Hence this solves the issue. The abstractions of the frameworks reduce the time being spent in development. At the same time, We need to be in a position to analyse the different tiers integrated together.

Representing ThreadDump details is basic thing with java monitor, but representing the details so that it can reduce our diagnosing time is highly important. Monitoring JTA becomes a valuable point in any java monitoring product. Still searching for better way of monitoring Struts/Spring/Hibernate layers individually. Hope we will get it soon!

Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s