Before C was tamed into ANSI C, we had a little joke: my code compiles, so it should run! (Ha ha!).
This was funny only if you understood C, because at that time the C compiler would accept just about anything C was truly a portable assembly language, created to see if it was possible to develop a portable operating system (Unix) that could be moved from one machine architecture to another without rewriting it from scratch in the new machines assembly language. So C was actually created as a side effect of building Unix, and not as a general-purpose programming language. Comment
Because C was targeted at programmers who wrote operating systems in assembly language, it was assumed that those programmers knew what they were doing and didnt need safety nets. For example, assembly-language programmers didnt need the compiler to check argument types and usage, and if they decided to use a data type in a different way than it was originally intended, they certainly must have good reason to do so, and the compiler didnt get in the way. Thus, getting your pre-ANSI C program to compile was only the first step in the long process of developing a bug-free program. Comment
The development of ANSI C along with stronger rules about what the compiler would accept came after lots of people used C for projects other than writing operating systems, and after the appearance of C++ which greatly improved your chances of having a program run decently once it compiled. Much of this improvement came through strong static type checking: strong, because the compiler prevented you from abusing the type, static because ANSI C and C++ perform type checking at compile time. Comment
To many people (myself included), the improvement was so dramatic that it appeared that strong static type checking was the answer to a large portion of our problems. Indeed, one of the motivations for Java was that C++s type checking wasnt strong enough (primarily because C++ had to be backward-compatible with C, and so was chained with its limitations). Thus Java has gone even further to take advantage of the benefits of type checking, and since Java has language-checking mechanisms that exist at run-time (C++ doesnt; whats left at run-time is basically assembly language very fast, but with no self-awareness) it isnt restricted to only static type checking[61]. Comment
It seems, however, that language-checking mechanisms can take us only so far in our quest to develop a correctly-working program. C++ gave us programs that worked a lot sooner than C programs, but often still had problems like memory leaks and subtle, buried bugs. Java went a long way towards solving those problems, and yet its still quite possible to write a Java program containing nasty bugs. In addition (despite the amazing performance claims always touted by the flaks at Sun) all the safety nets in Java added additional overhead, so sometimes we run into the challenge of getting our Java programs to run fast enough for a particular need (although most of the time, its more important to have a working program than one that runs at a particular speed). Comment
This chapter presents tools to solve the problems that the compiler doesnt. One of the biggest steps forward is the incorporation of automated unit testing, which doesnt just mean writing tests, but incorporating those tests into a build system that not only compiles your code but runs the tests every single time, as if the tests were part of the compilation process (youll soon start relying upon them as if they are). For this book, a custom testing system was developed to ensure the correctness of the program output (and to display the output directly in the code listing), but the defacto standard JUnit testing system will also be used when appropriate. To make sure that testing is automatic, tests are run as part of the build process using Ant, an open-source tool that has also become a defacto standard in Java development, and CVS, another open-source tool that maintains a repository containing all your source code for a particular project. Comment
Sometimes unit testing isnt enough, and you need to track down problems in a program that runs, but doesnt run right. In JDK 1.4, the logging API was introduced to allow you to easily report information about your program. This is a significant improvement over adding and removing println() statements in order to track down a problem, and this section will go into enough detail to give you a thorough grounding in this API. This chapter also provides an introduction to debugging, learning what information a typical debugger can provide for you to aid in the discovery of subtle problems. Finally, youll learn about profiling and how to discover the bottlenecks that cause your program to run too slowly. Comment
One of the important recent realizations is the dramatic value of unit testing. This is the process of building integrated tests into all the code that you create, and running those tests every time you do a build. Its as if you are extending the compiler, telling it more about what your program is supposed to do. That way, the build process can check for more than just syntax errors, since you teach it how to check for semantic errors as well. C-style programming languages, and C++ in particular, have typically valued performance over programming safety. The reason that developing programs in Java is so much faster than in C++ (roughly twice as fast, by most accounts) is because of Javas safety net: features like better type checking and garbage collection. By integrating unit testing into your build process, you are extending this safety net, and the result is that you can develop faster. You can also be bolder in the changes that you make, more easily refactor your code when you discover design or implementation flaws, and in general produce a better product, faster.Comment
The effect of unit testing on development is so significant that it is used throughout this book, not only to validate the code in the book but also to display the expected output. My own experience with unit testing began when I realized that, to guarantee the correctness of code in a book, every program in that book must be automatically extracted and organized into a source tree, along with an appropriate build system. The build system used in this book is Ant (described later in this chapter), and with it in place you can just type ant to build all the code for the book. The effect of the automatic extraction and compilation process on the code quality of the book was so immediate and dramatic that it soon became (in my mind) a requisite for any programming book how can you trust code that you didnt compile? I also discovered that if I wanted to make sweeping changes, I could do so using search-and-replace throughout the book or just by bashing the code around. I knew that if I introduced a flaw, the code extractor and the build system would flush it out.
As programs became more complex, however, I also found that there was a serious hole in my system. Being able to successfully compile programs is clearly an important first step, and for a published book it seems a fairly revolutionary one usually due to the pressures of publishing, its quite typical to randomly open a programming book and discover a coding flaw. However, I kept getting messages from readers reporting semantic problems in my code. These problems could only be discovered by running the code. Naturally, I understood this and took some early faltering steps towards implementing a system that would perform automatic execution tests, but I had succumbed to publishing schedules, all the while knowing that there was definitely something wrong with my process and that it would come back to bite me in the form of embarrassing bug reports (in the open source world, embarrassment is one of the prime motivating factors towards increasing the quality of ones code!). Comment
The other problem was that I was lacking a structure for the testing system. Eventually, I started hearing about unit testing and JUnit, which provided a basis for a testing structure. The initial versions of JUnit that I looked at were unsatisfactory to me because they required the programmer to write too much code to do the simplest thing. More recent versions have reduced the code significantly by using reflection, and so are much more satisfactory.
I needed to solve another problem, however, and that was to validate the output of a program, and to show the validated output in the book. I had gotten regular complaints that I didnt show enough program output in the book. My attitude was that the reader should be running the programs while reading the book, and many readers did just that and benefited from it. A hidden reason for that attitude, however, was that I didnt have a way to test that the output shown in the book was correct. I knew that over time, something would happen so that the output was no longer correct (or, I wouldnt get it right in the first place). The simple testing framework not only captures the console output of the program and most programs in this book produce console output but it also compares it to the expected output which is printed in the book as part of the source-code listing, so readers can see what the output will be and also know that this output has been verified by the build process, and that they can verify it themselves.
I wanted to see if the test system could be even easier and simpler to use, applying the Extreme Programming principle of do the simplest thing that could possibly work as a starting point, and then evolving the system as usage demands (In addition, I wanted to try to reduce the amount of test code, in an attempt to fit more functionality in less code for screen presentations). The result is the simple testing framework described next. Comment
The primary goal of this simple testing framework[62] is to verify output of all the examples in the book. You have already seen lines such as Comment
SimpleTest monitor = new SimpleTest(Class Name);
at the beginning of each main() method, which create an instance of SimpleTest. The main task of SimpleTest is to hijack System.out, and then copy the stream to both the standard output and an internal buffer. The internal buffer output, implemented as an ArrayList, is then used to verify the expected output[63].Comment
The constructor for SimpleTest, after calling the constructor for the base class, first saves a reference to the standard output, and then redirects System.out to the SimpleTest object. Notice that, since the static method setOut() takes as argument a PrintStream, SimpleTest must extend PrintStream. That is, we are unplugging the System.out reference from its normal object, which is a PrintStream, and instead plugging it into ourselves, so we must also be a PrintStream (or equivalently, something inherited from PrintStream). The original PrintStream reference is captured in the console reference inside SimpleTest, and every time console input is intercepted, it is sent to the original console as well as being stored inside the output List. Note that you would ordinarily set System.out back to its original object when you are finished with it, but here we are not actually removing the original functionality of System.out but merely adding to it, so it seems reasonably safe not to restore it. Comment
//: com:bruceeckel:simpletest:SimpleTest.java // Simple utility for testing program output. Hijacks // System.out to print both to the console and a buffer. package com.bruceeckel.simpletest; import java.io.*; import java.util.*; import java.util.regex.*; public class SimpleTest extends PrintStream { private List output = Collections.synchronizedList(new ArrayList()); private PrintStream console; private PrintStream err; private String className; private boolean endOfLine = true; public SimpleTest(String cname) { super(System.out); console = System.out; err = System.err; System.setOut(this); System.setErr(this); className = cname; } public void cleanup() { System.setOut(console); } private void reset() { output.clear(); if (!endOfLine) endOfLine = true; } private void addToOutput(String s) { if (s == null) s = "null"; if (s.equals("")) { if (endOfLine) output.add(s); return; } StringTokenizer st = new StringTokenizer(s, System.getProperty("line.separator")); if (endOfLine) output.add(st.nextToken()); else { String str = (String) output.remove(output.size() - 1); output.add(str.concat(st.nextToken())); } while (st.hasMoreTokens()) output.add(st.nextToken()); } public synchronized void print(boolean b) { console.print(b); addToOutput(b ? "true" : "false"); if (endOfLine) endOfLine = false; } public synchronized void print(char c) { console.print(c); addToOutput(String.valueOf(c)); if (endOfLine) endOfLine = false; } public synchronized void print(int i) { console.print(i); addToOutput(String.valueOf(i)); if (endOfLine) endOfLine = false; } public synchronized void print(long l) { console.print(l); addToOutput(String.valueOf(l)); if (endOfLine) endOfLine = false; } public synchronized void print(float f) { console.print(f); addToOutput(String.valueOf(f)); if (endOfLine) endOfLine = false; } public synchronized void print(double d) { console.print(d); addToOutput(String.valueOf(d)); if (endOfLine) endOfLine = false; } public synchronized void print(char[] s) { console.print(s); addToOutput(String.valueOf(s)); if (endOfLine) endOfLine = false; } public synchronized void print(String s) { console.print(s); addToOutput(s); if (endOfLine) endOfLine = false; } public synchronized void print(Object obj) { console.print(obj); addToOutput(String.valueOf(obj)); if (endOfLine) endOfLine = false; } public synchronized void println() { console.println(); if (endOfLine) output.add(new String("")); else endOfLine = true; } public synchronized void println(boolean x) { console.println(x); addToOutput(x ? "true" : "false"); if (!endOfLine) endOfLine = true; } public synchronized void println(char x) { console.println(x); addToOutput(String.valueOf(x)); if (!endOfLine) endOfLine = true; } public synchronized void println(int x) { console.println(x); addToOutput(String.valueOf(x)); if (!endOfLine) endOfLine = true; } public synchronized void println(long x) { console.println(x); addToOutput(String.valueOf(x)); if (!endOfLine) endOfLine = true; } public synchronized void println(float x) { console.println(x); addToOutput(String.valueOf(x)); if (!endOfLine) endOfLine = true; } public synchronized void println(double x) { console.println(x); addToOutput(String.valueOf(x)); if (!endOfLine) endOfLine = true; } public synchronized void println(char[] x) { console.println(x); addToOutput(String.valueOf(x)); if (!endOfLine) endOfLine = true; } public synchronized void println(String x) { console.println(x); addToOutput(x); if (!endOfLine) endOfLine = true; } public synchronized void println(Object x) { console.println(x); addToOutput(String.valueOf(x)); if (!endOfLine) endOfLine = true; } // Used for test output generation public void expect() { try { PrintStream fout = new PrintStream( new FileOutputStream( new File(className + "Output.txt"))); Iterator it = output.iterator(); while (it.hasNext()) fout.println(it.next()); fout.close(); } catch (FileNotFoundException e) { } finally { reset(); } } public void expect(Writer w) { PrintWriter pw = new PrintWriter(w); Iterator it = output.iterator(); while (it.hasNext()) pw.println(it.next()); pw.close(); reset(); } public void expectRegularExpression(Object[] expectedOutput) { int expectedLines = 0; for (int i = 0; i < expectedOutput.length; i++) if (expectedOutput[i].getClass() == String.class) expectedLines++; else expectedLines += ((RegularExpression) expectedOutput[i]) .getNumOfLines(); if (expectedLines != output.size()) { // Test failed console.println("test failed!"); throw new RuntimeException( "Error testing output of class " + className + ": num of lines of output and expected " + "output did not match (expected: " + expectedLines + " lines output: " + output.size() + " lines)"); } else { int i = 0; Matcher m = null; Iterator it = output.iterator(); while (it.hasNext()) { String ln = (String) it.next(); if (expectedOutput[i].getClass() == String.class) { if (!expectedOutput[i].equals(ln)) { console.println("test failed!"); console.println("expected: " + "'" + expectedOutput[i] + "'"); console.println("output: " + ln); throw new RuntimeException( "Error testing output of class " + className + ": line " + i + " of output did not match " + "expected output (expected: " + expectedOutput[i] + " output: " + ln); } } else { m = ( ( RegularExpression) expectedOutput[i]) .getMatcher( ln); for (int j = 0; j < ((RegularExpression) expectedOutput[i]) .getNumOfLines(); j++) { if (j > 0) m = m.reset((String) it.next()); if (!m.matches()) { console.println("test failed!"); console.println( "expected: " + m.pattern().pattern()); console.println("output: " + ln); throw new RuntimeException( "Error testing output of class " + className + ": line " + i + " of output did not match " + "expected output (expected: " + m.pattern().pattern() + " output: " + ln); } } } i++; } console.println("test ok"); reset(); } } public void expect(String[] expectedOutput) { if (expectedOutput.length != output.size()) { // Test failed console.println("test failed!"); throw new RuntimeException( "Error testing output of class " + className + ": num of lines of output and expected " + "output did not match (expected: " + expectedOutput.length + " lines output: " + output.size() + " lines)"); } else { int i = 0; Iterator it = output.iterator(); while (it.hasNext()) { String ln = (String) it.next(); if (!expectedOutput[i++].equals(ln)) { console.println("test failed!"); console.println( "expected: " + expectedOutput[i - 1]); console.println("output: " + ln); throw new RuntimeException( "Error testing output of class " + className + ": line " + i + " of output did not match " + "expected output (expected: " + expectedOutput[i - 1] + " output: " + ln); } } console.println("test ok"); reset(); } } public void expectIgnoreOrder(String[] expectedOutput) { try { Thread.currentThread().sleep(500); } catch (InterruptedException e) { } if (expectedOutput.length != output.size()) { // Test failed console.println("test failed!"); throw new RuntimeException( "Error testing output of class " + className + ": num of lines of output and " + "expected output did not match (expected: " + expectedOutput.length + " lines output: " + output.size() + " lines)"); } else { // Sort the arrays Object[] out = output.toArray(); Arrays.sort(out); Arrays.sort(expectedOutput); if (!Arrays.equals(out, expectedOutput)) { // Test failed console.println("test failed!"); throw new RuntimeException( "Error testing output of class " + className + " (output: " + out); } console.println("test ok"); reset(); } } } ///:~
SimpleTest contains a variety of print() and println() functions, inherited from PrintStream and overloaded for each type. Each of these functions writes both to the standard output and the ArrayList output. The expect() method can then be used to dump the content of output into a file. The overloaded version of expect(), which takes as argument a String array representing expected output, is used to verify that the output produced by the program is exactly as specified by the argument. If this is not the case, expect() raises a RuntimeException aborting the build process. Comment
Some examples in the book make use of a random number generator to produce different output values each time they are executed. For such examples, a version of expect() method is used which takes as argument an array of RegularExpression objects. Regular expressions are a powerful new feature of Java 1.4 that allow a set of strings to be specified by simply defining a pattern that such strings should match. Our RegularExpression class consists of a String representing a regular expression and an integer numOfLines specifying how many lines of output should be matched to this regular expression. Comment
//: com:bruceeckel:simpletest:RegularExpression.java // Regular expression for testing program output lines package com.bruceeckel.simpletest; import java.util.regex.*; public class RegularExpression { private String regExp; private int numOfLines; public RegularExpression(String s) { this(s, 1); } public RegularExpression(String s, int i) { regExp = s; numOfLines = i; } public int getNumOfLines() { return numOfLines; } public Matcher getMatcher(CharSequence input) { Pattern p = Pattern.compile(regExp); return p.matcher(input); } } ///:~
Output of examples utilizing a random number generator is then verified by matching the output lines to the corresponding regular expression.Comment
Sometimes however, due to non-deterministic scheduling of threads by the JVM, it is possible that the sequence of output lines produced by a program cannot be predicted. In such cases method expectIgnoreOrder() is used, which verifies that the output produced by the program is as specified by the String array argument, regardless of order. In other words, if output lines are stored in a String array, expectIgnoreOrder() verifies that the two output arrays are permutations of one another.Comment
Although the testing framework we have just described allows us to simply and easily verify program output, in some cases we may want to perform more extensive testing of particular programs functionality. JUnit, a quickly emerging standard for writing repeatable tests, allows us to do just that. SimpleTestTest demonstrates how JUnit could be used to write tests for the simple testing framework described above. In JUnit, tests are implemented in a subclass of TestCase. The setUp() method is overridden to create and initialize a common set of objects which will be used in all the tests. In our case only one object, String array output, is created, representing the expected output. Such testing context is known as a test fixture. JUnit calls setUp() before each test to ensure there will be no side effects between test runs.Comment
//: X1:SimpleTestTest.java // A set of unit tests for the testing // framework class SimpleTest // {Depends: junit.jar} // {Broken} import java.io.*; import com.bruceeckel.simpletest.*; import java.util.*; import junit.framework.*; public class SimpleTestTest extends TestCase { private List output = null; private boolean endOfLine = true; private SimpleTest monitor; // Initialize primitive types static final boolean b = true; static final char c = 'm'; static final int i = 200; static final long l = 123456789012345L; static final float f = 1.234f; static final double d = 1.234567e-50d; static final char[] s = new char[] { 'c', 'h', 'a', 'r', 'a', 'r', 'r', 'a', 'y' }; static final String str = new String("string"); static final Object o = new Date(); public SimpleTestTest(String name) { super(name); } protected void setUp() { monitor = new SimpleTest("SimpleTestTest"); } protected void tearDown() { monitor.cleanup(); } public void testExpectNoArgs() { generateRandomOutput(); // Dump output to StringWriter StringWriter sw = new StringWriter(); monitor.expect(sw); // Transfer content of // String[] output into StringWriter StringWriter expOutput = new StringWriter(); Iterator it = output.iterator(); while (it.hasNext()) expOutput.write((String)it.next() + '\n'); // Test if StringWriters match assertEquals(sw.toString(), expOutput.toString()); } private void addToOutput(String s) { if (endOfLine) output.add(s); else { String str = (String)output.remove(output.size() - 1); output.add(str.concat(s)); } } private void generateRandomOutput() { output = new ArrayList(); endOfLine = true; for (int i = 0; i < 100; i++) { int choice = (int)(Math.random() * 19); switch (choice) { case 0: System.out.println(b); addToOutput(b ? "true" : "false"); if (!endOfLine) endOfLine = true; break; case 1: System.out.println(c); addToOutput(String.valueOf(c)); if (!endOfLine) endOfLine = true; break; case 2: System.out.println(i); addToOutput(String.valueOf(i)); if (!endOfLine) endOfLine = true; break; case 3: System.out.println(l); addToOutput(String.valueOf(l)); if (!endOfLine) endOfLine = true; break; case 4: System.out.println(f); addToOutput(String.valueOf(f)); if (!endOfLine) endOfLine = true; break; case 5: System.out.println(d); addToOutput(String.valueOf(d)); if (!endOfLine) endOfLine = true; break; case 6: System.out.println(s); addToOutput(String.valueOf(s)); if (!endOfLine) endOfLine = true; break; case 7: System.out.println(str); addToOutput(str); if (!endOfLine) endOfLine = true; break; case 8: System.out.println(o); addToOutput(String.valueOf(o)); if (!endOfLine) endOfLine = true; break; case 9: System.out.println(); if (endOfLine) output.add(new String("")); else endOfLine = true; break; case 10: System.out.print(b); addToOutput(b ? "true" : "false"); if (endOfLine) endOfLine = false; break; case 11: System.out.print(c); addToOutput(String.valueOf(c)); if (endOfLine) endOfLine = false; break; case 12: System.out.print(i); addToOutput(String.valueOf(i)); if (endOfLine) endOfLine = false; break; case 13: System.out.print(l); addToOutput(String.valueOf(l)); if (endOfLine) endOfLine = false; break; case 14: System.out.print(f); addToOutput(String.valueOf(f)); if (endOfLine) endOfLine = false; break; case 15: System.out.print(d); addToOutput(String.valueOf(d)); if (endOfLine) endOfLine = false; break; case 16: System.out.print(s); addToOutput(String.valueOf(s)); if (endOfLine) endOfLine = false; break; case 17: System.out.print(str); addToOutput(str); if (endOfLine) endOfLine = false; break; case 18: System.out.print(o); addToOutput(String.valueOf(o)); if (endOfLine) endOfLine = false; break; } } } public void testExpect() { generateRandomOutput(); monitor.expect( (String[])output.toArray(new String[] { })); // Stop one line short of expected output Iterator it = output.iterator(); String line = null; while (it.hasNext()) { line = (String)it.next(); if (it.hasNext()) System.out.println(line); else break; } if (line != null) { try { monitor.expect( (String[])output.toArray(new String[] { })); fail("Should raise a RuntimeException"); } catch (RuntimeException e) { } // Finish printing expected output System.out.println(line); monitor.expect( (String[])output.toArray(new String[] { })); } //Print one extra line it = output.iterator(); while (it.hasNext()) System.out.println(it.next()); System.out.println(o); try { monitor.expect( (String[])output.toArray(new String[] { })); fail("Should raise a RuntimeException"); } catch (RuntimeException e) { } } public void testExpectIgnoreOrder() { generateRandomOutput(); // Change order of Strings (lines) in output int i = (int)(Math.random() * output.size()); int j = 0; while ((j = (int)(Math.random()*output.size())) == i) ; output.add(i, output.remove(j)); // expect() method should fail try { monitor.expect( (String[])output.toArray(new String[] { })); fail("Should raise a RuntimeException"); } catch (RuntimeException e) { } // Test if all of the output lines appear // in the expected output, regardless of order monitor.expectIgnoreOrder( (String[])output.toArray(new String[] { })); } public static void main(String[] args) { junit.textui.TestRunner.run(SimpleTestTest.class); } } ///:~
SimpleTestTest contains three test methods; in JUnit, test methods are ordinary methods with no parameters. Method testExpectNoArgs() passes a StringWriter to expect() of SimpleTest, and then uses assertEquals(), which is inherited from TestCase, to verify that the output captured by the SimpleTest and the produced output match. testExpect() and testExpectIgnoreOrder() are similar, except that they dont use assertEquals(). This is because methods expect() and expectIgnoreOrder() do not return any values, but instead raise a RuntimeException in case of failure. JUnit allows us to write tests that verify whether an expected exception is thrown. In testExpect(), method fail() triggers a failure that is logged by JUnit in case expect() does not raise a RuntimeException, as expected. Comment
JUnit supports two ways of determining which tests to run, static and dynamic. The dynamic approach relies on reflection and requires less code, and is preferable for our purposes. If reflection is used, the TestRunner tool included with JUnit extracts all methods starting with test from the test class file, and executes them. More complete description of JUnit features can be found at JUnit, Testing Resources for Extreme Programming (http://www.junit.org).Comment
I began my career writing programs in assembly-language which controlled real-time devices. These programs usually fit into a single file, so when I was introduced to the make utility I wasnt too excited, because the most complex thing I had ever needed to do was run an assembler or a C compiler on a few files of code. Back then, building a project wasnt the difficult part of my task, and it wasnt too cumbersome to run everything by hand.
Time passed, and two events occurred. First, I started to create more complex projects comprising many more files. Keeping track of which files needed compliation became more than I was able (or wanted) to think about. Second, because of this complexity I began to realize that no matter how simple the build process might be, if you do something more than a couple of times you begin to get sloppy, and parts of the process start to fall through the cracks.
I came to realize that for a system to be built in a robust and reliable fashion, I needed to automate everything that goes into the build process. This requires some concentration up front, just like writing a program requires concentration, but the payoff is that you solve the problems once, and then you rely on your build configuration to take care of the details from then on. Its a variation of the fundamental programming principle of abstraction: we raise ourselves up from the grinding details by hiding those details inside a process, and giving that process a name. For many years, the name of that process was make.
The make utility appeared along with C as a tool to create the Unix operating system. Makes primary function is to compare the date of two files and to perform some operation that will bring those two files up to date with each other. The relationships between all the files in your projects and the rules necessary to bring them up to date (the rule is usually running the C/C++ compiler on a source file) are contained in a makefile. The programmer creates a makefile containing the description of how to build the system. When you want to bring the system up to date, you simply type make at the command line. To this day, installing Unix/Linux programs consists of unpacking them and typing make commands.
The concept of make is clearly a good idea, and this idea proliferated to produce many versions of make. C and C++ compiler vendors typically included their own variation of make along with their compiler these variations often took liberties with what people considered to be the standard makefile rules, and so the resulting makefiles wouldnt run with each other. The problem was finally solved (as has often been the case) by a make that was, and still is, superior to all the other makes, and is also free so theres no resistance to using it[64]: GNU make. This tool has a significantly better feature set than the other versions of make, and is available on all platforms.
In the previous two editions of Thinking in Java, I used makefiles to build all the code in the books source-code tree. I automatically generated these makefiles one in each directory, and a master makefile in the root directory that would call the rest using a tool that I originally wrote for Thinking in C++, in C++ (in about 2 weeks) and later rewrote in Python (in about half a day) called MakeBuilder.py[65]. It worked for both Windows and Linux/Unix, but I had to write extra code to make this happen, and I never tried it on the Macintosh. Therein lies the first problem with make: you can get it to work on multiple platforms, but its not inherently cross-platform. So for a language thats supposed to be write once, run anywhere (that is, Java), you can spend a lot of effort getting the same behavior in the build system if you use make.
The rest of the problems with make can probably be summarized by saying that it is like a lot of tools developed for Unix: the person creating the tool couldnt resist the temptation to create their own language syntax, and as a result Unix is filled with tools that are all remarkably different, and equally incomprehensible. That is to say, the make syntax is quite difficult to understand in its entirety Ive been learning it for years and has lots of annoying things like its insistence on tabs instead of spaces.
All that said, note that I still find GNU make indispensable for many of the projects I create.
All of these issues with make irritated a Java programmer named James Duncan Davidson enough to cause him to create ant as an open-source tool that migrated to the Apache project at http://jakarta.apache.org/ant. This site contains the full download including the ant executable and documentation. Ant has grown and improved until it is now generally accepted as the defacto standard build tool for Java projects.
To make ant cross-platform, the format for the project description files is XML (which youll learn about in detail in Chapter XXX). Instead of a makefile, you create a buildfile, which is named by default build.xml (this allows you to just say ant on the command line. If you name your buildfile something else you have to specify that name with a command-line flag).
The only rigid requirement for your buildfile is that it be a valid XML file. Ant compensates for platform-specific issues like end-of-line characters and directory path separators. You can use tabs or spaces in the buildfile as you prefer. In addition, the syntax and tag names used in buildfiles result in readable, understandable (and thus, maintainable) code.
On top of all this, ant is designed to be extensible, with a standard interface that allows you to write your own tasks, if the ones that come with ant arent enough (however, they usually are, and the arsenal is regularly expanding).
Unlike make, the learning curve for ant is reasonably gentle. You dont need to know that much in order to create a buildfile that compiles Java code in a directory. Heres a very basic build.xml file, for example, from chapter 2 of this book:
<?xml version="1.0"?> <project name="Thinking in Java (c02)" default="c02.run" basedir="."> <!-- build all classes in this directory --> <target name="c02.build"> <javac srcdir="${basedir}" classpath="${basedir}/.." source="1.4" /> </target> <!-- run all classes in this directory --> <target name="c02.run" depends="c02.build"> <antcall target="HelloDate.run"/> </target> <target name="HelloDate.run"> <java taskname="HelloDate" classname="HelloDate" classpath="${basedir};${basedir}/.." fork="true" failonerror="true" /> </target> <!-- delete all class files --> <target name="clean"> <delete> <fileset dir="${basedir}" includes="**/*.class"/> <fileset dir="${basedir}" includes="**/*Output.txt"/> </delete> <echo message="clean successful"/> </target> </project>
The first line states that this file conforms to version 1.0 of XML. XML looks a lot like HTML (notice the comment syntax is identical), except that you can make up your own tag names and the format must strictly conform to XML rules. For example, an opening tag like <project must either end within the tag at its closing angle brace with a slash: /> or have a matching closing tag like you see at the end of the file: </project>. Within a tag you can have attributes, but the attribute values must be surrounded in quotes. XML allows free formatting, but indentation like you see above is typical.
Each buildfile can manage a single project, described by its <project> tag. The project has an optional name attribute which is used when displaying information about the build. The default attribute is required, and refers to the target that is built when you just type ant at the command line, without giving a specific target name. basedir is a directory reference that can be used in other places in the buildfile.
A target has dependencies and tasks. The dependencies say which other targets must be built before this target can be built? Youll notice that the default target to build is c02.run, and the c02.run target says that it in turn depends on c02.build. Thus, the c02.build target must be executed before c02.run can be executed. Partitioning the buildfile this way not only makes it easier to understand, it also allows you choose what you want to do via the ant command line: if you say ant c02.build, then it will only compile the code, but if you say ant co2.run (or, because of the default target, just ant), then it will first make sure things have been built, and then run the examples.
So, for the project to be successful, targets c02.build and c02.run must first succeed, in that order. c02.build contains a single task, which is a command that actually does the work of bringing things up to date. This task runs the javac compiler on all the Java files in this current base directory notice the ${} syntax used to produce the value of a previously-defined variable, and that the orientation of slashes in directory paths is not important, since ant compensates depending on the operating system you run it on. The classpath attribute gives a directory list to add to ants classpath, and source specifies the compiler to use (this is actually only noticed by JDK 1.4 and beyond). Note that the Java compiler is responsible for sorting out the dependencies between the classes themselves, so you dont have to explicitly state inter-file dependencies like you must with make and C/C++ (this saves a lot of effort).
To run the programs in the directory (which, in this case, is only the single program HelloDate), this buildfile uses a task named antcall. This task does a recursive invocation of ant on another target, which in this case just uses java to execute the program. Note that the java task has a taskname attribute this attribute is actually available for all tasks, and is used when ant outputs logging information.
As you might expect, the java tag also has options to establish the class name to be executed, and the classpath. In addition, the
fork="true" failonerror="true"
attributes tell ant to fork off a new process to run this program, and to fail the ant build if the program fails. You can look up all the different tasks and their attributes in the documentation that comes with the ant download.
The last target is one thats typically found in every buildfile it allows you to say ant clean and delete all the files that have been created in order to perform this build. Whenever you create a buildfile, you should be careful to include a clean target, because youre the person who typically knows the most about what can be deleted and what should be preserved.
The clean target introduces some new syntax. You can delete single items with the one-line version of this task, like this:
<delete file="${basedir}/HelloDate.class"/>
The multi-line version of the task allows you to specify a fileset, which is a more complex description of a set of files and may specify files to include and exclude using wildcards. The above filesets to delete include all files in this directory and all subdirectories that have a .class extension, and all files in the current subdirectory that end with Output.txt.
The above buildfile is fairly simple; within this books source code tree (which is on the CD ROM and downloadable from www.BruceEckel.com) youll find more complex buildfiles. Also, ant is capable of doing much more that what we use for this book for the full details of its capabilities, see the documentation that comes with the ant installation.
Ant comes with an extension API, so that you can create your own tasks by writing them in Java. You can find full details in the official ant documentation, and in the published books on ant.
As an alternative, you can simply write a Java program and call it from ant this way you dont have to learn the extension API. For example, to compile the code in this book we need to verify that the version of Java that the user is running is JDK 1.4 or greater, so we just created the following program:
//: com:bruceeckel:tools:CheckVersion.java // {RunByHand} package com.bruceeckel.tools; public class CheckVersion { public static void main(String[] args){ String version = System.getProperty("java.version"); char minor = version.charAt(2); if (minor < '4') throw new RuntimeException("JDK 1.4.0 or higher " + "is required to run the examples in this book."); System.out.println("JDK version checked out."); } } ///:~
This simply uses System.getProperty() to discover the java version, and throws an exception if it isnt at least 1.4. When ant sees the exception it will halt. Now you can include the following in any buildfile where you want to check the version number:
<java taskname="CheckVersion" classname="com.bruceeckel.tools.CheckVersion" classpath="${basedir}" fork="true" failonerror="true" />
If you use this approach to adding tools, you can write them and test them quickly, and if its justified you can invest the extra effort and write an ant extension.
The revision control system is a class of tool that has been developed over many years to help manage large team programming projects. It has also turned out to be fundamental to the success of virtually all open-source projects, because open-source teams are almost always distributed globally via the Internet. So even if there are only two people working on a project, they benefit from using a revision control system.
The defacto standard revision control system for open-source projects is called CVS, available at http://www.cvshome.org. Because it is open-source and because so many people know how to use it, CVS is also a common choice for closed projects. Some projects even use CVS as a way to distribute the system. CVS has the usual benefits of a popular open-source project: the code has been thoroughly reviewed, its available for your review and modification, and if any new flaws are discovered they are corrected very rapidly.
CVS keeps your code in a repository on a server. This server may be on a local area network, but it is typically available on the Internet so that people on the team can get updates without being at a particular location. To connect to CVS, you must have an assigned user name and password, so theres a reasonable level of security; for more security you can use the ssh protocol (although these are Linux tools, they are readily available in Windows using Cygwin see http://www.cygwin.com XXX).
Once the repository is initialized by your system administrator, team members may get a copy of the code tree by checking it out. For example, once your machine is logged into the appropriate CVS server (details of which are left out here) you can perform the initial checkout with a command like this:
cvs z5 co TIJ3code
This will connect with the CVS server and negotiate the checkout (co) of the code repository called TIJ3code. The -z5 argument tells the CVS programs at both ends to communicate using a gzip compression level of 5, in order to speed up the transfer over the network.
Once this command is completed, youll have a copy of the code repository on your local machine. In addition, youll see that each directory in the repository has an additional subdirectory named CVS. This is where all the CVS information about the files in that directory are stored.
Now that you have your own copy of the CVS repository, you can make changes to the files in order to develop the project. Typically these changes include corrections and feature additions, along with test code and modified buildfiles necessary to compile and run the tests. Youll find that its very unpopular to check in code that doesnt successfully run all its tests, because then everyone else on the team will get the broken code (and thus fail their builds).
When youve made your improvements and youre ready to check them in, you must go through a two-step process which is the crux of CVS code synchronization. First, you update your local repository to synchronize it with the main CVS repository by moving into the root of your local code repository and running this command:
cvs update dP
At this point, you arent required to log in because the CVS subdirectory keeps the login information for the remote repository, and the remote repository keeps signature information about your machine as a double check to verify your identity.
The -dP flag is optional. -d tells CVS to create any new directories on your local machine that might have been added to the main repository and -P tells CVS to prune off any directories on your local machine that have been emptied on the main repository. Niether of these things happens by default.
The main activity of update, however, is quite interesting. You should actually run update on a regular basis, not just before you do a checkin, because it synchronizes your local repository with the main repository. If it finds any files in the main repository that are newer than files on your local repository, it brings the changes onto your local machine. However, it doesnt just copy the files, but instead it does a line-by-line comparison of the files, and patches the changes from the main repository into your local version. If youve made some changes to a file and someone else has made changes to the same file, CVS will patch the changes together as long as the changes dont happen to the same lines of code (CVS matches the contents of the lines, and not just the line numbers, so even if line numbers change it will be able to synchronize properly). Thus, you can be working on the same file as someone else, and when you do an update any changes the other person has committed to the main repository will be merged with your changes.
Of course, its possible that two people might make changes to the same lines of the same file. This is an accident due to lack of communication normally youll tell each other what youre working on so as not to tread on each others code (also, if files are so big that it makes sense for two different people are working on different parts of the same file, you might consider breaking the big files up into smaller files, for easier project management). If this happens, CVS simply notes the collision and forces you to resolve it by fixing the lines of code that collide.
Note that no files from your machine are moved into the main repository during an update. The update only brings changed files from the main repository onto your machine, and patches in any modifications youve made. So how do your modifications get into the main repository? This is the second step the commit.
When you type
cvs commit
CVS will start up your default editor and ask you to write a description of your modification. This description will be entered into the repository so that others will know whats been changed. After that, your modified files will be placed into the main repository so they are available to everyone else, the next time they do an update.
CVS has other capabilities, but checking out, updating and committing are what youll be doing most of the time. For detailed information about CVS, books are available, and the main CVS web site has full documentation: http://www.cvshome.org. In addition, you can search on the Internet using Google or other search engines; there are some very nice condensed introductions to CVS which can get you started without bogging you down with too many details (the Gentoo Linux CVS Tutorial by Daniel Robbins is particularly straightforward).
By incorporating compiling and testing into your buildfiles, you can follow the practice of performing daily builds, advocated by the Extreme Programming folks and others. Regardless of the number of features that you currently have implemented, you always keep your system in a state that it can be successfully built, so that if someone performs a checkout and runs ant, the buildfile will perform all the compilations and run all the tests without failing.
This is a powerful technique. It means that you always have, as a baseline, a system that compiles and passes all its tests. At any time, you can always see what the true state of the development process is by examining the features that are actually implemented in the running system. One of the timesavers of this approach is that no one has to waste time coming up with a report explaining what is going on with the system anyone can see for themselves by checking out a current build and running the program.
Running builds daily, or more often, also ensures that if someone (accidentally, we presume) checks in changes that cause tests to fail, youll know about it in short order, before those bugs have a chance to propagate further problems in the system. Ant even has a task that will send email, because many teams set up their buildfile as a cron[66] job to automatically run daily, or even several times a day, and send email if it fails. There is also an open-source tool that automatically performs builds and provides a web page to show the status of the project; see http://cruisecontrol.sourceforge.net.
Logging is the process of reporting information about a running program. In a program which is debugged, this information can be ordinary status data which describes the progress of the program (for example, if you have an installation program you may log the steps taken during installation the directories where you stored files, startup values for the program, etc.). Comment
Logging is also very useful during debugging. Without logging, you might try to decipher the behavior of a program by inserting println( ) statements. Many examples in this book use that very technique, and in the absence of a debugger (a topic that will be introduced shortly) its about all you have. However, once you decide the program is working properly, youll probably take the println( ) statements out. Then if you run into more bugs, you may need to put them back in. Its much nicer if you can put in some kind of output statements, which will only be used when necessary.Comment
Prior to the availability of the logging API in JDK1.4, programmers would often use a technique that relies on the fact that the Java compiler will optimize away code that will never be called. If debug is a static final boolean and you say:Comment
if(debug) { System.out.println("Debug info"); }
then when debug is false, the compiler will completely remove the code within the braces (thus the code doesnt cause any run-time overhead at all when it isnt used). Using this technique you can place trace code throughout your program and easily turn it on and off. One drawback to the technique, however, is that you must recompile your code in order to turn your trace statements on and off, whereas its generally more convenient to be able to turn on the trace using a command-line flag when you run the program.Comment
The logging API in JDK1.4 provides a more sophisticated facility to report information about your program, with almost the same efficiency of the above technique. For very simple informational logging, you can do something like this:Comment
//: X1:InfoLogging.java import com.bruceeckel.simpletest.*; import java.util.logging.*; import java.io.*; public class InfoLogging { private static Logger logger = Logger.getLogger("InfoLogging"); public static void main(String[] args) { SimpleTest monitor = new SimpleTest("InfoLogging"); logger.info("Logging an INFO-level message"); monitor.expect(new String[] { }); } } ///:~
The output during one run is:
Jul 7, 2002 6:59:46 PM InfoLogging main INFO: Logging an INFO-level message
Notice that the logging system has detected the class name and method name from which the log message originated. Its not guaranteed that these names will be correct, so you shouldnt rely on their accuracy. If you want to ensure that the proper class name and method are printed, you can use a more complex method to log the message, like this:Comment
//: X1:InfoLogging2.java // Guaranteeing proper class and method names import com.bruceeckel.simpletest.*; import java.util.logging.*; import java.io.*; public class InfoLogging2 { private static Logger logger = Logger.getLogger("InfoLogging2"); public static void main(String[] args) { SimpleTest monitor = new SimpleTest("InfoLogging2"); SimpleTest test = new SimpleTest("InfoLogging2"); logger.logp(Level.INFO, "InfoLogging2", "main", "Logging an INFO-level message"); test.expect(new String[] {}); monitor.expect(new String[] { "test ok" }); } } ///:~
The logp() method takes arguments of the logging level (youll learn about this next), the class name and method name, and the logging string. You can see that its much simpler to just rely on the automatic approach if the class and method names reported during logging are not critical.Comment
The logging API provides multiple levels of reporting and the ability to change to a different level during program execution. Thus, you can dynamically set the logging level to any of the following states: Comment
ALL |
All logging messages reported |
SEVERE |
Only logging messages with the level SEVERE will be reported |
WARNING |
Logging messages with levels of WARNING and SEVERE will be reported |
INFO |
Logging messages with levels of INFO and above are reported |
CONFIG |
Logging messages with levels of CONFIG and above are reported |
FINE |
Logging messages with levels of INFO and above are reported |
FINER |
Logging messages with levels of INFO and above are reported |
FINEST |
Logging messages with levels of FINEST and above are reported. (Is this the same as ALL? If not, what is the difference?) |
OFF |
No logging messages reported |
You can see the effect of trying out the different levels of logging in the following example:Comment
//: X1:LoggingLevels.java import com.bruceeckel.simpletest.*; import java.util.logging.Level; import java.util.logging.Logger; import java.util.logging.Handler; import java.util.logging.LogManager; public class LoggingLevels { static Logger lgr = Logger.getLogger("com"), lgr2 = Logger.getLogger("com.bruceeckel"), util = Logger.getLogger("com.bruceeckel.util"), test = Logger.getLogger("com.bruceeckel.test"), rand = Logger.getLogger("random"); static void logMessages() { lgr.info("com : info"); lgr2.info("com.bruceeckel : info"); util.info("util : info"); test.severe("test : severe"); rand.info("random : info"); } public static void main(String[] args) { SimpleTest monitor = new SimpleTest("LoggingLevels"); lgr.setLevel(Level.SEVERE); System.out.println("com level: SEVERE"); logMessages(); util.setLevel(Level.FINEST); test.setLevel(Level.FINEST); rand.setLevel(Level.FINEST); System.out.println( "individual loggers set to FINEST"); logMessages(); lgr.setLevel(Level.SEVERE); System.out.println("com level: SEVERE"); logMessages(); monitor.expect(new String[] { "com level: SEVERE", "individual loggers set to FINEST", "com level: SEVERE" }); } } ///:~
The first few lines of main() are necessary because the default level of logging messages that will be reported is INFO and greater (more severe). If you do not change this then the messages of level CONFIG and below will not be reported (try taking out the lines to see this happen).Comment
You can have multiple logger objects in your program, and these loggers are organized into a hierarchical tree, which can be programmatically associated with the package namespace. Child loggers keep track of their immediate parent and by default pass the logging records up to the parent.Comment
The root logger object is always created by default, and is the base of the tree of logger objects. You get a reference to the root logger by calling the static method Logger.getLogger(""). Notice that it takes an empty string, rather than no arguments.Comment
Each Logger object can have one or more Handler objects associated with it. Each Handler object provides a strategy[67] for publishing the logging information, which is contained in LogRecord objects. To create a new type of Handler, you simply inherit from the Handler class and override the publish() method (along with flush() and close(), to deal with any streams you may use in the Handler).Comment
The root logger always has one associated handler by default, which sends output to the console. In order to access the handlers, you call getHandlers() on the Logger object. In the above code, we know that theres only one handler so we dont technically need to iterate through the list, but its safer to do so in general because someone else may have added other handlers to the root logger. The default level of each handler is INFO, so in order to see all the messages we set the level to ALL (which is the same as FINEST).Comment
The levels array allows easy testing of all the Level values. The logger is set to each value and all the different logging levels are attempted. In the output you can see that only messages at the currently selected logging level, and those messages which are more severe, are reported.Comment
A LogRecord is an example of a Messenger object[68], whose job is simply to carry information from one place to another. All the methods in the LogRecord are getters and setters. Heres an example that dumps all the information stored in a LogRecord using the getter methods:Comment
//: X1:PrintableLogRecord.java // Override LogRecord toString() import com.bruceeckel.simpletest.*; import java.util.ResourceBundle; import java.util.logging.*; public class PrintableLogRecord extends LogRecord { public static String nl = System.getProperty("line.separator"); public PrintableLogRecord(Level level, String str) { super(level, str); } public String toString() { String result = "Level<" + getLevel() + ">" + nl; result += "LoggerName<" + getLoggerName() + ">" + nl; result += "Message<" + getMessage() + ">" + nl; result += "CurrentMillis<" + getMillis() + ">" + nl; Object objParams[] = getParameters(); result += "Params"; if(objParams == null) result += "<" + null +">" + nl; else for(int i = 0; i < objParams.length; i++) result += " Param # <" + i + " value " + objParams[i].toString() + ">" + nl; ResourceBundle rb = getResourceBundle(); if(rb == null) result += "ResourceBundle<" + null + ">" + nl; else result += "ResourceBundle<" + rb.toString() + ">" + nl; String strName = getResourceBundleName(); if(strName == null) result += "ResourceBundleName<" + null + ">" + nl; else result += "ResourceBundleName<" + strName + ">" + nl; result += "SequencNumber<" + getSequenceNumber() + ">" + nl; Object objSrcName = getSourceClassName(); if(objSrcName == null) result += "SourceClassName<" + null + ">" + nl; else result += "SourceClassName<" + objSrcName + ">" + nl; result += "SourceMethodName<" + getSourceMethodName() + ">" + nl; result += "Thread Id<" + getThreadID() + ">" + nl; Throwable t = getThrown(); if(t == null) result += "Thrown<" + null + ">"; else result += "Thrown<" + t.toString() + ">"; return result; } public static void main(String[] args) { SimpleTest monitor = new SimpleTest("PrintableLogRecord"); PrintableLogRecord logRecord = new PrintableLogRecord(Level.FINEST, "Simple Log Record"); System.out.println(logRecord); monitor.expectRegularExpression(new Object[] { "Level<FINEST>", "LoggerName<null>", "Message<Simple Log Record>", new RegularExpression("CurrentMillis<.+>"), "Params<null>", "ResourceBundle<null>", "ResourceBundleName<null>", "SequencNumber<0>", "SourceClassName<null>", "SourceMethodName<null>", "Thread Id<10>", "Thrown<null>" }); } } ///:~
PrintableLogRecord is a simple extension of LogRecord that overrides toString() to call all the getter methods available in LogRecord.Comment
As noted above, you can easily create your own handler by inheriting from Handler and defining publish() to perform your desired operations. However, there are predefined handlers which will probably satisfy your needs without doing any extra work:Comment
StreamHandler |
Writes formatted records to an OutputStream |
ConsoleHandler |
Writes formatted records to System.err |
FileHandler |
Writes formatted log records either to a single file, or to a set of rotating log files |
SocketHandler |
Writes formatted log records to remote TCP ports |
MemoryHandler |
Buffers log records in memory |
For example, you often want to store logging output to a file. The FileHandler makes this easy:Comment
//: X1:LogToFile.java import com.bruceeckel.simpletest.*; import java.util.logging.*; public class LogToFile { private static Logger logger = Logger.getLogger("LogToFile"); public static void main(String[] args) throws Exception { SimpleTest monitor = new SimpleTest("LogToFile"); logger.addHandler( new FileHandler("LogToFile.xml")); logger.info("A message logged to the file"); monitor.expect(new String[] { }); } } ///:~
When you run this program, youll notice two things. First, even though were sending output to a file, youll still see console output. Thats because each message is converted to a LogRecord, which is first used by the local logger object, which passes it to its own handlers. At this point the LogRecord is passed to the parent object, which has its own handlers. This process continues until the root logger is reached. The root logger comes with a default ConsoleHandler, so the message appears on the screen as well as appearing in the log file (you can turn off this behavior by calling setUseParentHandlers(false)).Comment
The second thing youll notice is that the contents of the log file is in XML format, which will look something like this:Comment
<?xml version="1.0" standalone="no"?> <!DOCTYPE log SYSTEM "logger.dtd"> <log> <record> <date>2002-07-08T12:18:17</date> <millis>1026152297750</millis> <sequence>0</sequence> <logger>LogToFile</logger> <level>INFO</level> <class>LogToFile</class> <method>main</method> <thread>10</thread> <message>A message logged to the file</message> </record> </log>
The default output format for a FileHandler is XML. If you want to change the format, you must attach a different Formatter object to the handler. Here, a SimpleFormatter is used for the file in order to output as plain text format:Comment
//: X1:LogToFile2.java import com.bruceeckel.simpletest.*; import java.util.logging.*; public class LogToFile2 { private static Logger logger = Logger.getLogger("LogToFile2"); public static void main(String[] args) throws Exception { SimpleTest monitor = new SimpleTest("LogToFile2"); FileHandler logFile = new FileHandler("LogToFile2.txt"); logFile.setFormatter(new SimpleFormatter()); logger.addHandler(logFile); logger.info("A message logged to the file"); monitor.expect(new String[] { }); } } ///:~
The LogToFile2.txt file will look like this:Comment
Jul 8, 2002 12:35:17 PM LogToFile2 main INFO: A message logged to the file
You can register multiple handlers with each Logger object. When a logging request comes to the Logger, it notifies all the handlers that have been registered with it[69], as long as the logging level for the Logger is greater than or equal to that of the logging request. Each handler, in turn, has its own logging level; if the level of the LogRecord is greater than or equal to the level of the handler, then that handler publishes the record.Comment
Heres an example that adds a FileHandler and a ConsoleHandler to the Logger object:Comment
//: X1:MultipleHandlers.java import com.bruceeckel.simpletest.*; import java.util.logging.*; public class MultipleHandlers { private static Logger logger = Logger.getLogger("MultipleHandlers"); public static void main(String[] args) throws Exception { SimpleTest monitor = new SimpleTest("MultipleHandlers"); FileHandler logFile = new FileHandler("MultipleHandlers.xml"); logger.addHandler(logFile); logger.addHandler(new ConsoleHandler()); logger.warning("Output to multiple handlers"); monitor.expect(new String[] { }); } } ///:~
When you run the program, youll notice that the console output occurs twice thats because the root loggers default behavior is still enabled. If you want to turn this off, make a call to setUseParentHandlers(false):
//: X1:MultipleHandlers2.java import com.bruceeckel.simpletest.*; import java.util.logging.*; public class MultipleHandlers2 { private static Logger logger = Logger.getLogger("MultipleHandlers2"); public static void main(String[] args) throws Exception { SimpleTest monitor = new SimpleTest("MultipleHandlers2"); FileHandler logFile = new FileHandler("MultipleHandlers2.xml"); logger.addHandler(logFile); logger.addHandler(new ConsoleHandler()); logger.setUseParentHandlers(false); logger.warning("Output to multiple handlers"); monitor.expect(new String[] { }); } } ///:~
Now youll see only one console message.Comment
You can easily write custom handlers by inheriting from the Handler class. To do this, you must not only implement the publish() method (which performs the actual reporting) but also flush() and close(), which ensure that the stream that is used for reporting is properly cleaned up. Heres an example that stores information from the LogRecord into another object (a List of String). At the end of the program, the object is printed to the console:Comment
//: X1:CustomHandler.java // How to write custom handler // {Broken} import com.bruceeckel.simpletest.*; import java.util.logging.*; import java.util.*; public class CustomHandler { private static Logger logger = Logger.getLogger("CustomHandler"); private static List strHolder = new ArrayList(); public static void main(String[] args) { SimpleTest monitor = new SimpleTest("CustomHandler"); logger.addHandler(new Handler() { public void publish(LogRecord logRecord) { strHolder.add(logRecord.getLevel() + ":"); strHolder.add( logRecord.getSourceClassName() + ":"); strHolder.add( logRecord.getSourceMethodName() + ":"); strHolder.add( "<" + logRecord.getMessage() + ">"); strHolder.add( System.getProperty("line.separator")); } public void flush() {} public void close() {} }); logger.warning("Logging Warning"); logger.info("Logging Info"); System.out.print(strHolder); monitor.expect(new String[] { "[WARNING:, CustomHandler:, main:, <Logging Warning>, ", ", INFO:, CustomHandler:, main:, <Logging Info>, ", "]"}); } } ///:~
The console output comes from the root logger. When the ArrayList is printed you can see that only selected information has been captured into the object.Comment
When you write the code to send a logging message to a Logger object, you often decide at the time youre writing the code what level the logging message should be (the logging API certainly allows you to devise more complex systems wherein the level of the message can be determined dynamically, but this is less common in practice). The Logger object has a level that can be set so that it can decide what level of message to accept; all others will be ignored. This can be thought of as a basic filtering functionality, and its often all you need.Comment
Sometimes, however, you need more sophisticated filtering, so that you can decide whether to accept or reject a message based on something more than just the current level. To accomplish this you can write custom Filter objects. Filter is an interface that has a single method, boolean isLoggable(LogRecord record), which decides whether or not this particular LogRecord is interesting enough to report.Comment
Once you create a Filter, you register it with either a Logger or a Handler using the setFilter() method. For example, suppose youd like to only log reports about Ducks:Comment
//: X1:SimpleFilter.java import com.bruceeckel.simpletest.*; import java.util.logging.*; public class SimpleFilter { private static Logger logger = Logger.getLogger("SimpleFilter"); static class Duck {}; static class Wombat {}; static void sendLogMessages() { logger.log(Level.WARNING, "A duck in the house!", new Duck()); logger.log(Level.WARNING, "A Wombat at large!", new Wombat()); } public static void main(String[] args) { SimpleTest monitor = new SimpleTest("SimpleFilter"); sendLogMessages(); logger.setFilter(new Filter() { public boolean isLoggable(LogRecord record) { Object[] params = record.getParameters(); if(params == null) return true; // No parameters if(record.getParameters()[0] instanceof Duck) return true; // Only log Ducks return false; } }); logger.info("After setting filter.."); sendLogMessages(); monitor.expect(new String[] { }); } } ///:~
Before setting the Filter, messages about Ducks and Wombats are reported. The Filter is created as an anonymous inner class which looks at the LogRecord parameter to see if a Duck was passed as an extra argument to the log() method if so, it returns true to indicate that the message should be processed.Comment
Notice that the signature of getParameters() says that it will return an Object[]. However, if no additional arguments have been passed to the log() method, getParameters() will return null (in violation of its signature this is a bad programming practice). So instead of assuming that an array is returned (as promised) and checking to see if it is of zero length, we must check for null. If you dont do this correctly, then the call to logger.info() will cause an exception to be thrown.Comment
A Formatter is a way to insert a formatting operation into a Handlers processing steps. If you register a Formatter object with a Handler, then before the LogRecord is published by the Handler, it is first sent to the Formatter. After formatting, the LogRecord is returned to the Handler, which then publishes it.
To write a custom Formatter, extend the Formatter class and override format(LogRecord record). Then, register the Formatter with the Handler using the setFormatter() call, as seen here: Comment
//: X1:SimpleFormatterExample.java import com.bruceeckel.simpletest.*; import java.util.logging.*; import java.util.*; public class SimpleFormatterExample { private static Logger myLogger = Logger.getLogger("SimpleFormatterExample"); private static void logMessages() { myLogger.info("Line One"); myLogger.info("Line Two"); } public static void main(String[] args){ SimpleTest monitor = new SimpleTest("SimpleFormatterExample"); myLogger.setUseParentHandlers(false); Handler conHdlr = new ConsoleHandler(); conHdlr.setFormatter(new Formatter() { public String format(LogRecord record) { StringBuffer sbuf = new StringBuffer(); sbuf.append(record.getLevel() + " : "); sbuf.append(record.getSourceClassName() + " -:- " + record.getSourceMethodName() + " -:- "); sbuf.append(record.getMessage()); sbuf.append(System.getProperty("line.separator")); return sbuf.toString(); } }); myLogger.addHandler(conHdlr); logMessages(); monitor.expect(new String[] { }); } } ///:~
Remember that a logger like myLogger has a default handler that it gets from the parent logger (the root logger, in this case). Here, we are turning off the default handler by calling setUseParentHandlers(false), and then adding in a console handler to use instead. The new Formatter is created as an anonymous inner class in the setFormatter() statement. The overridden format() statement simply extracts some of the information from the LogRecord and formats it into a string. Comment
You can actually have one of your logging handlers send you an email, so that you can be automatically notified of important problems. The following example uses the JavaMail API to develop a Mail User Agent that uses the underlying mailing protocols (like SMTP, IMAP, POP) to send an email.
//: X1:EmailLogger.java // {RunByHand} Must be connected to the Internet // {Depends: mail.jar} // {Depends: activation.jar} import java.util.logging.*; import java.io.*; import java.util.Properties; import javax.mail.*; import javax.mail.internet.*; public class EmailLogger { private static Logger logger = Logger.getLogger("EmailLogger"); public static void main(String[] args) throws Exception { logger.setUseParentHandlers(false); Handler conHdlr = new ConsoleHandler(); conHdlr.setFormatter(new Formatter() { public String format(LogRecord record) { return record.getLevel() + " : " + record.getSourceClassName() + ":" + record.getSourceMethodName() + ":" + record.getMessage() + System.getProperty("line.separator"); } }); logger.addHandler(conHdlr); logger.addHandler( new FileHandler("EmailLoggerOutput.xml")); logger.addHandler(new MailingHandler()); logger.log(Level.INFO, "Testing Multiple Handlers", "SendMailTrue"); } } // A handler that sends mail messages class MailingHandler extends Handler { public void publish(LogRecord record) { Object[] params = record.getParameters(); if(params == null) return; // Send mail only if the parameter is true if (params[0].equals("SendMailTrue")) { new MailInfo("bruce@theunixman.com", new String[] { "bruce@theunixman.com" }, "smtp.theunixman.com", "Test Subject", "Test Content").sendMail(); } } public void close() {} public void flush() {} } class MailInfo { private String fromAddr; private String[] toAddr; private String serverAddr; private String subject; private String message; public MailInfo(String from, String[] to, String server, String subject, String message) { fromAddr = from; toAddr = to; serverAddr = server; this.subject = subject; this.message = message; } public void sendMail() { try { Properties prop = new Properties(); prop.put("mail.smtp.host", serverAddr); Session session = Session.getDefaultInstance(prop, null); session.setDebug(true); // Create a message Message mimeMsg = new MimeMessage(session); // Set the from and to address Address addressFrom = new InternetAddress(fromAddr); mimeMsg.setFrom(addressFrom); Address[] to = new InternetAddress[toAddr.length]; for (int i = 0; i < toAddr.length; i++) to[i] = new InternetAddress(toAddr[i]); mimeMsg.setRecipients( Message.RecipientType.TO,to); mimeMsg.setSubject(subject); mimeMsg.setText(message); Transport.send(mimeMsg); } catch (Exception e) { throw new RuntimeException(e); } } } ///:~
[[ Needs improvement: ]]
MailingHanlder is one of the Handlers registered with the logger. The MailingHandler in turn uses the MailInfo object to send an email. Whenever a logging message is sent with an additional parameter of SendMailTrue the MailingHandler knows that it needs to send an email.
The MailInfo object has the necessary state information required to send the email. This state information is provided to it through the constructor when it is instantiated.
To send an email you need to establish a Session with the Simple Mail Transfer Protocol (SMTP) server. You pass the address of the server to which you wish to establish a session with by creating a Properties object with a property named mail.smtp.host set to the value of the server address. You establish a session by making the Session.getDefaultInstance() call. The first argument is the Properties object and the second one is an instance of Authenticator that may be used for authenticating the user. The value of null specifies no authentication. The debugging flag is set to print communication of the client with the SMTP server.
MimeMessage is an abstraction of an Internet email message that extends the class Message. It helps you construct a message that complies with the MIME (Multipurpose Internet Mail Extensions) format. You construct a MimeMessage by passing it an instance of Session. You set the from and the to addresses by creating an instance of InternetAddress class (a subclass of Address). Finally you send the message using the static call Transport.send(). Transport is an abstract class. An implementation of Transport uses a specific protocol (generally SMTP) to communicate with the server to send the message. Comment
Although not mandatory, its advisable to give a logger the name of the class in which it is used. This allows you to manipulate the logging level of groups of loggers that reside in the same package hierarchy, at the granularlity of the directory package structure. For example, you can modify all the logging levels of all the packages in com, or just the ones in com.bruceeckel, or just the ones in com.bruceeckel.util, as shown in the following example: Comment
//: X1:LoggingLevelManipulation.java import com.bruceeckel.simpletest.*; import java.util.logging.Level; import java.util.logging.Logger; import java.util.logging.Handler; import java.util.logging.LogManager; public class LoggingLevelManipulation { static Logger lgr = Logger.getLogger("com"), lgr2 = Logger.getLogger("com.bruceeckel"), util = Logger.getLogger("com.bruceeckel.util"), test = Logger.getLogger("com.bruceeckel.test"), rand = Logger.getLogger("random"); static void logMessages() { lgr.info("com : info"); lgr2.info("com.bruceeckel : info"); util.info("util : info"); test.severe("test : severe"); rand.info("random : info"); } public static void main(String[] args) { SimpleTest monitor = new SimpleTest("LoggingLevelManipulation"); lgr.setLevel(Level.SEVERE); System.out.println("com level: SEVERE"); logMessages(); util.setLevel(Level.FINEST); test.setLevel(Level.FINEST); rand.setLevel(Level.FINEST); System.out.println( "individual loggers set to FINEST"); logMessages(); lgr.setLevel(Level.SEVERE); System.out.println("com level: SEVERE"); logMessages(); monitor.expect(new String[] { "com level: SEVERE", "individual loggers set to FINEST", "com level: SEVERE" }); } } ///:~
As you can see in the above code, if you pass getLogger() a string representing a namespace, the resulting Logger will control the severity levels of that namespace that is, all the packages within that namespace will be affected by changes to the severity level of the logger.
Each Logger keeps a track of its existing ancestor Logger. If a child logger already has a logging level set, then that level is used instead of the parent's logging level. Changing the logging level of the parent does not affect the logging level of the child once the child has its own logging level. Comment
Because it isnt in the same namespace, the logging level of random remains unaffected when the logging level of the logger com or com.bruceeckel is changed.Comment
At first glance, the Java logging API can seem rather over-engineered for most programming problems. The extra features and abilities dont come in handy until you start building larger projects. In this section well look at these features and recommended ways to use them. If youre only using logging on smaller projects you probably wont need to use these features. Comment
The file below shows how you can configure loggers in pa project by using a properties file:
//:! X1:log.prop #### Configuration File #### # Global Params # Handlers installed for the root logger handlers= java.util.logging.ConsoleHandler java.util.logging.FileHandler # Level for root logger is used by any logger # that does not have its level set .level= FINEST # Initialization class the public default constructor # of this class is called by the Logging framework config = ConfigureLogging # Configure FileHandler # Logging file name - %u specifies unique java.util.logging.FileHandler.pattern = java%g.log # Write 100000 bytes before rotating this file java.util.logging.FileHandler.limit = 100000 # Number of rotating files to be used java.util.logging.FileHandler.count = 3 # Formatter to be used with this FileHandler java.util.logging.FileHandler.formatter = java.util.logging.SimpleFormatter # Configure ConsoleHandler java.util.logging.ConsoleHandler.level = FINEST java.util.logging.ConsoleHandler.formatter = java.util.logging.SimpleFormatter # Set Logger Levels # com.level=SEVERE com.bruceeckel.level = FINEST com.bruceeckel.util.level = INFO com.bruceeckel.test.level = FINER random.level= SEVERE ///:~
[[ Need to describe details of the above listing ]] Comment
The configuration file above generates rotating log files, which are used to prevent any log file from becoming too large. By setting the FileHandler.limit value you give the maximum number of bytes allowed in one log file before the next one begins to fill. FileHandler.count determines the number of rotating log files to use; the configuration file above specifies three files. If all three files are filled to their maximum, then the first file begins to fill again, overwriting the old contents. Comment
Alternatively, all the output can be put in a single file by giving a FileHandler.count value of one. (FileHandler parameters are explained in detail in the Java API documentation). Comment
In order for the program below to use the configuration file shown above, you must specify the parameter java.util.logging.config.file on the command line: Comment
java -Djava.util.logging.config.file=log.prop ConfigureLogging
The configuration file can only modify the root logger. If you want to add filters and handlers for other loggers, you must write the code to do it inside a Java file, as noted in the constructor: Comment
//: X1:ConfigureLogging.java // {JVMArgs: -Djava.util.logging.config.file=log.prop} import com.bruceeckel.simpletest.*; import java.util.logging.*; public class ConfigureLogging { static Logger lgr = Logger.getLogger("com"), lgr2 = Logger.getLogger("com.bruceeckel"), util = Logger.getLogger("com.bruceeckel.util"), test = Logger.getLogger("com.bruceeckel.test"), rand = Logger.getLogger("random"); public ConfigureLogging() { /* Set Additional formatters, Filters and Handlers for the loggers here. You cannot specify the Handlers for loggers except the root logger from the configuration file. */ } public static void main(String[] args) { SimpleTest monitor = new SimpleTest("ConfigureLogging"); sendLogMessages(lgr); sendLogMessages(lgr2); sendLogMessages(util); sendLogMessages(test); sendLogMessages(rand); monitor.expect(new String[] { " Logger Name : com Level: SEVERE", " Logger Name : com.bruceeckel Level: FINEST", " Logger Name : com.bruceeckel.util Level: INFO", " Logger Name : com.bruceeckel.test Level: FINER", " Logger Name : random Level: SEVERE" }); } private static void sendLogMessages(Logger logger) { System.out.println(" Logger Name : " + logger.getName() + " Level: " + logger.getLevel()); logger.finest("Finest"); logger.finer("Finer"); logger.fine("Fine"); logger.config("Config"); logger.info("Info"); logger.warning("Warning"); logger.severe("Severe"); } } ///:~
The configuration will result in the output being sent to the files named java0.log, java1.log, and java2.log in the directory from which this program is executed.Comment
Although its not mandatory, you should generally consider using a logger for each class, following the standard of setting the logger name to be the same as the fully qualified name of the class. As shown earlier, this allows for finer-grained control of logging because of the ability to turn logging on and off based on namespaces. Comment
If you dont set the logging level for individual classes in that package, then the individual classes default to the logging level set for the package (assuming you name the loggers according to their package and class). Comment
If you control the logging level in a configuration file instead of changing it dynamically in your code, then you can modify logging levels without recompiling your code. Recompilation is not always an option when the system is deployed; often only the class files are shipped to the destination environment. Comment
Sometimes there is a requirement to execute some code to perform initialization activities such as adding Handlers, Filters and Formatters to loggers. This can be achieved by setting the config property in the properties file. You can have multiple classes whose initialization can be done using the config property. These classes should be specified using space-delimited values like this: Comment
config = ConfigureLogging1 ConfigureLogging2 Bar Baz
Classes specified in this fashion will have their default constructors invoked. Comment
Although this has been a fairly thorough introduction to the logging API, it doesnt include everything. For instance, we havent talked about the LogManager or details of the various built-in handlers such as MemoryHandler, FileHandler, ConsoleHandler, etc. You should go to the JDK documentation for further information.Comment
Although judicious use of System.out statements or logging information can produce valuable insight into the behavior of a program[70], for difficult problems this approach becomes cumbersome and time-consuming. In addition, you may need to peek more deeply into the program than print statements will allow. For this, you need a debugger.
In addition to more quickly and easily displaying information that you could produce with print statements, a debugger will also set breakpoints and then stop the program when it reaches those breakpoints. A debugger can also display the state of the program at any instant, view the values of variables that youre interested in, step through the program line by line, connect to a remotely running program, and more. Especially when you start building larger systems (where bugs can easily become buried), it pays to become familiar with debuggers.
The Java Debugger (JDB) is a command line debugger that ships with the JDK. JDB is at least conceptually a descendant of the Gnu Debugger (GDB, which was inspired by the original Unix DB), in terms of the instructions for debugging and its command line interface. JDB is useful for learning about debugging and performing simpler debugging tasks, and its helpful to know that its always available wherever the JDK is installed. However, for larger projects youll probably want to use a graphical debugger, described later.
Suppose youve written the following program:
//: X1:SimpleDebugging.java // {ThrowsException} public class SimpleDebugging { private static void foo1() { System.out.println("In foo1"); foo2(); } private static void foo2() { System.out.println("In foo2"); foo3(); } private static void foo3() { System.out.println("In foo3"); int j = 1; j--; int i = 5 / j; } public static void main(String[] args) { foo1(); } } ///:~
If you look at foo3(), the problem is obvious youre dividing by zero. But suppose this code is buried in a large program (as is implied here by the sequence of calls) and you dont know where to start looking for the problem. As it turns out, the exception that will be thrown will give enough information for you to locate the problem (this is just one of the great things about exceptions). But lets just suppose that the problem is more difficult than that, and that you need to drill into it more deeply and get more information than what an exception provides.
To run JDB, you must tells the compiler to generate debugging information by compiling SimpleDebugging.java with the g flag. Then you start debugging the program with the command line:
jdb SimpleDebugging
This brings up JDB and gives you a command prompt. You can view the list of available JDB commands by typing a ? at the prompt.
Heres an interactive debugging trace that shows how to chase down a problem:
Initializing jdb ... > catch Exception
The > indicates JDB is waiting for a command, and the commands typed in by the user are shown in bold. The command catch Exception causes a breakpoint to be set at any point where an exception is thrown (however, the debugger will stop anyway, even if you dont explicitly give this comment exceptions appear to be default breakpoints in JDB).
Deferring exception catch Exception. It will be set after the class is loaded. > run
Now the program will run till the next breakpoint, which in this case is where the exception occurs. Heres the result of the above run command:
run SimpleDebugging > VM Started: In foo1 In foo2 In foo3 Exception occurred: java.lang.ArithmeticException (uncaught)"thread=main", SimpleDebugging.foo3(), line=18 bci=15 18 int i = 5 / j;
The program runs till line 18 where the exception generated, but jdb does not exit when it hits the exception. The debugger also displays the line of code that caused the exception. You can list the point where the execution stopped in the program source by the list command as shown below.
main[1] list 14 private static void foo3() { 15 System.out.println("In foo3"); 16 int j = 1; 17 j--; 18 => int i = 5 / j; 19 } 20 21 public static void main(String[] args) { 22 foo1(); 23 }
The pointer (=>) in the above listing shows the current point from where the execution will resume. You could resume the execution by the cont (continue) command. But doing that will make JDB exit at the exception, printing the stack trace.
The locals command dumps the value of all the local variables:
main[1] locals Method arguments: Local variables: j = 0
You can see the value of j=0 is what caused the exception.
The wherei command prints the stack frames pushed in the method stack of the current thread:
main[1] wherei [1] SimpleDebugging.foo3 (SimpleDebugging.java:18), pc = 15 [2] SimpleDebugging.foo2 (SimpleDebugging.java:11), pc = 8 [3] SimpleDebugging.foo1 (SimpleDebugging.java:6), pc = 8 [4] SimpleDebugging.main (SimpleDebugging.java:22), pc = 0
Each line in the above trace after wherei represents a method call and the point where the call will return (which is shown by the value of the program counter pc). Here the calling sequence was main(), foo1(), foo2() and foo3(). You can pop the stack frame pushed when the call was made to foo3() with the pop command:
main[1] pop main[1] wherei [1] SimpleDebugging.foo2 (SimpleDebugging.java:11), pc = 8 [2] SimpleDebugging.foo1 (SimpleDebugging.java:6), pc = 8 [3] SimpleDebugging.main (SimpleDebugging.java:22), pc = 0
You can make the JDB step through the call to foo3() again with the reenter command:
main[1] reenter > Step completed: "thread=main", SimpleDebugging.foo3(), line=15 bci=0 System.out.println("In foo3");
The list command shows us that the execution begins at the start of foo3():
main[1] list 11 foo3(); 12 } 13 14 private static void foo3() { 15 => System.out.println("In foo3"); 16 int j = 1; 17 j--; 18 int i = 5 / j; 19 } 20
JDB also allows you to modify the value of the local variables. The divide by zero that was caused by executing this piece of code the last time can be avoided by changing the value of j. You can do this directly in the debugger, so that you can continue debugging the program without going back and changing the source file. Before you set the value of j, you will have to execute through line 25 since that is where j is declared.
main[1] step > In foo3 Step completed: "thread=main", SimpleDebugging.foo3(), line=16 bci=8 16 int j = 1; main[1] step > Step completed: "thread=main", SimpleDebugging.foo3(), line=17 bci=10 17 j--; main[1] list 13 14 private static void foo3() { 15 System.out.println("In foo3"); 16 int j = 1; 17 => j--; 18 int i = 5 / j; 19 } 20 21 public static void main(String[] args) { 22 foo1();
At this point j is defined and you can set its value so that the exception can be avoided.
main[1] set j=6 j=6 = 6 main[1] next > Step completed: "thread=main", SimpleDebugging.foo3(), line=18 bci=13 18 int i = 5 / j; main[1] next > Step completed: "thread=main", SimpleDebugging.foo3(), line=19 bci=17 19 } main[1] next > Step completed: "thread=main", SimpleDebugging.foo2(), line=12 bci=11 12 } main[1] list 8 9 private static void foo2() { 10 System.out.println("In foo2"); 11 foo3(); 12 => } 13 14 private static void foo3() { 15 System.out.println("In foo3"); 16 int j = 1; 17 j--; main[1] next > Step completed: "thread=main", SimpleDebugging.foo1(), line=7 bci=11 7 } main[1] list 3 public class SimpleDebugging { 4 private static void foo1() { 5 System.out.println("In foo1"); 6 foo2(); 7 => } 8 9 private static void foo2() { 10 System.out.println("In foo2"); 11 foo3(); 12 } main[1] next > Step completed: "thread=main", SimpleDebugging.main(), line=23 bci=3 23 } main[1] list 19 } 20 21 public static void main(String[] args) { 22 foo1(); 23 => } 24 } ///:~ main[1] next > The application exited
next executes a line at a time. You can see that the exception is avoided and we can continue stepping through the program. list is used to show the position in the program from where execution will proceed. Comment
Using a command line debugger like JDB can be inconvenient. You must use explicit commands to do things like looking at the state of the variables (locals, dump), listing the point of execution in the source code (list), finding out the threads in the system(threads), setting breakpoints (stop in, stop at) etc. A graphical debugger allows you to do all these things with a few clicks and also view the latest details of program being debugged without using explicit commands.
Thus, although you may want to get started by experimenting with JDB, youll probably find it much more productive to learn to use a graphical debugger in order to quickly track down your bugs. During the development of this edition of this book, we began using IBMs Eclipse editor and development environment, which contains a very good graphical debugger for Java. Eclipse is very well designed and implemented, and you can download it for free from www.Eclipse.org (this is a free tool, not a demo or shareware. Thanks to IBM for investing the money, time and effort to make this available to everyone).
Other free development tools have graphical debuggers as well, such as Suns Netbeans and the free version of Borlands JBuilder.
We should forget about small efficiencies, say about 97% of the time: premature optimization is the root of all evil. Donald Knuth
Although you should always keep the above quote in mind, especially when you are sliding down the slipperly slope of premature optimization, sometimes there comes a time when you need to decide where your program is spending all its time, and to see if you can improve the performance of those sections.
A profiling tool assists in this process by gathering information that allows us to see what parts of the program consume memory, and what methods consume maximum time. Some profilers even allow you to disable the garbage collector to help determine patterns of memory allocation.
A profiler can also be a useful tool in detecting threading deadlock in your program.
Here is the kind of help a profiler can give you about how memory is used in your program:
Profilers also keep track of how much time the CPU spends in various parts of your code. They can tell you:
This way you can decide what sections of your code need optimizing.
Coverage Testing shows you the lines of code in your program that were not executed during the test. This is not always so useful as the other profiling features, but it may help draw your attention to code that is not used and might therefore be a candidate for removal or refactoring.
To get coverage testing information for SimpleDebugging.java, you use the command:
java Xrunjcov:type=M SimpleDebugging
As an experiment, try putting lines of code that will not be executed into SimpleDebugging.java (youll have to be somewhat clever about this since the compiler can detect unreachable lines of code).
The profiler agent communicates the events it is interested in to the JVM. The JVM profiling interface supports the following events:
Allocate, move, and free an object
Create and delete a heap arena
Allocate and free a JNI global reference
Allocate and free a JNI weak global reference
Load and unload a compiled method
While profiling, the JVM sends these events to the profiler agent, which then transfers the desired information to the profiler front end, which can be a process running on another machine, if desired.
In this example you can see how to run the profiler that ships with the JDK. Although the information produced by this profiler is in the somewhat crude form of text files rather than a graphical representation which is typical of most of the commercial profilers, it still provides valuable help in determining the characteristics of your program.
You run the profiler by passing an extra argument to the JVM when you invoke the program. This argument must be in the form of a single string, without any spaces after the commas, like this (although it should be on a single line, it has wrapped in the book):
java Xrunhprof:heap=sites,cpu=samples,depth=10,monitor=y,thread=y,doe=y ListPerformance
Here are some traces of the file produced by HPROF. This file is created in the current directory and is named java.hprof.txt.
The top section of this file describes the details of the sections contained in the file. The data produced by the profiler is in different sections e.g. TRACE represents a trace section in the file. You will see a lot of TRACE sections each numbered so that they can be referenced later. The file also has a SITES section that shows the sites of memory allocation. The section has several rows, sorted by the number of bytes that are allocated and are being referenced the live bytes. The memory is listed in terms of the bytes. The column self represents the percentage of memory taken up by this site, the next column accum represents the cumulative memory percentage. The live bytes and live objects columns represent the number of live bytes at this site and the number of objects that were created that consumes these bytes. The allocated bytes and objects represent the total number of objects and bytes that are instantiated including the ones that are being used and the ones that are not being used. The difference in the number of bytes listed in allocated and live represent the bytes that can be garbage collected. The trace column actually references a TRACE in the file. The first row references trace 668 is shown below. The name represents the class whose instance was created.
SITES BEGIN (ordered by live bytes) Thu Jul 18 11:23:06 2002 percent live alloc'ed stack class rank self accum bytes objs bytes objs trace name 1 59.10% 59.10% 573488 3 573488 3 668 java.lang.Object 2 7.41% 66.50% 71880 543 72624 559 1 [C 3 7.39% 73.89% 71728 3 82000 10 649 java.lang.Object 4 5.14% 79.03% 49896 232 49896 232 1 [B 5 2.53% 81.57% 24592 310 24592 310 1 [S TRACE 668: (thread=1) java.util.Vector.ensureCapacityHelper(Vector.java:222) java.util.Vector.insertElementAt(Vector.java:564) java.util.Vector.add(Vector.java:779) java.util.AbstractList$ListItr.add(AbstractList.java:495) ListPerformance$3.test(ListPerformance.java:40) ListPerformance.test(ListPerformance.java:63) ListPerformance.main(ListPerformance.java:93)
The trace above shows the sequence of execution that does the memory allocation. Going through the trace as indicated by the line numbers you will find that there are two allocations that happen on this path. Object allocations take place on line number 222 of Vector.java (elementData = new Object[newCapacity];). This helps you infer what part of the program uses up a big chunk of memory (59.10 %). Note the [C shown above in SITE 1 represents the primitive type char. This is the internal representation of the JVM for the primitive types.
To determine the CPU utilization you can look up the CPU SAMPLES section. Below is a part of trace from this section.
SITES END CPU SAMPLES BEGIN (total = 514) Thu Jul 18 11:23:06 2002 rank self accum count trace method 1 28.21% 28.21% 145 662 java.util.AbstractList.iterator 2 12.06% 40.27% 62 589 java.util.AbstractList.iterator 3 10.12% 50.39% 52 632 java.util.LinkedList.listIterator 4 7.00% 57.39% 36 231 java.io.FileInputStream.open 5 5.64% 63.04% 29 605 ListPerformance$4.test 6 3.70% 66.73% 19 636 java.util.LinkedList.addBefore
The organization of this listing is similar to the organization of the SITES listings. The rows are sorted on basis of CPU utilization with the row on the top having the maximum CPU utilization as indicated in the self column. The accum column lists the cumulative CPU utilization. The count field specifies the number of times this method was called.[[TODO:Confirm]]. The next two columns respectively specify the trace number and the method that took this time. Consider the first row of the CPU SAMPLES section shown above. 28.12% of total CPU time was utilized in the method java.util.AbstractList.iterator() and it was called 145 times. The details of this call can be found out by looking at the trace number 662 which is listed below.
TRACE 662: (thread=1) java.util.AbstractList.iterator(AbstractList.java:332) ListPerformance$2.test(ListPerformance.java:28) ListPerformance.test(ListPerformance.java:63) ListPerformance.main(ListPerformance.java:93)
This trace helps you trace what caused a call to this method. You can infer that iterating through a list takes all that time.
The above technique is too basic and the information presented is in a primitive form. For large projects it is more desirable to have the information represented in graphical form. Graphic display of profiling results is provided by a number of profilers and is beyond the scope of this book.
Although it might be a bit surprising to think of a tool that was developed for documentation support as something that helps you track down problems in your programs, doclets can be surprisingly useful. The reason for this is that a doclet basically hooks into the Java parser, and so it has all the information available to the parser. With this, you can programmatically examine your code and thus flag potential problems.
The process of producing the API documentation from the Java source files involves the parsing of the source file and the formatting of this parsed file using the standard doclet. You can write a custom doclet to customize the formatting of your javadoc comments. However, doclets allow you to do far more than just formatting the comment since a doclet has almost all the information about the source file thats being parsed.
You can extract information about all the members of the class (such as fields, constructors, and methods) as well as the comments associated with each of the members. Details about the members is encapsulated inside special objects, which contain information about the properties of the member (private, static, final etc.). This information can be helpful in detecting poorly-written code, such as member variables that should be private but are public, method parameters without comments, and identifiers that do not follow naming conventions.
Javadoc may not catch all compilation errors. It will spot syntactical errors such as an unmatched brace, however, it may not catch semantic errors. For example, Javadoc will pass a call to non-existent method since it does not enforce this kind of semantic validity. The safest approach is to run the Java compiler on your code before attempting to use a doclet-based tool.
The parsing mechanism provided by javadoc parses the entire source file and stores it in memory, in an object of class RootDoc. The entry point for the doclet submitted to javadoc is start(RootDoc doc). It is comparable to a normal Java programs main(String[] args). You may traverse through the RootDoc object and extract the necessary information. The following example shows how to write a simple doclet it just prints out all the members of each class that was parsed:
//: X1:PrintMembersDoclet.java // Doclet that prints out all members of the class. import com.sun.javadoc.*; public class PrintMembersDoclet { public static boolean start(RootDoc root) { ClassDoc[] classes = root.classes(); processClasses(classes); return true; } private static void processClasses(ClassDoc[] classes) { for (int i = 0; i < classes.length; i++) { processOneClass(classes[i]); } } private static void processOneClass(ClassDoc cls) { FieldDoc fd[] = cls.fields(); for (int i = 0; i < fd.length; i++) processDocElement(fd[i]); ConstructorDoc cons[] = cls.constructors(); for (int i = 0; i < cons.length; i++) processDocElement(cons[i]); MethodDoc md[] = cls.methods(); for (int i = 0; i < md.length; i++) processDocElement(md[i]); } private static void processDocElement(Doc dc) { MemberDoc md = (MemberDoc)dc; System.out.print(md.modifiers()); System.out.print(" " + md.name()); if (md.isMethod()) System.out.println("()"); else if(md.isConstructor()) System.out.println(); } } ///:~
You can use the above doclet to print the members like this:
javadoc -doclet PrintMembersDoclet private PrintMembersDoclet
This invokes javadoc on the last argument in the command, which means it will parse the PrintMembersDoclet.java file. The -doclet option tells javadoc to use the custom doclet PrintMembersDoclet. The -private tag instructs javadoc to also print private members (the default is to only print protected and public members).
RootDoc contains a collection of ClassDoc that hold all the information about the class. Classes such as MethodDoc, FieldDoc and ConstructorDoc contain information regarding methods, fields and constructors, respectively. The method processOneClass() extracts the list of these members and prints them.
[61] It is primarily oriented to static checking, however. There is an alternative system, called latent typing or dynamic typing or weak typing, in which the type of an object is still enforced, but it is enforced at run-time, when the type is used, rather than at compile time. Writing code in such a language Python (http://www.python.org) is an excellent example gives the programmer much more flexibility and requires far less verbiage to satisfy the compiler, and yet still guarantees that objects are used properly. However, to a programmer convinced that strong, static type checking is the only sensible solution, latent typing is anathema and serious flame wars have resulted from comparisons between the two approaches. As someone who is always in pursuit of greater productivity, I have found the value of latent typing to be very compelling. In addition, the ability to think about the issues of latent typing help you, I believe, to solve problems that are difficult to think about in strong, statically typed languages.
[62] Inspired by Pythons doctest module.
[63] The ArrayList output is synchronized because it is possible for multiple threads to attempt writing to System.out at the same time. Youll learn all about multithreading in Chapter XXX.
[64] Except by the occasional company which, for reasons beyond comprehension, is still convinced that closed-source tools are somehow better or have superior tech support. The only situations where Ive seen this to be true are when tools have a very small user base, but even then it would be safer to hire consultants to modify open-source tools, and thus leverage prior work and guarantee that the work you pay for wont become unavailable to you (and also make it more likely that youll find other consultants already up to speed on the program).
[65] This is not available on the web site because its too customized to be generally useful.
[66] Cron is a program that was developed under Unix to run programs at specified times. However, it is also available in free versions under Windows, and as a Windows NT/2000 service: http://www.kalab.com/freeware/cron/cron.htm.
[67] A pluggable algorithm. Strategies allow you to easily change one part of a solution while leaving the rest unchanged. They are often used (as in this case) as ways to allow the client programmer to provide a portion of the code needed to solve a particular problem. For more details, see Thinking in Patterns with Java, downloadable at www.BruceEckel.com.
[68] A term coined by Bill Venners. This may or may not be a design pattern.
[69] This is the Observer design pattern (ibid).
[70] I learned C++ primarily by printing information, since at the time I was learning there were no debuggers available.