Using Oracle tkprof with JDBC thin client application

When attempting to profile a Hibernate based application, I found a statement that was incredibly slow and caused the system to basically halt for a few seconds before resuming execution. I wanted to profile it at the database level, and the best tool for the job is Oracle’s own tkprof.
The input for tkprof is a session trace file, and enabling one is a bit tricky. The reason – a JavaEE application, with multiple threads, have multiple connections, multiple database sessions, and the SQL_TRACE is on a per session level (I didn’t want to configure it for the entire database – the trace file would be totally unusable…)
So, I took the code and ran it in a standalone Java application, and enabled SQL Trace. Here’s how:

package com.tona.jdbc;

import java.sql.Connection;
import java.sql.DriverManager;
import java.sql.PreparedStatement;
import java.sql.ResultSet;
import java.sql.SQLException;
import java.sql.Statement;
import java.sql.Types;

import oracle.jdbc.OracleCallableStatement;

public class TestJDBC {
	public static void main(String[] args) throws Exception {
		Connection c = DriverManager.getConnection(JDBC_CONNECTION_STRING);
		
                // Set SQL_Trace to on
		Statement stmt = c.createStatement();
		stmt.executeUpdate("ALTER SESSION SET SQL_TRACE=TRUE");
		stmt.close();
		
                // Set SQL Trace location
		stmt = c.createStatement();
		stmt.executeUpdate("alter system set USER_DUMP_DEST='/tmp'");
		stmt.close();

		// JDBC logic comes here...

		c.close();
	}
}

Note
Changing the USER_DUMP_DEST parameter did not have any effect, and the SQL_TRACE was written to the default trace log directory on the server (in my case it was ./u01/app/oracle/diag/rdbms/SID/SID/trace)

How to reuse a java.lang.StringBuilder

It’s common knowledge in Java that you want to clear a StringBuilder object, and not recreate it. Why? GC for instance. But, surprisingly enough, there is no clear() method on the StringBuilder class, and so we resort to manual clear methods. The ones I’ve seen are:

  • new StringBuilder which basically recreates the object
  • setLength(0) which changes the internal flags of the StringBuilder
  • delete(0,sb.length()) which deletes the whole buffer

One would think that the best technique is setLength – but I’ve decided to give it a short test.
Here is the code I’ve used:


package com.tona;

import java.util.Random;

public class TestStringBuffer {
private static final int NUM_OF_RUNS = 100000;
private static final int MAX_LENGTH = 1000;
private static Random rand = new Random();

private static int fillString(StringBuilder sb,boolean isSameLenString) {

int length;

if (isSameLenString)
length = MAX_LENGTH;
else
length = rand.nextInt(MAX_LENGTH);

for (int i = 0; i < length; ++i) sb.append("a"); return length; } private void runBenchmark(boolean isSameLenString) { StringBuilder sb = new StringBuilder(); long start = System.currentTimeMillis(); for (int i = 0; i < NUM_OF_RUNS; ++i) { fillString(sb,isSameLenString); sb.setLength(0); } long end = System.currentTimeMillis(); long diffWithLen0 = end - start; start = System.currentTimeMillis(); for (int i = 0; i < NUM_OF_RUNS; ++i) { fillString(sb,isSameLenString); sb = new StringBuilder(); } end = System.currentTimeMillis(); long diffWithNew = end - start; start = System.currentTimeMillis(); for (int i = 0; i < NUM_OF_RUNS; ++i) { fillString(sb,isSameLenString); sb = new StringBuilder(MAX_LENGTH); } end = System.currentTimeMillis(); long diffWithNewConstLength = end - start; start = System.currentTimeMillis(); for (int i = 0; i < NUM_OF_RUNS; ++i) { fillString(sb,isSameLenString); sb.delete(0, sb.length()); } end = System.currentTimeMillis(); long diffWithDelete = end - start; start = System.currentTimeMillis(); for (int i = 0; i < NUM_OF_RUNS; ++i) { int length = fillString(sb,isSameLenString); sb.delete(0, length); } end = System.currentTimeMillis(); long diffWithDeleteConstLength = end - start; System.out.println("With setLength(0) " + diffWithLen0); System.out.println("With new StringBuilder() " + diffWithNew); System.out.println("With new StringBuilder(MAX_LENGTH) " + diffWithNewConstLength); System.out.println("With delete(0, sb.length()) " + diffWithDelete); System.out.println("With delete(0, length) " + diffWithDeleteConstLength); } public static void main(String[] args) { TestStringBuffer test = new TestStringBuffer(); System.out.println("Constant length string"); test.runBenchmark(true); System.out.println("Changing length string"); test.runBenchmark(false); } } [/java]

