Tuesday, September 29, 2009

Multiple Instances of Weblogic on same node

While QAing terracotta standalone ehcache and terracottta standalone hibernate, we need to test the kit with different containers such as tomcat, jetty, glassfish, weblogic, jboss. It is good if we have all setup in same machine. When trying to install weblogic server on same machine, we can start a managed server on the same machine or create another domain and use terracotta server to cluster it.

I came across a helpful blog to create new domains and a PDF file attached to it.
http://blogs.oracle.com/learnwithpavan/2008/09/any_application_server_need_to.html
http://blogs.oracle.com/learnwithpavan/mydocs/weblogic/Creating%20a%20new%20Weblogic%20Domain.pdf
On step 7 as mentioned in the pdf, we can change the listen port to any other unused port like 8001 and you are good to go.

We can start two different domain weblogic servers on same machine now.

Getting JAR version programmatically

While QAing Ehcache, just to make sure that we have correct JAR loaded and tested, we tried to get the version of JAR from the pom.properties in ehcache-core-xxx.jar. Following code help us accessing the jar file for a particular class, and subsequently the files in it.

 public String getEhcacheVersion(){
String ehcacheVersion = null;
JarInputStream jarIn = null;
File file = null;
try {
file = new File(Ehcache.class.getProtectionDomain()
.getCodeSource().getLocation().toURI());
jarIn = new JarInputStream(new FileInputStream(file));
JarEntry entry;

while ((entry = jarIn.getNextJarEntry()) != null) {
if (entry.getName().toUpperCase().equalsIgnoreCase("META-INF/maven/"
+"net.sf.ehcache/ehcache-core/pom.properties")){

BufferedReader reader = new BufferedReader(new InputStreamReader(jarIn));
String line = null;
while ((line = reader.readLine()) != null) {
if(line.startsWith("version")){
ehcacheVersion=line;
break;
}
}
}
}
}
catch (URISyntaxException e1) {e1.printStackTrace();}
catch (IOException e) {e.printStackTrace();}
finally {
if (jarIn != null)
try { jarIn.close(); } catch (Exception e) {}
}
return
ehcacheVersion;
}
mvn puts data into META-INF/maven/net.sf.ehcache/ehcache-core/pom.properties

#Generated by Maven
#Thu Sep 24 12:20:41 PDT 2009
version=xxx
groupId=net.sf.ehcache
artifactId=ehcache-core

We can also use MANIFEST.MF to get required data.

Friday, September 18, 2009

Hibernate 3 with Weblogic results in ClassNotFoundException HqlToken

When using Hibernate 3 with Weblogic Server 10.3, I was getting the following exception when deploying Terracotta h2lc tutorial application.

org.hibernate.QueryException: ClassNotFoundException: org.hibernate.hql.ast.HqlToken [from org.hibernate.tutorial.domain.Person p]
at org.hibernate.hql.ast.HqlLexer.panic(HqlLexer.java:80)
at antlr.CharScanner.setTokenObjectClass(CharScanner.java:340)
at org.hibernate.hql.ast.HqlLexer.setTokenObjectClass(HqlLexer.java:54)
at antlr.CharScanner.(CharScanner.java:51)
at antlr.CharScanner.(CharScanner.java:60)
at org.hibernate.hql.antlr.HqlBaseLexer.(HqlBaseLexer.java:56)
at org.hibernate.hql.antlr.HqlBaseLexer.(HqlBaseLexer.java:53)
at org.hibernate.hql.antlr.HqlBaseLexer.(HqlBaseLexer.java:50)
at org.hibernate.hql.ast.HqlLexer.(HqlLexer.java:49)
at org.hibernate.hql.ast.HqlParser.getInstance(HqlParser.java:67)
at org.hibernate.hql.ast.QueryTranslatorImpl.parse(QueryTranslatorImpl.java:268)
at org.hibernate.hql.ast.QueryTranslatorImpl.doCompile(QueryTranslatorImpl.java:182)
at org.hibernate.hql.ast.QueryTranslatorImpl.compile(QueryTranslatorImpl.java:136)
at org.hibernate.engine.query.HQLQueryPlan.(HQLQueryPlan.java:101)
at org.hibernate.engine.query.HQLQueryPlan.(HQLQueryPlan.java:80)
at org.hibernate.engine.query.QueryPlanCache.getHQLQueryPlan(QueryPlanCache.java:94)
at org.hibernate.impl.AbstractSessionImpl.getHQLQueryPlan(AbstractSessionImpl.java:156)
at org.hibernate.impl.AbstractSessionImpl.createQuery(AbstractSessionImpl.java:135)
at org.hibernate.impl.SessionImpl.createQuery(SessionImpl.java:1651)
at org.hibernate.tutorial.web.EventManagerServlet.init(EventManagerServlet.java:28)
at javax.servlet.GenericServlet.init(GenericServlet.java:241)
at weblogic.servlet.internal.StubSecurityHelper$ServletInitAction.run(StubSecurityHelper.java:283)
at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)
at weblogic.security.service.SecurityManager.runAs(Unknown Source)
at weblogic.servlet.internal.StubSecurityHelper.createServlet(StubSecurityHelper.java:64)
at weblogic.servlet.internal.StubLifecycleHelper.createOneInstance(StubLifecycleHelper.java:58)
at weblogic.servlet.internal.StubLifecycleHelper.(StubLifecycleHelper.java:48)
at weblogic.servlet.internal.ServletStubImpl.prepareServlet(ServletStubImpl.java:521)
at weblogic.servlet.internal.ServletStubImpl.execute(ServletStubImpl.java:235)
at weblogic.servlet.internal.TailFilter.doFilter(TailFilter.java:26)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:42)
at org.hibernate.tutorial.web.SessionInterceptor.doFilter(SessionInterceptor.java:41)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:42)
at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:3496)
at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)
at weblogic.security.service.SecurityManager.runAs(Unknown Source)
at weblogic.servlet.internal.WebAppServletContext.securedExecute(WebAppServletContext.java:2180)
at weblogic.servlet.internal.WebAppServletContext.execute(WebAppServletContext.java:2086)
at weblogic.servlet.internal.ServletRequestImpl.run(ServletRequestImpl.java:1406)
at weblogic.work.ExecuteThread.execute(ExecuteThread.java:201)
at weblogic.work.ExecuteThread.run(ExecuteThread.java:173)

This seems to be a known issue https://www.hibernate.org/250.html#A25

Solution:

For WAR files, Add WEB-INF/weblogic.xml

<?xml version="1.0" encoding="ISO-8859-1"?>
<!DOCTYPE weblogic-web-app PUBLIC "-//BEA Systems, Inc.//DTD Web Application 8.1//EN"
"http://www.bea.com/servers/wls810/dtd/weblogic810-web-jar.dtd">
<weblogic-web-app>
<container-descriptor>
<prefer-web-inf-classes>true</prefer-web-inf-classes>
</container-descriptor>
</weblogic-web-app>

Note: All the dependencies should be in the WAR
Warning: The above code can lead you to some ClassCastExceptions which is due to conflicting classes in WEB-INF/lib and system libs.
For me, it threw
java.lang.ClassCastException: weblogic.xml.jaxp.RegistryXMLReader cannot be cast to org.xml.sax.XMLReader  
at org.xml.sax.helpers.XMLReaderFactory.loadClass(Unknown Source)
at org.xml.sax.helpers.XMLReaderFactory.createXMLReader(Unknown Source)
at org.dom4j.io.SAXHelper.createXMLReader(SAXHelper.java:83)
at org.dom4j.io.SAXReader.createXMLReader(SAXReader.java:894)
at org.dom4j.io.SAXReader.getXMLReader(SAXReader.java:715)

so needed to remove xml-apis jar from WEB-INF/lib.

The above solution is for Web Archives only. For other applications, we might need to add the following code. Didnt tested this though :)

<?xml version="1.0" encoding="ISO-8859-1"?>
<weblogic-application>
<prefer-application-packages>
<package-name>antlr.*</package-name>
</prefer-application-packages>
</weblogic-application>

Monday, March 2, 2009

Examinator 16 Nodes - Test Run Results

Below is the result of the script for 16 tomcat server runs with Terracotta server. The MySQL server has been cleaned and restarted before the test run.

Analyzing Jmeter logs ...
==============================
502 Error = 0
503 Error = 0
DEV-1929 = 0

Response Time
==============================
Average JMeter response time [e1s31] = 96.8721
Average JMeter response time = 35.7428

Server Latency Stats
=====================
Average = 4.76148 ms
Minimum = 0 ms
Maximum = 7036 ms
Std. Deviation = 59.4633
Total # of Requests = 5407000
Nodes = 16

