Working with legacy code can be difficult at the best of times. But when it comes to adding new features, refactoring or maintaining code that you are not familiar with, it can become overwhelming. It can be especially difficult if you have been working with agile techniques for a few years and suddenly you are faced with copious amounts of code and no test case for as far as the eye can see.
So what can be done? The simple answer is to create unit tests. But, as you start modifying the code to break dependencies and enable testability, this can lead you into more trouble. What you really need is an unobtrusive way to evaluate expressions, find values, and determine which branch of the code is currently executing.
In his book "Working Effectively with Legacy Code," Michael Feathers talks about finding seams in legacy code to facilitate testing. The definition he provides for a seam is "a place where you can alter behavior in your program without editing in that place." Types of seams vary among languages, and for Java he defines two categories that are relevant, "link seams" - whereby ordering the class path differently, different classes can be substituted for testing; and "object seams" - where calls to constructors or methods are made using a sub-class or mock implementation, rather than the originally expected class. ( For more information see chapter 4 of "Working Effectively with Legacy Code", by Michael Feathers).
Another seam that I have found to be advantageous is the logging seam. Using this seam you can easily create unobtrusive unit tests around classes, without needing to edit class logic as well as avoiding behavior changes.
Finding the Seam
The untested code scenario from above is fairly common when working with legacy code or code that was not written with testability in mind. Examples are large methods and classes, complex branching (usually many levels of branching in the same method) and objects that are instantiated directly in the code when they are needed. Under these circumstances (as well as other others) the usual testing toolkit doesn't work well. The one advantage is that most code utilizes a logging framework.
From a testing perspective, it doesn't really matter what the original purpose of the logging code was. Whether it was used for information, debugging, or tracing - the important thing is that it provides telemetry information. This telemetry information can then be repurposed and used within unit tests, providing the safety net needed to confidently refactor code and add new features.
Additionally, adding new logging code into existing code is benign - it will not affect the existing functionality or behavior. This means that we can beef-up logging with new statements to report information (such as expression results, object instance values, and branching information) that we want to verify via unit tests. More details on this step will be provided later in the article.
The Test Case
In true testing fashion, let's develop the unit test first.
But before we get started, let's assume that the legacy code we are working with has been written in Java, and also that it utilizes the log4j logging framework from the Apache foundation.
The structure of the test case should follow the mock testing paradigm. These steps are:
- Create a mock object for the object being used by the class to be tested, hereafter called "ClassUnderTest".
- Configure the mock object with the testing expectations
- Apply or inject the mock object into the class under test
- Run the method being tested
- Validate that the expectations were met
In our case we are substituting the mock object for a logging appender. The appender will work (function) the same as a mock object - it will be primed with expectations before the test is run; it will capture calls from the class during testing; and finally, it will report on whether the expectations were met and whether any additional calls were made.
Here's the structure of the test case in code:
// create the testing appender
TestLoggingAppender appender = new TestLoggingAppender();
// add expectations
appender.addMessageToVerify("count=3");
appender.addMessageToVerify("finished processing");
// add the appender to those associated with the class under test
Logger log = LogManager.getLogger(ClassUnderTest.class);
log.setLevel(Level.INFO);
log.addAppender(appender);
// do usual test setup and configure the class under test
ClassUnderTest testme = new ClassUnderTest();
...
// run the method under test and verify the results
testme.myMethod();
// ensure all the expectations are met
assertTrue( appender.verify() );
The only trick here is to remember that when you use log4j, there are many different logging levels. When you configure the appender to receive logging information, you need to ensure the logging level is correctly set. In the code above, "log.setLevel(Level.INFO)" performs this function.
The Test Logging Appender
Finally, it's time to develop the test logging appender. We already know the methods that the test case is calling on the appender, so this gives us the initial structure of the class. These methods are "addMessageToVerify" and "verify."
Here is the first method.
public void addMessageToVerify( String msg ) {
called.put( msg, new State( msg, true, false ) );
}
When called, a new entry is added to a list of messages that is being managed by the appender. As well as the message, which is being used as the key for easier lookup, a state object is stored. The state object is a simple object that stores the message and two flags - denoting whether the message should be expected and whether it was called.
Next is "verify". This method uses the internal list of messages that has already been created. Returning a value of "true" signifies that all the messages that were expected to be called actually were, and that there were no additional messages logged to the appender. Otherwise a "false" value will be returned. Here's what it looks like:
public boolean verify() {
boolean result = true;
for( Iterator i=called.keySet().iterator(); i.hasNext(); ) {
State state = (State)called.get(i.next());
if( (!state.shouldCall() && state.wasCalled()) ||
(state.shouldCall() && !state.wasCalled()) )
result = false;
}
return result;
}
We have been talking about messages that are coming from the logging framework, but how does this happen? In order for our test logging appender class to accept logging messages, two things need to happen.
The first is that our test logging appender needs to be enabled in the test case. Logging is enabled with the code "LogManager.getLogger(ClassUnderTest.class)", and then our test logging appender is added to the list of appenders to receive logging messages with the call "log.addAppender(appender)."
Second, our test logging appender needs to extend the ConsoleAppender class. This introduces a new method, doAppend(LoggingEvent event), that we now need to implement:
public synchronized void doAppend(LoggingEvent loggingEvent) {
String msg = loggingEvent.getMessage().toString();
if( called.containsKey(msg) )
((State)called.get(msg)).setCalled(true);
else
called.put( msg, new State( msg, false, true ) );
}
Similar to the addMessageToVerify method, the doAppend method manipulates the internal list of messages. If the messages being logged exits, the doAppend method updates the status flag to denote that it has been called. If the message does not exist, then a new entry is added to the list with the flags set to denote that the message was not expected but called.
This completes the implementation of the test logging appender class. The complete implementation can be seen in listing 1.
Exploiting the Seam
The final step is to add the logging statements to the ClassUnderTest.
In our test case above we had the following two lines of code, which verifies that something happened three times, and that processing finished (presumably without exceptions).
appender.addMessageToVerify("count=3");
appender.addMessageToVerify("finished processing");
A possible method that the above expectations test is:
public void myMethod() {
// lots of code before the section we are interested in
try {
FileReader file = new FileReader("transactions.log");
BufferedReader reader = new BufferedReader(file);
String data;
int count = 0;
while( (data = reader.readLine())!=null ) {
process(data,count++);
}
LOG.info("count="+count);
LOG.info("finished processing");
} catch( Exception e ) {
// error processing
}
// more code afterwards
}
This is a simple example, and not indicative of what would normally be found in legacy code. The important thing to remember is that in order to test this section of code within the method, only two logging statements need to be added. No functionality is modified, and no refactoring needs to be performed.
When thinking about what to log, the following guidelines can be used:
- Static text can be logged to show starting and ending boundaries for the test area
- Static text can be logged within branches or loops to determine location
- Loop counter values can be logged to determine which loop iteration is being executed
- Branch determination logic (that which determines whether you do the "if" or the "else") can be logged
- Any variable (class, method or block scoped) value can be logged
- Any expression can be evaluated and the result logged
Conclusion
With the help of a logging framework, creating unit tests for legacy code can be an easy task. You can utilize existing logging, and unobtrusively add new logging statements to evaluate expressions, find values, and determine which branch of the code is currently executing. Now, with the test logging appender in your toolkit, you can confidently refactor existing legacy code and add new features without the fear of breaking existing functionality.
Listing 1 - The complete TestLoggingAppender listing.
public class TestLoggingAppender extends ConsoleAppender {
private Map called = new HashMap();
public boolean verify() {
boolean result = true;
for( Iterator i=called.keySet().iterator(); i.hasNext(); ) {
State state = (State)called.get(i.next());
if( (!state.shouldCall() && state.wasCalled()) ||
(state.shouldCall() && !state.wasCalled()) )
result = false;
}
return result;
}
public void printResults() {
for( Iterator i=called.keySet().iterator(); i.hasNext(); ) {
State state = (State)called.get(i.next());
StringBuffer sb = new StringBuffer();
sb.append("Logging message '").append(state.getMsg()).append("' ");
sb.append("was ").append( state.shouldCall()?"expected ":"not expected ");
sb.append( state.wasCalled()?"and called":"and was not called");
System.out.println(sb.toString());
}
}
public void addMessageToVerify( String msg ) {
called.put( msg, new State( msg, true, false ) );
}
public synchronized void doAppend(LoggingEvent loggingEvent) {
String msg = loggingEvent.getMessage().toString();
if( called.containsKey(msg) )
((State)called.get(msg)).setCalled(true);
else
called.put( msg, new State( msg, false, true ) );
}
class State {
private String msg;
private boolean shouldCall;
private boolean called;
public State( String msg, boolean shouldCall, boolean wasCalled ) {
this.msg = msg;
this.shouldCall = shouldCall;
this.called = wasCalled;
}
public String getMsg() {
return msg;
}
public boolean shouldCall() {
return shouldCall;
}
public boolean wasCalled() {
return called;
}
public void setCalled(boolean called) {
this.called = called;
}
}
}
About the author
Ian Roughley is a speaker, writer and independent consultant based out of Boston, MA. For over 10years he has been providing architecture, development, process improvement and mentoring services to clients ranging in size from fortune 10 companies to start-ups. Focused on a pragmatic and results-based approach, he is a proponent for open source, as well as process and quality improvements through agile development techniques.