Jak wykonać asercję JUnit dla komunikatu w programie rejestrującym


206

Mam testowany kod, który wywołuje program rejestrujący Java w celu zgłoszenia jego statusu. W kodzie testowym JUnit chciałbym sprawdzić, czy w tym rejestratorze wprowadzono poprawny wpis do dziennika. Coś w tym stylu:

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

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

Przypuszczam, że można tego dokonać za pomocą specjalnie dostosowanego programu rejestrującego (lub programu obsługi lub formatyzatora), ale wolałbym ponownie użyć rozwiązania, które już istnieje. (I, szczerze mówiąc, nie jest dla mnie jasne, jak uzyskać logRecord z rejestratora, ale załóżmy, że to możliwe.)

Odpowiedzi:


142

Potrzebowałem tego także kilka razy. Poniżej zebrałem małą próbkę, którą chciałbyś dostosować do swoich potrzeb. Zasadniczo tworzysz własne Appenderi dodajesz je do rejestratora, który chcesz. Jeśli chcesz zebrać wszystko, rootger jest dobrym miejscem do rozpoczęcia, ale możesz użyć bardziej szczegółowego, jeśli chcesz. Nie zapomnij usunąć programu dołączającego, gdy skończysz, w przeciwnym razie możesz spowodować wyciek pamięci. Poniżej zrobiłem to w ramach testu, ale setUplub@Before i tearDownczy @Aftermoże być lepsze miejsca, w zależności od potrzeb.

Ponadto implementacja poniżej gromadzi wszystko Listw pamięci. Jeśli dużo się logujesz, możesz rozważyć dodanie filtra, aby usunąć nudne wpisy lub zapisać dziennik do pliku tymczasowego na dysku (Wskazówka: LoggingEventjest Serializable, więc powinieneś być w stanie po prostu serializować obiekty zdarzeń, jeśli twój komunikat dziennika jest.)

import org.apache.log4j.AppenderSkeleton;
import org.apache.log4j.Level;
import org.apache.log4j.Logger;
import org.apache.log4j.spi.LoggingEvent;
import org.junit.Test;

import java.util.ArrayList;
import java.util.List;

import static org.hamcrest.CoreMatchers.is;
import static org.junit.Assert.assertThat;

public class MyTest {
    @Test
    public void test() {
        final TestAppender appender = new TestAppender();
        final Logger logger = Logger.getRootLogger();
        logger.addAppender(appender);
        try {
            Logger.getLogger(MyTest.class).info("Test");
        }
        finally {
            logger.removeAppender(appender);
        }

        final List<LoggingEvent> log = appender.getLog();
        final LoggingEvent firstLogEntry = log.get(0);
        assertThat(firstLogEntry.getLevel(), is(Level.INFO));
        assertThat((String) firstLogEntry.getMessage(), is("Test"));
        assertThat(firstLogEntry.getLoggerName(), is("MyTest"));
    }
}

class TestAppender extends AppenderSkeleton {
    private final List<LoggingEvent> log = new ArrayList<LoggingEvent>();

    @Override
    public boolean requiresLayout() {
        return false;
    }

    @Override
    protected void append(final LoggingEvent loggingEvent) {
        log.add(loggingEvent);
    }

    @Override
    public void close() {
    }

    public List<LoggingEvent> getLog() {
        return new ArrayList<LoggingEvent>(log);
    }
}

4
To działa świetnie. Jedyne ulepszenie, które wprowadziłbym, to zadzwonić logger.getAllAppenders(), a następnie przejść i zadzwonić appender.setThreshold(Level.OFF)do każdego (i zresetować je, gdy skończysz!). Dzięki temu „złe” wiadomości, które próbujesz wygenerować, nie pojawią się w dziennikach testu i nie przestraszą następnego programisty.
Coderer

1
W Log4j 2.x jest nieco bardziej skomplikowany, ponieważ musisz utworzyć wtyczkę, spójrz na to: stackoverflow.com/questions/24205093/...
paranza

1
Dzięki za to. Ale jeśli używasz LogBack, możesz użyć ListAppender<ILoggingEvent>zamiast tworzenia własnego niestandardowego programu dołączającego.
sinujohn

2
ale to nie działa dla slf4j! czy wiesz, jak mogę to zmienić, aby z tym współpracować?
Shilan

3
@sd Jeśli rzucać Loggersię org.apache.logging.log4j.core.Logger(klasy implementacji dla interfejsu) dostaniesz dostęp do setAppender()/removeAppender()ponownie.
David Moles,

59

