Comment faire une assertion JUnit sur un message dans un enregistreur

J'ai un code en cours de test qui appelle un enregistreur Java pour signaler son état. Dans le code de test JUnit, je voudrais vérifier que l'entrée de journal correcte a été effectuée dans cet enregistreur. Quelque chose dans le sens suivant:

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

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

Je suppose que cela pourrait être fait avec un enregistreur (ou un gestionnaire ou un formateur) spécialement adapté, mais je préférerais réutiliser une solution qui existe déjà. (Et, pour être honnête, il n'est pas clair pour moi comment obtenir le logRecord à partir d'un enregistreur, mais supposez que cela soit possible.)

J'ai également eu besoin de cela plusieurs fois. J'ai rassemblé un petit échantillon ci-dessous, que vous souhaitez adapter à vos besoins. Fondamentalement, vous créez le vôtre Appenderet l'ajoutez à l'enregistreur que vous souhaitez. Si vous souhaitez tout collecter, l'enregistreur racine est un bon point de départ, mais vous pouvez en utiliser un plus spécifique si vous le souhaitez. N'oubliez pas de supprimer l'Appender lorsque vous avez terminé, sinon vous pourriez créer une fuite de mémoire. Ci-dessous, je l'ai fait dans le cadre du test, mais setUpou @Beforeet tearDownou @Afterpourraient être de meilleurs endroits, selon vos besoins.

De plus, l'implémentation ci-dessous recueille tout dans une Listmémoire. Si vous vous connectez beaucoup, vous pouvez envisager d'ajouter un filtre pour supprimer les entrées ennuyeuses ou d'écrire le journal dans un fichier temporaire sur le disque (indice: LoggingEventest Serializable, vous devriez donc être en mesure de sérialiser simplement les objets d'événement, si votre message de journal est.)

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

Voici une solution Logback simple et efficace.
Il ne nécessite pas d'ajouter / créer de nouvelle classe.
Il repose sur ListAppender: un appender de retour en arrière de la boîte blanche où les entrées de journal sont ajoutées dans unpublic List champ que nous pourrions ainsi utiliser pour faire nos assertions.

Voici un exemple simple.

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

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

Les assertions JUnit ne semblent pas très adaptées pour affirmer certaines propriétés spécifiques des éléments de la liste.
Les bibliothèques d'association / assertion comme AssertJ ou Hamcrest semblent mieux pour cela:

Avec AssertJ ce serait:

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

Merci beaucoup pour ces réponses (étonnamment) rapides et utiles; ils m'ont mis sur la bonne voie pour ma solution.

La base de code où je veux l'utiliser, utilise java.util.logging comme mécanisme d'enregistrement, et je ne me sens pas suffisamment à l'aise dans ces codes pour changer complètement cela en log4j ou en interfaces / façades d'enregistreur. Mais sur la base de ces suggestions, j'ai «piraté» une extension julhandler et cela fonctionne comme un régal.

Un bref résumé suit. Étendre 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(){}
}

De toute évidence, vous pouvez stocker autant que vous le souhaitez / voulez / besoin de la LogRecord , ou les pousser tous dans une pile jusqu'à ce que vous obteniez un débordement.

Dans la préparation du junit-test, vous créez un java.util.logging.Loggeret ajoutez-en un nouveau LogHandler:

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

L'appel à setUseParentHandlers()est de faire taire les gestionnaires normaux afin que (pour cette exécution de test de junit) aucune journalisation inutile ne se produise. Faites tout ce dont votre code sous test a besoin pour utiliser cet enregistreur, exécutez le test et assertEquality:

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

(Bien sûr, vous déplaceriez une grande partie de ce travail dans une @Beforeméthode et apporteriez d'autres améliorations, mais cela encombrerait cette présentation.)

Une autre option consiste à se moquer de Appender et à vérifier si le message a été enregistré sur cet appender. Exemple pour Log4j 1.2.x et 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);
    }
}

En fait, vous testez un effet secondaire d'une classe dépendante. Pour les tests unitaires, il vous suffit de vérifier que

logger.info()

a été appelé avec le paramètre correct. Par conséquent, utilisez un cadre de simulation pour émuler l'enregistreur et cela vous permettra de tester le comportement de votre propre classe.

Le mocking est une option ici, bien que ce soit difficile, car les enregistreurs sont généralement des statiques privés finaux - donc la configuration d'un mock logger ne serait pas un jeu d'enfant, ou nécessiterait une modification de la classe testée.

