1 May 2014

Tomcat Performance Monitoring and Tuning


PART 1   |   PART 2   |   PART 3

This is the third and final part in the blog series on Tomcat whereby we will discuss some of the various options available to monitor Tomcat performance and also describe some of the configuration parameters we can tune to optimize Tomcat application performance. Finally we will introduce the Byteman framework which can be used to instrument and profile applications


Introduction


Following on from Andy's blog post looking at some of the many ways we can configure Tomcat for example to restrict administration access and error page handling within applications, we will be using the same server topology used in this series whereby we have a single Apache server instance which load balances requests to two different tomcat instances in the cluster.





Currently, there is a vast array of both open source and commercial monitoring tools on the market today and the many different ways in which we can tune a Tomcat instance depending on project requirements. In this blog, we will narrow our discussion to a specific number of tools we can use for monitoring and also focus on specific configuration parameters for tuning various resources. We will cover the following areas in this blog:

1) Provide an overview of the application we will use for testing and Apache JMeter setup

2) How to enable JMX Monitoring on Tomcat and provide an overview of some of the JMX Monitoring metrics in JConsole.

3) Monitoring and Tuning JVM Heap performance

4) Application Testing using a fixed number of test scenarios and demonstrate how performatce tuning can aid application request throughput and performance.

5) Instrumenting an application using the instrumentation framework called Byteman.

Application Overview

In this blog, we will use a very simple web application for performance testing purposes which will consist of a simple servlet class which will will retrieve a list of existing product orders from a mysql database instance and display them to the user in a browser. Both the source code and packaged war file can be downloaded from here.

We will also use here Apache JMeter 2.1.1 to allow us perform some simple load testing against the deployed web application above for a set different configuration settings in tomcat and measure performance using JConsole.

JConsole Overview

To monitor performance on each tomcat instance we will use JConsole which comes with JDK 1.7 Hotspot. We will run JConsole locally rather than remotely however if you wish to set up your tomcat instances to remotely accessed then please follow this link. There is no extra set up required to allow us to access the various JMX Mbeans attributes and operations in JConsole.

We will now provide a brief overview of some of the default MBean categories available for Tomcat which are listed in Figure 1.

Connector
The connector category provides an overview of the different connectors and the various mbean attribute values. We have defined two connectors in each tomcat server.xml file, one to accept http traffic and the other to accept AJP requests from an Apache load balancer. The attributes section lists all the connector configuration values we have specified in server.xml along with the default values for various connector attribute values.

DataSource

In this section, we can view all the data sources which we have defined with applications deployed to each tomcat instance. Furthermore, we can view the configuration values set on each data source and the default values if we have not explicitly set these values in the file context.xml defined within the deployed application. Finally, we can observe the state of each connection used in the application.

ThreadPool

In this category, we can view the thread pool configuration details used by the different connector types. On both tomcat instances we have defined we have two pools, one for service AJP and another to service http requests.

RequestProcessor

The request processor category will list mbean metrics associated with each of the threads in the AJP and http connection pool. For example we can ascertain, how log it took to process the last request, the maximum request time to process a request on that thread and the number of requests it has handled.

GlobalRequestProcessor

In this category, we can observe from the mbean attribute values listed the maximum amount of time it took to process a request overall, the cumulative number of errors while processing all requests and the total number of requests handled by all threads on the server.
































Figure 1: Catalina Default JMX Categories


Application Testing and Parameter Tuning
In this section, we will discuss multiple different application performance issues which we have contrived. In the first scenario, we  will modify the application above so that pooled connections used by the application are not returned to the pool and so create a connection leak within the application.

We will then describe 2 different scenarios: one whereby there are insufficient resources allocated to the tomcat server instances to service request loads in a timely manner. In the second scenario using the same load test as in scenario one, we will apply some basic performance tuning to the application and the tomcat server instances to improve performance. We will use JMeter for performance testing and JConsole to observe monitoring metrics. We should note we ran this simple load test 10 times to verify the results we observed below. The results below are a sample from one of these tests and are indicative of the pattern we observed. The application source code, web application war files and JMeter tests can be found here.

