JDBC query logging made easy

In most cases, JDBC PreparedStatements make performing database queries much easier, and can yield significant improvements in your overall application performance. But the PreparedStatement interface falls short when it comes to logging query statements. Whereas a PreparedStatement‘s strength lies in its variability, a good logging entry must describe exactly how the SQL being sent to the database will look after all the parameter placeholders have been replaced with actual parameter values. While there are several ways to get around this conundrum, none of them is easy to implement on any large scale, and most will clutter up your code.

In this article, you’ll learn how to extend the JDBC PreparedStatement interface for query logging. The LoggableStatement class implements the PreparedStatement interface, but adds a method for obtaining query strings in a format suitable for logging. Using the LoggableStatement class will both reduce the incidence of error in your logging code and produce code that is tidier and easier to manage over time.

Note that this article assumes that you have prior experience with JDBC and the PreparedStatement class.

Typical logging solutions

Listing 1 illustrates how a PreparedStatement is typically used when making a database query (albeit with initialization and error handling omitted). We’ll use the SQL query SELECT for our examples throughout this article, but the discussion applies just as well to other types of SQL statements such as DELETE, UPDATE, and INSERT.

Listing 1. A typical SQL database query

String sql = "select foo, bar from foobar where foo < ? and bar = ?";
    String fooValue = new Long(99);
    String barValue = "christmas";

    Connection conn = dataSource.getConnection();
    PreparedStatement pstmt = conn.prepareStatement(sql);

    pstmt.setLong(1,fooValue);
    pstmt.setString(2,barValue);

    ResultSet rs = pstmt.executeQuery();

    // parse result...

A good log entry for the query in Listing 1 might look something like this:

Executing query: select foo,bar from foobar where foo < 99 and
bar='christmas'

And here is one example of how the logging code for that entry might look. Notice that the question marks from Listing 1 have been replaced with values for each parameter.

