java - unitaria - Cómo hacer un JUnit assert en un mensaje en un registrador

sintaxis junit

Question

Tengo un código bajo prueba que solicita a un registrador de Java que informe su estado. En el código de prueba JUnit, me gustaría verificar que la entrada de registro correcta se realizó en este registrador. Algo a lo largo de las siguientes líneas:

methodUnderTest(bool x){
if(x)
logger.info("x happened")
}
@Test tester(){
// perhaps setup a logger first.
methodUnderTest(true);
assertXXXXXX(loggedLevel(),Level.INFO);
}

Supongo que esto podría hacerse con un registrador especialmente adaptado (o controlador, o formateador), pero preferiría volver a utilizar una solución que ya existe. (Y, para ser honesto, no me queda claro cómo acceder a logRecord desde un registrador, pero supongamos que eso es posible).

Answer 1

Como se mencionó en los otros, podrías usar un marco de burla. Para que esto funcione, debes exponer el registrador en tu clase (aunque preferiría que el paquete fuera privado en lugar de crear un setter público).

La otra solución es crear un registrador falso a mano. Tienes que escribir el registrador falso (más código de accesorio) pero en este caso preferiría la legibilidad mejorada de las pruebas contra el código guardado del marco de burla.

Haría algo como esto:

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

Answer 2

Efectivamente estás probando un efecto secundario de una clase dependiente. Para las pruebas unitarias, solo necesita verificar que

logger.info()

fue llamado con el parámetro correcto. Por lo tanto, utilice un marco burlón para emular el registrador y eso le permitirá probar el comportamiento de su propia clase.

Answer 3

En cuanto a mí, puedes simplificar tu prueba usando JUnit con Mockito . Propongo seguir la solución para ello:

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

Es por eso que tenemos una buena flexibilidad para las pruebas con diferentes cantidades de mensajes

Answer 4

Esto es lo que hice para logback.

Creé una clase 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();
}
}

Luego, en el padre de mi clase de prueba de la unidad de prueba, creé un método:

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

Tengo un archivo logback-test.xml definido en src / test / resources y agregué un appender de prueba:

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

y agregué este appender al apéndice raíz:

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

Ahora en mis clases de prueba que se extienden desde mi clase de prueba de padres puedo obtener el appender y obtener el último mensaje registrado y verificar el mensaje, el nivel, el arrojar.

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

Answer 5

Guau. No estoy seguro de por qué esto fue tan difícil. Descubrí que no pude usar ninguno de los ejemplos de código anteriores porque estaba usando log4j2 sobre slf4j. Esta es mi solución:

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

Answer 6

Hay dos cosas que podrías intentar probar.

• Cuando hay un evento de interés para el operador de mi programa, ¿realiza mi programa una operación de registro apropiada, que puede informar al operador de ese evento?
• Cuando mi programa realiza una operación de registro, ¿el mensaje de registro que produce tiene el texto correcto?

Esas dos cosas son en realidad cosas diferentes, por lo que podrían probarse por separado. Sin embargo, probar el segundo (el texto de los mensajes) es muy problemático, recomiendo no hacerlo. Una prueba de un mensaje de texto consistirá, en última instancia, en verificar que una cadena de texto (el texto esperado del mensaje) sea la misma que la cadena de texto utilizada en su código de registro, o que pueda derivarse de manera trivial de ella.

• Esas pruebas no prueban la lógica del programa en absoluto, solo prueban que un recurso (una cadena) es equivalente a otro recurso.
• Las pruebas son frágiles incluso un pequeño ajuste en el formateo de un mensaje de registro rompe sus pruebas.
• Las pruebas son incompatibles con la internacionalización (traducción) de su interfaz de registro. Las pruebas suponen que solo hay un posible mensaje de texto y, por lo tanto, solo un posible idioma humano.

Tenga en cuenta que tener el código de su programa (implementando algunas lógicas de negocios, tal vez) llamando directamente a la interfaz de registro de texto es un diseño pobre (pero desafortunadamente muy común). El código que es responsable de la lógica comercial también está decidiendo alguna política de registro y el texto de los mensajes de registro. Combina la lógica empresarial con el código de la interfaz de usuario (sí, los mensajes de registro forman parte de la interfaz de usuario de su programa). Esas cosas deberían estar separadas.

Por lo tanto, recomiendo que la lógica empresarial no genere directamente el texto de los mensajes de registro. En su lugar, delegarlo en un objeto de registro.

• La clase del objeto de registro debe proporcionar una API interna adecuada, que su objeto comercial puede usar para expresar el evento que ha ocurrido utilizando objetos de su modelo de dominio, no cadenas de texto.
• La implementación de su clase de registro es responsable de producir representaciones de texto de esos objetos de dominio, y presentar una descripción de texto adecuada del evento, y luego reenviar ese mensaje de texto al marco de registro de bajo nivel (como JUL, log4j o slf4j).
• La lógica de su negocio solo es responsable de llamar a los métodos correctos de la API interna de su clase de registrador, pasando los objetos de dominio correctos, para describir los eventos reales que ocurrieron.
• Su clase de registro concreto implements una interface que describe la API interna que su lógica comercial puede usar.
• Su (s) clase (s) que implementan la lógica comercial y deben realizar el registro tiene una referencia al objeto de registro para delegar. La clase de la referencia es la interface abstracta.
• Use la inyección de dependencia para configurar la referencia al registrador.