Oto proste i wydajne rozwiązanie Logback.
Nie wymaga dodawania / tworzenia żadnej nowej klasy.
Opiera się on na ListAppender: aplikatorze logback whitebox, w którym wpisy dziennika są dodawane wpublic List polu, którego moglibyśmy użyć do sformułowania naszych twierdzeń.

Oto prosty przykład.

Klasa Foo:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class Foo {

    static final Logger LOGGER = LoggerFactory.getLogger(Foo .class);

    public void doThat() {
        LOGGER.info("start");
        //...
        LOGGER.info("finish");
    }
}

Klasa FooTest:

import org.slf4j.LoggerFactory;
import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.read.ListAppender;

public class FooTest {

    @Test
    void doThat() throws Exception {
        // get Logback Logger 
        Logger fooLogger = (Logger) LoggerFactory.getLogger(Foo.class);

        // create and start a ListAppender
        ListAppender<ILoggingEvent> listAppender = new ListAppender<>();
        listAppender.start();

        // add the appender to the logger
        // addAppender is outdated now
        fooLogger.addAppender(listAppender);

        // call method under test
        Foo foo = new Foo();
        foo.doThat();

        // JUnit assertions
        List<ILoggingEvent> logsList = listAppender.list;
        assertEquals("start", logsList.get(0)
                                      .getMessage());
        assertEquals(Level.INFO, logsList.get(0)
                                         .getLevel());

        assertEquals("finish", logsList.get(1)
                                       .getMessage());
        assertEquals(Level.INFO, logsList.get(1)
                                         .getLevel());
    }
}

Asercje JUnit nie wydają się zbyt dobrze przystosowane do zapewnienia określonych właściwości elementów listy.
Biblioteki dopasowywania / asercji jako AssertJ lub Hamcrest wydają się do tego lepsze:

W przypadku AssertJ byłoby to:

import org.assertj.core.api.Assertions;

Assertions.assertThat(listAppender.list)
          .extracting(ILoggingEvent::getMessage, ILoggingEvent::getLevel)
          .containsExactly(Tuple.tuple("start", Level.INFO), Tuple.tuple("finish", Level.INFO));

Jak zatrzymać niepowodzenie testu, jeśli zarejestrujesz błąd?
Ghilteras,

@Gililas Nie jestem pewien, czy rozumiem. Rejestrowanie błędu nie powinno spowodować niepowodzenia testu. Co wyjaśnisz
davidxxx

Pamiętaj też, aby nie mockklasa, która jest testowana. Musisz utworzyć instancję z newoperatorem
Dmytro Chasovskyi

35

Bardzo dziękuję za te (zaskakująco) szybkie i pomocne odpowiedzi; postawili mnie na właściwej drodze do mojego rozwiązania.

Baza kodów, w której chcę tego użyć, używa java.util.logging jako mechanizmu rejestrującego i nie czuję się wystarczająco dobrze w tych kodach, aby całkowicie zmienić to na log4j lub logger interfejsy / fasady. Ale w oparciu o te sugestie „zhakowałem” rozszerzenie julhandlera i działa to jako uczta.

Poniżej znajduje się krótkie streszczenie. Przedłuż java.util.logging.Handler:

class LogHandler extends Handler
{
    Level lastLevel = Level.FINEST;

    public Level  checkLevel() {
        return lastLevel;
    }    

    public void publish(LogRecord record) {
        lastLevel = record.getLevel();
    }

    public void close(){}
    public void flush(){}
}

Oczywiście możesz przechowywać tyle, ile chcesz / chcesz / potrzebujesz z LogRecord, lub wepchnąć je wszystkie do stosu, aż pojawi się przepełnienie.

Przygotowując się do testu junit, tworzysz java.util.logging.Loggeri dodajesz LogHandlerdo niego takie nowe :

@Test tester() {
    Logger logger = Logger.getLogger("my junit-test logger");
    LogHandler handler = new LogHandler();
    handler.setLevel(Level.ALL);
    logger.setUseParentHandlers(false);
    logger.addHandler(handler);
    logger.setLevel(Level.ALL);

Wezwanie setUseParentHandlers()to ucisza normalne moduły obsługi, aby (dla tego testu testowego junit) nie było niepotrzebnego rejestrowania. Wykonaj wszystko, czego wymaga testowany kod, aby użyć tego programu rejestrującego, uruchom test i assertEquality:

    libraryUnderTest.setLogger(logger);
    methodUnderTest(true);  // see original question.
    assertEquals("Log level as expected?", Level.INFO, handler.checkLevel() );
}

