JUnit tests for logging

Logging refers to end-to-end functionality - scattered around the code and, as a rule, rarely covered by unit tests. The weak test coverage is obviously due to the fact that logging is not always important enough and is perceived as an auxiliary function rather than the purpose of the method, and testing through functionality can be quite difficult.
But when the correctness of the output to the log becomes critical or the sense of beauty requires us to fully cover the code with tests - it becomes impossible to do without testing loggers.

Suppose we have a simple class with a log4j logger and doSomethingWithInt method

import org.apache.log4j.Logger;
public class ClassWithLog4JLogger {
 private static final Logger logger =  Logger.getLogger(ClassWithLog4JLogger.class);
   public void doSomethingWithInt(int i){
       logger.info(" - метод doSomethingWithInt вызван с параметром i = " +i);
       if (i>0){
           logger.info(" - параметр i больше нуля");
       }else{
           logger.info(" - параметр i меньше или равен нулю");
       }
   }
}

We want to test the fact that a method call

new ClassWithLog4JLogger().doSomethingWithInt(1);

will lead to the output to the log

- the doSomethingWithInt method is called with the parameter i = 1
- the parameter i is greater than zero The


traditional testing approach involves injecting a mock object (using Mockitio ) into the tested class and, after working out the tested code, checking how and what parameters passed to mock.

The problem is that injecting a logger into our class is quite difficult - it is not passed to ClassWithLog4JLogger but returns from the static method, replacing returnValuewhich Mockito does not know how (and this has certain reasons - Mockito is designed to test objects, while the static method refers to the class and not the object). But the problem, of course, is solvable - and in several ways

Method 1. Mock for log4j-appender


“For the lack of a maid, we have a janitor ...” Let us not replace the logger itself - but we can slip a mock appender on it and make sure that the logger sends the events that we expect to the appendix.

Add the JUnit and Mockito project

junitjunit4.12testorg.mockitomockito-all1.10.19test

and write here such a test

import org.apache.log4j.Appender;
import org.apache.log4j.Logger;
import org.apache.log4j.spi.LoggingEvent;
import org.junit.Assert;
import org.junit.Test;
import org.junit.runner.RunWith;
import org.mockito.ArgumentCaptor;
import org.mockito.Mock;
import org.mockito.runners.MockitoJUnitRunner;
import static org.mockito.Mockito.times;
import static org.mockito.Mockito.verify;
@RunWith(MockitoJUnitRunner.class) // тест управляется Mockito который создаст и инициализирует мок-объекты
public class ClassWithLog4JLoggerAppenderMockTest {
   @Mock
   Appender mockAppender;
   @Test
   public void doLoggingTest() {
       // Получаем логгер для нашего класса
       Logger logger = Logger.getLogger(ClassWithLog4JLogger.class);
       // Передаем логгеру mock-аппендер
       logger.addAppender(mockAppender);
       // вызываем тестируемый метод
       ClassWithLog4JLogger classWithLog4JLogger = new ClassWithLog4JLogger();
       classWithLog4JLogger.doSomethingWithInt(1);
       // 'перехватчик' передаваемых в mock параметров
       ArgumentCaptor eventArgumentCaptor = ArgumentCaptor.forClass(LoggingEvent.class);
       //проверяем, что аппендер вызывался два раза
       verify(mockAppender, times(2)).doAppend(eventArgumentCaptor.capture());
       //проверяем с какими параметрами вызывался аппендер
       Assert.assertEquals(" - метод doSomethingWithInt вызван с параметром i = 1", eventArgumentCaptor.getAllValues().get(0).getMessage());
       Assert.assertEquals(" - параметр i больше нуля", eventArgumentCaptor.getAllValues().get(1).getMessage());
//проверяем с какими параметрами вызывался аппендер (уровень логирования)
Assert.assertEquals(Level.INFO, eventArgumentCaptor.getAllValues().get(0).getLevel());
Assert.assertEquals(Level.INFO, eventArgumentCaptor.getAllValues().get(1).getLevel());
   }
}

Everything seems to be quite simple and needs no explanation.

The only minus of this approach is that since we are testing not the logger but the appender, we do not check the arguments of the logger methods, but the arguments that the logger passes to the appender (LoggingEvents), and their verification takes a little more lines of code.

This approach will work if slf4J is used as a logger. This is an add-on to log4j (and a few other logging frameworks), which allows, for example, outputting parameters to the log without string concatenation (see the example below). The slf4J logger itself has no methods for adding an appender. But at the same time, he uses the subordinate framework (from those found in the classpath) in the process. If log4j is this framework, then we can slip the mock appender into the log4j logger - it will in turn be called from slf4J.

So, we add the dependencies to slf4j and its connection with log4j

org.slf4jslf4j-api1.7.25org.slf4jslf4j-log4j121.7.25

And we will test the class almost the same as in the previous example - the only difference is in the logger and passing parameters to the log (now without string concatenation)

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class ClassWithSlf4JLogger {
   private static final Logger logger = LoggerFactory.getLogger(ClassWithSlf4JLogger.class);
   public void doSomethingWithInt(int i) {
       logger.info(" - метод doSomethingWithInt вызван с параметром i = {}", i);
       if (i > 0) {
           logger.info(" - параметр i больше нуля");
       } else {
           logger.info(" - параметр i больше или равен нулю");
       }
   }
}

The test for it will remain exactly the same - only the name of the class for which we get the logger will change (despite the fact that it is still log4j and not the slf4j logger)!

Logger logger = Logger.getLogger(ClassWithSlf4JLogger.class);

Method 2. Substitution of slf4j implementation.
But what if we still want to replace not the appender but the logger itself? It’s possible. As mentioned above - slf4 uses one of the following frameworks to choose from (log4j, logback, etc.). You can add another implementation to the project and at the same time remove the rest from the classpath - then slf4 will “pick up” it. And in the test implementation of the logger, there are methods to check its calls.

So - add the dependency

uk.org.lidaliaslf4j-test1.2.0test

and - IMPORTANT (!) we delete other slf4j loggers if they are in the project during the build process.

maven-surefire-pluginorg.slf4j:slf4j-log4j12

The test (for the class used in the previous example) looks extremely simple

import org.junit.After;
import org.junit.Assert;
import org.junit.Test;
import uk.org.lidalia.slf4jtest.TestLogger;
import uk.org.lidalia.slf4jtest.TestLoggerFactory;
public class ClassWithSlf4JTestLoggerTest {
   //получаем тестовый логгер
   TestLogger logger = TestLoggerFactory.getTestLogger(ClassWithSlf4JLogger.class);
   @Test
   public void doLoggingTest() {
       ClassWithSlf4JLogger classWithSlf4JLogger = new ClassWithSlf4JLogger();
       classWithSlf4JLogger.doSomethingWithInt(1);
       //проверяем сообщения передаваемые в логгер
       Assert.assertEquals(" - метод doSomethingWithInt вызван с параметром i = {}", logger.getLoggingEvents().asList().get(0).getMessage());
       Assert.assertEquals(1, logger.getLoggingEvents().asList().get(0).getArguments().get(0));
       Assert.assertEquals(" - параметр i больше нуля", logger.getLoggingEvents().asList().get(1).getMessage());
       Assert.assertEquals(2,  logger.getLoggingEvents().asList().size());
   }
   @After
   public void clearLoggers() {
       TestLoggerFactory.clear();
   }
}

Nowhere is easier. But there is also a minus - the test will work only in conjunction with maven or another build system that will remove the classes of other loggers, while the previous test, which is sharpened by slf4j-log4j, will not work. In my opinion, this is not very convenient as it binds us in the tools used (it is mandatory to start with the maven) and tools (not using other loggers in tests).

Method 3: Mock Logger with PowerMock


PowerMock is like Mockito. But cooler. What's cooler? The fact that it can work with static methods, final classes, protected and even private fields ... A kind of hammer in a jewelry shop (by the way, the sledgehammer is depicted on the PowerMock logo) - the tool is too powerful in everyday use, but sometimes without it - nowhere. So it’s great for testing logging - we just redefine the LoggerFactory.getLogger method and slip our mock object into it,

org.powermockpowermock-api-mockito1.7.3testorg.powermockpowermock-module-junit41.7.3test

import org.junit.Test;
import org.junit.runner.RunWith;
import org.mockito.InOrder;
import org.mockito.Mockito;
import org.powermock.api.mockito.PowerMockito;
import org.powermock.core.classloader.annotations.PrepareForTest;
import org.powermock.modules.junit4.PowerMockRunner;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import static org.mockito.Matchers.any;
import static org.mockito.Matchers.anyString;
import static org.mockito.Matchers.anyVararg;
import static org.powermock.api.mockito.PowerMockito.mock;
@RunWith(PowerMockRunner.class)
// информируем PowerMock что придется вносить изменения в класс LoggerFactory
@PrepareForTest({LoggerFactory.class})
public class PowerMockitoLoggingTest {
   // наш фейковый логгер
   private static Logger logger = mock(Logger.class);;
   // перееопределяем работу метода LoggerFactory.getLogger - теперь при вызове всегда вернет наш логгер
   static{
       PowerMockito.spy(LoggerFactory.class);
       try {
           PowerMockito.doReturn(logger).when(LoggerFactory.class, "getLogger",
                   any());
       }catch (Exception e){
           e.printStackTrace();
       }
   }
   @Test
   public void doLoggingTest() {
       ClassWithSlf4JLogger classWithSlf4JLogger = new ClassWithSlf4JLogger();
       classWithSlf4JLogger.doSomethingWithInt(1);
       //протестируем вызовы нашего логгера.
       // ради разнообразия - убедимся заодно в том, что методы логгера вызывались не просто с верными параметрами но и в нужном порядке
       InOrder inOrd = Mockito.inOrder(logger);
       inOrd.verify(logger).info(" - метод doSomethingWithInt вызван с параметром i = {}",1);
       inOrd.verify(logger).info(" - параметр i больше нуля");
       Mockito.verify(logger, Mockito.times(1)).info(anyString());
       Mockito.verify(logger, Mockito.times(1)).info(anyString(), anyVararg());
   }

Summary


All methods have a right to exist. Appencing is the easiest, not requiring the use of new libraries (except for JUnit and Mockito), but it does not work directly with the logger.

Slf4j-test requires a minimum of code - but it makes you play with class substitution in the classpath. And PowerMock is quite simple and allows you to inject a mock-logger into the tested class.

Code example

Also popular now: