I was working on some legacy code (“legacy” meaning it has no automated test coverage) and I really wanted to write some automated acceptance tests for it. The problem is, I could not think of a way to do that without refactoring the code first. I did not want to do this because “it was already working” and the refactoring could have introduced new bugs. I had a chicken and egg problem: I didn’t want to modify code until I had automated tests but I had to modify code to write the automated tests. Which comes first?

I ended up using a trick that minimally changes the production code, actually improves the production code base, and allows me to write automated tests. It’s these two simple steps:

Add and use a logger in the production code you want to test. Write an automated test that mocks the logger.

In the rest of the article I’ll give an example that was close to my situation. Here’s what the code looked like:

package com.sleepeasysoftware.mockalogger; /** * Created by Daniel Kaplan on behalf of Sleep Easy Software. */ public class AnnoyingToTest { //more code public <T> void deepInTheBowelsOfTheProject(T object) { //lots of logic here //lots of guard statements that might return before it reaches the next line RemoteApi.getInstance().save(object); //I want to check that this is called here //lots more logic here } } 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 package com . sleepeasysoftware . mockalogger ; /** * Created by Daniel Kaplan on behalf of Sleep Easy Software. */ public class AnnoyingToTest { //more code public <T> void deepInTheBowelsOfTheProject ( T object ) { //lots of logic here //lots of guard statements that might return before it reaches the next line RemoteApi . getInstance ( ) . save ( object ) ; //I want to check that this is called here //lots more logic here } }

I specifically wanted to check if RemoteApi.getInstance().save(object); was called in this deepInTheBowelsOfTheProject method. Your reaction might be, “why not just mock out the RemoteApi if that’s what you want to check?” Well I agree, that would be the most straightforward way to do it but that wouldn’t work in this situation: The entry point of my test ends up calling RemoteApi.getInstance().save(object); in many places. I only care if it was called in this method.

I struggled with this for a while and came up with a solution I summarized above: I added a logger to this class and for the purposes of my test, I mocked it out. The class changed to look like this:

package com.sleepeasysoftware.mockalogger; import java.util.logging.Logger; /** * Created by Daniel Kaplan on behalf of Sleep Easy Software. */ public class AnnoyingToTest { public static Logger logger = Logger.getLogger(AnnoyingToTest.class.getName()); //more code public <T> void deepInTheBowelsOfTheProject(T object) { //lots of logic here //lots of guard statements that might return before it reaches the next line RemoteApi.getInstance().save(object); //I want to check that this is called here logger.info("I called save in deepInTheBowelsOfTheProject with this object class: " + object.getClass()); //lots more logic here } } 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 package com . sleepeasysoftware . mockalogger ; import java . util . logging . Logger ; /** * Created by Daniel Kaplan on behalf of Sleep Easy Software. */ public class AnnoyingToTest { public static Logger logger = Logger . getLogger ( AnnoyingToTest . class . getName ( ) ) ; //more code public <T> void deepInTheBowelsOfTheProject ( T object ) { //lots of logic here //lots of guard statements that might return before it reaches the next line RemoteApi . getInstance ( ) . save ( object ) ; //I want to check that this is called here logger . info ( "I called save in deepInTheBowelsOfTheProject with this object class: " + object . getClass ( ) ) ; //lots more logic here } }

With that logging statement in place, I could mock out the logger and run an acceptance test to check if that line of code ran. Also, there’s very little risk to this change and it will have the side effect adding better logs for debugging in the future. Here’s how my test looks:

package com.sleepeasysoftware.mockalogger; import org.junit.After; import org.junit.Before; import org.junit.Test; import java.util.logging.Logger; import static org.mockito.Mockito.mock; import static org.mockito.Mockito.verify; public class ImportantIntegrationTest { @Before public void setUp() throws Exception { AnnoyingToTest.logger = mock(Logger.class); } @After public void tearDown() throws Exception { AnnoyingToTest.logger = Logger.getLogger(AnnoyingToTest.class.getName()); //put things back the way they are } @Test public void testObjectICareAboutWasSaved() throws Exception { Important important = new Important(); important.run("some input"); verify(AnnoyingToTest.logger).info("I called save in deepInTheBowelsOfTheProject with this object class: " + ObjectICareAbout.class); } } 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 package com . sleepeasysoftware . mockalogger ; import org . junit . After ; import org . junit . Before ; import org . junit . Test ; import java . util . logging . Logger ; import static org . mockito . Mockito . mock ; import static org . mockito . Mockito . verify ; public class ImportantIntegrationTest { @Before public void setUp ( ) throws Exception { AnnoyingToTest . logger = mock ( Logger . class ) ; } @After public void tearDown ( ) throws Exception { AnnoyingToTest . logger = Logger . getLogger ( AnnoyingToTest . class . getName ( ) ) ; //put things back the way they are } @Test public void testObjectICareAboutWasSaved ( ) throws Exception { Important important = new Important ( ) ; important . run ( "some input" ) ; verify ( AnnoyingToTest . logger ) . info ( "I called save in deepInTheBowelsOfTheProject with this object class: " + ObjectICareAbout . class ) ; } }

This is a very nontraditional approach to testing, but if the alternative adds a lot of risk and takes a lot of time, it’s a very pragmatic thing to do.