L2 Configuration
==============================
TC_OPTS=-Xms4g -Xmx4g -XX:+DisableExplicitGC -XX:-TraceClassUnloading -XX:TargetSurvivorRatio=90 -Xss128k -XX:+AggressiveHeap -Dcom.tc.l2.objectmanager.fault.logging.enabled=true -Dcom.tc.l2.cachemanager.logging.enabled=true -Dcom.tc.l2.berkeleydb.je.maxMemoryPercent=15 -XX:SurvivorRatio=12

L1 Configuration
==============================
CATALINA_OPTS=-Duse.async.processing=true -Dasync.concurrency=5 -Dcom.tc.hibernate.useFineGrainedLocking=false -Dcom.tc.l1.cachemanager.enabled=false -Duse.pojoizer=true -Xms1024m -Xmx1024m -server -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -verbose:gc -XX:TargetSurvivorRatio=90 -Xss128k -XX:NewSize=512m -XX:MaxNewSize=512m

Object DB Size
==============================
26G /export1/bench/perfTests/terracotta/server/data/objectdb

L2 VerboseGC log Analysis

GC Report
================
Avg Full GC Duration = 6.12302 secs
Avg Full GC Interval = 99.5817 secs
Total Full GC Time = 385.75 secs

No. of Full GC = 63
Avg Young GC Duration = 0.234307 secs
Avg Young GC Interval = 10.8526 secs
No. of Young GC = 589
Total Young GC Time = 136.44 secs

Avg Young GC Occurence b/w Full GC = 9.34921
Avg Young GC Time b/w Full GC = 2.16571 secs

Friday, February 20, 2009

Initial Lassen Performance Results

The below are the test results for the 8 tomcat cluster with terracotta server. It is the result form the masterRun.sh script.
Analyzing Jmeter logs ...
==============================
502 Error = 0
503 Error = 0
DEV-1929 = 0
//This includes network latency, etc.
Response Time
==============================
Average JMeter response time [Last Page/e1s31] = 144.109 ms
Average JMeter response time = 98.2516 ms

//This is server latency printed by the apache tomcat servlet engine
Server Latency Stats
=====================
Average = 9.90304 ms
Minimum = 0 ms
Maximum = 5851 ms
Std. Deviation = 40.5956
Total # of Requests = 2704000
Nodes = 8

L2 Configuration
==============================
TC_OPTS=-Xms4g -Xmx4g -XX:+DisableExplicitGC -XX:-TraceClassUnloading -XX:TargetSurvivorRatio=90 -Xss128k -XX:+AggressiveHeap -Dcom.tc.l2.objectmanager.fault.logging.enabled=true -Dcom.tc.l2.cachemanager.logging.enabled=true -Dcom.tc.l2.berkeleydb.je.maxMemoryPercent=15 -XX:SurvivorRatio=12

L1 Configuration
==============================
CATALINA_OPTS=-Duse.async.processing=true -Dasync.concurrency=5 -Dcom.tc.hibernate.useFineGrainedLocking=false -Dcom.tc.l1.cachemanager.enabled=false -Duse.pojoizer=true -Xms1024m -Xmx1024m -server -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -verbose:gc -XX:TargetSurvivorRatio=90 -Xss128k -XX:NewSize=512m -XX:MaxNewSize=512m

// We have async TIM installed which let the saving the results to database asynchronously.
MySQL DB (perf28) Entries in EXAM_RESULT
=========================================
COUNT(*)
4547

MySQL DB (perf28) results completion time
==========================================
min(START_TIME) max(END_TIME) completionsecs
2009-02-20 04:40:12 2009-02-20 06:21:41 6089

Object DB Size
==============================
13G /export1/bench/perfTests/terracotta/server/data/objectdb

L2 VerboseGC log Analysis

GC Report
================
Avg Full GC Duration = 5.50871 secs
Avg Full GC Interval = 247.74 secs
Total Full GC Time = 137.718 secs

No. of Full GC = 25
Avg Young GC Duration = 0.230732 secs
Avg Young GC Interval = 25.8137 secs
No. of Young GC = 246
Total Young GC Time = 56.76 secs

Avg Young GC Occurence b/w Full GC = 9.84
Avg Young GC Time b/w Full GC = 2.2704 secs

The page response time is less than 10 ms.

The above response time includes Servlet Initialization time. All the servlets/application initializes when first request hits the tomcat server which could be bit high.

After 5 mins from the test run completion