(Oczywiście, dużą część tej pracy przeniosłeś na @Beforemetodę i wprowadziłeś inne ulepszenia, ale to zaśmieciłoby tę prezentację.)


16

Inną opcją jest wyśmiewanie programu Appender i sprawdzenie, czy wiadomość została zalogowana do tego programu. Przykład dla Log4j 1.2.x i mockito:

import static org.junit.Assert.assertEquals;
import static org.mockito.Mockito.mock;
import static org.mockito.Mockito.verify;

import org.apache.log4j.Appender;
import org.apache.log4j.Level;
import org.apache.log4j.Logger;
import org.apache.log4j.spi.LoggingEvent;
import org.junit.After;
import org.junit.Before;
import org.junit.Test;
import org.mockito.ArgumentCaptor;

public class MyTest {

    private final Appender appender = mock(Appender.class);
    private final Logger logger = Logger.getRootLogger();

    @Before
    public void setup() {
        logger.addAppender(appender);
    }

    @Test
    public void test() {
        // when
        Logger.getLogger(MyTest.class).info("Test");

        // then
        ArgumentCaptor<LoggingEvent> argument = ArgumentCaptor.forClass(LoggingEvent.class);
        verify(appender).doAppend(argument.capture());
        assertEquals(Level.INFO, argument.getValue().getLevel());
        assertEquals("Test", argument.getValue().getMessage());
        assertEquals("MyTest", argument.getValue().getLoggerName());
    }

    @After
    public void cleanup() {
        logger.removeAppender(appender);
    }
}

16

Skutecznie testujesz efekt uboczny klasy zależnej. W przypadku testów jednostkowych wystarczy to sprawdzić

logger.info()

został wywołany z poprawnym parametrem. Dlatego używaj frameworku do emulacji programu rejestrującego, który pozwoli ci przetestować zachowanie własnej klasy.


3
Jak wyśmiewałeś prywatne statyczne pole końcowe, które zdefiniowano w większości rejestratorów? Powermockito? Miłej zabawy ..
Stefano L

Stefano: To ostatnie pole zostało jakoś zainicjowane. Widziałem różne podejścia do wstrzykiwania Mocków, a nie prawdziwe. Prawdopodobnie wymaga to przede wszystkim pewnego poziomu projektu do testowania. blog.codecentric.de/en/2011/11/…
djna

Jak powiedział Mehdi, prawdopodobnie wystarczy odpowiedni Handler,
djna

11

Wyśmiewanie jest tutaj opcją, chociaż byłoby trudne, ponieważ rejestratory są zwykle prywatnymi statycznymi końcami - więc ustawienie fałszywego rejestratora nie byłoby bułką z masłem lub wymagałoby modyfikacji testowanej klasy.

Możesz utworzyć niestandardowy program dołączający (lub jakkolwiek się nazywa) i zarejestrować go - albo za pomocą pliku konfiguracyjnego tylko do testów, albo w środowisku wykonawczym (w pewien sposób, zależnie od środowiska rejestrowania). Następnie możesz pobrać ten moduł dołączający (statycznie, jeśli zadeklarowany w pliku konfiguracyjnym lub przez jego bieżące odniesienie, jeśli podłączasz go do środowiska wykonawczego) i zweryfikować jego zawartość.


10

Zainspirowany rozwiązaniem @ RonaldBlaschke, wymyśliłem:

public class Log4JTester extends ExternalResource {
    TestAppender appender;

    @Override
    protected void before() {
        appender = new TestAppender();
        final Logger rootLogger = Logger.getRootLogger();
        rootLogger.addAppender(appender);
    }

    @Override
    protected void after() {
        final Logger rootLogger = Logger.getRootLogger();
        rootLogger.removeAppender(appender);
    }

    public void assertLogged(Matcher<String> matcher) {
        for(LoggingEvent event : appender.events) {
            if(matcher.matches(event.getMessage())) {
                return;
            }
        }
        fail("No event matches " + matcher);
    }

    private static class TestAppender extends AppenderSkeleton {

        List<LoggingEvent> events = new ArrayList<LoggingEvent>();

        @Override
        protected void append(LoggingEvent event) {
            events.add(event);
        }

        @Override
        public void close() {

        }

        @Override
        public boolean requiresLayout() {
            return false;
        }
    }

}

... co pozwala na:

@Rule public Log4JTester logTest = new Log4JTester();

@Test
public void testFoo() {
     user.setStatus(Status.PREMIUM);
     logTest.assertLogged(
        stringContains("Note added to account: premium customer"));
}

Prawdopodobnie możesz sprawić, że użyje hamcrestu w mądrzejszy sposób, ale na tym zostawiłem.


6

W przypadku log4j2 rozwiązanie jest nieco inne, ponieważ AppenderSkeleton nie jest już dostępny. Ponadto użycie Mockito lub podobnej biblioteki do utworzenia Appendera z ArgumentCaptor nie będzie działać, jeśli oczekujesz wielu komunikatów rejestrowania, ponieważ MutableLogEvent jest ponownie wykorzystywany w wielu komunikatach dziennika. Najlepsze rozwiązanie, które znalazłem dla log4j2 to:

private static MockedAppender mockedAppender;
private static Logger logger;

@Before
public void setup() {
    mockedAppender.message.clear();
}

/**
 * For some reason mvn test will not work if this is @Before, but in eclipse it works! As a
 * result, we use @BeforeClass.
 */
@BeforeClass
public static void setupClass() {
    mockedAppender = new MockedAppender();
    logger = (Logger)LogManager.getLogger(MatchingMetricsLogger.class);
    logger.addAppender(mockedAppender);
    logger.setLevel(Level.INFO);
}

@AfterClass
public static void teardown() {
    logger.removeAppender(mockedAppender);
}

@Test
public void test() {
    // do something that causes logs
    for (String e : mockedAppender.message) {
        // add asserts for the log messages
    }
}

private static class MockedAppender extends AbstractAppender {

    List<String> message = new ArrayList<>();

    protected MockedAppender() {
        super("MockedAppender", null, null);
    }

    @Override
    public void append(LogEvent event) {
        message.add(event.getMessage().getFormattedMessage());
    }
}

5

Jak wspomniano od innych, możesz użyć frameworku. Aby to zadziałało, musisz ujawnić program rejestrujący w swojej klasie (chociaż raczej wolałbym, aby pakiet był prywatny, niż tworzenie publicznego setera).

Innym rozwiązaniem jest ręczne utworzenie fałszywego rejestratora. Musisz napisać fałszywy program rejestrujący (więcej kodu urządzenia), ale w tym przypadku wolałbym lepszą czytelność testów względem zapisanego kodu z fałszywego frameworka.

Zrobiłbym coś takiego:

class FakeLogger implements ILogger {
    public List<String> infos = new ArrayList<String>();
    public List<String> errors = new ArrayList<String>();

    public void info(String message) {
        infos.add(message);
    }

    public void error(String message) {
        errors.add(message);
    }
}

class TestMyClass {
    private MyClass myClass;        
    private FakeLogger logger;        

    @Before
    public void setUp() throws Exception {
        myClass = new MyClass();
        logger = new FakeLogger();
        myClass.logger = logger;
    }

    @Test
    public void testMyMethod() {
        myClass.myMethod(true);

        assertEquals(1, logger.infos.size());
    }
}

5

Łał. Nie jestem pewien, dlaczego to było takie trudne. Odkryłem, że nie mogłem użyć żadnego z powyższych przykładów kodu, ponieważ korzystałem z log4j2 nad slf4j. To jest moje rozwiązanie:

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));
  }
}

4

Oto, co zrobiłem dla logback.

Utworzyłem klasę TestAppender:

public class TestAppender extends AppenderBase<ILoggingEvent> {

    private Stack<ILoggingEvent> events = new Stack<ILoggingEvent>();

    @Override
    protected void append(ILoggingEvent event) {
        events.add(event);
    }

    public void clear() {
        events.clear();
    }

    public ILoggingEvent getLastEvent() {
        return events.pop();
    }
}

Następnie w rodzicu mojej klasy testów jednostek testowych stworzyłem metodę:

protected TestAppender testAppender;

@BeforeClass
public void setupLogsForTesting() {
    Logger root = (Logger)LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);
    testAppender = (TestAppender)root.getAppender("TEST");
    if (testAppender != null) {
        testAppender.clear();
    }
}

Mam plik logback-test.xml zdefiniowany w src / test / resources i dodałem program dołączający test:

<appender name="TEST" class="com.intuit.icn.TestAppender">
    <encoder>
        <pattern>%m%n</pattern>
    </encoder>
</appender>

i dodał ten program dołączający do programu głównego:

<root>
    <level value="error" />
    <appender-ref ref="STDOUT" />
    <appender-ref ref="TEST" />
</root>

Teraz w moich klasach testowych, które rozciągają się od mojej nadrzędnej klasy testowej, mogę pobrać program dołączający i zarejestrować ostatnią wiadomość oraz zweryfikować wiadomość, poziom, możliwość rzucenia.

