Как сделать JUnit assert для сообщения в логгере - PullRequest
156 голосов
/ 01 декабря 2009

У меня есть тестируемый код, который вызывает регистратор Java, чтобы сообщить о его состоянии. В тестовом коде JUnit я хотел бы убедиться, что в этом логгере была сделана правильная запись в журнале. Что-то вроде следующего:

methodUnderTest(bool x){
    if(x)
        logger.info("x happened")
}

@Test tester(){
    // perhaps setup a logger first.
    methodUnderTest(true);
    assertXXXXXX(loggedLevel(),Level.INFO);
}

Я полагаю, что это можно сделать с помощью специально адаптированного логгера (или обработчика, или форматера), но я бы предпочел повторно использовать уже существующее решение. (И, если честно, мне не ясно, как получить logRecord от регистратора, но предположим, что это возможно.)

Ответы [ 21 ]

4 голосов
/ 10 мая 2018

Ничего себе. Я не уверен, почему это было так сложно. Я обнаружил, что не смог использовать ни один из примеров кода выше, потому что я использовал log4j2 вместо slf4j. Это мое решение:

public class SpecialLogServiceTest {

  @Mock
  private Appender appender;

  @Captor
  private ArgumentCaptor<LogEvent> captor;

  @InjectMocks
  private SpecialLogService specialLogService;

  private LoggerConfig loggerConfig;

  @Before
  public void setUp() {
    // prepare the appender so Log4j likes it
    when(appender.getName()).thenReturn("MockAppender");
    when(appender.isStarted()).thenReturn(true);
    when(appender.isStopped()).thenReturn(false);

    final LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
    final Configuration config = ctx.getConfiguration();
    loggerConfig = config.getLoggerConfig("org.example.SpecialLogService");
    loggerConfig.addAppender(appender, AuditLogCRUDService.LEVEL_AUDIT, null);
  }

  @After
  public void tearDown() {
    loggerConfig.removeAppender("MockAppender");
  }

  @Test
  public void writeLog_shouldCreateCorrectLogMessage() throws Exception {
    SpecialLog specialLog = new SpecialLogBuilder().build();
    String expectedLog = "this is my log message";

    specialLogService.writeLog(specialLog);

    verify(appender).append(captor.capture());
    assertThat(captor.getAllValues().size(), is(1));
    assertThat(captor.getAllValues().get(0).getMessage().toString(), is(expectedLog));
  }
}
3 голосов
/ 19 апреля 2017

Что касается меня, вы можете упростить свой тест, используя JUnit с Mockito. Я предлагаю следующее решение для этого:

import org.apache.log4j.Appender;
import org.apache.log4j.Level;
import org.apache.log4j.LogManager;
import org.apache.log4j.spi.LoggingEvent;
import org.junit.After;
import org.junit.Before;
import org.junit.Test;
import org.junit.runner.RunWith;
import org.mockito.ArgumentCaptor;
import org.mockito.Captor;
import org.mockito.InjectMocks;
import org.mockito.Mock;
import org.mockito.runners.MockitoJUnitRunner;

import java.util.List;

import static org.assertj.core.api.Assertions.assertThat;
import static org.assertj.core.api.Assertions.tuple;
import static org.mockito.Mockito.times;

@RunWith(MockitoJUnitRunner.class)
public class MyLogTest {
    private static final String FIRST_MESSAGE = "First message";
    private static final String SECOND_MESSAGE = "Second message";
    @Mock private Appender appender;
    @Captor private ArgumentCaptor<LoggingEvent> captor;
    @InjectMocks private MyLog;

    @Before
    public void setUp() {
        LogManager.getRootLogger().addAppender(appender);
    }

    @After
    public void tearDown() {
        LogManager.getRootLogger().removeAppender(appender);
    }

    @Test
    public void shouldLogExactlyTwoMessages() {
        testedClass.foo();

        then(appender).should(times(2)).doAppend(captor.capture());
        List<LoggingEvent> loggingEvents = captor.getAllValues();
        assertThat(loggingEvents).extracting("level", "renderedMessage").containsExactly(
                tuple(Level.INFO, FIRST_MESSAGE)
                tuple(Level.INFO, SECOND_MESSAGE)
        );
    }
}

Именно поэтому у нас есть хорошая гибкость для тестов с различным количеством сообщений

0 голосов
/ 20 марта 2018

Что я сделал, если все, что я хочу сделать, это увидеть, что какая-то строка была записана (в отличие от проверки точных операторов журнала, которая слишком хрупкая), это перенаправить StdOut в буфер, сделать содержимое, затем сбросить StdOut:

PrintStream original = System.out;
ByteArrayOutputStream buffer = new ByteArrayOutputStream();
System.setOut(new PrintStream(buffer));

// Do something that logs

assertTrue(buffer.toString().contains(myMessage));
System.setOut(original);
0 голосов
/ 12 декабря 2017

Есть две вещи, которые вы, возможно, пытаетесь проверить.

  • Когда есть событие, представляющее интерес для оператора моей программы, выполняет ли моя программа соответствующую операцию регистрации, которая может информировать оператора об этом событии.
  • Когда моя программа выполняет операцию регистрации, имеет ли сообщение, которое она выдает, правильный текст.

Эти две вещи на самом деле разные вещи, и поэтому могут быть проверены отдельно. Тем не менее, тестирование второго (текст сообщения) настолько проблематично, что я рекомендую вообще не делать этого. В конечном итоге проверка текста сообщения будет состоять из проверки того, что одна текстовая строка (ожидаемый текст сообщения) совпадает или может быть легко получена из текстовой строки, используемой в коде регистрации.

  • Эти тесты вообще не проверяют логику программы, они только проверяют, что один ресурс (строка) эквивалентен другому ресурсу.
  • Испытания хрупкие; даже незначительные изменения в форматировании сообщения журнала нарушают ваши тесты.
  • Тесты несовместимы с интернационализацией (переводом) вашего интерфейса регистрации. Тесты предполагают, что существует только один возможный текст сообщения и, следовательно, только один возможный человеческий язык.

Обратите внимание, что наличие в программном коде (возможно, реализующего некоторую бизнес-логику) прямого вызова интерфейса ведения текстового журнала - плохой дизайн (но, к сожалению, очень обычный). Код, отвечающий за бизнес-логику, также определяет политику ведения журнала и текст сообщений журнала. Он смешивает бизнес-логику с кодом пользовательского интерфейса (да, сообщения журнала являются частью пользовательского интерфейса вашей программы). Эти вещи должны быть отдельными.

Поэтому я рекомендую, чтобы бизнес-логика напрямую не генерировала текст сообщений журнала. Вместо этого пусть он делегируется объекту регистрации.

  • Класс объекта ведения журнала должен предоставлять подходящий внутренний API, который ваш бизнес-объект может использовать для выражения события, которое произошло с использованием объектов вашей доменной модели, а не текстовых строк.
  • Реализация вашего класса ведения журналов отвечает за создание текстовых представлений этих объектов домена и отрисовку подходящего текстового описания события, а затем пересылку этого текстового сообщения в низкоуровневую структуру ведения журналов (например, JUL, log4j или slf4j) .
  • Ваша бизнес-логика отвечает только за вызов правильных методов внутреннего API вашего класса регистратора, передачу правильных доменных объектов для описания реальных событий, которые произошли.
  • Ваш конкретный класс ведения журнала implements и interface, который описывает внутренний API, который может использовать ваша бизнес-логика.
  • Ваш класс (ы), который реализует бизнес-логику и должен выполнять ведение журнала, имеет ссылку на объект ведения журнала для делегирования. Классом ссылки является реферат interface.
  • Используйте внедрение зависимостей для установки ссылки на регистратор.

Затем вы можете проверить, правильно ли ваши классы бизнес-логики сообщают интерфейсу ведения журнала о событиях, создав поддельный регистратор, который реализует внутренний API ведения журнала, и используя внедрение зависимостей на этапе настройки вашего теста.

Как это:

 public class MyService {// The class we want to test
    private final MyLogger logger;

    public MyService(MyLogger logger) {
       this.logger = Objects.requireNonNull(logger);
    }

    public void performTwiddleOperation(Foo foo) {// The method we want to test
       ...// The business logic
       logger.performedTwiddleOperation(foo);
    }
 };

 public interface MyLogger {
    public void performedTwiddleOperation(Foo foo);
    ...
 };

 public final class MySl4jLogger: implements MyLogger {
    ...

    @Override
    public void performedTwiddleOperation(Foo foo) {
       logger.info("twiddled foo " + foo.getId());
    }
 }

 public final void MyProgram {
    public static void main(String[] argv) {
       ...
       MyLogger logger = new MySl4jLogger(...);
       MyService service = new MyService(logger);
       startService(service);// or whatever you must do
       ...
    }
 }

 public class MyServiceTest {
    ...

    static final class MyMockLogger: implements MyLogger {
       private Food.id id;
       private int nCallsPerformedTwiddleOperation;
       ...

       @Override
       public void performedTwiddleOperation(Foo foo) {
          id = foo.id;
          ++nCallsPerformedTwiddleOperation;
       }

       void assertCalledPerformedTwiddleOperation(Foo.id id) {
          assertEquals("Called performedTwiddleOperation", 1, nCallsPerformedTwiddleOperation);
          assertEquals("Called performedTwiddleOperation with correct ID", id, this.id);
       }
    };

    @Test
    public void testPerformTwiddleOperation_1() {
       // Setup
       MyMockLogger logger = new MyMockLogger();
       MyService service = new MyService(logger);
       Foo.Id id = new Foo.Id(...);
       Foo foo = new Foo(id, 1);

       // Execute
       service.performedTwiddleOperation(foo);

       // Verify
       ...
       logger.assertCalledPerformedTwiddleOperation(id);
    }
 }
0 голосов
/ 29 августа 2017

Если вы используете java.util.logging.Logger, эта статья может быть очень полезна, она создает новый обработчик и делает утверждения в журнале. Вывод: http://octodecillion.com/blog/jmockit-test-logging/

0 голосов
/ 11 мая 2017

Используйте приведенный ниже код. Я использую тот же код для моего весеннего интеграционного теста, где я использую log back для регистрации. Используйте метод assertJobIsScheduled для утверждения текста, напечатанного в журнале.

import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.spi.LoggingEvent;
import ch.qos.logback.core.Appender;

private Logger rootLogger;
final Appender mockAppender = mock(Appender.class);

@Before
public void setUp() throws Exception {
    initMocks(this);
    when(mockAppender.getName()).thenReturn("MOCK");
    rootLogger = (Logger) LoggerFactory.getLogger(ch.qos.logback.classic.Logger.ROOT_LOGGER_NAME);
    rootLogger.addAppender(mockAppender);
}

private void assertJobIsScheduled(final String matcherText) {
    verify(mockAppender).doAppend(argThat(new ArgumentMatcher() {
        @Override
        public boolean matches(final Object argument) {
            return ((LoggingEvent)argument).getFormattedMessage().contains(matcherText);
        }
    }));
}
0 голосов
/ 06 августа 2015

Еще одна идея, о которой стоит упомянуть, хотя это и более старая тема, - создание производителя CDI, чтобы внедрить ваш регистратор, чтобы сделать насмешку легкой. (И это также дает преимущество в том, что больше не нужно объявлять «весь оператор логгера», но это не по теме)

Пример:

Создание логгера для внедрения:

public class CdiResources {
  @Produces @LoggerType
  public Logger createLogger(final InjectionPoint ip) {
      return Logger.getLogger(ip.getMember().getDeclaringClass());
  }
}

Классификатор:

@Qualifier
@Retention(RetentionPolicy.RUNTIME)
@Target({TYPE, METHOD, FIELD, PARAMETER})
public @interface LoggerType {
}

Использование регистратора в вашем производственном коде:

public class ProductionCode {
    @Inject
    @LoggerType
    private Logger logger;

    public void logSomething() {
        logger.info("something");
    }
}

Тестирование регистратора в вашем тестовом коде (приведем пример easyMock):

@TestSubject
private ProductionCode productionCode = new ProductionCode();

@Mock
private Logger logger;

@Test
public void testTheLogger() {
   logger.info("something");
   replayAll();
   productionCode.logSomething();
}
0 голосов
/ 20 июня 2018

API для Log4J2 немного отличается. Также вы можете использовать его async appender. Я создал защелку для этого:

    public static class LatchedAppender extends AbstractAppender implements AutoCloseable {

    private final List<LogEvent> messages = new ArrayList<>();
    private final CountDownLatch latch;
    private final LoggerConfig loggerConfig;

    public LatchedAppender(Class<?> classThatLogs, int expectedMessages) {
        this(classThatLogs, null, null, expectedMessages);
    }
    public LatchedAppender(Class<?> classThatLogs, Filter filter, Layout<? extends Serializable> layout, int expectedMessages) {
        super(classThatLogs.getName()+"."+"LatchedAppender", filter, layout);
        latch = new CountDownLatch(expectedMessages);
        final LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
        final Configuration config = ctx.getConfiguration();
        loggerConfig = config.getLoggerConfig(LogManager.getLogger(classThatLogs).getName());
        loggerConfig.addAppender(this, Level.ALL, ThresholdFilter.createFilter(Level.ALL, null, null));
        start();
    }

    @Override
    public void append(LogEvent event) {
        messages.add(event);
        latch.countDown();
    }

    public List<LogEvent> awaitMessages() throws InterruptedException {
        assertTrue(latch.await(10, TimeUnit.SECONDS));
        return messages;
    }

    @Override
    public void close() {
        stop();
        loggerConfig.removeAppender(this.getName());
    }
}

Используйте это так:

        try (LatchedAppender appender = new LatchedAppender(ClassUnderTest.class, 1)) {

        ClassUnderTest.methodThatLogs();
        List<LogEvent> events = appender.awaitMessages();
        assertEquals(1, events.size());
        //more assertions here

    }//appender removed
0 голосов
/ 10 февраля 2016

Используя Jmockit (1.21), я смог написать этот простой тест. Тест проверяет, что конкретное сообщение об ошибке вызывается только один раз.

@Test
public void testErrorMessage() {
    final org.slf4j.Logger logger = org.slf4j.LoggerFactory.getLogger( MyConfig.class );

    new Expectations(logger) {{
        //make sure this error is happens just once.
        logger.error( "Something went wrong..." );
        times = 1;
    }};

    new MyTestObject().runSomethingWrong( "aaa" ); //SUT that eventually cause the error in the log.    
}
0 голосов
/ 06 марта 2019

Если вы используете log4j2, решение из https://www.dontpanicblog.co.uk/2018/04/29/test-log4j2-with-junit/ позволило мне утверждать, что сообщения были зарегистрированы.

Решение выглядит так:

  • Определение приложения log4j в качестве правила ExternalResource

    public class LogAppenderResource extends ExternalResource {
    
    private static final String APPENDER_NAME = "log4jRuleAppender";
    
    /**
     * Logged messages contains level and message only.
     * This allows us to test that level and message are set.
     */
    private static final String PATTERN = "%-5level %msg";
    
    private Logger logger;
    private Appender appender;
    private final CharArrayWriter outContent = new CharArrayWriter();
    
    public LogAppenderResource(org.apache.logging.log4j.Logger logger) {
        this.logger = (org.apache.logging.log4j.core.Logger)logger;
    }
    
    @Override
    protected void before() {
        StringLayout layout = PatternLayout.newBuilder().withPattern(PATTERN).build();
        appender = WriterAppender.newBuilder()
                .setTarget(outContent)
                .setLayout(layout)
                .setName(APPENDER_NAME).build();
        appender.start();
        logger.addAppender(appender);
    }
    
    @Override
    protected void after() {
        logger.removeAppender(appender);
    }
    
    public String getOutput() {
        return outContent.toString();
        }
    }
    
  • Определите тест, который использует ваше правило ExternalResource

    public class LoggingTextListenerTest {
    
        @Rule public LogAppenderResource appender = new LogAppenderResource(LogManager.getLogger(LoggingTextListener.class)); 
        private LoggingTextListener listener = new LoggingTextListener(); //     Class under test
    
        @Test
        public void startedEvent_isLogged() {
        listener.started();
        assertThat(appender.getOutput(), containsString("started"));
        }
    }
    

Не забудьте иметь log4j2.xml в составе src / test / resources

...