Vous pouvez créer un Appender personnalisé (ou son nom) et l'enregistrer - soit via un fichier de configuration de test uniquement, soit à l'exécution (d'une certaine manière, en fonction du cadre de journalisation). Et puis vous pouvez obtenir cet appender (soit statiquement, s'il est déclaré dans le fichier de configuration, soit par sa référence actuelle, si vous le branchez à l'exécution) et vérifier son contenu.

Inspiré par la solution de @ RonaldBlaschke, j'ai trouvé ceci:

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

}

... ce qui vous permet de faire:

@Rule public Log4JTester logTest = new Log4JTester();

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

Vous pourriez probablement lui faire utiliser hamcrest de manière plus intelligente, mais je l'ai laissé là.

Pour log4j2, la solution est légèrement différente car AppenderSkeleton n'est plus disponible. En outre, l'utilisation de Mockito ou d'une bibliothèque similaire pour créer un Appender avec un ArgumentCaptor ne fonctionnera pas si vous attendez plusieurs messages de journalisation car le MutableLogEvent est réutilisé sur plusieurs messages de journal. La meilleure solution que j'ai trouvée pour log4j2 est:

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

Comme mentionné dans les autres, vous pouvez utiliser un cadre de simulation. Pour que cela fonctionne, vous devez exposer l'enregistreur dans votre classe (bien que je préfère de préférence le rendre privé au lieu de créer un setter public).

L'autre solution consiste à créer un faux enregistreur à la main. Vous devez écrire le faux logger (plus de code de montage) mais dans ce cas, je préférerais la lisibilité améliorée des tests par rapport au code enregistré du framework de simulation.

Je ferais quelque chose comme ça:

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

Sensationnel. Je ne sais pas pourquoi cela a été si difficile. J'ai trouvé que je ne pouvais pas utiliser l'un des exemples de code ci-dessus parce que j'utilisais log4j2 sur slf4j. Voici ma solution:

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

Voici ce que j'ai fait pour la déconnexion.

J'ai créé une classe 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();
    }
}

Ensuite, dans le parent de ma classe de test unitaire testng, j'ai créé une méthode:

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

J'ai un fichier logback-test.xml défini dans src / test / resources et j'ai ajouté un appender de test:

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

et a ajouté cet appender à l'appendice racine:

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

Maintenant, dans mes classes de test qui s'étendent de ma classe de test parent, je peux obtenir l'appender et obtenir le dernier message enregistré et vérifier le message, le niveau, le jetable.

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

Pour Junit 5 (Jupiter), OutputCaptureExtension de Spring est très utile. Il est disponible depuis Spring Boot 2.2 et est disponible dans l' artefact spring-boot-test .

Exemple (tiré de 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");
    }
}

Quant à moi, vous pouvez simplifier votre test en utilisant JUnitavec Mockito. Je lui propose la solution suivante:

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

C'est pourquoi nous avons une belle flexibilité pour les tests avec différentes quantités de messages

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

L'API pour Log4J2 est légèrement différente. Vous pouvez également utiliser son appender asynchrone. J'ai créé un appender verrouillé pour cela:

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

Utilisez-le comme ceci:

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

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

    }//appender removed

Notez que dans Log4J 2.x, l'interface publique org.apache.logging.log4j.Loggern'inclut pas les méthodes setAppender()et removeAppender().

Mais si vous ne faites rien de trop sophistiqué, vous devriez pouvoir le convertir en classe d'implémentation org.apache.logging.log4j.core.Logger, qui expose ces méthodes.

Voici un exemple avec Mockito et 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);

Une autre idée mérite d'être mentionnée, bien qu'il s'agisse d'un sujet plus ancien, la création d'un producteur CDI pour injecter votre enregistreur afin que la moquerie devienne facile. (Et cela donne également l'avantage de ne plus avoir à déclarer la "totalité de l'instruction logger", mais c'est hors sujet)

Exemple:

Création de l'enregistreur à injecter:

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

Le qualificatif:

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

Utilisation de l'enregistreur dans votre code de production:

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

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

Test de l'enregistreur dans votre code de test (donnant un exemple easyMock):

@TestSubject
private ProductionCode productionCode = new ProductionCode();

@Mock
private Logger logger;

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

En utilisant Jmockit (1.21), j'ai pu écrire ce test simple. Le test garantit qu'un message ERREUR spécifique est appelé une seule fois.

@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.    
}

Se moquer de l'Appender peut aider à capturer les lignes de journal. Trouvez un exemple sur: 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")));
}

Utilisez le code ci-dessous. J'utilise le même code pour mon test d'intégration de printemps où j'utilise le journal de connexion pour la journalisation. Utilisez la méthode assertJobIsScheduled pour affirmer le texte imprimé dans le journal.

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

si vous utilisez java.util.logging.Loggercet article peut être très utile, il crée un nouveau gestionnaire et fait des assertions sur le journal Sortie: http://octodecillion.com/blog/jmockit-test-logging/

Il y a deux choses que vous essayez peut-être de tester.

• Lorsqu'il y a un événement intéressant l'opérateur de mon programme, mon programme effectue-t-il une opération de journalisation appropriée, qui peut informer l'opérateur de cet événement.
• Lorsque mon programme effectue une opération de journalisation, le message de journal qu'il produit contient-il le texte correct?

Ces deux choses sont en fait des choses différentes et pourraient donc être testées séparément. Cependant, tester le second (le texte des messages) est tellement problématique, je déconseille de le faire du tout. Un test d'un texte de message consistera finalement à vérifier qu'une chaîne de texte (le texte de message attendu) est identique à la chaîne de texte utilisée dans votre code de consignation ou peut en être dérivée de manière triviale.

• Ces tests ne testent pas du tout la logique du programme, ils testent seulement qu'une ressource (une chaîne) est équivalente à une autre ressource.
• Les tests sont fragiles; même une modification mineure de la mise en forme d'un message de journal rompt vos tests.
• Les tests sont incompatibles avec l'internationalisation (traduction) de votre interface de journalisation. Les tests supposent qu'il n'y a qu'un seul texte de message possible, et donc qu'un seul langage humain possible.

Notez que le fait d'avoir votre code de programme (implémentant une logique métier, peut-être) appelant directement l'interface de journalisation de texte est une mauvaise conception (mais malheureusement très commode). Le code responsable de la logique métier détermine également une stratégie de journalisation et le texte des messages de journal. Il mélange la logique métier avec le code de l'interface utilisateur (oui, les messages de journalisation font partie de l'interface utilisateur de votre programme). Ces choses devraient être séparées.

Je recommande donc que la logique métier ne génère pas directement le texte des messages de journal. Au lieu de cela, déléguez-le à un objet de journalisation.

• La classe de l'objet de journalisation doit fournir une API interne appropriée, que votre objet métier peut utiliser pour exprimer l'événement qui s'est produit à l'aide d'objets de votre modèle de domaine, et non de chaînes de texte.
• L'implémentation de votre classe de journalisation est chargée de produire des représentations textuelles de ces objets de domaine et de rendre une description textuelle appropriée de l'événement, puis de transmettre ce message texte à la structure de journalisation de bas niveau (comme JUL, log4j ou slf4j).
• Votre logique métier est uniquement responsable d'appeler les méthodes correctes de l'API interne de votre classe d'enregistreur, en passant les objets de domaine corrects, pour décrire les événements réels qui se sont produits.
• Votre classe de journalisation concrète implementsan interface, qui décrit l'API interne que votre logique métier peut utiliser.
• Votre ou vos classes qui implémentent la logique métier et doivent effectuer la journalisation ont une référence à l'objet de journalisation auquel déléguer. La classe de la référence est l'abstrait interface.
• Utilisez l'injection de dépendances pour configurer la référence à l'enregistreur.

Vous pouvez ensuite tester que vos classes de logique métier informent correctement l'interface de journalisation des événements, en créant un faux journal, qui implémente l'API de journalisation interne, et en utilisant l'injection de dépendances dans la phase de configuration de votre test.

Comme ça:

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

Ce que j'ai fait si tout ce que je veux faire, c'est de voir qu'une chaîne a été enregistrée (au lieu de vérifier les instructions de journal exactes qui est tout simplement trop fragile), c'est de rediriger StdOut vers un tampon, de faire un contient, puis de réinitialiser 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);

J'ai répondu à une question similaire pour log4j voir comment-puis-je-tester-avec-junit-that-a-warning-was-logged-with-log4

Ceci est plus récent et exemple avec Log4j2 (testé avec 2.11.2) et 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");
        }
    }
}

Utilisation des dépendances Maven suivantes

 <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>

Si vous utilisez log4j2, la solution de https://www.dontpanicblog.co.uk/2018/04/29/test-log4j2-with-junit/ m'a permis d'affirmer que les messages étaient enregistrés.

La solution va comme ceci:

• Définir un appender log4j en tant que règle 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();
      }
  }

• Définissez un test qui utilise votre règle 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"));
      }
  }

N'oubliez pas que log4j2.xml fait partie de src / test / resources