ILoggingEvent lastEvent = testAppender.getLastEvent();
assertEquals(lastEvent.getMessage(), "...");
assertEquals(lastEvent.getLevel(), Level.WARN);
assertEquals(lastEvent.getThrowableProxy().getMessage(), "...");

Nie wiem, gdzie jest zdefiniowana metoda getAppender?!?
bioinfornatics

getAppender to metoda na ch.qos.logback.classic.Logger
kfox

4

W przypadku Junita 5 (Jupiter) Spring OutputCaptureExtension jest całkiem użyteczny. Jest dostępny od wersji Spring Boot 2.2 i jest dostępny w artefakcie testu rozruchu wiosny .

Przykład (wzięty z javadoc):

@ExtendWith(OutputCaptureExtension.class)
class MyTest {
    @Test
    void test(CapturedOutput output) {
        System.out.println("ok");
        assertThat(output).contains("ok");
        System.err.println("error");
    }

    @AfterEach
    void after(CapturedOutput output) {
        assertThat(output.getOut()).contains("ok");
        assertThat(output.getErr()).contains("error");
    }
}

Uważam, że oświadczenia dziennika są różne getOut()lub getErr().
Ram

Oto odpowiedź, której szukałem (choć pytanie nie jest związane z wiosennym bootowaniem)!
helleye

3

Jak dla mnie można uprościć za pomocą testu JUnitz Mockito. Proponuję dla niego następujące rozwiązanie:

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)
        );
    }
}

Właśnie dlatego mamy niezłą elastyczność w testach z różną ilością komunikatów


1
Aby nie powtarzać prawie takich samych bloków kodu, chcę dodać, że prawie 1to1 działa dla mnie dla Log4j2. Po prostu zmieniając import na „org.apache.logging.log4j.core”, when(appender.isStarted()).thenReturn(true); when(appender.getName()).thenReturn("Test Appender"); prześlij logger na „org.apache.logging.log4j.core.Logger”, dodaj i zmień LoggingEvent -> LogEvent
Aliaksei Yatsau

3
Here is the sample code to mock log, irrespective of the version used for junit or sping, springboot.

import ch.qos.logback.classic.spi.LoggingEvent;
import ch.qos.logback.core.Appender;
import org.mockito.ArgumentMatcher;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.junit.Test;

import static org.mockito.Matchers.argThat;
import static org.mockito.Mockito.mock;
import static org.mockito.Mockito.verify;
import static org.mockito.Mockito.when;

public class MyTest {
  private static Logger logger = LoggerFactory.getLogger(MyTest.class);

    @Test
    public void testSomething() {
    ch.qos.logback.classic.Logger root = (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(ch.qos.logback.classic.Logger.ROOT_LOGGER_NAME);
    final Appender mockAppender = mock(Appender.class);
    when(mockAppender.getName()).thenReturn("MOCK");
    root.addAppender(mockAppender);

    //... do whatever you need to trigger the log

    verify(mockAppender).doAppend(argThat(new ArgumentMatcher() {
      @Override
      public boolean matches(final Object argument) {
        return ((LoggingEvent)argument).getFormattedMessage().contains("Hey this is the message I want to see");
      }
    }));
  }
}

1
To zadziałało dla mnie. Wiersz „kiedy (mockAppender.getName ()). Then Return („ MOCK ”)” nie był dla mnie potrzebny.
Mayank Raghav

1

Interfejs API dla Log4J2 jest nieco inny. Być może korzystasz z jego asynchronicznego programu dołączającego. W tym celu utworzyłem zatrzaskowego programu dołączającego:

    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());
    }
}

Użyj tego w ten sposób:

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

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

    }//appender removed

1

Zauważ, że w Log4J 2.x interfejs publiczny org.apache.logging.log4j.Loggernie zawiera setAppender()iremoveAppender() metod .

Ale jeśli nie robisz nic szczególnego, powinieneś być w stanie rzucić to na klasę implementacji org.apache.logging.log4j.core.Logger , która ujawnia te metody.

Oto przykład z Mockito i AssertJ :

// Import the implementation class rather than the API interface
import org.apache.logging.log4j.core.Logger;
// Cast logger to implementation class to get access to setAppender/removeAppender
Logger log = (Logger) LogManager.getLogger(MyClassUnderTest.class);

// Set up the mock appender, stubbing some methods Log4J needs internally
Appender appender = mock(Appender.class);
when(appender.getName()).thenReturn("Mock Appender");
when(appender.isStarted()).thenReturn(true);

