Functional testing : Asserting that a line was logged by Logback

29 11 2011

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

    @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");
      }
    }));
  }
}
About these ads

Actions

Information

3 responses

2 12 2011
Christian Schlichtherle

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?

3 12 2011
Aurelien

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 12 2011
huxi

As it is a somewhat related topic:
You may be interested in http://stackoverflow.com/questions/945659/is-there-any-way-to-automatically-execute-junit-testcases-once-with-all-logging and the answer I gave to myself. I was struggling with this issue for quite a while until I came up with this solution.

Leave a Reply

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

WordPress.com Logo

You are commenting using your WordPress.com 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




Follow

Get every new post delivered to your Inbox.

%d bloggers like this: