Wednesday, February 07, 2007

Garrulous Software

A particularly annoying characteristic of software these days is excessive chattiness. This occurs at both the user and developer level. In fact, one of the things I prefer on the Mac vs. Windows is the lack of meaningless messages the Mac generates (No, I do NOT want to clean off my desktop right now!). Pestering messages at the OS level distract from your attention and diminish your productivity. In The Humane Interface, Jef Raskin discusses the locus of attention, which is the work you are trying to perform. Anything that moves your locus of attention had better be a) relevant to your work and b) urgent and important. In fact, I think its a good idea to turn off the automatic notifications of email arrival, especially if it interrupts real work. Experts on "flow" maintain that it takes up to 20 minutes to get back to that deep concentration state, and it gets harder as the day goes on to overcome the inertia required to get back to that flow state.

The problem in the development world is much worse. It seems like the norm now to generate tons of meaningless noise. Think about application server startup, scrolling messages into the console faster than you can read it. 99% of that information is just the application server saying, over and over again like an idiot, "I'm OK...I'm OK...I'm OK.............I'm OK" (that last one was an EJB loading). The only thing that allows you to see errors is the massive stack traces that come from errors in the J2EE world. In fact, this problem is so bad that developers have taken to dubious practices to make their own messages to stand out from the flood of useless information. Admit it...you've put a Systen.out.println() in your J2EE code to debug it (a whole other subject). And, to make yours stand out from the noise, you put 30 or 40 "~"'s in front of it. Of course, your coworker is doing the same thing, and they use 30 or 40 "#"'s for theirs. Before long, application servers look like they have Tourette's Syndrome, spewing mostly meaningless noise.

My pair and I encountered this very problem recently. We were working with client code that makes heavy (handed) use of Log4J to spew out messages to the console. Unfortunately, that makes for ugly unit test results: you can't see the interesting stuff for all the immense noise being generated by the code under test. In this case, it wasn't as simple as turning off the logging level (the code under test was creating an instance of something that had its own logging stuff buried deep inside). So, after a little thought, we figured out how to shut it up.

In out test case, we unplug the normal output stream, like so:

protected void setUp() throws Exception {
super.setUp();
originalOut = System.out;
System.setOut(new PrintStream(new DumbOutputStream()));
}
And, in tearDown, we put it back:

protected void tearDown() throws Exception {
super.tearDown();
System.setOut(originalOut);
}
Our "DumbOutputStream" isn't stupid, just quiet:

private class DumbOutputStream extends OutputStream {
public void write(int b) throws IOException {
//do nothing, because I'm dumb.
}
}
This effectively shut off the fountain of noise, leaving the testing framework's output (which occurs on System.err, not System.out) alone. Sometimes, you have to work hard just to shut something up.

1 comment:

Joshua Graham said...

Your solution is nice and fast for testing.

If you also want this behaviour in production code, look at the techniques used by various LoggingOutputStream classes around. The one in Log4J's contribs is a little old in its API usage but works nicely.

Obviously, at some point (like your main) you need to activate the hijacking of System.out (and System.err if you like).

You can then log all System.out's to your own logger/category (I call mine "console") at INFO level, and System.err's at ERROR level and turn that category's level to ERROR in the configuration. Whispery quiet :)

Sounds like a nice addition to JUnit for the test runner to do this all by itself.