Scenario 1: Connection Leak Detection

In the first scenario, we will deliberately change the application so as to not close connections the application uses and so create a connection leak within the running application deployed to the two tomcat instances.  We will now briefly overview the jmeter and tomcat configuration details.

1) Apache JMeter Setup

The Apache JMeter test script named DBTestGroup.jmx consists of a thread group of 1000 threads whereby a http servlet request is made every second.

2) Connection Pool Setup

In the test web application deployed to each tomcat, we have configured a connection pool with 10 database connections whereby connections which are abandoned will be logged in the log file named catalina.out since the "logAbandoned" attribute is set to "true". We can view the connection pool configuration below which is deployed along with the application in a file named context.xml:

<Context>
<Resource name="jdbc/productdb" auth="Container" type="javax.sql.DataSource"
               maxTotal="10" maxIdle="30" maxWaitMillis="10000" logAbandoned="true"
               username="xxxx" password="xxxx" driverClassName="com.mysql.jdbc.Driver"
               url="jdbc:mysql://localhost:3306/products"/>
</Context>

We will now execute the JMeter test described above and view the tomcat logs for connection issues. We can observe the two exceptions below, the first whereby it would appear we are unable to obtain a connection from the connection pool and the second stating that database connections are being abandoned. 

1)
java.sql.SQLException: Cannot get a connection, pool error Timeout waiting for idle object
at org.apache.tomcat.dbcp.dbcp2.PoolingDataSource.getConnection(PoolingDataSource.java:110)at org.apache.tomcat.dbcp.dbcp2.BasicDataSource.getConnection(BasicDataSource.java:1413)
at org.winters.tomcat8tests.DirectoryRetrieval.getOrderDetails(DirectoryRetrieval.java:63)

2)
Abandoned connection log message:
 org.apache.catalina.loader.WebappClassLoader.clearReferencesThreads Stack trace of thread "Abandoned connection cleanup thread":
 java.lang.Object.wait(Native Method)
 java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)


Scenario 2: Poorly Tuned Instances

In this second scenario, we will run a JMeter test which execute 5000 requests against both tomcat instances whereby we will not change the configuration of the AJP connector from the default values and where we have a maximum of 10 database connections in the pool to service database requests. We can view the AJP connector settings, database pool settings and JVM heap settings used below.


1) AJP Connector configuration:

<Connector port="8009" protocol="AJP/1.3" redirectPort="8443"/>

2) Database Pool Configuration:

<Resource name="jdbc/productdb" auth="Container" type="javax.sql.DataSource"
               maxTotal="10" maxIdle="30" maxWaitMillis="10000" logAbandoned="true"
               username="root" password="admin" driverClassName="com.mysql.jdbc.Driver"
               url="jdbc:mysql://localhost:3306/products"/>
</Context>

3) JVM Settings:

We have set the minimum and maximum heap size to 1GB respectively as below:

export CATALINA_OPTS="-Xms1024m -Xmx1024m"


Results

Although JMeter provides us with saome useful performance statistics, we will JConsole to monitor the performance of the test. We can observe below in Figure 2 and 3 that the maximum time to process a request out of 1878 requests processed by one of the Tomcat servers took 4858 milliseconds whereby it took 373041 milliseconds to process 1878 requests. In Figure 3, we can find out metrics for each of the AJP threads used to process requests. We have provided an example of just one here whereby it took just 73 milliseconds to process the last request whereby the maximum time to process any one request on this thread took 4744 milliseconds.




Figure 2: GlobalRequestProcessor Mbean Attribute Values































Figure 3: RequestProcessor Mbean Attribute Values

Scenario 3: Optimized Tomcat Instances

In this final test scenario, we will perform some basic tuning on both tomcat instances to the AJP connector configuration in server.xml, the connection pool configuration described in context.xml and the JVM heap size allocated to each Tomcat instance.

1) AJP Connector configuration:

