Monday, April 16, 2007

FindBugs - Writing custom detectors (Part 1)

Some words in advance...

Recently I wrote about multi-threading problems with java.util.Calendar and java.text.DateFormat. The last sentence was So maybe it is time to search your code for all static usages of the Calendar and various ...Format classes, before you start getting strange errors.

Searching code is not very practical, especially if you do it manually. Everyone knows you can look at code for hours, without seeing an problem - and as soon as it has reached production systems it starts breaking up in various ways :-)

Fortunately smart and reknown people have devised ways of making the computer look for bugs automatically. Amongst others, FindBugs is a very nice - and free - tool that analyzes your Java application's compiled bytecode and looks for numerous so called bug patterns. Those patterns are divided into categories, such as "Bad practice", "Correctness", "Multithreaded correctness", "Performance" and some more. Each of them looks for a specific kind of error people tend to make in their programs. While there are a lot (close to 300 if I remember correctly) of patterns included with the release you can download, not every bug you find will be covered by one of them. Luckily, as FindBugs is free software, you can add you own "detectors" to it if you encounter something you believe is lurking around in your (and other people's) code.

In case you are completely knew to FindBugs or the idea of static code analysis in general, go have a look at a Google Tech Talk by Bill Pugh, one of the minds behind FindBugs. You should then go and download the latest version and run it against you code. You will be amazed on what (sometimes stupid) mistakes you will find.

Because I had some problems finding a good howto on writing bug detectors, I decided to write one myself. The only (hands on, step by step) source I found was a tutorial on developers.net. When you read on, you will probably find some parallels to that article, however I believe it is good to have one more example. After I started writing I decided to split the tutorial in two, because it was growing too long. This first part is about detecting the declaration of static Calendar or DateFormat fields. The second will be about finding invocations on static instances, which is a little bit trickier. For the impatient, you can go grab the latest trunk revision from the FindBugs repository on Google Code. You will find the my detector there, because to my pleasure it was included in the official distribution. It will probably be deactivated by default in the upcoming 1.2.0 release, because it was already in the release candidate stages when I submitted my patch. You will be able to try it out, however I will use the time and try and improve it a little more.

The howto...

But now, let's get to it.

Something to think about

Imagine you want to write a simple utility class that allows you to format java.util.Date objects to a specific display format. java.text.SimpleDateFormat is ideal for the job. Because the format is going to be the same for all dates you pass to the getFormattedDate() method, you employ a static instance of the formatter to save some resources. To make sure everything works a you expect, you use some assertions:

import java.text.SimpleDateFormat;
import java.util.Calendar;
import java.util.Date;


public class BadCalendar {
    /** common formatter, displays just the time */
    static SimpleDateFormat formatter = new SimpleDateFormat("HH-mm-ss");
    
    /** 
     * Format the given date according to the predefined pattern.
     * @param aDate the date to be formatted (just the time is used)
     * @return formatted time String
     */
    public static String getFormattedDate(Date aDate) {
        return formatter.format(aDate);
    }

    public static void main(String[] args) {
        String formatted;
        Calendar cal = Calendar.getInstance();
        
        cal.set(2007, Calendar.JANUARY, 01, 01, 01, 01);
        formatted = getFormattedDate(cal.getTime());
        assert formatted.equals("01-01-01");
        
        cal.set(2007, Calendar.JANUARY, 01, 01, 01, 02);
        formatted = getFormattedDate(cal.getTime());
        assert formatted.equals("01-01-02");
        
        cal.set(2007, Calendar.JANUARY, 01, 01, 01, 03);
        formatted = getFormattedDate(cal.getTime());
        assert formatted.equals("01-01-03");
    }
}

Running this program will yield no result, i. e. the assertions are ok (remember you have to use the -enableassertions parameter to have them actually executed. You change one of the assertions so that it must fail, to verify they are working.). You might add more test cases to make absolutely sure that there is no bug lurking in this code. You may in fact be perfectly comfortable that this class is bug free in itself.