mysql -u root -h perf28 -e 'SELECT COUNT(*) FROM exam.EXAM_RESULT'
+----------+
| COUNT(*) |
+----------+
| 9600 |
+----------+

Lassen Performance Tuning

We need to apply the performance tuning parameters on Tomcat and HTTP server.

Tomcat Server Tuning

Jasper Configuration

Tomcat JSP compiler Jasper has some recommended configuration for production environment or rather non-development environment. They are described below and are made to web.xml

http://tomcat.apache.org/tomcat-6.0-doc/jasper-howto.html#Production%20Configuration



<servlet>
<servlet-name>jsp</servlet-name>
<servlet-class>org.apache.jasper.servlet.JspServlet</servlet-class>
<init-param>
<param-name>fork</param-name>
<param-value>false</param-value>
</init-param>
<init-param>
<param-name>xpoweredBy</param-name>
<param-value>false</param-value>
</init-param>

<!-- development Is Jasper used in development mode? If true, ---->
<!-- the frequency at which JSPs are checked for ---->
<!-- modification may be specified via the ---->
<!-- modificationTestInterval parameter. [true] ---->
<!-- -->

<init-param> <param-name>development</param-name> <param-value>false</param-value> </init-param>

<!-- mappedfile Should we generate static content with one ---->
<!-- print statement per input line, to ease ---->
<!-- debugging? [true] ---->
<!-- -->

<init-param>
<param-name>mappedfile</param-name>
<param-value>false</param-value>
</init-param>

<!-- modificationTestInterval ---->
<!-- Causes a JSP (and its dependent files) to not ---->
<!-- be checked for modification during the ---->
<!-- specified time interval (in seconds) from the ---->
<!-- last time the JSP was checked for ---->
<!-- modification. A value of 0 will cause the JSP ---->
<!-- to be checked on every access. ---->
<!-- Used in development mode only. [4] ---->
<!-- -->

<init-param>
<param-name>modificationTestInterval</param-name>
<param-value>3600</param-value>
</init-param>

<!-- genStrAsCharArray Should text strings be generated as char ---->
<!-- arrays, to improve performance in some cases? ---->
<!-- [false] ---->
<!-- -->

<init-param>
<param-name>genStringAsCharArray</param-name>
<param-value>true</param-value>
</init-param>

<load-on-startup>3</load-on-startup> </servlet>


Server Configuration

The following changes were made regarding the tomcat server made to server.xml

Reference: http://tomcat.apache.org/tomcat-6.0-doc/config/http.html

<Connector port="8080" protocol="HTTP/1.1"
enableLookups="false"
maxThreads="500"
minSpareThreads="100"
maxKeepAliveRequests="1"
acceptCount="200"
connectionTimeout="20000"
redirectPort="8443" />

maxThreads

It is the maximum number of request processing threads to be created by this Connector, which therefore determines the maximum number of simultaneous requests that can be handled. The number were set to 500 as there were requests rejected giving connection refused error when load applied on the server was about 400 user. There is thinktime applied in the test which should reduce the concurrency in the server but at certain point of time, there were few requests kept alive if the keep-alive timeout is too high.

maxThreads were increased to 1200, to match the number of users/node. This wasn't necessary but to solve the 40 min problem so that the connections are not refused by tomcat. Since maxThreads were increased, minSpareThreads were also increased to 500.

maxKeepAliveRequests

The maximum number of HTTP requests which can be pipelined until the connection is closed by the server. Setting this attribute to 1 will disable HTTP/1.0 keep-alive, as well as HTTP/1.1 keep-alive and pipelining. Setting this to -1 will allow an unlimited amount of pipelined or keep-alive HTTP requests. If not specified, this attribute is set to 100. There are redirects for each request so its good to have keep alive so that each redirected request is handled by the same thread.

Keep Alive on the tomcat server has been disabled, which probably solves the 502 Bad proxy gateway error

acceptCount

The maximum queue length for incoming connection requests when all possible request processing threads are in use. Any requests received when the queue is full will be refused. The default value is 10. It is set high so that we dont have any requests that is getting refused by the server.

MySQL Server tuning

The limit on connections made to MySQL server is specified by the max_client parameter. The default value is 100, so if we have connection pool size of 100 on the app servers, the limit on mysql server throws "com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: Too many connections".

The max connections were set to 800 which were eventually increased to 3300 (200 per node and 100 extra)

Load Balancer Tuning

The number of connections were increased from the default to handle the load.

<IfModule worker.c>
ServerLimit 50

