Jeremy Hylton : weblog : 2003-10-21

Integrating unittest and logging

Tuesday, October 21, 2003, 11:42 a.m.

There ought to be some way to integrating the logging and unittest module. That is, a test could say that it expects a certain message to get logged or that it does not expect a message to get logged. I don't know if there is a way to write tests so that this wouldn't be unbearably tedious, but I suspect there is.

Jim and I have been talking about this feature for years, but have never had the time to pursue it. I was reminded of it recently because I was testing code that was designed to catch and log errors and continue. There was a real bug in the code that I spent hours trying to find; it was getting logged but its only effect on the test was to cause it to hang.

Large frameworks tend to have layers that catch unexpected exceptions and try to continue. It could be argued that this is a misfeature, but let's assume that it isn't. How do you test these systems? A legitimate bug in the code won't cause the framework to fall over, it will just keeping going. One possibility is to write a test that asserts that no errors are logged while the test is running.

We've made several abortive attempts to cause tests to fail when errors are logged. The problem is that many tests cause errors to be logged as part of normal operation. A ZEO server logs exceptions raised when executing remote method invocations. It is convenient to review these logs on a running server to look for signs of trouble. Many of the tests deliberately provoke exceptions, which are logged by the server. So those tests would need to indicate that they expect some error to be logged.

The question, then, is how to write a declaration of expected logging behavior. Should you write declarations for tests that do generate logging messages? Or can you should write declarations that say when you don't expect logging? The former seems more promising, because it would be hard to say what wasn't expected. In either case, however, you'd probably need to limit it to certain subsystems (assuming that the test involved several packages). Otherwise, a change to some other subsystem to add a log message could cause your tests to fail.