Now, as we now know that the formatting works, let's put it to some use:

import java.text.SimpleDateFormat;
import java.util.Date;
import java.util.Random;


public class BadCalendar2 {
    static SimpleDateFormat formatter = new SimpleDateFormat("HH-mm-ss");
    
    
    public static String getFormattedDate(Date aDate) {
        return formatter.format(aDate);
    }
    
    public static void main(String[] args) {
        for (int i = 0; i < 10; i++) {
            Worker worker = new Worker();
            worker.setName("Thread " + i);
            worker.start();
        }
    }
}


class Worker extends Thread {
    private Random random = new Random();
    
    public void run() {
        long quitBy = System.currentTimeMillis() + 20000L; // in 20s
        while (System.currentTimeMillis() < quitBy) {
            // 1970-01-01 < date < 1970-01-02
            Date date = new Date(random.nextInt(86400000));
            String result = BadCalendar2.getFormattedDate(date);
            try {
                // simulate some real work of varying length
                System.out.println(getName() + " working..." + result);
                Thread.sleep(random.nextInt(500));
            } catch (InterruptedException e) {
                ; // ignore
            }
        }
    }
}

The Worker class in this example simulates some work that takes between 0 and 500ms. Part of this work is to print a random timestamp, formatted using the getFormattedDate() method from BadCalendar. When you run it, it will work for 20 seconds and then finish. The output looks like this:

...
Thread 0 working...14-51-02
Thread 6 working...18-08-00
Thread 7 working...01-38-54
Thread 8 working...04-46-19
Thread 9 working...04-59-00
Thread 4 working...13-16-49
Thread 8 working...05-00-37
Thread 7 working...18-43-29
Thread 2 working...15-51-10
Thread 5 working...11-52-46
Thread 0 working...05-23-37
Thread 4 working...03-39-22
...

Looks good, doesn't it? Nicely formatted time values. However if you were to use this kind of date formatting utility in a real world application you might get weird error reports from your customers, complaining about times they never entered or even some random, not reproducible ArrayIndexOutOfBoundsExceptions. While the first part of this might be explained by mistakes users make entering dates they shouldn't be able to produce the exceptions in this code, should they?

Having a closer look at the SimpleDateFormat JavaDoc reveals this paragraph:

Date formats are not synchronized. It is recommended to create separate format instances for each thread. If multiple threads access a format concurrently, it must be synchronized externally.

Now that sounds suspicious. Usually you wouldn't read the JavaDoc of a class so simple and so well-known (at least I did not). So maybe we can verify if we have a multi-threading problem by double-checking the values the formatter returns:

import java.text.SimpleDateFormat;
import java.util.Date;
import java.util.Random;


public class BadCalendar2 {
    static SimpleDateFormat formatter = new SimpleDateFormat("HH-mm-ss");
    
    
    public static String getFormattedDate(Date aDate) {
        return formatter.format(aDate);
    }
    
    public static void main(String[] args) {
        for (int i = 0; i < 10; i++) {
            Worker worker = new Worker();
            worker.setName("Thread " + i);
            worker.start();
        }
    }
}


class Worker extends Thread {
    private Random random = new Random();
    
    public void run() {
        long quitBy = System.currentTimeMillis() + 20000L; // in 20s
        while (System.currentTimeMillis() < quitBy) {
            // 1970-01-01 < date < 1970-01-02
            Date date = new Date(random.nextInt(86400000));
            String result = BadCalendar2.getFormattedDate(date);
            SimpleDateFormat myDateFormat = new SimpleDateFormat("HH-mm-ss");
            String myResult = myDateFormat.format(date);
            try {
                // simulate some real work of varying length
                if (myResult.equals(result)) {
                    System.out.println(getName() + " working... ok:" + result);
                } else {
                    System.out.println(getName() + " working... fail: " + result + " != " + myResult);
                }
                       
                Thread.sleep(random.nextInt(500));
            } catch (InterruptedException e) {
                ; // ignore
            }
        }
    }
}

