/log-capture

assertions for logging with logback

Primary LanguageJavaMIT LicenseMIT

log-capture

Apache License 2 Build Status Maven Central

Simple assertions for log messages. See Examples.

Note that log-capture asserts evaluated log statements. That means it depends on a logging implementation (logback), but works with any logging facade (slf4j and others)

var name="world";
log.info("hello {}", name);
log.warn("bye {}", name);

logCapture.assertLoggedInOrder(
    info("hello world"),
    warn("bye world")
);

It's even simple when there's more than just the message and level to assert:

logCapture.assertLoggedInOrder(
    info("hello world",
        logger("com.acme.helloworld.WorldGreeter"))
    warn("bye world",
        exception().expectedType(WorldNotFoundException.class))
);

Table of Contents

Usage

Maven

Add log-capture as a test dependency to your project. If you use Maven, add this to your pom.xml:

<dependency>
    <groupId>de.dm.infrastructure</groupId>
    <artifactId>log-capture</artifactId>
    <version>4.0.0</version>
    <scope>test</scope>
</dependency>

Additional matchers

The default matchers can match level and/or message. But there are additional matchers for log messages. See also the detailed example below

MDC content

import static de.dm.infrastructure.logcapture.ExpectedMdcEntry.mdc;

...

MDC.put("key", "value");
log.info("did something");