#initial number of server processes to start
#http://httpd.apache.org/docs/2.2/mod/mpm_common.html#startservers
StartServers 3

#minimum number of worker threads which are kept spare
#http://httpd.apache.org/docs/2.2/mod/mpm_common.html#minsparethreads
MinSpareThreads 5000

#maximum number of worker threads which are kept spare
#http://httpd.apache.org/docs/2.2/mod/mpm_common.html#maxsparethreads
MaxSpareThreads 5000

#upper limit on the configurable number of threads per child process
#http://httpd.apache.org/docs/2.2/mod/mpm_common.html#threadlimit
ThreadLimit 200

#maximum number of simultaneous client connections
#http://httpd.apache.org/docs/2.2/mod/mpm_common.html#maxclients
MaxClients 10000

#number of worker threads created by each child process
#http://httpd.apache.org/docs/2.2/mod/mpm_common.html#threadsperchild
ThreadsPerChild 200

#maximum number of requests a server process serves
#http://httpd.apache.org/docs/2.2/mod/mpm_common.html#maxrequestsperchild
MaxRequestsPerChild 100000
</IfModule>

Linux tuning

We observed "too many open files" error on the linux machines. The hard limit for the "open files" parameter shown by ulimit -aH was set too low. We increased the ulimit on all the linux machines to the max (65536). This number also determines the number of socket that can be opened on a linux machine.

java.net.SocketException: Too many open files in system
at java.net.Socket.createImpl(Socket.java:388)
at java.net.Socket.(Socket.java:362)
at java.net.Socket.(Socket.java:240)
at org.apache.commons.httpclient.protocol.DefaultProtocolSocketFactory.createSocket(DefaultProtocolSocketFactory.java:80)
at org.apache.commons.httpclient.protocol.DefaultProtocolSocketFactory.createSocket(DefaultProtocolSocketFactory.java:122)
at org.apache.commons.httpclient.HttpConnection.open(HttpConnection.java:707)
at org.apache.commons.httpclient.HttpMethodDirector.executeWithRetry(HttpMethodDirector.java:387)
at org.apache.commons.httpclient.HttpMethodDirector.executeMethod(HttpMethodDirector.java:171)
at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:397)
at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:323)
at org.apache.jmeter.protocol.http.sampler.HTTPSampler2.sample(HTTPSampler2.java:838)
at org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.sample(HTTPSamplerBase.java:1021)
at org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.sample(HTTPSamplerBase.java:1007)
at org.apache.jmeter.threads.JMeterThread.run(JMeterThread.java:290)
at java.lang.Thread.run(Thread.java:619)

Monitoring Lassen Performance Runs

Here is a brief descriptions of the logs.

1. server.<server_name>.log [ Dir:LassenPerfFramework/logs ]
This contains the startup logs for Terracotta Servers. If there are problems in the starting Terracotta Servers, check these logs first.

2. TCserver_GC.<server_name>.log [ Dir:LassenPerfFramework/logs ]
This contains the verbose GC output for the Terracotta Servers. If you want to work with different JVM GC settings, these logs contains the GC information.

3. log*.jtl [ Dir:LassenPerfFramework/logs ]
This contains the output from the JMeter test run. Each HTTP Response Logging from the Cluster goes into this. This does NOT contains the response body for the successful responses (HTTP response Code:302 or 200). For errors/exceptions (HTTP response Code:500 ,502, 503, 404, etc), JMeter prints out the Response from the server. It helps in diagnosing the problems.

Each line contains the response time for that sample and response code from the server.
<httpSample t="5" lt="5" ts="1184177284608" s="true" lb="/examinator/" rc="200" rm="OK" tn="Thread Group 1-1" dt="text"/>
t="5" : 5 ms is the response time for this sample
lb="/examinator" : The URL hit by the HTTP request.
rc="200" : HTTP Response code from the server
tn="Thread Group 1-1" : Thread Group.

4. GC*.log [ Dir:LassenPerfFramework/logs ]
This contains the output from JMeter that how many threads have started plus the JVM verbose GC output if enabled.

5. responseTime.log [ Dir: ~/perfTests/tomcat/logs ]
This contains the output from the ResponseTimeTrackingValve installed on the tomcat servers. It prints out the average, maximum, minimum server latency time per 1000 requests. This doesnt include the network latency.

6. catalina.out [ Dir: ~/perfTests/tomcat/logs ]
These are the logs from the Tomcat servers. Any tomcat related errors will be logged in these logs.