log.addAppender(appender);
try {
    new MyClassUnderTest().doSomethingThatShouldLogAnError();
} finally {
    log.removeAppender(appender);
}

// Verify that we got an error with the expected message
ArgumentCaptor<LogEvent> logEventCaptor = ArgumentCaptor.forClass(LogEvent.class);
verify(appender).append(logEventCaptor.capture());
LogEvent logEvent = logEventCaptor.getValue();
assertThat(logEvent.getLevel()).isEqualTo(Level.ERROR);
assertThat(logEvent.getMessage().getFormattedMessage()).contains(expectedErrorMessage);

0

Innym pomysłem, o którym warto wspomnieć, chociaż jest to starszy temat, jest stworzenie producenta CDI, który wstrzykuje twój rejestrator, aby kpiny stały się łatwe. (I ma to tę zaletę, że nie musi już deklarować „całej instrukcji rejestratora”, ale to nie na temat)

Przykład:

Tworzenie rejestratora do wstrzyknięcia:

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

Kwalifikator:

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

Za pomocą rejestratora w kodzie produkcyjnym:

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

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

Testowanie rejestratora w kodzie testowym (podając przykład easyMock):

@TestSubject
private ProductionCode productionCode = new ProductionCode();

@Mock
private Logger logger;

@Test
public void testTheLogger() {
   logger.info("something");
   replayAll();
   productionCode.logSomething();
}

0

Używając Jmockit (1.21) mogłem napisać ten prosty test. Test sprawdza, czy określony komunikat o błędzie jest wywoływany tylko raz.

@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

Wyśmiewanie programu dołączającego może pomóc uchwycić wiersze dziennika. Znajdź próbkę na: http://clearqa.blogspot.co.uk/2016/12/test-log-lines.html

// Fully working test at: https://github.com/njaiswal/logLineTester/blob/master/src/test/java/com/nj/Utils/UtilsTest.java

@Test
public void testUtilsLog() throws InterruptedException {

    Logger utilsLogger = (Logger) LoggerFactory.getLogger("com.nj.utils");

    final Appender mockAppender = mock(Appender.class);
    when(mockAppender.getName()).thenReturn("MOCK");
    utilsLogger.addAppender(mockAppender);

    final List<String> capturedLogs = Collections.synchronizedList(new ArrayList<>());
    final CountDownLatch latch = new CountDownLatch(3);

    //Capture logs
    doAnswer((invocation) -> {
        LoggingEvent loggingEvent = invocation.getArgumentAt(0, LoggingEvent.class);
        capturedLogs.add(loggingEvent.getFormattedMessage());
        latch.countDown();
        return null;
    }).when(mockAppender).doAppend(any());

    //Call method which will do logging to be tested
    Application.main(null);

    //Wait 5 seconds for latch to be true. That means 3 log lines were logged
    assertThat(latch.await(5L, TimeUnit.SECONDS), is(true));

    //Now assert the captured logs
    assertThat(capturedLogs, hasItem(containsString("One")));
    assertThat(capturedLogs, hasItem(containsString("Two")));
    assertThat(capturedLogs, hasItem(containsString("Three")));
}

0

Użyj poniższego kodu. Używam tego samego kodu do wiosennego testu integracji, w którym do logowania używam logowania. Użyj metody assertJobIsScheduled, aby potwierdzić tekst wydrukowany w dzienniku.

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

Istnieją dwie rzeczy, które możesz próbować przetestować.

  • Gdy wystąpi zdarzenie interesujące operatora mojego programu, czy mój program wykonuje odpowiednią operację rejestrowania, która może poinformować operatora o tym zdarzeniu.
  • Kiedy mój program wykonuje operację rejestrowania, czy komunikat, który generuje, zawiera poprawny tekst.

Te dwie rzeczy są właściwie różnymi rzeczami, dlatego można je przetestować osobno. Jednak testowanie drugiego (tekstu wiadomości) jest tak problematyczne, że w ogóle nie polecam tego robić. Test tekstu wiadomości będzie ostatecznie polegał na sprawdzeniu, czy jeden ciąg tekstowy (oczekiwany tekst wiadomości) jest taki sam lub może być w prosty sposób uzyskany z ciągu tekstowego użytego w kodzie logowania.

  • Te testy w ogóle nie testują logiki programu, tylko testują, czy jeden zasób (ciąg znaków) jest równoważny z innym zasobem.
  • Testy są kruche; nawet drobne poprawki w formatowaniu wiadomości dziennika psują testy.
  • Testy są niezgodne z internacjonalizacją (tłumaczeniem) interfejsu logowania. Testy zakładają, że istnieje tylko jeden możliwy tekst komunikatu, a zatem tylko jeden możliwy ludzki język.

