C H A P T E R 9
Debugging and Unit Testing
Debugging is a big part of software development. To effectively debug, you must be able to “think” like a computer and dive into the code, deconstructing every step that lead to the logic error that you're working to resolve. In the beginning of computer programming, there weren't a lot of tools to help in debugging. Mostly, debugging involved taking a look at your code and spotting inconsistencies; then resubmit the code to be compiled again. Today, every IDE offers the ability of using breakpoints and inspecting memory variables, making it much easier to debug. Outside the IDE there are other tools that help in daily debugging, building, and testing of your project; and these tools ensure that your code is being continually tested for errors introduced when programming. In this chapter, you explore the different tools that will help aid in debugging, analyzing, and testing Java software. Hopefully these recipes will help you debug faster, and burn less of that midnight oil.
9-1. Understanding Exceptions
Problem
You caught and logged an Exception (as described in solution 6-1), and need to understand what happened.
Solution
Analyze the Exception's StackTrace() method:
try {
int a = 5/0;
} catch (Exception e) {
e.printStackTrace();
}
java.lang.ArithmeticException: / by zero
at org.java7recipes.chapter9.Recipe9_1.start(Recipe9_1.java:18)
at org.java7recipes.chapter9.Recipe9_1.main(Recipe9_1.java:13)
How It Works
In Programming lingo, a stack refers to the list of functions that were called to get to a point in your program, usually starting from the immediate (System.out.println()) to the more general (public static void main). Every program keeps track of how it got to a specific part of the code. Stack trace's output refer to the stack that was in memory when an error occurred. Exceptions thrown in Java keep track of where they happened and what code path was taken to when the exception was thrown. Stack trace shows from the most specific place where the exception happened (the line where the exception occurred) to the top-level invoker of the offending code (and everything in-between). This information then allows you to pinpoint what kind of method calls were done, and might shed some light on why the exception was thrown.
In this example, the divide by zero Exception occurred on line 18 of Recipe9_1.java and was caused by a call from the main() method (at line 13). Sometimes, when looking at the Stack trace's output, you will see methods that don't belong to the project. This happens naturally as sometimes method calls are generated in other parts of a working system. It is, for example, very common to see AWT methods in Swing applications when an exception is raised (due to the nature of the EventQueue). If you look at the more specific function calls (earliest), you will eventually run with the project's own code and can then try to figure out why the exception was thrown.
Note The Stack trace output will contain line number information if the program is compiled with “Debug” info. By default, most IDEs will include this information when running in a Debug configuration.
9-2: Locking Down Behavior of Your Classes
Problem
You need to lock down the behavior of your class and want to create unit tests that verify that behavior in your application.
Solution
Use JUnit to create unit tests that verify behavior in your classes.
To use this solution, you need to include the JUnit dependencies. JUnit can be downloaded from (http://www.junit.org). Once downloaded, add the junit-xxx.jar file and the junit-xxx-dep.jar file to your project (where xxx is the downloaded version number). When JUnit becomes part of your project, you will be able to include the org.junit and junit.framework namespaces.
In this example you create two unit tests for the MathAdder class. It contains two methods: addNumber (int, int) and substractNumber (int,int). These two methods return the addition (or subtraction) of their passed parameters (a simple class). The unit tests (marked by the @Test annotation) verifies that the MathAdder class does, in fact, add and/or subtract two numbers.
package org.java7recipes.chapter9;
import junit.framework.Assert;
import org.junit.Test;
/**
* Created by IntelliJ IDEA.
* User: Freddy
* Date: 9/15/11
* Time: 5:36 PM
* Simple Unit Test
*/
public class Recipe9_3_MathAdderTest {
@Test
public void testAddBehavior() {
Recipe_9_3_MathAdder adder = new Recipe_9_3_MathAdder();
for (int i =0;i < 100;i++) {
for (int j =0;j < 100;j++) {
Assert.assertEquals(i+j,adder.addNumbers(i,j));
}
}
}
@Test
public void testSubstractBehavior() {
Recipe_9_3_MathAdder adder = new Recipe_9_3_MathAdder();
for (int i =0;i < 100;i++) {
for (int j =0;j < 100;j++) {
Assert.assertEquals(i-j,adder.substractNumber(i,j));
}
}
}
}
public class Recipe_9_3_MathAdder {
public int addNumbers (int first, int second) {
return first+second;
}
public int substractNumber (int first, int second) {
return first-second;
}
}
How It Works
Unit tests are a way of enforcing expected behaviors on your classes. Having unit tests in your project makes it less likely to break old functionality when adding or refactoring it. When you create unit tests, you are specifying how an object should behave (what is referred to as its contract). The unit tests will then test that the expected behavior happens (they do this by verifying the result of a method and using the different JUnit.Assert methods).
The first step to write a unit test is to create a new class that describes the behavior you want to verify. One of the general unit–test naming conventions is to create a class with the same name as the class being tested with the postfix of Test; in this recipe's example, the main class is called Recipe9_3_MathAdder, while the testing class is called Recipe9_3_MathAdderTest.
The Unit test class (MathAdderTest) will contain methods that check and verify the behavior of the class. To do so, it annotates the method names. Annotation refers to the capability of Java of adding extra information to a class/method that doesn't necessarily change the code. This extra information is not used by the program, but by the compiler/builder (or external tools) to guide the compilation, building, and/or testing of the code. For unit testing purposes, you annotate the methods that are part of the unit test by writing @Test before each method name. Within each method, you use Assert.assertEquals (or any of the other Assert static methods) to verify behavior.
The Assert.assertEquals method instructs the unit testing framework to verify that the expected value of the method call from the class that we are testing is the same as the actual value returned by its method call. In the recipe example, Assert.assertEquals verifies that the MathAdder is correctly adding the two integers. While the scope of this class is trivial, it shows the bare minimum requirements to have a fully functional unit test.
If the Assert call succeeds, it gets reported in the unit test framework as a “Passed” test; if the Assert call fails, then the unit test framework will stop and display a message showing where the unit test failed. Most modern IDEs have the capability of running unit test classes by simply right-clicking its name and selecting Run/Debug (and that's the intended way of running Chapter_9_3_MathAdderTest recipe).
While it is true that IDEs can run unit tests while developing, they are created with the intention of being run automatically (usually triggered by a scheduled build or by a version control system's check-in), which is what the recipe 9-3 talks about.
9-3. Scripting Your Unit Tests
Problem
You need to automatically run your unit tests.
Solution
Use and configure JUnit + Ant. To do so, follow these steps:
- Download Apache Ant (located at
http://ant.apache.org/). - Uncompress Apache Ant into a folder (for example,
c:antfor Windows systems). - Make sure that Apache Ant can be executed from the command line. In Windows, this means adding the
apache-ant/binfolder to the path as follows:- Go to Control Panel
System. - Click Advanced system settings.
- Click Environment Variables.
- In the System Variables list, double-click the variable name
PATH. - At the end of the string, add “;
C:apache-ant-1.8.2in” (or the folder that you uncompressed Apache Ant into). - Click OK (on each of the popup boxes that were opened before) to accept the changes.
- Go to Control Panel
Make sure that the JAVA_HOME environment variable is defined. In Windows, this means adding a new environment variable called JAVA_HOME. For example:
- Go to Control Panel System.
- Click Advanced system settings.
- Click Environment Variables.
- In the System Variables list, check to see whether there is variable named JAVA_HOME and that the value points to your JDK distribution,
- If JAVA_HOME is not present, click New. Set the variable name to JAVA_HOME and set the variable value to
C:Program FilesJavajdk1.7.0or the root of your JDK 7 installation.
Test that you can reach Ant, and that Ant can find your JDK installation. To test that the changes took effect in Windows, do the following:
- Open a command window
- Type
ANT.- If you receive the message “Ant is not recognized as an internal or external command", redo the first steps of setting up the PATH variable (the first set of instructions).
- If you receive the message “unable to locate tools.jar” You need to create and/or update the JAVA_HOME path for your installation (the second set of instructions).
- The message “Buildfile: build.xml does not exist!"means that your setup is ready to be built using Ant. Congratulations!
Note When changing environment variables in Microsoft Windows, it is necessary to close previous command line windows and reopen them because changes are only applied to new command windows. To open a command window in Microsoft Windows, click Start, type CMD, and press Enter.
Create build.xml at the root of your project, and put the following bare-bones Ant script as the contents of the build.xml file. This particular build.xml file contains information that Ant will use to compile and test this recipe.
<project default="test" name="Chapter9Project" basedir=".">
<property name="src" location="src"/>
<property name="build" location="build/"/>
<property name="src.tests" location="src/"/>
<property name="reports.tests" location="report/" />
<path id="build.path">
<fileset dir="dep">
<include name="**/*.jar" />
</fileset>
<pathelement path="build" />
</path>
<target name="build">
<mkdir dir="${build}" />
<javac srcdir="${src}" destdir="${build}">
<classpath refid="build.path" />
</javac>
</target>
<target name="test" depends="build">
<mkdir dir="${reports.tests}" />
<junit fork="yes" printsummary="yes" haltonfailure="yes">
<classpath refid="build.path" />
<formatter type="plain"/>
<batchtest fork="yes" todir="${reports.tests}">
<fileset dir="${src.tests}">
<include name="**/*Test*.java"/>
</fileset>
</batchtest>
</junit>
</target>
</project>
Note To execute this recipe, open a command line window, navigate to the Chapter 9 folder, type ant, and press Enter.
How It Works
Apache Ant (or simply Ant) is a program that allows you to script your project's build and unit testing. By configuring Ant, you can build, test, and deploy your application using the command line (In turn, it can then be scheduled to be run automatically by the operating system). Ant can have tasks to automatically run unit tests and give a report on the result of these tests. These results can then be analyzed after each run to pinpoint changes in behavior.
Although Ant might be difficult to understand, it allows for a lot of flexibility on how to compile, build, and weave code. By using Ant, you are allowing utmost configuration on how your project is built.
Tip Visit http://ant.apache.org/manual/tutorial-helloworldwithant.html for a more in-depth tutorial of Ant.
The build.xmlfile contains instructions on how to compile your project, which classpath to use, and what unit tests to run. Each build.xml will have a <project> tag that contains the steps to build the project. Within each <project> there are targets, which are “steps” in the build process. A <target> can depend on other targets, allowing you to establish dependencies in your project (in this recipe's example, the target “test” depends on the target “build"; meaning that to run the test target, Ant will first run the build target).
Each target has tasks. These tasks are extensible, and there is a core set of tasks that you can use out of the box. The <javac> task will compile a set of Java files specified in the src attribute and write the output to the dest attribute. As part of the <javac> task, you can specify the classpath to use. In this example, the classpath is specified by referring to a previously defined path, called build.path. Ant provides ample support for creating classpaths. In this recipe, the classpath is defined as any file that has the .jar extension located in the dep folder.
The other task in the build target is the <junit> task. This task will find unit test specified in its task and run it. The unit tests are defined in the <batchtest> property. By using the <fileset> property, you tell JUnit to find any file that has the word Test in its name and ends with the .java extension. Once the JUnit runs each test, it will write out a summary to the console and write a report on the results of the unit tests to the reports.tests folder.
Tip Even though they look strange, you can define variables in a build.xml file by using the <property> tag. Once a property is defined, it can be accessed as part of other task by using the ${propertyName} syntax. This allows you to quickly change your build script in response to project changes (for example, switching target/source folders around).
9-4. Determining Code Coverage
Problem
You need to generate reports on how much of your project the unit tests cover.
Solution
Use the Emma code coverage tool to create code coverage reports. For example, the following is a new version of build.xml that adds Emma code coverage to our unit testing:
<project default="test" name="Chapter9Project" basedir=".">
<property name="src" location="src"/>
<property name="build" location="build/"/>
<property name="reports.tests" location="report/" />
<!-- Emma Code Coverage Info -->
<property name="emma.dir" value="dep/emma" />
<property name="emma.enabled" value="true" />
<path id="emma.lib" >
<pathelement location="${emma.dir}/emma.jar" />
<pathelement location="${emma.dir}/emma_ant.jar" />
</path>
<property name="coverage.dir" value="coverage" />
<taskdef resource="emma_ant.properties" classpathref="emma.lib" />
<path id="build.path">
<fileset dir="dep">
<include name="**/*.jar" />
</fileset>
<pathelement path="build" />
</path>
<target name="clean">
<delete dir="${build}" />
<delete dir="${reports.tests}" />
<delete dir="${coverage.dir}" />
<mkdir dir="${build}" />
<mkdir dir="${reports.tests}" />
<mkdir dir="${coverage.dir}" />
</target>
<target name="build">
<javac srcdir="${src}" destdir="${build}">
<classpath refid="build.path" />
</javac>
</target>
<target name="test" depends="clean,build">
<emma enabled="${emma.enabled}" >
<instr mode="overwrite" metadatafile="${coverage.dir}/metadata.emma" >
<instrpath>
<pathelement path="${build}" />
</instrpath>
<filter excludes="*Test*" />
</instr>
</emma>
<junit fork="yes" printsummary="yes" haltonfailure="yes">
<classpath refid="build.path" />
<formatter type="plain"/>
<batchtest fork="yes" todir="${reports.tests}">
<fileset dir="${build}">
<include name="**/*Test*.class"/>
</fileset>
</batchtest>
<jvmarg value="-XX:-UseSplitVerifier" />
<jvmarg value="-Demma.coverage.out.file=${coverage.dir}/coverage.emma" />
<jvmarg value="-Demma.coverage.out.merge=true" />
</junit>
<emma enabled="${emma.enabled}" >
<report sourcepath="${src}" >
<fileset dir="${coverage.dir}" >
<include name="*.emma" />
</fileset>
<txt outfile="${coverage.dir}/coverage.txt" />
<html outfile="${coverage.dir}/coverage.html" />
</report>
</emma>
</target>
</project>
To run this recipe, you will need to download and add the Emma code coverage .jar files. To do so, go to http://emma.sourceforge.net/ and download the latest Emma code coverage version. After downloading, uncompress the Emma download into a folder in your computer. Copy the /lib folder from the uncompressed Emma folder into dep/emma in your application. Make sure that dep/emma/emma.jar and dep/emma/emma_ant.jar are present.
Note To execute this recipe from Ant, open a command-line window, navigate to the Chapter 9 folder, type ant –f emmabuild.xml and press Enter.
How It Works
An important feature of creating unit tests is measuring how much code they execute of the tested classes. The more project code the unit tests execute, the safer it is to assume that changes in expected behavior will be caught by the unit tests. Code coverage is defined as the percentage of lines of code that the unit tests have run versus the total lines of code the project has. By having a larger code coverage, most of the code base is being verified. (A typical code coverage goal is about 80 percent of the lines of code tested; more coverage than that and you might be testing trivial functionality such as getters and setters of a simple Java class.
By combining Emma, Ant, and JUnit you can get code coverage reporting for your application. Code coverage is a very important measure for a lot of programming disciplines. It offers a way of understanding how effectively the current codebase is covered, and how solid the unit tests are in terms of covering functionality.
In this build.xml file, there are new sections that describe how to measure code coverage. The first section of build.xml defines a new Emma task that can be used by Ant. The way Emma's code coverage works is by going through a process called instrumentation, which refers to a task that changes the compiled bytecode. In Emma's case, it's adding extra instructions that record coverage information. Using the recorded coverage information, Emma puts together a report that shows code coverage that was achieved when running the unit tests.
In the build.xml script, Emma instrumentation happens at the beginning of the <target name=“test”>. The first <Emma> task defines what files to instrument. For the recipe, the files to instrument are located in the /build folder. The Emma task also specifies how to instrument (overwrite). Overwrite instrumentation means that Emma takes the original class file, instruments it (changes the content to add the new instructions), and saves it with the same name. Within our instrumentation step, you also specify to exclude any file that has the Test name in it because it is a common practice not to include unit test lines of code as part of the code coverage.
The second part of the <target name="test"> involves running the unit tests. This is very similar to recipe 9-3; even so, there are a couple of differences. The first difference is that you specify the unit tests to run as .class files instead of .java files. The second difference is that there are new JVM arguments added for unit tests. JVM arguments are defined by the <jvmarg> properties. These properties tell the instrumented classes that information related to code coverage should be written to a file named coverage.emma, and that it should be done in aggregate (don't overwrite the file for each unit test being executed).
Note Due to the new Java 7 bytecode, you need to add the <jvmarg value=“-XX:-UseSplitVerifier” /> property. This is due to an incompatibility between Emma and the new Java 7 bytecode, which the j vmarg property fixes.
After running the unit tests, the third part of the <target name=“ptest”> involves generating a report of the collected code coverage statistics (Figure 9-1 shows an example of the coverage of our unit tests from recipe 9-2). This is done by adding a new <emma><report> task that specifies the location and formatting of the report. By using these three tools (Ant, JUnit, and Emma) you have created an automated build that runs unit tests and reports on code coverage exercised by unit tests.
Figure 9-1. Emma code coverage report
9-5. Finding Bugs Early
Problem
You want to find the most number of bugs at design time.
Solution
Use FindBugs to scan your software for issues.
The following is our new build.xml file that adds FindBugs reporting:
<project default="test" name="Chapter9Project" basedir=".">
<property name="src" location="src"/>
<property name="build" location="build/"/>
<property name="reports.tests" location="report/" />
<property name="classpath" location="dep/" />
<!-- Emma Code Coverage Info -->
<property name="emma.dir" value="dep/emma" />
<property name="emma.enabled" value="true" />
<path id="emma.lib" >
<pathelement location="${emma.dir}/emma.jar" />
<pathelement location="${emma.dir}/emma_ant.jar" />
</path>
<property name="coverage.dir" value="coverage" />
<taskdef resource="emma_ant.properties" classpathref="emma.lib" />
<!-- Findbugs Static Analyzer Info -->
<property name="findbugs.dir" value="dep/findbugs" />
<property name="findbugs.report" value="findbugs" />
<path id="findbugs.lib" >
<fileset dir="${findbugs.dir}" includes="*.jar"/>
</path>
<taskdef name="findbugs" classpathref="findbugs.lib" classname="edu.umd.cs.findbugs.anttask.FindBugsTask"/>
<path id="build.path">
<fileset dir="dep">
<include name="**/*.jar" />
</fileset>
</path>
<target name="clean">
<delete dir="${build}" />
<delete dir="${reports.tests}" />
<delete dir="${coverage.dir}" />
<delete dir="${instrumented}" />
<mkdir dir="${build}" />
<mkdir dir="${reports.tests}" />
<mkdir dir="${coverage.dir}" />
</target>
<target name="build">
<javac srcdir="${src}" destdir="${build}" debug="${debug}">
<classpath refid="build.path" />
</javac>
</target>
<target name="test" depends="clean,build">
<emma enabled="${emma.enabled}" >
<instr mode="overwrite" metadatafile="${coverage.dir}/metadata.emma" >
<instrpath>
<pathelement path="${build}" />
</instrpath>
<filter excludes="*Test*" />
</instr>
</emma>
<junit fork="yes" printsummary="yes" haltonfailure="yes">
<classpath refid="build.path" />
<formatter type="plain"/>
<batchtest fork="yes" todir="${reports.tests}">
<fileset dir="${build}">
<include name="**/*Test*.class"/>
</fileset>
</batchtest>
<jvmarg value="-XX:-UseSplitVerifier" />
<jvmarg value="-Demma.coverage.out.file=${coverage.dir}/coverage.emma" />
<jvmarg value="-Demma.coverage.out.merge=true" />
</junit>
<emma enabled="${emma.enabled}" >
<report sourcepath="${src}" >
<fileset dir="${coverage.dir}" >
<include name="*.emma" />
</fileset>
<txt outfile="${coverage.dir}/coverage.txt" />
<html outfile="${coverage.dir}/coverage.html" />
</report>
</emma>
</target>
<target name="findbugs" depends="clean">
<antcall target="build">
<param name="debug" value="true" />
</antcall>
<mkdir dir="${findbugs.report}" />
<findbugs home="${findbugs.dir}"
output="html"
outputFile="${findbugs.report}/index.html"
reportLevel="low"
>
<class location="${build}/" />
<auxClasspath refid="build.path" />
<sourcePath path="${src}" />
</findbugs>
</target>
</project>
To run this recipe, download FindBugs (http://findbugs.sourceforge.net/downloads.html). Uncompress into a folder in your computer; then copy the contents of the ./lib/ folder into your project's /dep/findbugs folder (create the /dep/findbugs folder if necessary). Make sure that /dep/findbugs/findbugs.jar and /dep/findbugs/findbugs-ant.jar are present.
How It Works
FindBugs is a Static Code Analyzer (SCA). It will parse your program's compiled file and spot errors in coding (not syntax errors, but certain types of logic errors). As an example, one of the errors that FindBugs will spot is comparing two Strings using == instead of String.equals(). The analysis is then written as HTML (or text) that can be viewed with a browser. Catching errors from FindBugs is easy, and adding it as part of your continuous integration process is extremely beneficial.
At the beginning of build.xml, you define the FindBugs tasks. Much the same as you did for the Emma tasks (see Recipe 9.4), this section specifies where are the jar files that defines the new task (depfindbugs), and also defines a property of where to put the report when done.
The build.xml also has a new target project called “findbugs.” The findbugs target compiles the source files with debug information (having debug information helps on the FindBugs report as it will include the line# when reporting errors), and then proceeds to analyze the bytecode for errors. In the findbugs task, you specify the location of the compiled .class files (this is the <class> property), the location of the dependencies for your project (<auxClasspath> property), and the location of the source code (<sourcePath> property).
Within the findbugs target, there is a <antcall> task. The <antcall> task simply runs the target specified within the <antcall> task. Just before the <antcall> task, you assign the debug <property> to true. This, in turns gets passed to the <javac> task as debug="${debug}". When the debug <property> is set to true, the <javac>task will include debug information into the compilation of the Java source files. Having debug information in the compiled files will help generate a more readable FindBugs report as it will include line numbers for where issues are found. The trick of assigning properties from within an Ant target is used throughout build.xml files to selectively enable certain behavior when going through specific build targets. If you were to build the regular build target, the results of the build would not contain debug information. If instead, you were to build the findbugs target because the findbugs target replaces the debug <property> to true, the result of the build would have debug information.
Tip To invoke Ant to run the default “target” (as specified in the build.xml), you just type ant. To specify another .xml file (instead of build.xml), you type ant –f nameofotherfile.xml. To change the default target to run, you type the name of the target at the end (for example, ant clean). To run this example, type ant –f findbugsbuild.xml findbugs. This will ask Ant to use findbugsbuild.xml file and to run the findbugs target.
9-6. Monitoring Garbage Collection in your Application
Problem
You notice that your application seems to be slowing down and suspect that there are garbage collections happening.
Solution 1
Add -Xloggc:gc.log-XX:+PrintGCDetails-XX:+PrintGCTimeStamps as parameters when starting your Java program. These parameters will allow you to log garbage collection information to the gc.log file, including the time garbage collections happen and the details (if it was a minor or major garbage collection and how long it took).
Ant target that executes Recipe 9_6 with garbage logging on.
<target name="Recipe9_6" depends="build">
<java classname="org.java7recipes.chapter9.Recipe9_6" fork="true">
<classpath refid="build.path" />
<jvmarg value="-Xloggc:gc.log" />
<jvmarg value="-XX:+PrintGCDetails" />
<jvmarg value="-XX:+PrintGCTimeStamps" />
</java>
</target>
In this build.xml file, the Java task is being used to add the arguments for garbage collection logging to the compiler before launching the application. To run this example throughout Ant, type ant Recipe9_6.
Solution 2
Analyze your program's memory consumption by using VisualVM (an external GNU Open Source Java profiler and visualization tool).To use and install VisualVM, go to http://visualvm.java.net/, download and follow the steps for installation (usually uncompressing in the folder of your choice and then clicking the provided executable). Figure 9-2 shows a screenshot of VisualVM profiling Recipe9_6.
Figure 9-2. VisualVMprofiling Recipe9-6
How It Works
Adding the flag to log garbage collection in solution 1 will cause your Java application to write minor and major garbage collections information into a log file. This allows you to “reconstruct” in time what happened to the application and allows you to spot probable memory leaks (or at least other memory-related issues). This is the preferred troubleshooting method for production systems as it is usually lightweight and can be analyzed after the fact.
Solution 2 instead involves using an open-source tool called VisualVM. This tool allows you to profile code live. It is a great tool to understanding in situ what's happening inside your application, as you can see real-time monitoring of CPU consumption, garbage collections, threads created, and classes loaded. VisualVM has its own extensive list of features that should be visited and that every Java developer should have as part of his or her arsenal of tools.
For solution 2, while Recipe9_6 is running, start VisualVM. You will see that there is a list of running virtual machines on the left tree view (under Local). Double-click the Recipe9_6 virtual machine, and you should see the current Memory consumption under the Monitor tab.
Tip While explaining all VisualVM options is beyond the scope of the book, it is a good idea to visit and view the different VisualVM plug-ins. One especially useful plug-in when debugging Memory issues is called Visual GC, which is accessible from the VisualVM interface by going to Tool Plugins Available Plugins, and selecting Visual GC. This plug-in will display even more information on Garbage Collections, including the different Memory spaces (Eden, Tenured, PermGen), and visually show how these spaces are growing/garbage collected.
9-7: Spotting Memory Leaks in Your Application
Problem
You notice that your application keeps consuming memory until it cannot continue working.
Solution
Use VisualVM to take and view the memory dump.
For this recipe, run the Recipe9_7 program in the example download. That program will launch a Swing frame. On this frame there is a button called Let's Create Windows that when clicked will create a new frame. The frame also has another button (Let's Close The Windows) that when clicked will close all the created frames. This program has a memory leak, and the memory leak is apparent when looking at the VisualVM memory graph.
Using VisualVM, you will see that there is an org.java7recipes.chapter9.Recipe9_7 Java process. Click it to connect. You should be able to see in the Monitor tab what the current memory consumption is. By clicking the Let's Create Windows button and the Let's Close The Windows button, you will see that the Memory consumption in the Monitor tab keeps going up. Look at Figure 9-3 for an example of what you should see.
After the memory size is up around 250Kb, click the button called Heap Dump, which will take a memory dump. The heap dump then will describe what is being held onto memory.
Figure 9-3. Memory image from Recipe9-7
How It Works
VisualVM allows you to take a snapshot on what is happening in the JVM. When hunting for memory leaks, you want to concentrate on what is the object that has the most memory allocation (the usual suspects are Maps). Once you find the objects that use the most memory, it is a matter to see who has the reference to it. By then removing the references to the object (for example, removing it from the map) you can gain control of memory and fix memory leaks.
Note VisualVM will satisfy most of the needs when it comes to troubleshooting memory issues, but there are JDK-provided tools as well. The most well-known is JMap, which will get a memory dump from the application specified by the process ID (PID). A typical usage is JMap -dump:format=b <pid>, which will create a heap dump with the default file name of heap_dump.out. Memory dumps collected using JMap can be viewed in VisualVM. The JDK also has an included viewer called JHat (http://download.oracle.com/javase/7/docs/technotes/tools/share/jhat.html).
When you take a heap dump (as described in this recipe), VisualVM will open up a new tab that shows the contents of the heap. Close to the top are Summary, Classes, Instances, and OQL Console buttons. For the purpose of this recipe, you will need to click the Classes button, which will give you a screen similar to Figure 9-4.
Figure 9-4. Class breakdown in VisualVM
On this view, if you sort by Size (by clicking the Size column), you will notice that object that uses the most memory is the int[] (an Int array). Even though the recipe's program doesn't have any Int arrays defined, the memory leak seems to be related to those Int arrays. To explore the int[], double-click the int[] at the beginning. It will take you to the Instances tab, and describe all the int[] instances that are currently defined in your application.
When debugging memory leaks, sometimes it is not obvious where is the leak coming from. This particular example shows int[] as the cause of the leak, even though when looking at the recipe's code there isn't any int[]. This happens because you have not defined int[], but instead have defined something that uses int[]. (You will find out at the end of the recipe what object was defining and causing the leak.)
In the left of the instance view, you can see each instance of int[] that is on the system, while on the right (under the section titled References), VisualVM displays who is using the int[]. For this exercise, click an int[] instance that has the size of 1800024, and look at the references. On the references, you can expand to “walk upwards” on who owns the int[]. After expanding the references, you will eventually see that they are being held by an Icon, which in turn is held by a JFrame. This presents the clue that JFrames are being held in memory and that the JFrames are not being disposed of. See Figure 9-5 for a screenshot on where to spot the JFrame (it's in the selected row of the bottom-right table).
Figure 9-5. Int[] references pointing to icons on a JFrame
With this newfound knowledge that JFrames is what is being “held,” you can then go back to the Classes tab and search for JFrame. You can see that there are 100+ JFrames still in memory, even though the recipe specifies them to be DISPOSE_ON_CLOSE. Clicking the JFrame will give you the list of instances of the JFrame and you can drill down on “who” is holding a reference to the JFrame.
After some digging through VisualVM (as shown in Figure 9-6), you find out that the reference to the JFrame is being held by the created Windows set. Upon closer inspection of the code, you can see that the created Windows set is populated with newly created JFrames, but never “emptied.” So the JFrame, being “held” by the set, couldn't be garbage collected when closed. The fix for the leak can be found in Recipe9_7_Fixed for the curious at heart.
In short, finding memory leaks usually involves following strange paths. At the beginning of this recipe, the memory dump showed int[] as the culprit, but in the end, it was a Set that held a reference to the JFrames that was never cleared, which in turn held an Icon, which in turn held an int[].
Figure 9-6. JFrame references being held in a createdWindows Set
9-8. Getting a Thread Dump
Problem
Your program seems to “hang” without doing anything, and you suspect that there might be a deadlock.
Solution
Use JStack to get a thread dump, and then analyze the thread dump for deadlocks. The following JStack is a thread dump from Recipe 9_8, which creates a deadlock:
C:>Jstack –l 9588
01 Found one Java-level deadlock:
02 =============================
03 Thread-0:
04 waiting for ownable synchronizer 0x00000000eab716b8, (a ReentrantLock$NonfairSync),
05 which is held by "main"
06 main:
07 waiting for ownable synchronizer 0x00000000eab716e8, (aReentrantLock$NonfairSync),
08 which is held by "Thread-0"
09
10 Java stack information for the threads listed above:
11 ===================================================
12 Thread-0:
13 at sun.misc.Unsafe.park(Native Method)
14 - parking to wait for <0x00000000eab716b8> (a j.u.c.l.ReentrantLock$NonfairSync)
15 at j.u.c.l.LockSupport.park(LockSupport.java:186)
16 at j.u.c.l.aqs.parkAndCheckInterrupt(aqs.java:834)
17 at j.u.c.l.aqs.acquireQueued(aqs.java:867)
18 at j.u.c.l.aqs.acquire(aqs.java:1197)
19 at j.u.c.l.ReentrantLock$NonfairSync.lock(ReentrantLock.java:214)
20 at j.u.c.l.ReentrantLock.lock(ReentrantLock.java:290)
21 at org.java7recipes.chapter9.Recipe9_8$1.run(Recipe9_8.java:28)
22 at java.lang.Thread.run(Thread.java:722)
23 main:
24 at sun.misc.Unsafe.park(Native Method)
25 - parking to wait for <0x00000000eab716e8> (a j.u.c.l.ReentrantLock$NonfairSync)
26 at j.u.c.l.LockSupport.park(LockSupport.java:186)
27 at j.u.c.l.aqs.parkAndCheckInterrupt(aqs.java:834)
28 at j.u.c.l.aqs.acquireQueued(aqs.java:867)
29 at j.u.c.l.aqs.acquire(aqs.java:1197)
30 at j.u.c.l.ReentrantLock$NonfairSync.lock(ReentrantLock.java:214)
31 at j.u.c.l.ReentrantLock.lock(ReentrantLock.java:290)
32 at org.java7recipes.chapter9.Recipe9_8.start(Recipe9_8.java:38)
33 at org.java7recipes.chapter9.Recipe9_8.main(Recipe9_8.java:20)
34
35 Found 1 deadlock.
For this recipe to work, you must have as part of your PATH environment variable the JDK's bin folder (For example C:Program Filesjavajdk1.7.0in). If you have this path, you can run the tools such as JStack and JPS.
The JStack command uses as an argument –l (a dash and the letter L), which specifies a Long listing (it does extra work to get more information about the threads running). The JStack also needs to know the PID of the target VM. A quick way to list all running JVMs is to type JPS and press Enter. This will list the running VMs and their PIDs. Figure 9-7 shows a screenshot of a JStack finding a deadlock in Recipe 9-8.
Note For the purposes of this example, j.u.c.l represents java.util.concurrent.locks, and aqs represents AbstractQueuedSynchronizer.
Figure 9-7. JStack results
How It Works
JStack allows you to see all the stack traces that the current running threads have. JStack will also try to find deadlocks (circular dependencies of locks) that might be stalling your system. JStack will not find other problems such as livelock(when a thread is always spinning, i.e. something like while(true)), or starvation (when a thread cannot execute because it is too low of a priority or there are too many threads competing for resources), but it will help you understand what each of the threads in your program is doing.
Deadlocks happen because one thread is waiting for a resource that another thread has, and the second thread is waiting for a resource that the first thread has. In this situation, neither thread can continue because both are waiting for each other to release the resource that each one owns. Deadlocks don't only happen between two threads, but can also involve a “string” of threads so that Thread A is waiting for Thread B is waiting for Thread C is waiting for Thread D is waiting for the original Thread A. It is important to understand the dump to find the culprit resource.
In this recipe's example, Thread-0 wants to acquire the lock named “0x00000000eab716b8";it's described in the thread dump as “waiting for ownable synchronizer". Thread-0 cannot acquire the lock because it is held by the main thread. The main thread, on the other hand, wants to acquire the lock “0x00000000eab716e8” (notice that they are different; the first lock ends in b8, while the second ends in e8), which is held by Thread-0. This is a textbook definition of a deadlock on which each thread is forever waiting for each other to release the lock the other thread has.
Aside from deadlock, looking at thread dumps gives you an idea about what your program is doing in realtime. Especially in multithreaded systems, using thread dumps will help clarify where a thread is sleeping or what condition it is waiting for.
Tip JStack is usually lightweight enough to be run in a live system, so if you need to troubleshoot live problems, you can safely use JStack.