log4jdbc - Invalid operation: result set is closed - DB2 JCC Driver

While troubleshooting a "resultset is closed" issue, the immediate thing that came into mind is the DB2 JCC driver's default behavior of implicitly closing the ResultSet upon find that the cursor has been placed after the last row (ie the result set has exhausted). And calling ResultSet.next() on such a state will throw the exception stating "resultset is closed". As in my previous post, DB2 provides a workaround to tolerate the call next() on exhausted resultset by setting the property allowNextOnExhaustedResultSet = 1.  But in the current case, it is not the next() that was causing the problem and instead the call to ResultSet.getMetaData() after the ResultSet has been exhausted. But who calls this getMetaData on a already closed resultset? From the exception stack, we noticed the application has been plugged in with the log4jdbc for monitoring the JDBC operations and it is the log4jdbc invoking the getMetaData() at an in-appropriate time which the DB2 JCC driver does not like.

Further digging into log4jdbc, we discovered that the stack of log4jdbc might correspond to version 1.12 or less. And from version 1.13 and above they have a fix for this problem where they verify if the resultset is usable by calling rs.isClosed() check before invoking the getMetaData() call. And there seems to be an issue with the isClosed() API when DB2 implicitly closes the ResultSet which is addressed by a WebSphere datasource custom property resultSetUnusableWhenNoMoreResults="true". So the problem can be resolved by upgrading the log4jdbc to a higher version along with the WebSphere datasource custom property resultSetUnusableWhenNoMoreResults="true".

com.ibm.db2.jcc.am.SqlException: [jcc][t4][10120][10898][3.65.131] Invalid operation: result set is closed. ERRORCODE=-4470, SQLSTATE=null
    at com.ibm.db2.jcc.am.kd.a(Unknown Source)
    at com.ibm.db2.jcc.am.kd.a(Unknown Source)
    at com.ibm.db2.jcc.am.kd.a(Unknown Source)
    at com.ibm.db2.jcc.am.ResultSet.checkForClosedResultSet(Unknown Source)
    at com.ibm.db2.jcc.am.ResultSet.getMetaDataX(Unknown Source)
    at com.ibm.db2.jcc.am.ResultSet.getMetaData(Unknown Source)
    at com.ibm.ws.rsadapter.jdbc.WSJdbcResultSet.getMetaData(WSJdbcResultSet.java
    at net.sf.log4jdbc.DefaultResultSetCollector.getMetaDataIfNeeded(DefaultResultSetCo
    at net.sf.log4jdbc.DefaultResultSetCollector.methodReturned(DefaultResultSetCollecto
    at net.sf.log4jdbc.ResultSetSpy.reportAllReturns(ResultSetSpy.java:89)
    at net.sf.log4jdbc.ResultSetSpy.reportReturn(ResultSetSpy.java:159)
    at net.sf.log4jdbc.ResultSetSpy.next(ResultSetSpy.java:1998)
    at org.hibernate.loader.Loader.processResultSet(Loader.java:950)

Disclaimer: These are my personal views and does not reflect my employer in any way!!

Invalid operation: result set is closed.

 The following exception can occur with the DB2 JCC Driver when calling rs.next() after the cursor has been positioned after the last row of the ResultSet.

  Invalid operation: result set is closed. ERRORCODE=-4470, SQLSTATE=null
    at com.ibm.db2.jcc.am.bd.a(bd.java:663)
    at com.ibm.db2.jcc.am.bd.a(bd.java:60)
    at com.ibm.db2.jcc.am.bd.a(bd.java:103)
    at com.ibm.db2.jcc.am.ResultSet.checkForClosedResultSet(ResultSet.java:4528)
    at com.ibm.db2.jcc.am.ResultSet.nextX(ResultSet.java:329)
    at com.ibm.db2.jcc.am.ResultSet.next(ResultSet.java:308)
    at com.ibm.ws.rsadapter.jdbc.WSJdbcResultSet.next(WSJdbcResultSet.java:3110)

The following snippets can help to get a better understanding of why this error occurs.

db2> create table test(col1 varchar(10) ) ; // let us leave the table empty with no rows.

try {
            Context ctx = new InitialContext();
            DataSource ds = (DataSource)ctx.lookup("jdbc/db2");
            Connection con = ds.getConnection();           
            PreparedStatement pstmt = con.prepareStatement("select * from test");
            ResultSet rs  = pstmt.executeQuery();
            rs.next(); // this implicitly closes the ResultSet as there are no rows in the table test
            rs.next(); // this will result in the SQLException : Invalid operation: result set is closed.
      }   catch (Exception e){  }

As per the above code snippet, DB2 JCC Driver closes the result set implicitly when it find no more rows in the ResultSet and this is their default behavior. Hence calling ResultSet.next() on a closed resultset can lead to the exception "Invalid operation: result set is closed". 

 To get around this problem the jcc driver provides a property named "allowNextOnExhaustedResultSet" that can be set on the datasource as custom property in WAS.  Setting allowNextOnExhaustedResultSet = 1 ensures that ResultSet.next() returns false if the cursor was previously positioned after the last row of the ResultSet.

In the tWAS environment the property can be set as a datasource custom property and be sure to set the type as Integer and the value as 1. For liberty you can define the property in the server.xml like below:
<dataSource id="DB2" jndiName="jdbc/db2">                         
     <jdbcDriver libraryRef="DB2JCC4Lib"/>                        
     <properties.db2.jcc databaseName="SAMPLE" password="password" 
      portNumber="50000" serverName="localhost" user="user"
      allowNextOnExhaustedResultSet="1" />                       
</dataSource>                                                     

Disclaimer: These are my personal views and does not reflect my employer in any way!!