logCapture.assertLogged(info("did something", mdc("key", "value")));`

Exceptions

import static de.dm.infrastructure.logcapture.ExpectedException.exception;

...

log.warn("oh no!",
    new IllegalArgumentException("shame on you!",
        new NullPointerException("never use null")));

logCapture.assertLogged(
    warn("oh no!",
        exception()
            .expectedType(IllegalArgumentException.class)
            .expectedCause(exception()
                .expectedType(NullPointerException.class)
                .expectedMessageRegex("never use null")
                .build())
            .build()
    ));

Markers

import static de.dm.infrastructure.logcapture.ExpectedMarker.marker;

...

log.info(MarkerFactory.getMarker("my-marker"), "hello with marker");

logCapture.assertLogged(info("hello with marker", marker("my-marker")));

Key-Value

import static de.dm.infrastructure.logcapture.ExpectedKeyValue.keyValue;

...

log.atInfo().setMessage("hello").addKeyValue("meaning", 42).log();

logCapture.assertLogged(info("hello", keyValue("meaning", 42)))

Logger name

import static de.dm.infrastructure.logcapture.ExpectedLoggerName.logger;

...

log.info("did something");

logCapture.assertLogged(info("did something", logger("com.acme.foo")));

Examples

Unit Test Example:

package my.company.application;

import de.dm.infrastructure.logcapture.LogCapture;
import de.dm.infrastructure.logcapture.LogExpectation;
...

public class MyUnitTest {

    Logger logger = LoggerFactory.getLogger(MyUnitTest.class);

    @RegisterExtension //use @Rule for LogCapture 2/JUnit 4
    public LogCapture logCapture = LogCapture.forCurrentPackage();

    @Test
    public void twoLogMessagesInOrder() {
        log.info("something interesting");
        log.error("something terrible");

        //assert that the messages have been logged
        //expected log message is a regular expression
        logCapture.assertLogged(
            info("^something interesting$"),
            error("terrible")
        );
        
        //is the same assertion, but also asserts the order of these log messages
        logCapture.assertLoggedInOrder(
            info("^something interesting$"),
            error("terrible")
        );

        //assert that no log message containing "something unwanted" with any log level exists 
        //and that no log message with level DEBUG exists
        logCapture.assertNotLogged(
            any("something unwanted"),
            debug()
        );
    }
}

Integration Test Example:

package my.company.application;

import utility.that.logs.Tool;
import irrelevant.utility.Irrelevant;
import de.dm.infrastructure.logcapture.LogCapture;
...

public class MyIntegrationTest {

    Logger logger = LoggerFactory.getLogger(MyIntegrationTest.class);

    // captures only logs from my.company and utility.that.logs and sub-packages
    @RegisterExtension //use @Rule for LogCapture 2/JUnit 4
    public LogCapture logCapture = LogCapture.forPackages("my.company", "utility.that.logs");

    @Test
    public void twoLogMessagesInOrder() {
        Irrelevant.doSomething();
        Tool.doSomething();

        log.info("something interesting");
        log.error("something terrible");

        logCapture.assertLogged(
            info("^something interesting$"),
            info("^start of info from utility.that.logs"),
            error("terrible"));
    }
}

Example with additional MDC matcher

package my.company.application;

...

import static de.dm.prom.logcapture.ExpectedMdcEntry.withMdc;

...

public class MyUnitTest {
    Logger logger = LoggerFactory.getLogger(MyUnitTest.class);

    @RegisterExtension
    public LogCapture logCapture = LogCapture.forCurrentPackage();

    @Test
    public void logMessageWithMdcInformation() {
        MDC.put("my_mdc_key", "this is the MDC value");
        log.info("this message has some MDC information attached");
        MDC.put("other_mdc_key", "this is the other MDC value");
        log.info("this message has some additional MDC information attached");

        // asserts my_mdc_key for both message and other_mdc_key for the second one
        logCapture
            .with(mdc("my_mdc_key", "^this is the MDC value$"))
            .assertLoggedInOrder(
                info("information attached"),
                info("additional MDC information attached",
                    mdc("other_mdc_key", "^this is the other MDC value$")));
    }
}

If assertLogged fails because the message is correct, but the MDC value is wrong, the assertion error will contain the actual MDC values of the last captured log event where the log message and level matched.

This can be useful for debugging purposes. For example, this test code:

    MDC.put("my_mdc_key","this is the wrong MDC value");
    MDC.put("other_mdc_key","this is the other MDC value");
    log.info("this message has some MDC information attached");

    logCapture.assertLogged().info("information attached",
        mdc("my_mdc_key","^something expected that never occurs$"),
        mdc("other_mdc_key","^this is the other MDC value$"));

will output:

java.lang.AssertionError: Expected log message has occurred, but never with the expected MDC value: Level: INFO, Regex: "information attached"
  Captured message: "this message has some MDC information attached"
  Captured MDC values:
    my_mdc_key: "this is the wrong MDC value"
    other_mdc_key: "this is the other MDC value"

More Examples

See ReadableApiTest.java for more usage examples.

Usage outside of JUnit 5 (Cucumber example)

If you intend to use LogCapture outside of a JUnit test, you cannot rely on JUnit's @RegisterExtension annotation and must call LogCapture's addAppenderAndSetLogLevelToTrace() and removeAppenderAndResetLogLevel() methods manually.

Be aware that this will still cause JUnit to be a dependency.

Cucumber example

Here's an Example that shows how to use LogCapture with Cucumber 4:

Cucumber feature file

And with MDC logging context
  | contextId      | contentRegex                    |
  | mdc_key | ^some mdc value |
* the following messages were logged
  | level | messageRegex   |
  | INFO  | ^Something happened$ |
  | INFO  | ^Something else happened with the same mdc context$ |

Changes

4.0.0

  • breaking change: log-capture now requires Java 17
  • breaking change: all deprecated parts have been removed
  • added a new log event matcher for key-value content
  • lots of dependency updates

3.6.2

  • Fixed an assertion message concerning captured Exceptions.

3.6.1

  • Fixed a misleading and wrong assertion message. The assertion itself was correct, but the message always said all matchers did not match when only a subset did not match.

3.6.0

3.5.0

  • Added new Log Event Matcher: ExpectedKeyValue.keyValue(...) to assert StructuredArguments.keyValue(...) from Logstash
  • Improved readability for assertion errors when using assertNotLogged(...)
  • Updated dependencies

3.4.1

  • Improved Javadoc for deprecated methods

3.4.0

  • Added assertNotLogged(...) for asserting that no matching log message has been logged
  • Added more factory methods for warn(...), error(...) as a shortcut to ignore the message when matching
  • Added any(...) factory method for matching any log message regardless of level

3.3.0

  • Introduced a new fluent API with
    • better readability
    • extensible log message assertions (to assert attached Exceptions, Markers and LoggerName beyond MDC content)
  • Deprecated the old API (will be removed in 4.0, how to update)

3.2.1

Added deprecated addAppenderAndSetLogLevelToDebug() again for compatibility

3.2.0

Added fluent API

3.1.0

Added assertNothingElseLogged()

3.0.0

Updated from JUnit 4 to JUnit 5.

To update from 2.x.x to 3.x.x:

  • Use JUnit 5 instead of JUnit 4
  • Replace @Rule in logging tests with @RegisterExtension

2.0.1

Fixed a bug where multiline log messages (for example Messages that contain a stack trace) could not be matched.

Updating from Version 1.x.x to 2.x.x

  • LogCapture.forUnitTest() has been replaced with LogCapture.forCurrentPackage()
  • LogCapture.forIntegrationTest(...) has been replaced with LogCapture.forPackages(...)
  • logCapture.addAppender() has been replaced with logCapture.addAppenderAndSetLogLevelToTrace()
  • logCapture.removeAppender() has been replaced with logCapture.removeAppenderAndResetLogLevel()

Updating from Version 3.2.x or lower to Version 3.3.x or higher

Since the old API has been deprecated in 3.3.0 existing assertions should be replaced in preparation for 4.0. So for example:

...

import static ch.qos.logback.classic.Level.INFO;
import static de.dm.infrastructure.logcapture.ExpectedMdcEntry.withMdc;

...

// plain assertion
logCapture.assertLogged(INFO, "Something happened.");
// assertion with MDC
logCapture.assertLogged(INFO, "Something with MDC content", 
    withMdc("bookingNumber", "1234"));
// in-order assertion
logCapture
    .assertLogged(INFO, "Step 1")
    .thenLogged(INFO, "Step 2");

needs to be replaced with:

...

import static de.dm.infrastructure.logcapture.ExpectedMdcEntry.mdc;
import static de.dm.infrastructure.logcapture.LogExpectation.info;

...

// plain assertion
logCapture.assertLogged(info("Something happened."));
// assertion with MDC
logCapture.assertLogged(info("Something with MDC content",
    mdc("rabattUpdate", "CapturableHeadline")));
// in-order assertion
ogCapture.assertLoggedInOrder(
    info("Step 1")
    info("Step 2")
);