[Из песочницы] JUnit тесты для логирования
Логирование относится к сквозной функциональности — разбросанной по коду и, как правило, редко покрываемой юнит-тестами. Слабое покрытие тестами, очевидно, связано с тем что вывод в лог не всегда достаточно важен и воспринимается скорее как вспомогательная функция, а не цель работы метода, к тому же тестировать сквозную функциональность бывает достаточно сложно.
Но когда корректность вывода в лог становится критичной или же чувство прекрасного требует от нас полного покрытия кода тестами — без тестирования логгеров становится не обойтись.
Предположим у нас есть простой класс с log4j-логгером и методом doSomethingWithInt
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 больше или равен нулю");
}
}
}
Мы хотим протестировать факт того что вызов метода
new ClassWithLog4JLogger().doSomethingWithInt(1);
приведет к выводу в лог
— метод doSomethingWithInt вызван с параметром i = 1
— параметр i больше нуля
Традиционный подход к тестированию предполагает, инжектирование mock-объекта (с помощью Mockitio) в тестируемый класс и, после отработки тестируемого кода, проверку того как и какие параметры передавались в mock.
Проблема в том, что инжектировать логгер в наш класс достаточно сложно — он не передается в ClassWithLog4JLogger, а возвращается из static-метода, подменять returnValue которого Mockito не умеет (и у этого есть определенные основания — Mockito предназначено для тестирования объектов, в то время как static-метод относится к классу, а не объекту). Но проблема, конечно, решаема — причем несколькими способами
Способ 1. Mock для log4j-Appender-а
«За неимением горничной имеем дворника…» Пусть мы не можем подменить сам логгер —, но мы можем подсунуть ему mock-аппендер и убедиться, что логгер передает в аппеддер те события которые мы ожидаем.
Добавим проект JUnit и Mockito
junit
junit
4.12
test
org.mockito
mockito-all
1.10.19
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());
}
}
Все вроде бы достаточно просто и не нуждается в пояснении.
Единственный минус такого подхода — так как мы тестируем не логгер, а аппендер то мы проверяем не аргументы методов логгера, а аргументы которые логгер передает аппендеру (LoggingEvent-ы), а их верификация занимает чуть больше строчек кода.
Данный подход сработает и в том случае если в качестве логгера используется slf4J Это надстройка над log4j (и еще несколькими фреймворками логирования), позволяющая, например, выводить в лог параметры без конкатинации строк (см. пример ниже). Сам slf4J-логгер не имеет методов для добавления аппендера. Но при этом он в процессе работы использует нижестоящий фреймворк (из найденных в classpath). Если этим фреймворком будет log4j то мы можем подсунуть mock-аппендер в log4j-логгер — он в свою очередь будет вызван из slf4J
Итак, добавляем зависимости на slf4j и его связку с log4j
org.slf4j
slf4j-api
1.7.25
org.slf4j
slf4j-log4j12
1.7.25
И протестируем класс почти такой же как в предыдущем примере — отличие только в логгере и передачи параметров в лог (теперь без конкатенации строк)
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 больше или равен нулю");
}
}
}
Тест для него останется точно таким же — изменится только название класса для которого получаем логгер (при том что это по-прежнему log4j, а не slf4j логгер)!
Logger logger = Logger.getLogger(ClassWithSlf4JLogger.class);
Способ 2. Подмена slf4j-имплементации.
Но что если мы все же хотим подменить не аппендер, а сам логгер? Это таки-возможно. Как уже говорилось выше — slf4 использует на выбор один из нижестоящих фреймворков (log4j, logback и т.д.) Можно добавить в проект еще одну реализацию и при этом удалить из classpath остальные — тогда slf4 «подхватит» именно ее. А в тестовой реализации логгера есть методы позволяющие проверить его вызовы.
Итак — добавляем зависимость
uk.org.lidalia
slf4j-test
1.2.0
test
и — ВАЖНО (!) удаляем в процессе сборки другие slf4j-логгеры если они есть в проекте.
maven-surefire-plugin
org.slf4j:slf4j-log4j12
Тест (для класса, используемого в прошлом примере) выглядит крайне просто
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();
}
}
Проще некуда. Но есть и минус — работать тест будет только в связке с maven-ом или другой системой сборки которая удалит классы других логгеров, при этом предыдущий тест, заточенный на slf4j-log4j не отработает. На мой взгляд это не очень удобно так как сковывает нас в используемых средствах (обязательно запуск мавеном) и инструментах (не использование в тестах других логгеров).
Способ 3. Mock-логгер при помощи PowerMock
PowerMock — это как Mockito. Но круче. Чем круче? Тем, что может работать со static-методами, финальными классами, protected и даже private полями… Эдакий молоток в ювелирной лавке (кстати, именно кувалда изображена на эмблеме PowerMock) — в повседневном использовании инструмент слишком мощный, но иногда и без него — никуда. Вот и для тестирования логирования он отлично подходит — мы просто переопределялем метод LoggerFactory.getLogger и подсовываем ему наш mock-объект,
org.powermock
powermock-api-mockito
1.7.3
test
org.powermock
powermock-module-junit4
1.7.3
test
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());
}
Резюме
Все способы имеют право на существование. Мокирование аппендера представляется наиболее простым, не требующем использования новых (кроме JUnit и Mockito) библиотек, но не работает непосредственно с логгером.
Slf4j-test требует минимум кода —, но заставляет играться с подменой классов в classpath. А PowerMock достаточно прост и позволяет инжектить в тестируемый класс mock-логгер.
Код примеров
