Breaking news, industry blogs and live commentary

IBM News on Ulitzer

Subscribe to IBM News on Ulitzer: eMailAlertsEmail Alerts newslettersWeekly Newsletters
Get IBM News on Ulitzer: homepageHomepage mobileMobile rssRSS facebookFacebook twitterTwitter linkedinLinkedIn


IBM Journal Authors: Yeshim Deniz, Lana Tannir, Liz McMillan, APM Blog, Janakiram MSV

Related Topics: Virtualization Magazine, Java EE Journal, JavaBlackBelt, Sun Developer Journal, IBM Journal, Java Developer Magazine

Article

Anatomy of a Java Finalizer

Experimenting on finalizer implementations in various Java Virtual Machines

Analysis of the Java Heap
The IBM HeapAnalyzer is also one of top five technologies at alphaWorks. It's actually the most popular technology there. HeapAnalyzer commands about 10% of the downloads at the site. You can get a copy of IBM HeapAnalyzer here.

This Java heap dump is about 70MB in size. -Xmx1000m should be enough for IBM HeapAnalyzer to process it. If you get java.lang.OutOfMemoryError from IBM HeapAnalyzer, you need to add more to the JVM with the -Xmx command-line option. Here's a command-line example for a Unix system to start version 3.4 of IBM HeapAnalyzer:

# /usr/java5/bin/java -Xmx1000m -jar ha34.jar

This is an example for Windows system:

C:\java5\bin\java -Xmx1000m -jar ha34.jar

If higher than V3.4 is available, please use that version. V3.4 is the latest version as of January 2009.

Currently there's no headless mode for IBM HeapAnalyzer. The following is the first screen from the tool. We can just click on the folder icon and open the Java heap dump (see Figure 5).

After the Java heap dump is loaded, an analysis window shows up with a Java heap leak suspect as seen in Figure 6.

Java heap usage is 52,053,322 bytes or approximately 49.6MB. Considering that we set -Xmx50m in the command line, it makes sense that the Java heap got exhausted. Unlike gasoline in your car's gas tank, it's virtually impossible to use up the last drop of the Java heap for a couple of reasons. One explanation is that there are 0.4MB of free Java heap but we wanted a 0.5MB Java heap. We would get java.lang.OutOfMemoryError even though we have 0.4MB of free space. Probably 0.4MB of space may not be a single contiguous space anyway.

IBM HeapAnalyzer identifies a leak suspect, java/lang/ref/Finalizer, which is responsible for 51,879,248 bytes (99.665596 %) of Java heap.

51,879,248 (99%) [32] 5 java/lang/ref/Finalizer 0x25783a48

In the reference tree view, the suspect is highlighted in blue. Please note that we use the word, leak suspect, not leak perpetrator, since the tool can't be 100% sure whether this is a root cause of the Java heap leak. That's why we don't want a computer to make decisions under any judicial system.

So, why does IBM HeapAnalyzer think java/lang/ref/Finalizer is a leak suspect in Figure 7?

Here's a clue:

Number of objects with finalize() method                  1,298,247
Number of garbage objects implementing finalize() method  1,298,242

The number of garbage objects implementing the finalize() method is almost the same as the number of objects with a finalize() method. In most cases, the Java heap dump isn't supposed to contain any garbage because by default most of JVMs do garbage collection before generating a heap dump. But we do have garbage objects implementing finalize() method according to HeapAnalyzer's analysis. If you're skeptical about the analysis, let's investigate further to see whether the analysis is correct or not.

We can expand java/lang/ref/Finalizer to see what objects are referenced from java/lang/ref/Finalizer. After a couple of expansions from the reference tree view we realize that java/lang/ref/Finalizer objects are linked like chains.

If we click on one of the java/lang/ref/Finalizers, we can see the properties and values of the object in the window on the right.

java/lang/ref/Finalizer next      0x257838e0
Java/lang/ref/Finalizer prev     0x25783930

The properties "next" and "prev" are variables of the java/lang/ref/Finalizer. They have references to the java/lang/ref/Finalizer. Each java/lang/ref/Finalizer has a reference to a java/lang/ref/Finalizer in the variable "prev" and a reference to a java/lang/ref/Finalizer in the variable "next." We can also find a variable "referent" that has a reference to an ObjectWYieldFinalizer. Does this object look familiar? You're right. That's an instance of the class we just built and ran.

ObjectWYieldFinalizer referent      0x25783900