A continuación, puede probar que las clases de lógica de negocios le dicen correctamente a la interfaz de registro sobre eventos, creando un registrador de simulación, que implementa la API de registro interno y el uso de la inyección de dependencia en la fase de configuración de la prueba.

Me gusta esto:

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

Answer 7

Inspirado por la solución de @RonaldBlaschke, se me ocurrió esto:

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

... lo que te permite hacer:

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

Probablemente puedas hacer que use hamcrest de una manera más inteligente, pero lo dejé así.

Answer 8

La burla es una opción aquí, aunque sería difícil, porque los leñadores generalmente son privados y estáticos, por lo que configurar un registrador simulado no sería pan comido, o requeriría la modificación de la clase bajo prueba.

Puede crear un Appender personalizado (o como se llame), y registrarlo, ya sea a través de un archivo de configuración de solo prueba o en tiempo de ejecución (de una manera, dependiendo del marco de trabajo de registro). Y luego puede obtener ese appender (ya sea estáticamente, si se declara en el archivo de configuración, o por su referencia actual, si está conectando el tiempo de ejecución), y verificar su contenido.

Answer 9

Lo he necesitado varias veces también. He creado una pequeña muestra a continuación, que te gustaría ajustar a tus necesidades. Básicamente, usted crea su propio Appender y lo agrega al registrador que desea. Si desea recopilar todo, el registrador de raíz es un buen lugar para comenzar, pero puede usar uno más específico si lo desea. No olvides quitar el Appender cuando hayas terminado, de lo contrario, podrías crear una pérdida de memoria. A continuación lo hice dentro de la prueba, pero setUp o @Before y tearDown o tearDown podrían ser lugares mejores, según sus necesidades.

Además, la implementación a continuación recopila todo en una List en la memoria. Si está registrando mucho, podría considerar agregar un filtro para eliminar las entradas aburridas, o escribir el registro en un archivo temporal en el disco (Sugerencia: LoggingEvent es Serializable , por lo que debería poder serializar los objetos del evento, si el mensaje de registro es).

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

Answer 10

Lo que he hecho si todo lo que quiero hacer es ver que se haya registrado algo de cadena (en lugar de verificar sentencias de registro exactas que son demasiado frágiles) es redirigir StdOut a un buffer, hacer un contenedor y luego reiniciar 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);

Answer 11

Mocking the Appender puede ayudar a capturar las líneas de registro. Encuentre una muestra en: 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")));
}

Answer 12

Muchas gracias por estas (sorprendentemente) respuestas rápidas y útiles; me pusieron en el camino correcto para mi solución.

La base de código era Quiero usar esto, usa java.util.logging como su mecanismo de registro, y no me siento lo suficientemente a gusto en esos códigos para cambiarlo completamente a log4j o a interfaces / fachadas de registradores. Pero en base a estas sugerencias, he "pirateado" una extensión de Julyhandler y eso funciona como un regalo.

Un breve resumen sigue. Extienda 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(){}
}

Obviamente, puede almacenar tanto como quiera / quiera / necesite de LogRecord , o empujarlos a todos en una pila hasta que obtenga un desbordamiento.

En la preparación para la prueba junit, usted crea un java.util.logging.Logger y le agrega un nuevo 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);

La llamada a setUseParentHandlers() consiste en silenciar los controladores normales, de modo que (para esta ejecución de prueba junit) no se produzca ningún registro innecesario. Haga lo que su código-bajo-prueba necesite para usar este registrador, ejecute la prueba y assertEquality:

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

(Por supuesto, movería gran parte de este trabajo a un método @Before y realizaría otras mejoras variadas, pero eso complicaría esta presentación).

Answer 13

Otra idea que vale la pena mencionar, aunque es un tema más antiguo, es crear un productor de CDI para inyectar su registrador para que la burla sea fácil. (Y también da la ventaja de no tener que declarar la "declaración del registrador completo" nunca más, pero eso es fuera de tema)

Ejemplo:

Creando el registrador para inyectar:

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

El calificador:

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

Usando el registrador en su código de producción:

public class ProductionCode {
@Inject
@LoggerType
private Logger logger;
public void logSomething() {
logger.info("something");
}
}

Probando el registrador en su código de prueba (dando un ejemplo de easyMock):

@TestSubject
private ProductionCode productionCode = new ProductionCode();
@Mock
private Logger logger;
@Test
public void testTheLogger() {
logger.info("something");
replayAll();
productionCode.logSomething();
}

Answer 14

Otra opción es simular a Appender y verificar si el mensaje se ha registrado en este appender. Ejemplo para Log4j 1.2.x y 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);
}
}

Answer 15

Para log4j2, la solución es ligeramente diferente porque AppenderSkeleton ya no está disponible. Además, usar Mockito, o una biblioteca similar para crear un Appender con un ArgumentCaptor no funcionará si está esperando múltiples mensajes de registro porque MutableLogEvent se reutiliza en varios mensajes de registro. La mejor solución que encontré para log4j2 es:

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

Answer 16

Usa el siguiente código Estoy usando el mismo código para mi prueba de integración de primavera en la que estoy utilizando el inicio de sesión para el registro. Use el método assertJobIsScheduled para afirmar el texto impreso en el registro.

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

Answer 17

Usando Jmockit (1.21) pude escribir esta prueba simple. La prueba se asegura de que se invoque un mensaje ERROR específico solo una vez.

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

Answer 18

si está utilizando java.util.logging.Logger este artículo puede ser muy útil, crea un nuevo controlador y realiza afirmaciones en el registro Salida: http://octodecillion.com/blog/jmockit-test-logging/