Perils of using an elderly FitLibrary

I learned about a really useful tool today while trying to hunt down a bug in a set of Fit automated acceptance tests.

Last September, my colleague Darren Bishop had set up the automated acceptance test infrastructure for a Maven/Java project I subsequently joined. He used version 20080812 of the Maven dependency (org.fitnesse.fitlibrary), probably because it was the latest available in the Maven Central repository. Thus the stage was set for my troubles last night and this morning!

While working on a small enhancement with a developer in the customer's product support unit, I noticed that one of the Fit tests was producing a blank report and not being counted in the summary totals. A comparison with other spreadsheets that did run properly revealed no significant differences.

Back at base, it quickly became apparent that I had to single-step through the program to find out where it was going wrong. But I could find no source jar for this version of fitlibrary - the latest dependency version available with source was from 2006. What to do?

After a futile attempt to desk-walkthrough the code of FolderRunner and SpreadsheetRunner, Keith Braithwaite suggested decompiling the class files. JD-Eclipse to the rescue! I installed it in my Eclipse and found it so insanely useful that I will never want to be without it again. Basically it creates beautifully formatted source code for you on demand (obviously without the programmer's original comments and documentation). This means that you can set breakpoints and single-step through library code even if you have no source attachment for your library. Installation was really easy. After that, if you single-step into a library method, the "source" is opened automatically. You can also open a .class file directly in the package explorer by browsing the libraries on your project's build path.

There's just one slight gotcha: the line numbers in the decompiled code rarely match the original, so if the class file contains line number annotations your instruction pointer and breakpoints may appear to be a few lines away from the location reported in the debugger's thread view. Ignore the cursor and read off the current line number from the comment at the start of each line. You can turn off the display of metadata and line numbers in the JD preferences, and I have done so - it needs a restart of Eclipse to take effect, but setting breakpoints is much easier afterwards.

So, what was the solution to the mystery?

In the FitLibrary class SpreadsheetRunner, the method collectTables() used an Iterator to return the rows of the test script one at a time and convert them into arrays of values that the runner could subsequently invoke to execute the test:

HSSFRow row = (HSSFRow)it.next();
HSSFCell[] cells = getCells(row);
String[] borderedCellValues = getBorderedCellValues(cells, workbook);

Unfortunately, getCells() dimensioned an array of HSSFCell objects using the value returned by a row:

private HSSFCell[] getCells(HSSFRow row) {
int maxCell = row.getLastCellNum();
HSSFCell[] cells = new HSSFCell[maxCell];
...
return cells;
}

When the row was "empty", getLastCellNum() returned -1, which caused the next line to throw a NegativeArraySizeException. This exception was caught by FolderRunner.runFile(), which attempted to report the problem to the standard output, but this didn't appear in the Maven test log.

I have not found out what makes POI decide that a row is "empty". There was only a single spreadsheet row in the entire suite of tests that was interpreted in this way. I achieved a workaround by pasting a copy of another blank row of cells onto this row, but the danger is that anyone could inadvertently reintroduce the error.

Lessons:

• You can still use the Java debugger if you don't have the source. JD-Eclipse worked very well for me, even though it is only at version 0.1.3. (I wonder if it will decompile classes written in other languages such as JRuby?)
  


• It's time someone made a proper Maven dependency, with sources and javadoc, of the latest Fit, Fitnesse and FitLibrary versions - the current version of FitLibrary, dated April 5th, 2011 in fact solves the exact problem I encountered!
  

File Handles in the JVM

I recently spent three or four fruitless hours (spread across several days) trying to get a bunch of Fit tests to run reliably. The setup fixture was used to clean out the folders in which the program under test was intended to find its input data and write its output data. Subsequent fixtures created the input files, executed the program under test, and analysed the output files.

So far so good, but as the number of tests gradually increased we started to get failures apparently at random. I suspected that the setup fixture was not deleting all the files out of the input and output folders, so increased the rigour of this method by invoking the FileUtils deleteDirectory method and throwing a runtime exception if it failed even after five retries.

It turned out that this was frequently failing because some process was keeping file handles open on files within the test folder hierarchy. Under Windows, this prevents the containing folder from being deleted or moved. We suspected virus checkers, search indexers and the like, but it turned out to be the Fit test harness itself. Even though we had taken great care to flush and close every file stream used by our Fit fixtures, the VM was not always releasing the corresponding file handles and so the next invocation of the setup fixture failed.

The answer turned out to be surprisingly simple: invoke the garbage collector and finalizer before retrying the call to deleteDirectory. Now it works every time!

Code sample:

...
import static org.apache.commons.io.FileUtils.deleteDirectory;
...
    public static void zapDirectory(String path) {
        ...
        File directory = new File(path);
        for (int i = RETRY_COUNT; directory.exists(); i--) {
            try {
                deleteDirectory(directory);
            } catch(IOException e) {
                if (i <= 0) {
                    throw new RuntimeException("Cannot delete folder \"
                        + path + "\" because: " + e.getMessage());
                }
                try {
                    System.gc();
                    System.runFinalization();
                    Thread.sleep(SLEEP_INTERVAL);
                } catch(InterruptedException e1) {
                    // don't care if interrupted
                }
            }
            if (directory.exists()) {
                throw new RuntimeException("Cannot delete folder \"
                    + path + "\" for an unknown reason");
            }
        }
    }