I was looking at a problem in the early chapters of Artificial Intelligence: A Modern Approach. It’s called Vacuum World. This is a very simple agent problem consisting of a vacuum placed on a grid. The grid has only two squares, each of which is either dirty or clean. The vacuum has three actions: move left, move right, and suck.

I wrote a simple implementation of this in Java (because the course I’m taking uses Java), starting out something like this:

public class Vacuum {
    private GridSquare location;
    public void moveLeft() { ... };
    public void moveRight() { ... };
    public void suck() { ... };
}

Obvious, beginner’s OOP, right? But then I start to second-guess myself. Is location really a property of the vacuum? Or is it a property of the vacuum in its environment? That is, does the location variable belong in the Vacuum class, in the Grid class (the environment), or in some “world” object that encompasses both the vacuum and the grid? Should Vacuum even be allowed to have a reference directly to its location, or should it query the environment indirectly, as in “Is the square I am currently occupying (wherever it may be) dirty?”

The example code on the A.I.M.A. web site seems to go out of its way to be inscrutably OO, with the behavior of the vacuum divided among half a dozen abstract “agent” classes. I think the vacuum there stores its location as an integer, but I couldn’t swear it to you.

I decide to play around with the Java logging facility. I write a simple test program:

import java.util.logging.*;

public class LoggingTest {
    public static void main(String[] args) {
	Logger log = Logger.getLogger("com.stuartsierra");
	log.entering("LoggingTest", "main");
	log.info("Info Message");
	log.warning("Warning Message");
	log.exiting("LoggingTest", "main");
    }
}

Compile, run, and I get this:

Aug 30, 2006 10:48:45 AM LoggingTest main
INFO: Info Message
Aug 30, 2006 10:48:45 AM LoggingTest main
WARNING: Warning Message

Hmm. Not quite what I expected. Two out of my four log messages don’t appear. Back to the API docs. Ah, yes, I need to set the logging level if I want to get finer-grained messages like “entering” and “exiting.” So I add the line,

log.setLevel(Level.FINEST);

just after getLogger(), compile, and run again. Same exact result — the “entering” and “exiting” messages don’t appear. I look at the API docs again. Nothing strikes me. The Java (TM) Logging Overview doesn’t enlighten me either. I try Level.ALL, just to make sure. Nope, Java doesn’t want to print those messages.

Now if I were on a deadline, I would say screw it and go do some real work. But I want to understand why this doesn’t work. After three or four web searches I find An Introduction to the Java Logging API. As it turns out, I need to set the level not just of my Logger, but also of each of the Handlers receiving messages from it. The article suggests this code:

Handler[] handlers =
   Logger.getLogger( "" ).getHandlers();
for ( int index = 0; index < handlers.length; index++ ) {
   handlers[index].setLevel( Level.FINE );
}

I insert that into my test code, and lo and behold, it works:

Aug 31, 2006 11:05:53 AM LoggingTest main
FINER: ENTRY
Aug 31, 2006 11:05:53 AM LoggingTest main
INFO: Info Message
Aug 31, 2006 11:05:53 AM LoggingTest main
WARNING: Warning Message
Aug 31, 2006 11:05:53 AM LoggingTest main
FINER: RETURN

So what’s the lesson of all this? It’s easy just to say “Java’s logging API is weird.” But I’m sure those Handlers are in there for a reason. I can imagine wanting to send the same stream of log messages to a file and a window at the same time. I can even imagine wanting to send different levels of log detail to different outputs. I do think it is a mistake to have the level-setting code duplicated in both Logger and Handler, as it means more work for me, the client programmer who gets frustrated when his code doesn’t do what he expects it to. At the least, the API documentation for Logger.setLevel() should mention that you need to set the level on all the Handlers too.

More generally, I think this is an example of how a library can be too customizable. Picture the feature list: “Custom logging levels per-logger and per-output.” Sounds great, until you have to remember to set them both to the same value to get what you want.