Almost all of java/lang/ref/Finalizers have references to ObjectWYieldFinalizers as referents. Please note too that java/lang/ref/Finalizer has a reference to a java/lang/ref/ReferenceQueue in the variable "queue." We will come back later to check the variable "queue."

java/lang/ref/ReferenceQueue queue      0x2579a048

Let's take a look at the variable "prev" of the leak suspect java/lang/ref/Finalizer at 0x25783a48. It has a reference to another java/lang/ref/Finalizer. We can click on the icon Tree View to open more reference tree views (see Figure 8).

java/lang/ref/Finalizer prev             0x25783a70
java/lang/ref/ReferenceQueue queue       0x2579a048

java/lang/ref/Finalizer at 0x25783a70 is marked with V (check icon) under the leak suspect java/lang/ref/Finalizer at 0x25783a48. This means java/lang/ref/Finalizer at 0x25783a70 is also referenced from other objects. We can find it under java/lang/ref/ReferenceQueue at 0x2579a048. There's the same chain pattern of java/lang/ref/Finalizer. Here's a something very interesting. The variable "queue" does not have a reference to java/lang/ref/ReferenceQueue. Instead it's pointing to java/lang/ref/ReferenceQueue$Null.

java/lang/ref/ReferenceQueue$Null queue     0x2579b9c8

Is that only for java/lang/ref/Finalizer at 0x25783a70? We can expand java/lang/ref/Finalizer at 0x25783a70 to see what other java/lang/ref/Finalizer objects have in the variable "queue" (see Figure 9).

It's very interesting that other java/lang/ref/Finalizer objects also have 0x2579b9c8 (java/lang/ref/ReferenceQueue$Null) in the variable "queue." Let's find out what java/lang/ref/ReferenceQueue$Null at 0x2579b9c8 is. Select java/lang/ref/ReferenceQueue$Null at 0x2579b9c8, bring up a pop-up menu and select List parents menu as seen in Figure 10.

Here's list of objects that have references to java/lang/ref/ReferenceQueue$Null at 0x2579b9c8. Let's sort them by name by clicking on the name header of the table. Click on it again to sort in reverse order. We can find the class of java/lang/ref/ReferenceQueue at the top of the table. From the detailed information pop-up menu of the class java/lang/ref/ReferenceQueue, we can see that the address 0x2579b9c8 is referenced as the variable "ENQUEUED" (see Figure 11).

java/lang/ref/ReferenceQueue$Null ENQUEUED    0x2579b9c8

Based on the variable name "ENQUEUED," we can guess that any java/lang/ref/Finalizer object with ENQUEUED in the "queue" variable is queued for finalization. Other java/lang/ref/Finalizer objects without ENQUEUED in the "queue" variable are eventually going to be enqueued for finalization. How many java/lang/ref/Finalizer objects do we have in the queue? Probably 1,251,762 according to the variable "queueLength" of java/lang/ref/ReferenceQueue, which means 46,485 java/lang/ref/Finalizer objects need to be enqueued (see Figure 12).

If a java/lang/ref/Finalizer object is enqueued, is it finalized? Not necessarily, according to our investigation. In ObjectWYieldFinalizer, we implemented the finalize() method with Thread.yield(), which means it likely never completes executing the finalize() method. So java/lang/ref/Finalizer objects will stay in the queue and cause the Java heap to leak. The java/lang/ref/Finalizer object itself might be small in size. If we have millions of them, that's not trivial. Furthermore, java/lang/ref/Finalizer doesn't hang around alone, it has a reference to the object that has the finalize() method. So we would have millions of java/lang/ref/Finalizer objects and their referenced objects, millions of objects that have finalize() methods in the Java heap growing and growing. Eventually we would see java.lang.OutOfMemoryError due to Java heap exhaustion.

We have a similar result with ObjectWExceptionFinalizer.

Let's run ObjectWEmptyFinalizer in which we did not implement any code in the finalize() method and ObjectWOFinalizer that did not have any finalize() method on Sun's JVM. Even after several hours, we don't see any java.lang.OutOfMemoryError. -XX:+HeapDumpOnOutOfMemoryError will not create any Java heap dump if there's no java.lang.OutOfMemoryError. Here's another card for that situation. -XX:+HeapDumpOnCtrlBreak will create a Java heap dump on a Control-Break key combination or SIGQUIT signal. This is a way to trigger a Java heap dump on demand. Currently not all of Sun's JVMs support these options. Please refer to the JVM documentation for detailed information.

