I’ve just spend two hours trying to find out why a unit test wasn’t outputting any debug messages after a certain point (trying to diagnose a memory leak I’ve found in NIO that can crash a 512Mb server in under 8 seconds - and afraid it’s something wrong with gathering writes in 1.4.2_04; more on that later, once I’ve worked out whether it’s our code or not and have a small test case).
After 1.8 hours I’d narrowed it down to a single line (there are lots of different code-paths so I had to check each one), a line whose sole purpose is to apply logging filters to all future log messages, based on the resource being requested. Of course, the unit test is mostly testing uninteresting stuff, like very common requests.
Took me ten minutes of looking through the source of the logging filter applier thinking “is this blocking on a synchronization lock?” (there’s java.lang.Thread-related code involved) before I realised the stunningly obvious. Low and behold, now I notice there’s a config file for this unit test that specifically does NOT filter all the boring stuff. Arggh! And it was only earlier this week that I brought up the suggestion that we should make our SCM automatically overwrite config files when it exports unit tests. Doh, Doh, and triple Doh!