The Java Specialists' Newsletter
Issue 1702009-02-27 Category: Performance Java version: Java 1.2 - 6.0

Welcome to the 170th issue of The Java(tm) Specialists' Newsletter, sent from the beautiful island of Crete. A few weeks ago, Helene's Mac Mini hard disk packed up. Opening the Mac Mini voids the warranty, but I had no choice as the support in Greece is terrible. So after some handy work with spatulas and screw drivers, the drive was replaced with a larger and faster specimen. Next I booted the Mac OS X DVD and clicked on "Restore from Backup". A few hours later, everything, and I mean everything was back. User accounts, emails, settings, programs. Very impressive indeed.

We intend being in Chania (Crete) during August this year, so please let me know a while in advance if you are planning a visit to our island this season. We have some nice local restaurants, where they serve delicious Cretan specialities.

Thanks for reading this newsletter on our website. We also have a mailing list. That is where the real action takes place (webinars, free reports, etc.). Maybe subscribe today?

Advanced Java Courses on Crete:Java Specialists Master Course 18-21 June 2013 and Concurrency Specialists Course 6-9 August 2013.

Discovering Objects with Non-trivial Finalizers

We should all know by now that implementing the finalize() method is usually a bad idea. For reasons why, have a look at Joshua Bloch's book on Effective Java, Brian Goetz's book on Java Concurrency in Practice and Jack Shirazi's book on Java Performance Tuning. Then there are several articles and presentations. For example, Jack Shirazi again explaining Finalizers part 1 and part 2. A talk about Finalizers at Java One by Hans Boehm and lastly a nice article by Tony Printezis. I have no doubt left out many relevant articles, but you probably got the point: Avoid Finalizers.

The one place where I have implemented the finalize() method was when I wanted to make sure that a resource was being closed. The finalize() method would then check that I really had done so. Fortunately, when our finalize() method is trivial, that is, it has an empty body, it is ignored by the Finalizer mechanism. We can define a private static final boolean field that we use to conditionally remove the body of the finalize() method. Thus when the field is set to false, the static compiler removes the body of the if() statement from the compiled byte code. Since it then contains only a trivial finalize() method, it is not marked for finalization.

Consider the class ConditionalFinalizer. It represents a resource that ought to be closed. We can use the finalizer to look for situations where the client code did not call the close() method:

public class ConditionalFinalizer {
  private static final boolean DEBUG = true;

  // Should be volatile as it is accessed from multiple threads.
  // Thanks to Anton Muhin for pointing that out.
  private volatile boolean resourceClosed;
  private final int id;

  public ConditionalFinalizer(int id) {
    this.id = id;
    resourceClosed = false;
  }

  protected void finalize() throws Throwable {
    if (DEBUG) {
      if (!resourceClosed) {
        System.err.println(
            "You forgot to close the resource with id " + id);
        close();
      }
      super.finalize();
    }
  }

  public void close() {
    resourceClosed = true;
  }
}
  

We can test this once with DEBUG set to true and then again set to false. We should see dramatic differences in performance. On my machine it takes about 18 seconds with a non-trivial finalize() method, that is when DEBUG=true, but only 300 milliseconds when DEBUG=false. Here is the test code:

public class ConditionalFinalizerTest1 {
  public static void main(String[] args)
      throws InterruptedException {
    long time = System.currentTimeMillis();
    for (int i = 0; i < 10 * 1000 * 1000; i++) {
      ConditionalFinalizer cf = new ConditionalFinalizer(i);
      if (i % (1000 * 1000) != 0) {
        cf.close();
      }
    }
    time = System.currentTimeMillis() - time;
    System.out.println("time = " + time);
  }
}
  

Have a look at Jack Shirazi's article for reasons why we have such a dramatic difference in performance. Finalizers introduce an extra step in the GC, so objects end up in the old generation unnecessarily.

The real cost of the finalize() method is that there are handles to all our objects. This causes them to survive too many collections, thus making them get promoted prematurely to the old generation. The continuous old generation GC is what makes it so slow. In our tests, we found that sometimes 80% of CPU was spent in GC. We could improve the situation by setting the various generation size ratios, but the cost was still substantial. With some VMs we even got an OutOfErrorMemory as the Finalizer could not keep up with the object creation rate.

Memory Overhead

