Functional testing : Asserting that a line was logged by Logback

I encountered a tricky problem today, I was writing a test for which the assertion was onto some function called or not.

I couldn’t mock that function as it was part of an external API for which I couldn’t change the real Object to a mocked Object.

There was a solution, checking that this function was logging a particular event or not.

So in order to assert that this specific line was logged or not, I added a mocked Appender.

(Note: The Appender is the class that will actually do the logging, e.g. ConsoleAppender to log to the console)

I’m using here two great libraries: Mockito and Logback, please refer to my other post explaining how to configure Logback.

Here is the code:

package com.jsoft.test;

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

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

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

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

5 thoughts on “Functional testing : Asserting that a line was logged by Logback

  1. I think there is something fundamentally wrong with this use case: There is a reason why logging output is not normally available to an application. This is because logging is almost never part of the application logic. It’s been designed to support post-mortem analysis. However, nowadays it’s mostly used as a foul excuse not to develop proper automated tests (I’m not blaming you here).

    So if the logging output is not part of the application logic, then why would you want to test it anyway?

    1. That’s a good point, I realize I didn’t make myself clear. I was not unit testing (I just updated the title of my blog post, it was wrong).
      I was doing functional testing, meaning that I don’t have access to the internal of the classes, and I actually do not aim at unit test a particular function but instead I want to do black-box testing on some API. So my interest is to find out that this API is behaving the way I expect it to. Looking at the logs is similar as if I were testing a website and looking at the HTML output. Thanks for the comment, it allowed me to clarify that point, because I agree, if you start to do unit testing based on output, you’re doing it wrong.

  2. I put logging into code for postmortem / diagnostic reasons.
    That is a capability of the system that I want to assert works as expected by testing so that I can be assured it’s going to work ok in prod and be there when I need it.
    It is legitimate therefore to test.

    There are other testing frameworks for SLF4J however the one I am aware of does not fare well when using concurrent test execution which is common in my experience. For this reason I put together a testing utility that works well in a concurrent test environment and doesn’t rely on classpath tweaks like StaticLogBinder which always causes problems.

    I’ve chimed in on a few discussion on slf4j log testing and their limitations so I decided to put my words into code and that git repo is the result.

    Take a look here …

  3. Wow, that is just genius! Thanks a lot!
    I have a lot of old code to test, that I’m not allowed to change containing some methods, that log something into a log file which will be parsed by some external scripts, so I need to get sure that the data in the logs are correct. With this code, I managed.

Leave a Reply

Fill in your details below or click an icon to log in: Logo

You are commenting using your account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s