And here are the results:

Constant length string
With setLength(0) 1524
With new StringBuilder() 1501
With new StringBuilder(MAX_LENGTH) 1365
With delete(0, sb.length()) 1369
With delete(0, length) 1391
Changing length string
With setLength(0) 686
With new StringBuilder() 743
With new StringBuilder(MAX_LENGTH) 796
With delete(0, sb.length()) 715
With delete(0, length) 698

(Note that changing string length uses a Random, so results may vary).
With StringBuilder object with a fixed length, the new StringBuilder with the predefined length is the best option, although not much slower than the delete method. With the varying length strings, setLength and delete and more of less on par (give it a few runs and you'll see it for yourself).
So, now you know how to clean your StringBuilder object. Enjoy.

FileDescriptor.sync()

First and foremost – a week ago, I never even knew this method existed in Java. Basically – it let you force the file writing to the disk. Turns out Arjuna (JBoss transactions) is using it in its ShadowStore class, to ensure transaction data is stored to disk. It makes sense – as they want to recover transactions in case of a server crash.
Now, if you read my last post, on the inflation of EJBs, you know that 200 EJBs working together is a mess. And I’ve reached a point where 15% of CPU time of a single transaction is spent on this FileDescriptor.sync() method. Since I couldn’t refactor the whole code – I had to think of another solution. Here goes.

I’ve written a new class, that extends ShadowStore.

public class TonaStore extends ShadowingStore {
    public TonaStore(ObjectStoreEnvironmentBean objectStoreEnvironmentBean) throws ObjectStoreException
    {
        super(objectStoreEnvironmentBean);
    	syncWrites = false;
    }
}

I deployed it to a JAR file, and placed it in the server/all/lib directory.

Now, I opened the /server/all/deploy/transactions-jboss-beans.xml file, and changed ActionStore section to the following:

    <bean name="ActionStoreObjectStoreEnvironmentBean" class="com.arjuna.ats.arjuna.common.ObjectStoreEnvironmentBean">

        <annotation>@org.jboss.aop.microcontainer.aspects.jmx.JMX(name="jboss.jta:name=ActionStoreObjectStoreEnvironmentBean", exposedInterface=com.arjuna.ats.arjuna.common.ObjectStoreEnvironmentBeanMBean.class, registerDirectly=true)</annotation>
        
        <constructor factoryClass="com.arjuna.common.internal.util.propertyservice.BeanPopulator" factoryMethod="getNamedInstance">
            <parameter>com.arjuna.ats.arjuna.common.ObjectStoreEnvironmentBean</parameter>
            <parameter>default</parameter>
        </constructor>
        <property name="objectStoreDir">${jboss.server.data.dir}/tx-object-store</property>
	<property name="objectStoreType">com.tona.ts.common.TonaStore</property>
    </bean>

I got almost a 100% increase in hits/second. Sweet.

WebSphere 7 – deployment performance

Well, I’m currently running a migration project from Oracle’s OC4J to WebSphere 7. Why 7? Because the customer wants to use JSF 1.2, and EJB 3 – and we decided on going to WAS7 instead of WAS6.1 with the fix packs.

The migration wasn’t so smooth – the customer used some proprietary code we had to change. And let me tell you – configuring TopLink to run on WAS is a real pain, especially when some TopLink code is accessed through EJBs and some through regular Java classes from the web tier.
But the real problem was WAS7 deployment. It took forever… We tried running it from RAD7.5 or from the admin console directly – it was painful. It took around 5 minutes, and every configuration action that required application restart took ages to complete.
Turns out the problem lies in the JavaEE5 spec. When you deploy an EAR it needs to look for annotated classes that are marked as EJB and servlets. So deploying a WAR file with a large number of classes and JAR files will be very slow.
There are deployment separation solutions (putting the classes in the app-inf/lib of the EAR instead of web-inf/lib of the WAR) but a quick fix, that fits when you don’t use annotated servlets is to add the metadata-complete attribute to your web.xml file (in the web-app tag). It tells the deployer that all of your servlets and filters are configured inside the web.xml file.
See this link for the complete web_app_2_5 XSD description. http://java.sun.com/xml/ns/javaee/web-app_2_5.xsd