On a 64-bit machine every object uses at least 16 bytes of memory. A Boolean instance uses 24 bytes, so 192 bits to represent a single bit of information! However, if we make the class implement a non-trivial finalize() method, then it also creates a java.lang.ref.Finalizer instance (16 bytes), which contains a next pointer (8 bytes) and a prev pointer (8 bytes) to represent a linked list. Since Finalizer extends Reference, it also contains a pointer to the referent (8 bytes), a pointer to the reference queue (8 bytes), another next pointer (8 bytes) and a "discovered" pointer (8 bytes). This all adds up to 64 additional bytes for each instance created with a non-trivial finalize() method on a 64-bit machine, so each such object uses 80 bytes at least!

Finding Finalizeable Objects

I hope it is clear that Finalization is something we want to avoid if possible. So what do we do if we have a system and we suspect that there are many objects with a non-trivial finalize() method? How do we find out what these objects are? How do we find out what classes they belong to? The java.lang.ref.Finalizer class contains a linked list, where the head is referenced by the unfinalized field.

All access to this linked list is synchronized with a static lock, thus adding a point of contention to the system. If we want to iterate over this list and print out the objects, we should first synchronize on the same lock.

To access this information, we will define an MBean that prints all objects with a non-trivial finalize() method. When detailed is true, it prints out all the field values of the objects. We can furthermore force the finalizers to run in a separate thread to the default Finalizer thread, with runFinalizers(). This could be necessary if the Finalizer thread gets stuck processing a finalize() method. Also, we offer the System.gc() method via the MBean interface:

public interface FinalizerWatcherMBean {
  int getNumberOfObjectsThatMightGetFinalizedOneDay();
  void printObjectsThatMightGetFinalizedOneDay(boolean detailed);
  void printUniqueClassesWithFinalizers();
  void runFinalizers();
  void collectGarbage();
}
  

We have the following implementation, using reflection to glean the correct information from the Finalizer class. It is fairly simple, all I needed to find out was where to look for the information. We use a simple visitor to walk over the linked list. Various methods then implement their own visitors to process the elements. This way we only have to write the iterating code once.

import java.lang.ref.Reference;
import java.lang.reflect.Field;
import java.util.*;

public class FinalizerWatcher implements FinalizerWatcherMBean {
  private final Class<?> finalizerClazz;
  private final Object lock;
  private final Field unfinalizedField;
  private final Field nextField;
  private final Field referentField;

  public FinalizerWatcher() {
    try {
      finalizerClazz = Class.forName("java.lang.ref.Finalizer");

      // we need to lock on this field to avoid racing conditions
      Field lockField = finalizerClazz.getDeclaredField("lock");
      lockField.setAccessible(true);
      lock = lockField.get(null);

      // the start into the linked list of finalizers
      unfinalizedField = finalizerClazz.getDeclaredField(
          "unfinalized");
      unfinalizedField.setAccessible(true);

      // the next element in the linked list
      nextField = finalizerClazz.getDeclaredField("next");
      nextField.setAccessible(true);

      // the object that the finalizer is defined on
      referentField = Reference.class.getDeclaredField("referent");
      referentField.setAccessible(true);
    } catch (RuntimeException e) {
      throw e;
    } catch (Exception e) {
      throw new IllegalStateException(
          "Could not create FinalizerWatcher", e);
    }
  }

  public int getNumberOfObjectsThatMightGetFinalizedOneDay() {
    class CountingVisitor implements Visitor {
      private int objectsToBeFinalized = 0;

      public void visit(Object value) {
        objectsToBeFinalized++;
      }
    }
    CountingVisitor visitor = new CountingVisitor();
    processAll(visitor);
    return visitor.objectsToBeFinalized;
  }

  private interface Visitor {
    public void visit(Object value) throws IllegalAccessException;
  }

  public void printObjectsThatMightGetFinalizedOneDay(
      final boolean detailed) {
    class PrintingVisitor implements Visitor {
      private int objectsToBeFinalized = 0;

      public void visit(Object value)
          throws IllegalAccessException {
        System.out.println(value);
        if (detailed) showAllFieldValues(value);
        objectsToBeFinalized++;
      }
    }
    PrintingVisitor visitor = new PrintingVisitor();

    System.out.println("Objects registered for finalization");
    System.out.println("===================================");
    processAll(visitor);
    System.out.println("Found " + visitor.objectsToBeFinalized +
        " objects registered for finalization");
  }

  public void printUniqueClassesWithFinalizers() {
    class Counter {
      int value;
    }

    final Map<String, Counter> classes =
        new TreeMap<String, Counter>();

    class UniqueClassesVisitor implements Visitor {
      public void visit(Object value)
          throws IllegalAccessException {
        String className = value.getClass().getName();
        Counter count = classes.get(className);
        if (count == null) count = new Counter();
        count.value++;
        classes.put(className, count);
      }
    }

    UniqueClassesVisitor visitor = new UniqueClassesVisitor();
    processAll(visitor);
    System.out.println("Unique Classes with Finalizers");
    System.out.println("==============================");
    for (Map.Entry<String, Counter> entry : classes.entrySet()) {
      System.out.printf("%d\t%s%n", entry.getValue().value,
          entry.getKey());
    }
  }