Zauważ, że kod programu (być może implementujący pewną logikę biznesową) bezpośrednio wywołujący interfejs rejestrowania tekstu jest kiepski (ale niestety bardzo powszechny). Kod odpowiedzialny za logikę biznesową decyduje również o niektórych zasadach rejestrowania i treści komunikatów dziennika. Łączy logikę biznesową z kodem interfejsu użytkownika (tak, komunikaty dziennika są częścią interfejsu użytkownika programu). Te rzeczy powinny być oddzielne.

Dlatego zalecam, aby logika biznesowa nie generowała bezpośrednio tekstu komunikatów dziennika. Zamiast tego należy go delegować do obiektu rejestrującego.

  • Klasa obiektu rejestrowania powinna zapewniać odpowiedni wewnętrzny interfejs API, którego obiekt biznesowy może użyć do wyrażenia zdarzenia, które wystąpiło przy użyciu obiektów modelu domeny, a nie ciągów tekstowych.
  • Wdrożenie klasy rejestrowania jest odpowiedzialne za tworzenie reprezentacji tekstowych tych obiektów domeny i renderowanie odpowiedniego tekstowego opisu zdarzenia, a następnie przekazywanie tej wiadomości tekstowej do niskiego poziomu środowiska rejestrowania (takiego jak JUL, log4j lub slf4j).
  • Twoja logika biznesowa jest odpowiedzialna tylko za wywoływanie poprawnych metod wewnętrznego interfejsu API klasy rejestratora, przekazywanie prawidłowych obiektów domeny, w celu opisania faktycznych zdarzeń, które miały miejsce.
  • Twój rejestrowania beton klasy , który opisuje wewnętrzny API logiki biznesowej mogą korzystać.implementsinterface
  • Twoja klasa (klasy), która implementuje logikę biznesową i musi wykonywać rejestrowanie, ma odniesienie do obiektu rejestrowania, do którego ma zostać delegowana. Klasą referencji jest streszczenie interface.
  • Użyj iniekcji zależności, aby skonfigurować odwołanie do programu rejestrującego.

Następnie możesz przetestować, czy klasy logiki biznesowej poprawnie informują interfejs rejestrowania o zdarzeniach, tworząc próbny program rejestrujący, który implementuje wewnętrzny interfejs API rejestrowania, i wykorzystując wstrzykiwanie zależności w fazie konfiguracji testu.

Lubię to:

 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

To, co zrobiłem, jeśli chcę tylko zobaczyć, że jakiś ciąg został zarejestrowany (w przeciwieństwie do weryfikacji dokładnych instrukcji dziennika, które są po prostu zbyt kruche), to przekierowanie StdOut do bufora, wykonanie zawiera, a następnie zresetowanie 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);

1
Próbowałem tego z java.util.logging(chociaż użyłem System.setErr(new PrintStream(buffer));, ponieważ loguje się do stderr), ale to nie działa (bufor pozostaje pusty). jeśli używam System.err.println("foo")bezpośrednio, to działa, więc zakładam, że system rejestrujący zachowuje własne odniesienie do strumienia wyjściowego, z którego pobiera System.err, więc moje wywołanie System.setErr(..)nie ma wpływu na dane wyjściowe dziennika, tak jak dzieje się to po inicjacji systemu dziennika.
hoijui

0

Odpowiedziałem na podobne pytanie dotyczące log4j, zobacz jak-can-i-test-with-junit-that-a-warning-was-logged-with-log4

Jest to nowszy przykład z Log4j2 (testowany z 2.11.2) i junit 5;

    package com.whatever.log;

    import org.apache.logging.log4j.Level;
    import org.apache.logging.log4j.LogManager;
    import org.apache.logging.log4j.core.Logger;
    import org.apache.logging.log4j.core.*;
    import org.apache.logging.log4j.core.appender.AbstractAppender;
    import org.apache.logging.log4j.core.config.Configuration;
    import org.apache.logging.log4j.core.config.LoggerConfig;
    import org.apache.logging.log4j.core.config.plugins.Plugin;
    import org.apache.logging.log4j.core.config.plugins.PluginAttribute;
    import org.apache.logging.log4j.core.config.plugins.PluginElement;
    import org.apache.logging.log4j.core.config.plugins.PluginFactory;
    import org.junit.jupiter.api.AfterEach;
    import org.junit.jupiter.api.BeforeEach;
    import org.junit.jupiter.api.DisplayName;
    import org.junit.jupiter.api.Test;

    import java.util.ArrayList;
    import java.util.List;
    import static org.junit.Assert.*;

