Tuesday, March 11, 2014

Supporting World War Cthulhu

There's a campaign on indiegogo.

Monday, March 10, 2014

SQLExceptions have nested exceptions

A while ago, I created a high performance program to create thousands of records. The exact number depends on the existing data. Recently the program failed for a database. It happens. The error log wasn't very useful, unfortunately. The trouble was I used SQL batch processing to speed up the program, but all that showed up was:
ERROR: [jcc][t4][102][10040][4.11.69] Batch failure. The batch was submitted, but at least one exception occurred on an individual member of the batch.
Use getNextException() to retrieve the exceptions for specific batched elements. ERRORCODE=-4229, SQLSTATE=null
com.ibm.db2.jcc.am.BatchUpdateException: [jcc][t4][102][10040][4.11.69] Batch failure. The batch was submitted, but at least one exception occurred on an individual member of the batch.
Use getNextException() to retrieve the exceptions for specific batched elements. ERRORCODE=-4229, SQLSTATE=null
at com.ibm.db2.jcc.am.gd.a(gd.java:404)
at com.ibm.db2.jcc.am.o.a(o.java:365)
at com.ibm.db2.jcc.am.kn.a(kn.java:4375)
at com.ibm.db2.jcc.am.kn.c(kn.java:4156)
at com.ibm.db2.jcc.am.kn.executeBatch(kn.java:2436)
at com.ibm.tivoli.maximo.dbmanage.connection.LoggingPreparedStatement.executeBatch(LoggingPreparedStatement.java:768)
at com.ibm.tivoli.maximo.integrity.repair.RefillAncestorTable.executeAncInsert(RefillAncestorTable.java:445)
The actual problem wasn't shown but at least the error message gave me a hint of what I needed to do.
        catch (Exception e)
        {
            e.printStackTrace();
            // handle exceptions found under SQLExceptions
            if (e instanceof SQLException)
            {
                SQLException se = (SQLException) e ;
                
                SQLException sub = se.getNextException() ;
                while (sub != null)
                {
                    sub.printStackTrace() ;
                    sub = sub.getNextException() ;
                }
            }
        }
When I ran with this, I got multiple time out errors because the table was locked. We restarted the database and we could run again to reproduce the original problem. 

But that code is incomplete, since each SQLException can have a Throwable cause. An IOException could be the cause of a SQLException, for example. I ended up creating a method that would print stack traces of all the exceptions. I tried to copy the format of the printStackTrace method.
    public static String listException(Throwable t)
    {
        return listException(t,-1) ;
    }
    
    private static String listException(Throwable t, int numStackRows)
    {
        StringBuilder ret = new StringBuilder() ;
        if (t != null)
        {
            // show the top exception
            // exception message
            ret.append(((Throwable) t).getMessage()).append("\n") ;
            // exception stack trace (full)
            ret.append(listStackTraceElements(t.getStackTrace(), numStackRows)) ;
            
            // support showing the nested cause or nested exceptions, if SQLException
            Throwable sub = t.getCause() ;
            if (sub != null)
            {
                ret.append("Caused by: ") ;
                ret.append(listException(sub, SUBTRACESIZE)) ;
            }
            else if (t instanceof SQLException)
            {
                // get the sub-batch exceptions
                SQLException se = (SQLException) t ;
                LinkedList batchErrs = new LinkedList() ;
                SQLException chainedExp = se.getNextException() ;
                while (chainedExp != null)
                {
                    batchErrs.add(chainedExp) ;
                    chainedExp = chainedExp.getNextException() ;
                }
                
                // output depends on # of exceptions while in batch
                int numBatchE = batchErrs.size() ;
                
                if (numBatchE == 1)
                {
                    // only one
                    SQLException batchExp = batchErrs.getFirst() ;
                    ret.append("Error in SQL Batch: ").append(batchExp.getMessage()).append("\n") ;
                    ret.append(listStackTraceElements(batchExp.getStackTrace(), SUBTRACESIZE)) ;
                }
                else if (numBatchE > 1)
                {
                    // multiple
                    int i = 0 ;
                    for (SQLException be: batchErrs)
                    {
                        i++ ;
                        ret.append("Error in SQL Batch, ").append(i).append(" of ").append(numBatchE).append(": ").append(be.getMessage()).append("\n") ;
                        ret.append(listStackTraceElements(be.getStackTrace(), SUBTRACESIZE)) ;
                    }
                }
            }
        }
        return ret.toString() ;
    }

    private static String listStackTraceElements(StackTraceElement[] stackTrace, int numRows)
    {
        StringBuilder ret = new StringBuilder() ;
        
        int i = 0 ;
        for (; (i < stackTrace.length) && (i != numRows); i++)
        {
            StackTraceElement trc = stackTrace[i] ;
            ret.append(TAB).append("at ").append(trc.getClassName()).append('(').append(trc.getFileName()).append(": ") ;
            int lineNum = trc.getLineNumber() ;
            if (lineNum < 1)
            {
                ret.append("Native Method") ;
            }
            else
            {
                ret.append(lineNum) ;
            }
            ret.append(')') ;
            ret.append("\n") ;
        }
        
        if (i < stackTrace.length)
        {
            // Stack Trace was cut off
            ret.append(TAB).append("... ").append(stackTrace.length - i).append(" more").append("\n") ;
        }

        return ret.toString() ;
    }

The catch code is then much cleaner:
        catch (Exception e)
        {
            String expStr = AppenderAdapter.listException(e) ;
            System.out.println(expStr) ;
            out.println(expStr) ;
            
            throw e;
        }

Friday, March 7, 2014

Found performance issue when inserting data using batches.

I have a program that creates a great number of records. The number of records created depends on the existing data, but in one case this was 1.4 million records. For performance, I used a PreparedStatement executing 5000 inserts at a time. A simplified version of my code is below.

PreparedStatement ps = con.prepareStatement("insert into personancestor (ancestor, personid, hierarchylevels, personancestorid) values (?,?,?,nextval for personancestorseq)") ;
int useCount = 0;
for (int i = 0; i < 30000; i++)
{
  ps.setString(1, "ANC" + i)  ;
  ps.setString(2, "PER" + i)  ;
  ps.setInt(3, 1) ;
  ps.addBatch() ;
  useCount++ ;
  if (useCount >= 5000)
  {
    ps.executeBatch() ;
    //ps.clearBatch() ; - this doesn't help performance

    // close and reprepare the statement to clear the data inserted earlier.
    ps.close() ;
    ps = con.prepareStatement("insert into personancestor (ancestor, personid, hierarchylevels, personancestorid) values (?,?,?,nextval for personancestorseq)") ;
    con.commit()  ;
    useCount = 0 ;
    Date nd = new Date() ;
    System.out.println("5000 inserts in " + (nd.getTime() - d.getTime()) + " ms. " + (i+1) + " total inserts.") ;
    d = nd ;
  }
}
if (useCount > 0)
{
 ps.executeBatch() ;
}
ps.close() ;
con.commit() ;
con.close() ;

I found that if I didn't re-prepare the statement, then apparently all the previous rows remain in memory. The inserts take longer and longer, until the program is just hung. Calling the PrepareStatement's clearBatch method had no effect. I was connecting to a DB2 database using the com.ibm.db2.jcc.DB2Driver class, and I don't know if this is a problem with just the DB2 connection, or this is expected behavior or not.
After fixing the data, I was able to create 1.4 million records in about 20 minutes.