I’ve seen a number of different patterns for testing logging and we just ran into this again at work, so I thought it’d be worth writing up a couple of them.
Simple logging
Many of the java based logging frameworks allow you to log and then choose to separate what you log from what needs to be done by attaching appenders to them. The common pattern here is to declare a static log instance inside each class, typically using the fully qualified class name. Most logging frameworks then treat this as a hierarchy of loggers that allow you to configure what type of logging at different levels.
I find the best strategy for testing this style of logging is to add an in memory appender that will capture the output that is sent to the logging framework. I will post an example with given frameworks in a second, but here are a few different concerns you need to think about:
- Getting a reference to the log – Most loggers are made private static. You can choose to break encapsulation slightly by weakening the access to package local just so that a test can get access to the log. I find that injecting it in as a dependency in the constructor appears to complicated, and dislike setter based dependency injection in an attempt to keep fields more immutable.
- Creating an appender to capture the output – This is where you’ll have to go to whichever logging framework and find out how appenders work. Most have a console appender, or something that you can simply extend and capture a logging event
- Make the appender capture the output – This is pretty easy. You must make a choice whether or not you want only your appender to capture the log events, or if you want it to go to other appenders as well.
- Clean up – The consequence of adding an appender with state is not a problem in a single test. When wired up across a long test suite, you potentially increase the amount of memory being consumed to the point where you’ll get out of memory errors. I find that it’s important to make sure that your appenders remove themselves from the logger at the end of the test to avoid side effects and to make sure they get garbage collected by the JVM. In a following post, you’ll see the pattern I tend to use.
More complex logging services
If you’re application requires more than just file based logging, and other actions need to be performed, you may still consider injecting a type of logger into the class that uses it. At this point, testing it becomes like any other interaction-based test and you can probably use mocking or stubbing to test the correct things are passed to to it.
By default, I wouldn’t really go through the motions of setting up a logging service unless there was some real need for it. The standard style of loggers and configuration of behaviour gives you quite a lot already.
Re: getting a reference
If I need to get access to a logger for testing, the pattern I would use is Chained Constructors (I also tend to make loggers instance variables instead of static, the loggers themselves tend to be singletons anyway)
It does slightly pollute the autocomplete, but I’m pretty sure that most people could guess between “Do I want the Foo(Bar) or Foo(Bar, Logger)?”
Generally, I wouldn’t test my logging output. If I’m doing something complicated that needs testing, then that’s a big warning sign, and if I’m testing the messages or the log levels, then I end up with mirror tests (a particularly insidious DRY violation)
Hi Andy,
Thanks for your comment. I think Chained Constructors does pollute things as well, and sometimes complicates things in projects that use autowiring. I find that package-local seems to be the least complicated and less verbose than another constructor.
I agree with you though that I wouldn’t test most logging output. With these tests, I think the focus is less on the mirroring side, and leaving intention for people about why the logging is important and sometimes what should be output.
Ah, don’t get me started on Autowiring 🙂
I’ve looked at the example you’ve given, and I’m still not convinced of why I would want to use it.
Hi Andy,
I won’t try to get you started on autowiring. Sometimes you don’t have a choice on this when you join projects. You have to live with what you get 😉
Anyway, the example isn’t supposed to convince people. It’s just stating a way to do it.
I hope that not all your projects rope you into the existing way of doing things. It’s demoralising if we are unable to make a change for the better.
It might help the people who could use this if you explained the why, because that’s what they’re likely to be searching for. If they already know the how, they won’t need to search for it.
Hi Andy,
I don’t think it’s very fair to assume that by doing things the same way when you first join a project you do not intend to make a change for the better. I think change is only good if you understand the context. I’m sure you’d agree with me that implementing change for change’s sake is not “for the better.” Better is contextual.
Anyway, this post wasn’t intend to describe the why behind the how, but I feel that is another blog post altogether.
Thanks for the great discussion