class TestLogger {

    private TestAppender testAppender;
    private LoggerConfig loggerConfig;
    private final Logger logger = (Logger)
            LogManager.getLogger(ClassUnderTest.class);

    @Test
    @DisplayName("Test Log Junit5 and log4j2")
    void test() {
        ClassUnderTest.logMessage();
        final LogEvent loggingEvent = testAppender.events.get(0);
        //asset equals 1 because log level is info, change it to debug and
        //the test will fail
        assertTrue(testAppender.events.size()==1,"Unexpected empty log");
        assertEquals(Level.INFO,loggingEvent.getLevel(),"Unexpected log level");
        assertEquals(loggingEvent.getMessage().toString()
                ,"Hello Test","Unexpected log message");
    }

    @BeforeEach
    private void setup() {
        testAppender = new TestAppender("TestAppender", null);

        final LoggerContext context = logger.getContext();
        final Configuration configuration = context.getConfiguration();

        loggerConfig = configuration.getLoggerConfig(logger.getName());
        loggerConfig.setLevel(Level.INFO);
        loggerConfig.addAppender(testAppender,Level.INFO,null);
        testAppender.start();
        context.updateLoggers();
    }

    @AfterEach
    void after(){
        testAppender.stop();
        loggerConfig.removeAppender("TestAppender");
        final LoggerContext context = logger.getContext();
        context.updateLoggers();
    }

    @Plugin( name = "TestAppender", category = Core.CATEGORY_NAME, elementType = Appender.ELEMENT_TYPE)
    static class TestAppender extends AbstractAppender {

        List<LogEvent> events = new ArrayList();

        protected TestAppender(String name, Filter filter) {
            super(name, filter, null);
        }

        @PluginFactory
        public static TestAppender createAppender(
                @PluginAttribute("name") String name,
                @PluginElement("Filter") Filter filter) {
            return new TestAppender(name, filter);
        }

        @Override
        public void append(LogEvent event) {
            events.add(event);
        }
    }

    static class ClassUnderTest {
        private static final Logger LOGGER =  (Logger) LogManager.getLogger(ClassUnderTest.class);
        public static void logMessage(){
            LOGGER.info("Hello Test");
            LOGGER.debug("Hello Test");
        }
    }
}

Korzystanie z następujących zależności maven

 <dependency>
 <artifactId>log4j-core</artifactId>
  <packaging>jar</packaging>
  <version>2.11.2</version>
</dependency>
<dependency>
    <groupId>org.junit.jupiter</groupId>
    <artifactId>junit-jupiter-api</artifactId>
    <version>5.5.0</version>
    <scope>test</scope>
</dependency>

Próbowałem tego i dostałem błąd w metodzie instalacji w wierszu loggerConfig = configuration.getLoggerConfig (logger.getName ()); Błąd nie może uzyskać dostępu do pliku klasy org.apache.logging.log4j.spi.LoggerContextShutdownEnabled dla org.apache.logging.log4j.spi.LoggerContextShutdownEnabled nie znaleziono
Carlos Palma

Przejrzałem kod i wprowadziłem kilka drobnych zmian, ale zadziałało to dla mnie. Sugeruję sprawdzenie zależności i upewnienie się, że wszystkie operacje importowania są prawidłowe
Haim Raman

Cześć, Haim. Skończyło się na wdrożeniu rozwiązania logback ... ale myślę, że masz rację, aby go zaimplementować, musiałem wyczyścić import, który zrobiłem z innej wersji log4j.
Carlos Palma

-1

Jeśli używasz log4j2, rozwiązanie z https://www.dontpanicblog.co.uk/2018/04/29/test-log4j2-with-junit/ pozwoliło mi stwierdzić, że wiadomości zostały zarejestrowane.

Rozwiązanie wygląda następująco:

  • Zdefiniuj program dołączający log4j jako regułę 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();
        }
    }
  • Zdefiniuj test, który korzysta z reguły 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"));
        }
    }

Nie zapomnij mieć log4j2.xml jako części src / test / resources

Korzystając z naszej strony potwierdzasz, że przeczytałeś(-aś) i rozumiesz nasze zasady używania plików cookie i zasady ochrony prywatności.
Licensed under cc by-sa 3.0 with attribution required.