The AJP connector configuration below is configured so that there are two threads allocated to accept new connections. This should be configured to the number of processors on the machine however two should be suffice here. We have also allocated 400 threads to process requests, the default value is 200. The "acceptCount" is set to 100 which denotes the maximum queue length to be used for incoming connections. The default value is 10. Lastly we have set the minimum threads to 20 so that there are always 20 threads running in the pool to service requests.

 <Connector port="8009" protocol="AJP/1.3" redirectPort="8443" acceptorThreadCount="2" maxThreads="400" acceptCount="200" minSpareThreads="20"/>

2) Database Pool Configuration:

We have modified the maximum number of pooled connections to 200 so that there are ample connections in the pool to service requests.

<Context>
<Resource name="jdbc/productdb" auth="Container" type="javax.sql.DataSource"
               maxTotal="200" maxIdle="30" maxWaitMillis="10000" logAbandoned="true"
               username="xxxx" password="xxxx" driverClassName="com.mysql.jdbc.Driver"
               url="jdbc:mysql://localhost:3306/products"/>
</Context>

3) JVM Settings:

Since we have increased the maximum number of pooled connections and AJP connector thread thresholds above, we should increase the heap size appropriately. We have set the minimum and maximum heap size to 2GB respectively as below:

export CATALINA_OPTS="-Xms2048m -Xmx2048m"

Results

We can observe from the JConsole Mbean metrics below there is a significant improvement in performance. The maximum time it took to process a request is 2048 milliseconds and the overall processing time to handle 3464 requests is 206741 milliseconds. If we observe the result sin Figure 5 from an individual AJP thread, we can observe it took 46 milliseconds to process the last request whereby the maximum time it took to process a request on this thread is 1590 miliseconds. This particular thread has processed 141 requests whereby it took a total time of 5843 milliseconds to process these requests.
































Figure 4: GlobalRequestProcessor Mbean Attribute Values

































Figure 5: RequestProcessor Mbean Attribute Values

For more details on tomcat 8 connector parameters, please visit this link


JVM Heap Monitoring and Tuning

Specifying appropriate JVM heap parameters to service your deployed applications on tomcat is paramount to application performance. There are a number of different ways which we can monitor JVM heap usage including using JDK hotspot tools such as jstat, JConsole etc however to gather detailed on when and how garbage collection is being performed, it is useful to turn on GC logging on the Tomcat instance. We can turn on GC logging by modifying the catalina start up script with the following command:

JAVA_OPTS="$JAVA_OPTS -verbose:gc -Xloggc:gc.log -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps"

We can set the minimum and maximum heap size, the size of the young generation and the maximum amount of memory to be allocated to the permanent generation used to store application class metadata by specifying the setting the CATALINA_OPTS parameter by executing this command:

export CATALINA_OPTS="-Xms1024m -Xmx2048m -XX:MaxNewSize=512m -XX:MaxPermSize=256m" 

Code Instrumentation

Byteman is a tool which simplifies tracing and testing of Java programs. Byteman allows you to insert extra Java code into your application, either as it is loaded during JVM startup or even after it has already started running. The injected code is allowed to access any of your data and call any application methods, including where they are private. You can inject code almost anywhere you want and there is no need to prepare the original source code in advance nor do you have to recompile, repackage or redeploy your application. Byteman works by modifying the bytecode of your application classes at runtime whereby we can install and uninstall rules to inject traces into a running application using the bminstall and bmsubmit scripts. In this section, we will demonstrate how to use the byteman instrumentation framework with the Tomcat instances in our topology.

The syntax of a Byteman rule follows this pattern:

RULE <rule name>
CLASS <class name>
METHOD <method name>
BIND <bindings>
IF   <condition>
DO   <actions>
ENDRULE

The RULE keyword identifies the rule name (Rule names do not have to be unique but it obviously helps when debugging rule scripts if they clearly identify the rule).

The CLASS can identify a class either with or without the package qualification.

The METHOD name can identify a method with or without an argument list or return type.

The BIND specification ca be used to bind application variable into rule variables which can subsequently be referenced in the rule body.

The IF section can be ovbiously used to check Rule conditions

The DO section is the Rule action which can be a rule expression, return values or throw action


