ONJava.com -- The Independent Source for Enterprise Java
oreilly.comSafari Books Online.Conferences.

advertisement

AddThis Social Bookmark Button

Tuning JDBC: Measuring JDBC performance
Pages: 1, 2, 3

Wrapping the ResultSet class

The ResultSetWrapper class once again consists mainly of delegated methods:



public class ResultSetWrapper implements ResultSet
{
  ResultSet realResultSet;
  StatementWrapper parentStatement;
  String sql;

  public ResultSetWrapper(ResultSet resultSet, StatementWrapper statement, String sql) {
    realResultSet = resultSet;
    parentStatement = statement;
    this.sql = sql;
  }

  public boolean absolute(int row) throws SQLException {
    return realResultSet.absolute(row);
  }

  ...

Again, there are some methods which are not plain delegations. The getStatement() method returns the statement that generated this ResultSet. We need to return the StatementWrapper:

  public Statement getStatement() throws SQLException {
    return parentStatement;
  }

The getArray() methods need to return a wrapped Array object:

  public Array getArray(int i) throws SQLException {
    return new SQLArrayWrapper(realResultSet.getArray(i), parentStatement, sql);
  }

  public Array getArray(String colName) throws SQLException {
    return new SQLArrayWrapper(realResultSet.getArray(colName), parentStatement, sql);
  }

And finally, we need to add logging. Many developers erroneously believe that the various Statement.execute*() methods incur the main cost of the database interaction. This is true for database updates, and for database reads that involve only a few rows. But if more than a few rows of a query are being read, then the ResultSet.next() method can spend a significant amount of time fetching rows from the database. If many rows are to be read, ResultSet.next() calls can cumulatively take much more time than the execution of the SQL statement. So it is natural to log the ResultSet.next() calls.

  public boolean next() throws SQLException {
    Thread t = Thread.currentThread();
    JDBCLogger.startLogSqlNext(t, sql);
    boolean b = realResultSet.next();
    JDBCLogger.endLogSqlNext(t, sql);
    return b;
  }

There are other ResultSet calls that you can log if you need, such as previous(), or insertRow(), etc. But most applications will only need next() logged, and that is how Ill leave the class.

The JDBC wrapper framework

That pretty much covers the classes that need wrapping. I haven't explicitly shown the Array wrapper or the DatabaseMetaData wrapper, but they are straightforward, needing only delegation and ResultSetWrappers and ConnectionWrappers returned instead of ResultSets and Connections. All of the classes in full for JDBC 2 can be obtained from the further resources section. JDBC 1, JDBC 2 and the upcoming JDBC 3 are all amenable to this technique of using wrapper objects to measure database interaction. They differ in their interface definitions (and so, require different wrapper classes), but all of the wrapper classes for the different versions can be created in the same way, following the procedure covered in this article.

The class I haven't yet shown you is the JDBCLogger class. A simple implementation of that class would be with null calls for the logging methods. This would provide no logging:

package tuning.jdbc;

public class JDBCLogger
{
  public static void startLogSqlQuery(Thread t, String sql) {}
  public static void endLogSqlQuery(Thread t, String sql) {}
  public static void startLogSqlNext(Thread t, String sql) {}
  public static void endLogSqlNext(Thread t, String sql) {}

}

A more useful definition would be to time the queries. The following methods work by holding the start time of the query and finding the elapsed time for the query when it finishes. The methods are kept simple by assuming that SQL queries cannot recurse within the same thread, an assumption which is generally true:

  private static Hashtable QueryTime = new Hashtable();

  public static void startLogSqlQuery(Thread t, String sql)
  {
     if (QueryTime.get(t) != null)
       System.out.println("WARNING: overwriting sql query log time for " + sql);
     QueryTime.put(t, new Long(System.currentTimeMillis()));
  }

  public static void endLogSqlQuery(Thread t, String sql)
  {
     long time = System.currentTimeMillis();
     time -= ((Long) QueryTime.get(t)).longValue();
     System.out.println("Time: " + time + " millis for SQL query " + sql);
     QueryTime.remove(t);
  }

Using these methods in the JDBCLogger class would provide output lines similar to:

Time: 53 millis for SQL query SELECT * FROM JACKTABL

for every SQL query execution. This gives you precise measurements for each of your SQL queries. You can also sum the queries in the JDBCLogger class, retain the maximum half-dozen measurements or so, and then print out a summary statment. The summary measurements I usually like to have are minimum, maximum, average, standard deviation, and 90th percentile value. These summary values tend to be more useful for a scaled-up system, whereas printing individual lines for each query is more useful when profiling the system during development.

Using the JDBC wrapper framework

I have found the techniques presented here to be very useful in determining the performance of JDBC calls, both in development and in deployed applications. Because the wrappers are simple and robust, and require very little alteration to the application using them (i.e, are low maintenance), they are suitable to be retained within a deployed application. Creating a configurable JDBCLogger class will allow you to turn logging on and off at will.

During development, these classes have enabled me to identify both individually expensive database interactions and repeated database interactions which are expensive because of their cumulative cost. Identifying these expensive database interactions is the necessary first step to improving your application's performance. In deployed environments, these wrapper classes have identified discrepancies between the expected performance and those actually obtained, and have helped to identify why those discrepancies exist.

Note that there is also a free tool available from Provision6, called the P6Spy driver, which uses the techniques illustrated in this article to log JDBC calls.

After you have used these classes to pinpoint where JDBC is causing a performance problem, you will need to tune the database interactions. The performance tuning techniques to tune JDBC will be presented in future Tuning JDBC articles.

Further Resources

Jack Shirazi is the author of Java Performance Tuning. He was an early adopter of Java, and for the last few years has consulted mainly for the financial sector, focusing on Java performance.


Read more Java Design and Performance Optimization columns.

Return to ONJava.com.