RetroVue At Work
Allen had finally decided that there was a bug in the JVM. Either that, or he was losing his mind. This was one of those bugs that "couldn't happen."
Allen used to like null pointer exceptions. The stack backtrace always identified the offending line, which usually indicated the offending variable, and then (eventually) he would find the bug. But lately he had started to dread the null pointer exception. "The stack backtrace helped me to understand the symptom of the bug, but the code containing the actual cause of the bug was often far removed from the exception throwing code," he explained. "And by the time the exception was thrown, the underlying cause was sometime in the past. Who assigned null to the variable? And when? Where? That's the real bug, and by the time the exception occurs, it's usually way too late to pinpoint the cause."
In this particular case, the null value was contained in a field, so it wasn't too difficult using conventional tools to find all the places in the code where it was used. From that list, Allen whittled it down to a long list of assignments.
But upon examination of the code, it seemed none of them could be the cause. In each case, if the value were null, it would have blown up a few lines before the assignment, because in each case the value was dereferenced. Allen dutifully added some print statements, but they just confirmed what he had already surmised. He examined the constructors and added code to check the initialization values, but they, too, always verified that the value being assigned was nonnull.
After two days of tearing his hair out, he e-mailed his colleague Carl for help. "I don't think Allen really expected me to be able to help," Carl said. "I work remotely, and I wasn't familiar with Allen's code. But he sounded desperate." Carl asked Allen to run the program under RetroVue and send him the resulting journal file. Ten minutes after receiving it, Carl sent Allen information (see Figure 3) that he had captured from the RetroVue journal viewer and marked up. RetroVue clearly showed that, although the value of the argument was not null (line 115), the field named "configuration" was indeed being assigned a null value in GraphElement's constructor on line 119. That would explain the eventual null pointer exception. But why wasn't the argument value being assigned to the field? Allen examined the constructor one more time:
115 public GraphElement(GraphNode parent, Configuration configuration) {
116 if (configuration == null) {throw new IllegalArgumentException();}
117 this.parent = parent;
118 this.children = new GraphNode[0];
119 this.configuration = configuration;
120 }
Finally, he noticed the spelling error. Because the configuration argument was missing a "u," it was never used in the constructor at all (except in the check for null, which Allen had added, inadvertently duplicating the spelling error with copy-and-paste). So line 119, which was supposed to copy the nonnull argument value into the field, simply copied the field to itself (as if the assignment statement had been written this.configuration = this.configuration;). And, of course, the field's initial value was null.
The incident convinced Allen to start using RetroVue himself. "We had found and fixed the bug, but now I was curious why it occurred intermittently. Using RetroVue, I got a clear understanding of exactly what was going on in these classes in less than an hour. And along the way, I found and fixed another potential bug, and discovered the cause of a performance problem that another engineer had been struggling with."
— Ron Hughes
http://www.visicomp.com/