In Figure 13 there's an analysis of a Java heap dump from ObjectWEmptyFinalizer. Of course, we have to trigger a Java heap dump with a -XX:+HeapDumpOnCtrlBreak command-line option in place since there's no java.lang.OutOfMemoryError.

Java heap usage is only 218,189 bytes. That's why we didn't get any java.lang.OutOfMemoryError. There are only nine objects that have finalize() methods in the Java heap. We had millions of them in the Java heap dump from ObjectWYieldFinalizer. There are chains of java/lang/ref/Finalizer objects but only nine of them exist. Looks like the JVM didn't have any problem completing the finalize() methods of the ObjectWEmptyFinalizer and reclaiming spaces occupied by ObjectWEmptyFinalizer and Finalizers.

Let's try the IBM Java runtime and take a look at the Java garbage collection trace and Java heap dumps. You don't need a -XX:+HeapDumpOnCtrlBreak or -XX:+HeapDumpOnOutOfMemoryError command-line option on an IBM JVM. You can create a Java heap dump on a Control-Break key combination or SIGQUIT signal without any additional command-line options. Here's a Java garbage collection trace from an IBM Java virtual machine. With a -verbosegc option alone, we can get quite a lot of information (see Listing 7).

Figure 14 shows the analysis and recommendation from the IBM Pattern Modeling and Analysis Tool. They're similar.

From chart view, the used tenured area goes up rapidly and reaches the maximum limit (see Figure 15).

The IBM Java runtime provides a Portable Heap Dump (PHD) format of the Java heap dump by default in recent versions. In earlier versions a Text (TXT) format was provided by default. Here's a Java heap dump from ObjectWYieldFinalizer on IBM Java 6. Yes, there's a java.lang.OutOfMemoryError (see Figure 16).

Java heap usage is 52,427,816 bytes, approximately 49.99MB, almost reaching the maximum Java heap size of 50MB. No wonder we got java.lang.OutOfMemoryError. Unfortunately there's no leak suspect in the Java heap dump taken from IBM Java 6. We don't see any java/lang/ref/Finalizer object chains either in the IBM Java 6 heap dump. Let's search for ObjectWYieldFinalizer objects by clicking on search icon and putting ObjectWYieldFinalizer in the search string (see Figure 17).

We have as many as 3,251,653 ObjectWYieldFinalizer objects. They are holding 52,026,464 bytes of Java heap. ObjectWYieldFinalizer objects are not referenced from java/lang/ref/Finalizer objects. They do not have any parents. We see the same pattern in IBM Java 5 runtime as well. It seems that IBM Java 5 and Java 6 implement Finalizers in native code even though I haven't looked at the source code. ObjectWYieldFinalizer object should have been garbage collected but they are still in Java heap. They are not referenced from any Java object, which means they are referenced from native code. That's why I suspect that IBM Java 6 and Java 5 implement Finalizers in native code. Is that a good move? Maybe or maybe not. The efficiency of the native code would be an upside. We have more room in the Java heap since Finalizers use less Java heap thanks to native Finalizers. In the IBM Java 6 heap dump, 3,251,653 ObjectWYieldFinalizer objects were able to fit in 50MB of Java heap whereas Sun's Java 6 could only accommodate 1,298,244 ObjectWYieldFinalizer objects in 50MB of Java heap. But IBM Java 6 and Java 5 would consume native memory to handle native Finalizers. Native memory usage is not limited by the -Xmx command-line option. A downside is that we can no longer keep track of Finalizers in the Java heap dump (see Figure 18).

Let's check out what IBM Java used to be in Java Virtual Machine version 1.4.2. Here's a Java heap dump from ObjectWYieldFinalizer on IBM Java 1.4.2 (see Figure 19).

This looks like the Java heap dump from Sun's Java runtime. We see the same pattern of chained java/lang/ref/Finalizer objects.

Number of garbage objects implementing finalize() method  1,073,276
Number of objects with finalize() method                  1,073,654
Java heap usage                                               52,527,856 bytes

By expanding Finalizer objects, we can confirm that reference structures are almost same as what we saw with Sun's Java heap dump (see Figure 20).

The java/lang/ref/Finalizer object at 0x4f12d78 has a reference to the java/lang/ref/ReferenceQueue object at 0x2872730. The java/lang/ref/Finalizer object at 0x4f12d48 has a reference to java/lang/ref/ReferenceQueue$Null at 0x2869d20, which is probably enqueued for finalization. Unfortunately the IBM Java heap dump (PHD/TXT) does not provide the names of variables or the contents of the variables. So there's no way to find out which Finalizer object is the next Finalizer object from the PHD or TXT format of the Java heap dump.