To instrument our application, we have created a basic rule named servletmonitor.btm which will be invoked each time a http service method is invoked which will output to the catalina.out log file the current counter value tracking the number of times the servlet instance has been invoked:

RULE Count All Successful Servlet Invocations
CLASS javax.servlet.http.HttpServlet
METHOD service(javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse)
AT EXIT
BIND servletPath = $1.getServletPath(),
     contextPath = $1.getContextPath()
IF TRUE
DO createCounter("servlet.allInvocations", 0)
   ,incrementCounter("servlet.allInvocations")
   ,traceln("[BYTEMAN] *** ServletTrace: allInvocations=[" + readCounter("servlet.allInvocations") + "]")
   ,traceln("[BYTEMAN] *** ServletTrace: allInvocations=[" + readCounter("servlet.allInvocations") + "], Path=[" + contextPath + servletPath + "]")     
  ,traceStack("[BYTEMAN] *** traceStack: " + $0)
ENDRULE

We will now modify the catalina.sh startup script to use the "javaagent" jvm command line parameter whereby Byteman requests will be received on port 9096 on host 192.168.1.65 which is the same as the Tomcat host machine.  We have also allocated 1GB of heap to the byteman instance. We have set up Byteman here to install the rule above however just to note it is not necessary to this as we could using the bmsubmit utility to install and uninstall this rule as necessary.

BYTEMAN_OPTS="-Dorg.jboss.byteman.verbose=true -Dorg.jboss.byteman.transform.all -javaagent:/home/andy/Downloads/byteman-download-2.1.4.1/lib/byteman.jar=script:/home/andy/Downloads/byteman-download-2.1.4.1/rules/servletmonitor.btm,boot:/home/andy/Downloads/byteman-download-2.1.4.1/lib/byteman.jar,boot:/home/andy/Downloads/byteman-download-2.1.4.1/sample/lib/byteman-sample.jar,listener:true,port:9096,address:192.168.1.65"
  
JAVA_OPTS="$BYTEMAN_OPTS -Xms1024m -Xmx1024m -XX:MaxPermSize=256m $JAVA_OPTS"

We can now run some simple JMeter tests and observe the log output below whereby we can view the trace messages generated by Byteman as specified in the rule servletmonitor.btm

Catalina.out log file output:

Installed rule using default helper : Count All Successful Servlet Invocations
Count All Successful Servlet Invocations execute
Count All Successful Servlet Invocations execute
Count All Successful Servlet Invocations execute
[BYTEMAN] *** ServletTrace: allInvocations=[1]
[BYTEMAN] *** ServletTrace: allInvocations=[2], Path=[/TomcatDBTest/DirectoryRetrieval]
[BYTEMAN] *** ServletTrace: allInvocations=[2]
[BYTEMAN] *** ServletTrace: allInvocations=[2], Path=[/TomcatDBTest/DirectoryRetrieval]
[BYTEMAN] *** ServletTrace: allInvocations=[3]
[BYTEMAN] *** ServletTrace: allInvocations=[3], Path=[/TomcatDBTest/DirectoryRetrieval]
[BYTEMAN] *** traceStack: org.winters.tomcat8tests.DirectoryRetrieval@7c13dd72javax.servlet.http.HttpServlet.service(HttpServlet.java:671)
javax.servlet.http.HttpServlet.service(HttpServlet.java:725)
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:301)

Summary

In this blog, we have demonstrated how to monitor Tomcat using JConsole to monitor performance and also demonstrated by using some basic tuning how we can improve Tomcat performance. Finally, we provided a brief introduction to the Byteman instrumentation framework and how we can use it with Tomcat to gather useful metrics and to trace application code at runtime with little overhead. There are other tools which we one could explore for performance monitoring such as RHQ, Hyperic and using embedded administration user interfaces and tools in Tomcat to gather performance metrics.









2 comments :

  1. Wouldn't JMX slow down tomcat compared when not using it? And affect performance also?

    ReplyDelete
  2. JMX won't slow it down as all the information is collected in the MBeans anyway by Tomcat.

    ReplyDelete