  public void runFinalizers() {
    System.runFinalization();
  }

  public void collectGarbage() {
    System.gc();
  }

  private void processAll(Visitor visitor) {
    try {
      synchronized (lock) {
        Object finalizer = unfinalizedField.get(null);
        while (finalizer != null) {
          Object value = referentField.get(finalizer);
          visitor.visit(value);
          finalizer = nextField.get(finalizer);
        }
      }
    } catch (IllegalAccessException e) {
      throw new IllegalStateException(e);
    }
  }

  private void showAllFieldValues(Object value)
      throws IllegalAccessException {
    Class clazz = value.getClass();
    Collection<Field[]> allFields = new ArrayList<Field[]>();
    while (clazz != null) {
      allFields.add(clazz.getDeclaredFields());
      clazz = clazz.getSuperclass();
    }
    for (Field[] fields : allFields) {
      for (Field field : fields) {
        field.setAccessible(true);
        System.out.println("\t" + field.getName() + "=" +
            field.get(value));
      }
    }
  }
}
  

We register this as an MBean like this:

import javax.management.*;
import java.lang.management.ManagementFactory;

public class MBeanUtil {
  private static final FinalizerWatcher FINALIZER_WATCHER =
      new FinalizerWatcher();

  public static FinalizerWatcher getFinalizerWatcher() {
    return FINALIZER_WATCHER;
  }

  static {
    try {
      MBeanServer mbs =
          ManagementFactory.getPlatformMBeanServer();
      mbs.registerMBean(FINALIZER_WATCHER, new ObjectName(
          "eu.javaspecialists.performance:type=FinalizerWatch"));
    } catch (RuntimeException e) {
      throw e;
    } catch (Exception e) {
      throw new IllegalStateException(e);
    }
  }
}
  

Once our MBean is set up, we can attach to the process with JConsole so we can call the various methods:

public class ConditionalFinalizerTest2 {
  public static void main(String[] args) throws Exception {
    MBeanUtil.getFinalizerWatcher();
    ConditionalFinalizerTest1.main(args);
    System.out.println("Done - going to sleep for a minute");
    Thread.sleep(60000);
  }
}
  

The printUniqueClassesWithFinalizers() method shows something like this:

    Unique Classes with Finalizers
    ==============================
    1332675 ConditionalFinalizer
    17      java.io.FileInputStream
    2       java.io.FileOutputStream
    4       java.lang.ClassLoader$NativeLibrary
    7       java.net.SocksSocketImpl
    1       java.util.concurrent.ScheduledThreadPoolExecutor
    1       java.util.concurrent.ThreadPoolExecutor
    3       java.util.jar.JarFile
    3       java.util.zip.Inflater
  

We could thus very easily spot that we have too many objects with finalizers. In my FinalizerWatcher, I also offer the function to print all the objects with their fields to the console. This would typically only be useful when you don't have too many objects in the list. For example:

public class FinalizerWatcherTest {
  public static void main(String[] args)
      throws InterruptedException {
    MBeanUtil.getFinalizerWatcher();

    while (true) {
      A a = new A();
      a = null;
      Thread.currentThread().sleep(1000);
    }
  }

  public static class A {
    private boolean val;

    protected void finalize() throws Throwable {
      super.finalize();
      System.out.println("A.finalize");
    }
  }
}
  

The objects registered for finalization, with detail, would be shown like this:

    Objects registered for finalization
    ===================================
    java.io.FileInputStream@2c7ac5
            fd=java.io.FileDescriptor@38462a
            channel=null
            SKIP_BUFFER_SIZE=2048
            skipBuffer=null
    FinalizerWatcherTest$A@17b79a6
            val=false
    FinalizerWatcherTest$A@13f99af
            val=false
    FinalizerWatcherTest$A@82c23d
            val=false
    Socket[addr=/null,port=0,localport=0]
            server=null
            port=1080
            external_address=null
            useV4=false
            cmdsock=null
    ...
  

We can now see all the objects that are registered to one day be finalized. I've tried to make the FinalizerWatcher lightweight enough that it should still work in a busy system. However, in a stressed system, we might not be able to attach JConsole, in which case, just write a java.util.Timer that calls the printUniqueClassesWithFinalizers() periodically.

Kind regards

Heinz

Performance Articles Related Java Course Discuss at The Java Specialist Club