Analysis of Java Thread Dumps
We can also take a look at this problem from the Java thread's point of view. Let's get a copy of the IBM Thread and Monitor Dump Analyzer for Java from http://www.alphaworks.ibm.com/tech/jca and analyze Java thread dumps.

The Java thread dump at the top, javacore.20081111.081343.3360.txt, is taken from the IBM Java 1.4.2 runtime (see Figure 21).

Another dump at the middle, verbosegc.txt_1, is taken from the Sun Java 6 runtime. The other thread dump at the bottom, javacore.20081111.081932.2172.0003.txt, is taken from the IBM Java 6 runtime.

We can see the Finalizer thread and the Reference Handler thread. We do not see the Reference Handler thread in the IBM Java 6 thread dump though. All Finalizer threads are executing the java.lang.Thread.yield() method, which causes the current thread (Finalizer thread) to pause and allow other thread to run. Reference Handler threads enqueue Finalizer objects for finalization. All the stack traces of the Finalizer thread have runFinalizer() or similar methods. The runFinalizer() method calls the finalize() method in the ObjectWYieldFinalizer object and the finalize() method calls the java.lang.Thread.yield() method. Basically the Finalizer thread paused because of the java.lang.Thread.yield() method.

Conclusion
We ran an experiment on various finalizer implementations in various Java Virtual Machines. We used a handful of tools to investigate the problem from different perspectives. The finalize() method could be used to do cleanup tasks on any system resources before an object is discarded when the object is no longer referenced. We observed that there's risks in using the finalize() method in the current implementation of IBM and Sun Java Virtual Machines. If we want to perform cleanup tasks on objects, we might want to consider finalizers as a last resort and implement our own more predictable cleanup method.

More Stories By Jinwoo Hwang

Jinwoo Hwang is a software engineer, inventor, author, and technical leader at IBM WebSphere Application Server Technical Support in Research Triangle Park, North Carolina. He joined IBM in 1995 and worked with IBM Global Learning Services, IBM Consulting Services, and software development teams prior to his current position at IBM. He is an IBM Certified Solution Developer and IBM Certified WebSphere Application Server System Administrator as well as a SUN Certified Programmer for the Java platform. He is the architect and creator of the following technologies:

Mr. Hwang is the author of the book C Programming for Novices (ISBN:9788985553643, Yonam Press, 1995) as well as the following webcasts and articles:

Mr. Hwang is the author of the following IBM technical articles:

  • VisualAge Performance Guide,1999
  • CORBA distributed object applet/servlet programming for IBM WebSphere Application Server and VisualAge for Java v2.0E ,1999
  • Java CORBA programming for VisualAge for Java ,1998
  • MVS/CICS application programming for VisualAge Generator ,1998
  • Oracle Native/ODBC application programming for VisualAge Generator ,1998
  • MVS/CICS application Web connection programming for VisualAge Generator ,1998
  • Java applet programming for VisualAge WebRunner ,1998
  • VisualAge for Java/WebRunner Server Works Java Servlet Programming Guide ,1998
  • RMI Java Applet programming for VisualAge for Java ,1998
  • Multimedia Database Java Applet Programming Guide ,1997
  • CICS ECI Java Applet programming guide for VisualAge Generator 3.0 ,1997
  • CICS ECI DB2 Application programming guide for VigualGen, 1997
  • VisualGen CICS ECI programming guide, 1997
  • VisualGen CICS DPL programming guide, 1997

Mr. Hwang holds the following patents in the U.S. / other countries:


Comments (1) View Comments

Share your thoughts on this story.

Add your comment
You must be signed in to add a comment. Sign-in | Register

In accordance with our Comment Policy, we encourage comments that are on topic, relevant and to-the-point. We will remove comments that include profanity, personal attacks, racial slurs, threats of violence, or other inappropriate material that violates our Terms and Conditions, and will block users who make repeated violations. We ask all readers to expect diversity of opinion and to treat one another with dignity and respect.


Most Recent Comments
vishetty 07/30/09 07:28:00 AM EDT

Hi,
you seem to say that,
"If there's any exception thrown by the finalize() method, the finalization of the object is halted.", But the Java Language specification seems to say "If an uncaught exception is thrown during the finalization, the exception is ignored and finalization of that object terminates".
Is this is a IBM JVM specific behavior?