System.out.println("Executing query: select foo, bar from foobar where foo
< "+fooValue+" and bar = '+barValue+"'")

A somewhat better approach would be to create a method, let’s call it replaceFirstQuestionMark, which takes the query string and replaces the question marks with parameter values, as shown in Listing 2. The use of such a method removes the need to create duplicate strings to describe the SQL statement.

Listing 2. Using replaceFirstQuestionMark for string substitution

// listing 1 goes here

     sql = replaceFirstQuestionMark(sql, fooValue);
     sql = replaceFirstQuestionMark(sql, barValue);
     System.out.println("Executing query: "+sql);

While easy to implement, none of these solutions is ideal. The problem is that whenever a change is made to the SQL template, the logging code must be changed as well. It is almost inevitable that at some point you’ll make a mistake. The query will be changed but you’ll forget to update the logging code, and you’ll end up with logging entries that don’t match the queries being sent to the database — a debugging nightmare.

What we really need is a design that lets us use each parameter variable (fooValue and barValue in our example) just once. We’d like a method that will let us obtain the query string with parameter placeholders replaced with actual values. Because java.sql.PreparedStatement has no such method we have to implement one ourselves.

A custom solution

Our custom implementation of PreparedStatement will act as a wrapper around the “real statement” provided by the JDBC driver. The wrapper statement will forward all method calls (for example, setLong(int, long) and setString(int,String)) to the “real statement.” Before doing so it will save the relevant parameter values so that they may be used to produce logging output.

Listing 3 shows how the LoggableStatement class implements java.sql.PreparedStatement, and how it is constructed using a JDBC connection and an SQL template as input.

Listing 3. LoggableStatement implements java.sql.PreparedStatement

public class LoggableStatement implements java.sql.PreparedStatement {

     // used for storing parameter values needed
      // for producing log
     private ArrayList parameterValues;

     // the query string with question marks as
     // parameter placeholders
     private String sqlTemplate;

     // a statement created from a real database
     // connection
     private PreparedStatement wrappedStatement;

    public LoggableStatement(Connection connection, String sql)
      throws SQLException {
      // use connection to make a prepared statement
      wrappedStatement = connection.prepareStatement(sql);
      sqlTemplate = sql;
      parameterValues = new ArrayList();
    }
     }

How LoggableStatement works

Listing 4 illustrates how LoggableStatement adds a call to the saveQueryParamValue() method, as well as invoking the corresponding method on the “real statement” for the methods setLong and setString. The saveQueryParamValue() call is added in a similar manner to all methods used for parameter setting (for example, setChar, setLong, setRef, and setObj). Listing 4 also shows how the method executeQuery is wrapped without calling saveQueryParamValue(), because it is not a “parameter setting” method.

Listing 4. LoggableStatement methods

public void setLong(int parameterIndex, long x)
         throws java.sql.SQLException {
      wrappedStatement.setLong(parameterIndex, x);
      saveQueryParamValue(parameterIndex, new Long(x));
   }

   public void setString(int parameterIndex, String x)
       throws java.sql.SQLException {
      wrappedStatement.setString(parameterIndex, x);
      saveQueryParamValue(parameterIndex, x);
   }

  public ResultSet executeQuery() throws java.sql.SQLException {
     return wrappedStatement.executeQuery();
   }

The saveQueryParamValue() method is shown in Listing 5. It converts each parameter value to a String representation, saving it for later use by the getQueryString method. By default, an object will be converted to a String using its toString method, but if the object is a String or a Date, it will be surrounded by single quotation marks (”). The getQueryString() method lets you copy most queries from the log and paste them without modification into an interactive SQL processor for testing and debugging. You can revise the method as needed to convert the parameter values of other classes.

Listing 5. The saveQueryParamValue() method

private void saveQueryParamValue(int position, Object obj) {
      String strValue;
      if (obj instanceof String || obj instanceof Date) {
           // if we have a String, include '' in the saved value
           strValue = "'" + obj + "'";
      } else {
           if (obj == null) {
                // convert null to the string null
                 strValue = "null";
           } else {
                // unknown object (includes all Numbers), just call toString
                strValue = obj.toString();
           }
      }
      // if we are setting a position larger than current size of
      // parameterValues, first make it larger
      while (position >= parameterValues.size()) {
           parameterValues.add(null);
      }
      // save the parameter
      parameterValues.set(position, strValue);
 }

When all parameters are set using the standard methods, we simply call the getQueryString() method on our LoggableStatement to get the query string. All the question marks will be replaced by real parameter values, which are ready for output to our chosen logging destination.

Using LoggableStatement

Listing 6 shows how the code in Listings 1 and 2 has been changed to use LoggableStatement. Introducing LoggableStatement into our application code solves the problem of duplicated parameter variables. When a change is made to the SQL template, we only have to update the parameter setting calls (for example, add a pstmt.setString(3,"new-param-value")) on the PreparedStatement. The change will be reflected in the logging output without any manual updates to the logging code.

Listing 6. LoggableStatement at work

String sql = "select foo, bar from foobar where foo < ? and bar = ?";
    long fooValue = 99;
    String barValue = "christmas";

    Connection conn = dataSource.getConnection();
    PreparedStatement pstmt;

    if(logEnabled) // use a switch to toggle logging.
        pstmt = new LoggableStatement(conn,sql);
    else
        pstmt = conn.prepareStatement(sql);

    pstmt.setLong(1,fooValue);
    pstmt.setString(2,barValue);

    if(logEnabled)
       System.out.println("Executing query: "+
         ((LoggableStatement)pstmt).getQueryString());

    ResultSet rs = pstmt.executeQuery();

Conclusion

With the simple steps outlined in this article, you can extend the JDBC PreparedStatement interface for query logging. The technique we’ve used here can be thought of as “extension by wrapping” or as an instance of the Decorator design pattern. Extension by wrapping is useful in situations where you must extend the API but subclassing isn’t an option.

You will find the source code for the LoggableStatement class in the Download section. You can either use it as is, or customize it for the particular needs of your database application.

Download

j-loggable.zip