REVERT TO CONSOLE

I recently had to write a batch process in Java using Hibernate and Spring – a real standalone application with a main() and everything. This has been a fairly unique experience for me, since I normally work within an application; with only one logger, with a shared Spring applicationContext.xml, etc. The following outlines what I did in all it’s glory…

This stand alone batch process had to process roughly 1.5 million rows of data, with calls to multiple tables for each. The application relied on a lot of code that I hadn’t written, mysteriously wrapped into a rather ambiguously decoupled “tool”.

Originally the code that I inherited processed the entire batch in memory. The application would flow roughly like this:

1. Retrieve the list of everything to be processed – this made use of Spring’s jdbcTemplate to perform the query.
2. Iterate over the list and process each- this was done via several Hibernate selection statements, and returned a list of objects to be updated.
3. Perform update using Spring’s BatchSqlUpdate.

You can see that this process isn’t using the traditional Hibernate batching described in the documentation. Rather, it uses Hibernate to perform the queries, and Spring to perform the batching. This, unfortunately, makes it a little harder to tune for performance.

This design had two major issues with it up front:

1. It would need to be modified to run through a subset of those rows that produced errors the first time.
2. The performance was awful. My rough calculations concluded it would take 8 months to run on my desktop- if I could avoid OutofMemoryErrors.

The next design was an attempt to mitigate both of the issues from the first. I retrieved a flat file list of the 1.5 million rows to run through, and split them into separate files of 1000 each:
> split -l 1000 -a 3 bigfile fileprefix

I then wrote several shell scripts to read in the files in order, build the classpath and call my Java app on each, and move the log files to avoid overwriting them. I’m not particularly good at shell scripting so I’m not going to elaborate on how I did that. But to break down the new design into a few easy steps, it then looked like this:

1. Find the next file to process
2. Call the Java app and send it the file
3. Iterate over the list, retrieve each row and process
4. Perform post-update processing
5. Move produced logs

This resulted in immediate improvements to the performance. For one, by breaking up the Java app from doing everything in memory to reading from a file of 1000, I took care of the OutofMemoryException. Secondly, I modified the process in such a way that I produced a list of error rows that could be run again at a later time (after they’re fixed). This sped up the batch process significantly, going from approximately 8 months to approximately 48 days. This was good, but not nearly good enough.
Over the course of the next week I eventually found several issues that impacted performance:

• The JVM heap settings. I had inadvertantly removed them when I first started hacking up the application design. Here’s an example of what the app originally looked like in the JProbe memory debugger:
  In this picture, the yellow represents memory allocated by the JVM, blue represents memory being used by the application. You can see that the memory gradually increases, and when it reaches a certain threshold, the JVM responds by allocating more memory. The problem with this is that it takes a significant amount of time to allocate more memory, and it can be avoided by something simple like -Xms16m -Xmx64m.
• Nothing is quite as fun as finding a known bug in an Oracle driver. Unfortunately, I don’t have a link to provide you with exactly what this bug is, all I have is a note from the DBA, “You hit a bug in the 10g JDBC that we’re familiar with and Oracle is not offering up a date for a fix. We’re not globally discouraging the use of the 10g JDBC because this bug happens only with bind variables and certain outer joins — some applications don’t have both conditions.
  Stay with the 9i JDBC so you can use prepared statements.” When I switched to using 9i, I lopped 10 seconds off of every retrieval call. Just like magic! I wish I knew exactly what the conditions were for this.
• The previous two bullets definitely improved performance, but I was still left with a memory leak. The issue, I found, was in the Hibernate 1st level caching. I added a few lines of code to the end of each row process:

                while( iter.hasnext() ) {
                   ....do stuff.....
                   Session session = (Session)sessionFactory.getCurrentSession();
                   session.flush();
                   session.clear();
                          }

This is what ultimately took care of the memory leak. The resulting memory graph looked like this:

Much better!

At this point my estimates show it will take about 6 days to run on my desktop, that’s a marked improvement over 48.

That’s the report from this point, next I’ll post more on ehcache.