Running this will turn out something like:

...
Thread 9 working... ok:05-58-52
Thread 7 working... ok:02-49-29
Thread 2 working... ok:09-14-50
Thread 0 working... ok:07-27-27
Thread 6 working... fail: 07-27-27 != 03-01-43
Thread 5 working... ok:21-37-10
Thread 0 working... ok:00-10-40
Thread 5 working... ok:12-32-35
Thread 2 working... fail: 12-32-35 != 11-34-26
Thread 3 working... ok:05-16-31
Thread 0 working... ok:16-46-49
Thread 9 working... ok:16-39-35
Thread 8 working... ok:23-42-52
Thread 7 working... ok:07-39-06
Thread 6 working... ok:11-23-54
Thread 5 working... ok:04-24-50
Thread 1 working... ok:07-55-40
...

So we indeed get different results from what we would expect. Looking closer at the implementation of SimpleDateFormat reveals that it uses a Calendar internally. As those are not thread-safe (even though their documentation does not mention this, see Sun Bug #6178997) we get messed up results. So it's clearly good advise not to share the static instance of the formatter across thread boundaries. Instead, one should use an instance per Thread or at least synchronize access to the shared one.

What to do?

This is a very subtle kind of bug, nothing you will find just by reading the code. It looks perfectly alright unless you or someone in your team took a closer look at the documentation and knew about this particular issue. But there are different things and you will come across one that neither you nor someone near you has seen before. And it is very likely to make the same mistake again, perhaps not now, but in a few weeks or months. Tracking the problem down will be difficult again.

People's minds have a somewhat limited capacity, and people have limited time to look for errors - they are needed to get the programming done. What about leaving the recurring, tedious tasks to someone - something - that can do it better and faster? Enter code analysis software, e. g. FindBugs.

As far as I could see, there was no particular bug pattern detector for this special kind of problem in the downloadable FindBugs package. Creating a new one requires some knowledge about the byte code level and what to look for in it. The problem at hand could be described like this:

  • a static field of type java.util.Calendar or a subclass thereof
  • a static field of type java.text.DateFormat or a subclass thereof
  • method calls on static instances of java.util.Calendar or a subclass thereof
  • method calls on static instances of java.text.DateFormat or a subclass thereof

The general idea of a detector is to find certain patterns in the bytecode of a class. To do so it will read the .class files and put them through pattern matchers that are implemented using the visitor pattern. While reading it will call appropriate visitor methods, depending on what element (method, field declaration etc.) is at hand. Writing a detector means implementing one or more of those methods, building up an idea about what the class is intended to do. The framework behind this is the Apache Bytecode Engineering Library.

Looking at some of the existing detectors can help to get an idea about the concept, however I found it easier to start fresh with an initially empty subclass of edu.umd.cs.findbugs.BytecodeScanningDetector. First thing to override is the visit(Field) method - after all this is to find field declarations.

@Override
public void visit(Field aField) {
    super.visit(aField);
}

Upon visiting a field there are some things to be done:

  • Check if the field is declared static, otherwise it is of no interest. This is easily done: The Field object that is passed into the visit method knows about this.
  • Check if the field's type is an object (in contrast to a primitive int, for example). This is also easy: the Field can tell its type.
  • If it is an object, check if it's defined as a Calendar/DateFormat or a subclass. This needs something to compare to. There is an ObjectTypeFactory that can be used to create an appropriate object for Calendars and DateFormats.
  • If all of this is true, issue a warning, otherwise ignore the field

This is what code looks like:

import java.text.DateFormat;
import java.util.Calendar;
import java.util.HashMap;
import java.util.Map;

import org.apache.bcel.classfile.Code;
import org.apache.bcel.classfile.Field;
import org.apache.bcel.classfile.JavaClass;
import org.apache.bcel.generic.ObjectType;

import edu.umd.cs.findbugs.BugInstance;
import edu.umd.cs.findbugs.BugReporter;
import edu.umd.cs.findbugs.BytecodeScanningDetector;
import edu.umd.cs.findbugs.ba.ObjectTypeFactory;


/**
 * Detector for static fields of type {@link java.util.Calendar} or
 * {@link java.text.DateFormat} and their subclasses. Because {@link Calendar}
 * is unsafe for multithreaded use, static fields look suspicous. To work
 * correctly, all access would need to be synchronized by the client which
 * cannot be guaranteed.
 * 
 * @author Daniel Schneller
 */
public class StaticCalendarDetector extends BytecodeScanningDetector {

    /** External Debug flag set? */
    private static final boolean DEBUG = Boolean.getBoolean("debug.staticcal");

    /** The reporter to report to */
    private BugReporter reporter;

    /** Name of the class being inspected */
    private String currentClass;

    /** {@link ObjectType} for {@link java.util.Calendar} */
    private final ObjectType calendarType = ObjectTypeFactory.getInstance("java.util.Calendar");

    /** {@link ObjectType} for {@link java.text.DateFormat} */
    private final ObjectType dateFormatType = ObjectTypeFactory.getInstance("java.text.DateFormat");

    /** Constant for types of fields */
    private static final int TYPE_UNDEFINED = 0;

    /** Constant for types of fields */
    private static final int TYPE_CALENDAR = 1;

    /** Constant for types of fields */
    private static final int TYPE_DATEFORMAT = 2;


    /** ProgramCounter of the last seen  {@link org.apache.bcel.generic.GETSTATIC} call to a {@link Calendar} */
    private int seenStaticGetCalendarAt;

    /** ProgramCounter of the last seen  {@link org.apache.bcel.generic.GETSTATIC} call to a {@link DateFormat} */
    private int seenStaticGetDateFormatAt;

    /**
     * Map of stores of a static {@link Calendar} instance to a register.
     * Keys: Registers, Values: ProgramCounters
     */
    private Map<Integer, Integer> registerStaticStoreCalendarAt = new HashMap<Integer, Integer>();

    /**
     * Map of stores of a static {@link DateFormat} instance to a register.
     * Keys: Registers, Values: ProgramCounters
     */
    private Map<Integer, Integer> registerStaticStoreDateFormatAt = new HashMap<Integer, Integer>();

    /**
     * Remembers the class name
     */
    @Override
    public void visit(JavaClass someObj) {
        currentClass = someObj.getClassName();
        super.visit(someObj);
    }

    /**
     * Checks if the visited field is of type {@link Calendar} or
     * {@link DateFormat} or a subclass of either one. If so and the field is
     * static it is suspicious and will be reported.
     */
    @Override
    public void visit(Field aField) {
        super.visit(aField);
        if (!aField.isStatic()) return; // exit early on non-static fields
        Object fieldtype = aField.getType();
        if (!(fieldtype instanceof ObjectType)) return; // exit early on non-object fields

        ObjectType objecttype = (ObjectType)fieldtype;
        int tTyp = TYPE_UNDEFINED;
        try {
            if (objecttype.subclassOf(calendarType)) {
                tTyp = TYPE_CALENDAR;
            } else if (objecttype.subclassOf(dateFormatType)) {
                tTyp = TYPE_DATEFORMAT;
            }
        } catch (ClassNotFoundException e) {
            ; // ignore
        }

        String typeForMessage;
        switch (tTyp) {
        case TYPE_CALENDAR:
            typeForMessage = "STCAL_STATIC_CALENDAR_INSTANCE"; // as in findbugs.xml
            break;
        case TYPE_DATEFORMAT:
            typeForMessage = "STCAL_STATIC_SIMPLE_DATE_FORMAT_INSTANCE"; // as in findbugs.xml
            break;
        default:
            typeForMessage = null;
            break;
        }
        if (typeForMessage != null) {
            reporter.reportBug(new BugInstance(this, typeForMessage, NORMAL_PRIORITY).addClass(currentClass).addField(
                    currentClass, aField.getName(), aField.getSignature(), true));
        }
    }

This is everything that needs to be coded to implement the detection of static fields of one of the types we are interested in. In order to include this in a FindBugs sweep it needs to be packaged as a FindBugs plugin. This requires two more files: findbugs.xml and messages.xml. They contain some meta information about the check (like which category it belongs to) and the messages that should be printed when the detector finds something.

findbugs.xml:

<FindbugsPlugin>
 <Detector class="de.bismarck.findbugs.checks.StaticCalendarDetector" speed="fast" />
 <BugPattern abbrev="STCAL" type="STCAL_STATIC_CALENDAR_INSTANCE" category="MT_CORRECTNESS" />
 <BugPattern abbrev="STCAL" type="STCAL_STATIC_SIMPLE_DATE_FORMAT_INSTANCE" category="MT_CORRECTNESS" />
</FindbugsPlugin>



messages.xml:

<MessageCollection>
<Detector class="de.bismarck.findbugs.checks.StaticCalendarDetector">
<Details>
<![CDATA[
<p>This detector warns about static fields of type java.util.Calendar or java.text.DateFormat (and subclasses) because Calendars are inherently unsafe for multithreaded use. It is a fast detector.</p>
]]>
</Details>
</Detector>

<BugPattern type="STCAL_STATIC_CALENDAR_INSTANCE">
<ShortDescription>Static Calendar</ShortDescription>
<LongDescription>Found static field of type java.util.Calendar in {1}</LongDescription>

<Details>
<![CDATA[
<p>Even though the JavaDoc does not contain a hint about it, Calendars are inherently unsafe for multihtreaded use. Sharing a single instance across thread boundaries without proper synchronization will result in erratic behavior of the application. Under 1.4 problems seem to surface less often than under Java 5 where you will probably see random ArrayIndexOutOfBoundsExceptions or IndexOutOfBoundsExceptions in  sun.util.calendar.BaseCalendar.getCalendarDateFromFixedDate().</p>

<p>You may also experience serialization problems.</p>
<p>For more information on this see <a href="http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6231579">Sun Bug #6231579</a>
and <a href="http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6178997">Sun Bug #6178997</a>.</p>
]]>

</Details>
</BugPattern>

<BugPattern type="STCAL_STATIC_SIMPLE_DATE_FORMAT_INSTANCE">
<ShortDescription>Static DateFormat</ShortDescription>
<LongDescription>Found static field of type java.text.DateFormat in {1}</LongDescription>
<Details>
<![CDATA[
<p>As the JavaDoc states, DateFormats are inherently unsafe for multithreaded use. 
Sharing a single instance across thread boundaries without proper synchronization will result in erratic behavior of the application.</p>
<p>You may also experience serialization problems.</p>
<p>For more information on this see <a href="http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6231579">Sun Bug #6231579</a>
and <a href="http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6178997">Sun Bug #6178997</a>.</p>
]]>
</Details>
</BugPattern>

<BugCode abbrev="STCAL">Static use of type Calendar or DateFormat</BugCode>
</MessageCollection>

The detector class and the XML files must be packaged into a jar file. This can be put into the plugins directory of your FindBugs installation. This is all thre is to it to activate the detector. I recommend launching FindBugs from a command line window (using java.exe instead of javaw.exe on Windows) to see any error messages that might prevent your plugin from loading.

The second part of this tutorial will be about enabling the detector to find invocations of methods on static instances of the thread-unsafe classes. Stay tuned.

1 comment:

Razafindralambo Tiana said...

Hi,
nice tutorial, but can you explain to me how the findbugs engine decides to invoke a visit(X) method before or after another visit(Y) one ?

I understand that visitClassContext() or visit(JavaClass class) is invoked first, but I don't understand what determines the invokation of the other visit() methods and in what order ?