Hot questions for Using Mockito in logging

Question:

I have written a class to manage logging within an android application project. The LogManager is basically a wrapper for android.util.log It handles logging to a file, if the application crashes, and standard debug logging. I would like to unit test the class using JUnit.

I have tried the following but it does not seem to produce the results I would expect after reading the examples:

LogManager.class (This is a simplified version of the class I have used, for demonstration purposes)

public class LogManager implements ILogManager
{
     public void log(String tag, String message)
     {
           Log.e(tag, message);
     }
}

And here is my test class

@RunWith(RobolectricGradleTestRunner.class)
@Config(constants = BuildConfig.class, sdk = 21)
@PrepareForTest({Log.class, LogManager.class})
public class LogManagerUnitTest
{

    @Test
    public void testLogConsoleInfo()
    {
        PowerMockito.mockStatic(Log.class);

        LogManager.getInstance().log(LogLevel.INFO, "test", "test");

        PowerMockito.verifyStatic(Mockito.times(1));
        Log.e(anyString(), anyString());
    }
}

My problem is that this passes no matter what I put. E.g: if I instead replace the last call with Log.wtf(...) it still passes. I would have assumed that it should fail since Log.wtf was not called in the static class Log? So my question is, why isn't this approach working as expected and what would be the correct way to do it?


Answer:

I started a fresh project and was able to get it to fail tests and succeed appropriately using the following, so I'm assuming the runwith was the culprit:

@RunWith(PowerMockRunner.class)
@PrepareForTest(android.util.Log.class) 
public class LoggerUnitTest {
    @Test
    public void testLog() throws Exception
    {
        PowerMockito.mockStatic(Log.class); //        when(Log.e(anyString(), anyString())).thenReturn(1);

        Logger.log("test", "test");

        PowerMockito.verifyStatic(times(1));
        Log.e(anyString(), anyString());
    } }

Question:

I am trying to test a static method that catches exception coming from different sub-calls or from the method itself and does just log the exception messages. By requirements, I cannot change the method implementation. Spying sub-calls is not a option in this case as we want to be consistent over the tests and since some executions throw exceptions from the method body itself, we finally opted to check... the error log messages.

Therefore, I want to mock the logger that will be called from the method, add an answer to the logging call when the logger calls error(...) with a match to a specific message. So far so good in my side. An example of what I do is as follow:

Mockito.doAnswer(new Answer<Void>()
{
    @Override
    public Void answer(InvocationOnMock invocation) throws Throwable {
        Object[] args = invocation.getArguments();
        String errorMessage = (String) args[0];
        assertTrue(errorMessage.contains(SPECIFIC_MESSAGE));
        return null;
    }
}).when(logger).error(Matchers.startsWith(GENERIC_PREFIX));

We decided to use PowerMockito to mock the static call and returned our mocked logger from LoggerFactory.getLogger(...)

Logger logger = Mockito.mock(Logger.class); 
PowerMockito.mockStatic(LoggerFactory.class);
Mockito.when(LoggerFactory.getLogger(any(Class.class))).thenReturn(logger);

Now comes our problem:

For each test, the value of the message SPECIFIC_MESSAGE to check changes. So we mock a logger for each test, mock the static LoggerFactory call to return the logger and then add our specific answer to our logger.error(...) call for this specific instance. But the first Answer which is added to the logger.error call during our first test seems to override all the other answers. Same execution occurs with each test.

I thought that the problem could come from Mockito that would return a singleton mock but I tested for that and it's not the case. Then I thought my problem could come from my LoggerFactory.getLogger(...) call which would return all the time the same instance of a logger but not the case either. Here is an implementation that shows the same issue I'm having with my code with the related execution log trace.

import java.util.Arrays;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

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

    public static void main(String[] args)
    {
        logger.error("Error = " + Arrays.toString(args));
    }
}

import org.junit.Test;
import org.junit.runner.RunWith;
import org.mockito.Matchers;
import org.mockito.Mockito;
import org.mockito.invocation.InvocationOnMock;
import org.mockito.stubbing.Answer;
import org.powermock.api.mockito.PowerMockito;
import org.powermock.core.classloader.annotations.PrepareForTest;
import org.powermock.modules.junit4.PowerMockRunner;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import static org.mockito.Mockito.*;
import static org.junit.Assert.*;

@RunWith(PowerMockRunner.class)
@PrepareForTest({LoggerFactory.class})
public class AppTest
{
    @Test
    public void firstTest()
    {
        Logger logger = Mockito.mock(Logger.class); 
        PowerMockito.mockStatic(LoggerFactory.class);
        Mockito.when(LoggerFactory.getLogger(any(Class.class))).thenReturn(logger);

        Mockito.doAnswer(new Answer<Void>()
        {
            @Override
            public Void answer(InvocationOnMock invocation) throws Throwable {
                Object[] args = invocation.getArguments();
                String errorMessage = (String) args[0];
                System.out.println("Calling from firstTest");
                assertTrue(errorMessage.contains("a"));
                return null;
            }
        }).when(logger).error(Matchers.startsWith("Error"));

        App.main(new String[]{ "a" });
    }

    @Test
    public void secondTest()
    {
        Logger logger = Mockito.mock(Logger.class); 
        PowerMockito.mockStatic(LoggerFactory.class);
        Mockito.when(LoggerFactory.getLogger(any(Class.class))).thenReturn(logger);

        Mockito.doAnswer(new Answer<Void>()
        {
            @Override
            public Void answer(InvocationOnMock invocation) throws Throwable {
                Object[] args = invocation.getArguments();
                String errorMessage = (String) args[0];
                System.out.println("Calling from secondTest");
                assertTrue(errorMessage.contains("b"));
                return null;
            }
        }).when(logger).error(Matchers.startsWith("Error"));

        App.main(new String[]{ "b" });
    }
}

TRACE:

Calling from firstTest
Calling from firstTest

Any idea why is the second answer not processed? Thanks in advance.

EDIT:

Issue is actually coming from the static method mock. "Then I thought my problem could come from my LoggerFactory.getLogger(...) call which would return all the time the same instance of a logger but not the case either." is actually wrong. It is valid inside my test where calling getLogger(...) returns the logger mock being mocked inside the test but when actually calling the App.main(...) method, the mocked getLogger(...) method call inside main(...) always return the same instance and is not reset between tests as expected. Mockito is supposed to reset between tests per documentation. A mockito's bug or limitation? Troubles related to interactions between Mockito and PowerMockito?


Answer:

I found a solution which is to prepare the class to static mock at the method level for each test. Adding @PrepareForTest(LoggerFactory.class) before signature is actually solving the problem which was that the logger factory mock wasn't being reset between test and therefore the first call Mockito.when(LoggerFactory.getLogger(any(Class.class))).thenReturn(logger); was always valid and always returning the same logger.

Question:

I am trying to write tests that check whether certain lines have been logged. I googled for a while but I cannot figure out why LOG is not replaced.

Class to test:

public class Example {
    private static final Logger LOG = LoggerFactory.getLogger(Example.class);

    public void foo(...)
    {
       if(...)
         LOG.warn("Warning");
       //...
    }
}

Test:

@RunWith(PowerMockRunner.class)
@PrepareForTest({LoggerFactory.class})
public class MyTest
{
    @Mock
    Logger logger;

    @InjectMocks
    private final Example example = new Example();

    @Test
    public void test1() {
        PowerMockito.mockStatic(LoggerFactory.class);
        logger = PowerMockito.mock(Logger.class);
        PowerMockito.when(LoggerFactory.getLogger(Example.class)).thenReturn(logger);

        example.foo(...);

        Mockito.verify(logger).warn("Warning");
    }
}

SLF4J is used and PowerMock 1.7.1.

PS: Replacing private static final Logger LOG is no option in this project.


Answer:

You are creating your subject too early. You arrange the mock well after the subject has already been created.

create the subject after arranging the static mock

@RunWith(PowerMockRunner.class)
@PrepareForTest({LoggerFactory.class})
public class MyTest {

    @Test
    public void test1() {
        //Arrange
        Logger logger = PowerMockito.mock(Logger.class);

        PowerMockito.mockStatic(LoggerFactory.class);           
        PowerMockito.when(LoggerFactory.getLogger(Example.class)).thenReturn(logger);

        Example example = new Example();

        //Act
        example.foo(..);

        //Assert
        Mockito.verify(logger).warn("Warning");
    }
}

Question:

Let's say I have the following class like this:

public class MyClass {
  public static final Logger LOG = Logger.getLogger(MyClass.class);

  public void myMethod(String condition) {
    if (condition.equals("terrible")) {
      LOG.error("This is terrible!");
      return; 
    }
    //rest of logic in method
  }
}

My unit test for MyClass looks something like this:

@Test
public void testTerribleCase() throws ModuleException {
  myMethod("terrible"); 
  //Log should contain "This is terrible!" or assert that error was logged
}

Is there some way to determine that the log contains the specific String "This is terrible"? Or even better, is there a way to determine if it logged an error at all without looking for a specific String value?


Answer:

Create a custom filter to look for the message and record if it was ever seen.

@Test
public void testTerribleCase() throws ModuleException {
    class TerribleFilter implements Filter {
        boolean seen;
        @Override
        public boolean isLoggable(LogRecord record) {
            if ("This is terrible!".equals(record.getMessage())) {
                seen = true;
            }
            return true;
        }
    }

    Logger log = Logger.getLogger(MyClass.class.getName());
    TerribleFilter tf = new TerribleFilter();
    log.setFilter(tf);
    try {
        myMethod("terrible");
        assertTrue(tf.seen);
    } finally {
        log.setFilter(null);
    }
}

Question:

I am writting a test case where i have to mock RestTemplate. But when i execute the test cases i am facing NoClassDefFoundException. Below is my code

@RunWith(MockitoJUnitRunner.class)
class X{
  @InjectMocks
   private YService yService;

   @Mock
   private RestTemplate restTemplate;

@Test
public void test(){
  when(restTemplate.postForObject(Mockito.anyString(),Mockito.any(),Mockito.any())).thenReturn("HelloWorld");
}
}

Gradle is not downloading the commons-logging dependency If i try to include it as dependency in build.gradle.


Answer:

Probably you may be needing apache commons logging in classpath

<dependency>
    <groupId>commons-logging</groupId>
    <artifactId>commons-logging</artifactId>
    <version>1.2</version>
</dependency>

Question:

I am having a class which extends LazyLogging trait

class TaskProcessor()
  extends Processor
    with LazyLogging {

  def a1() = {
    logger.info("Test logging")
  }
}

Now, I want to test whether my logging works. So I followed this example Unit test logger messages using specs2 + scalalogging and wrote my test as follows

 "TaskProcessor" should "test logging" in {

    val mockLogger = mock[Logger]
    val testable = new TaskProcessor {
      override val logger: Logger = mockLogger
    }
    verify(mockLogger).info("Test logging")
}

I get the following error

Error:(32, 20) overriding lazy value logger in trait LazyLogging of type com.typesafe.scalalogging.Logger;
 value logger must be declared lazy to override a concrete lazy value
      override val logger: Logger = mockLogger

To resolve this, I modify statement

  override val logger: Logger = mockLogger

to

  override lazy val logger: Logger = mockLogger

I get the following error

Cannot mock/spy class com.typesafe.scalalogging.Logger
Mockito cannot mock/spy following:
  - final classes
  - anonymous classes
  - primitive types
org.mockito.exceptions.base.MockitoException: 
Cannot mock/spy class com.typesafe.scalalogging.Logger
Mockito cannot mock/spy following:
  - final classes
  - anonymous classes
  - primitive types
    at org.scalatest.mockito.MockitoSugar.mock(MockitoSugar.scala:73)
    at org.scalatest.mockito.MockitoSugar.mock$(MockitoSugar.scala:72)

My dependecies are as follows

 "org.scalatest" %% "scalatest" % "3.0.5" % "test",
  "org.mockito" % "mockito-all" % "1.10.19" % Test,
  "com.typesafe.scala-logging" %% "scala-logging" % "3.9.2",

Can anyone please guide me as to how I can mock the logger and do the testing.


Answer:

The problem is that com.typesafe.scalalogging.Logger class cannot be mocked because it's final, but we still can mock underlying org.slf4j.Logger.

import org.scalatest.mockito.MockitoSugar
import org.slf4j.{Logger => UnderlyingLogger}
import com.typesafe.scalalogging.Logger
import org.scalatest.{Matchers, WordSpec, FlatSpec}
import org.mockito.Mockito._

class TaskProcessorSpec extends FlatSpec with Matchers with MockitoSugar {

  "TaskProcessor" should "test logging" in {

    val mockLogger = mock[UnderlyingLogger]
    when(mockLogger.isInfoEnabled).thenReturn(true)

    val testable = new TaskProcessor {
      override lazy val logger = Logger(mockLogger)
    }
    testable.a1()

    verify(mockLogger).info("Test logging")
  }
}

Question:

I am using the mockAppender method of the Appender class and I am trying to figure how to have the following snippet of code return true if either the text below is not logged, or .doAppend is not called at all.

verify(mockAppender).doAppend(argThat(new ArgumentMatcher() {
  @Override
  public boolean matches(final Object argument) {
    return ((LoggingEvent) argument).getFormattedMessage().contains(
        "Sending request to partner: "
        + "https://<URL>/hosted/api/tokenize with args");
  }
}));

Answer:

If I understand the question, simply return the inverse:

return !((LogginEvent) ... etc.

Just as a suggestion, you might consider using an @Captor in your verify instead, and then asserting on the @Captor's value:

ArgumentCaptor<LoggingEvent> argument = ArgumentCaptor.forClass(LoggingEvent.class);
// or more succinct to use a field with @Captor annotation

verify(mockAppender).doAppend(logEventCaptor);
assertFalse(logEventCaptor.getValue().contains("theTextYouWantToExclude");

Question:

I'm working on some old code that does not handle exceptions very well. One test I'm writing, stubs a method that throws an exception, which I need to confirm is the correct exception. The only way to test this exception that I can see, is to capture the argument when it is being logged and compare the strings.

When I run this I get:

Wanted but not invoked: logger.error(Capturing argument)

Actually there were zero interactions with this mock

@Test
public void testRunCipherThrowsException() throws Exception
{
    final Logger logger = mock(Logger.class);
    ArgumentCaptor<Logger> argument = ArgumentCaptor.forClass(Logger.class);

    when(cipher.doSomething(any(byte[].class))).thenThrow(new IllegalBlockSizeException("Bad block size"));
    Mockito.verify(logger).error(argument.capture());

    _task.run();

    assertEquals("The execution failed.  Details: Bad block size", argument.getValue().getName());
}

Here is a snippet from the class I am testing - in debug I am hitting that line of code every time.

try
{

final byte[] result = cipher.doSomething(testData);

catch (final Exception ex)
    {
        _consequtiveFailures++;
        _logger.error("The execution failed.  Details: " + ex.getMessage(), ex);
    }

I've tried to arrange the test a few different ways thinking the verify might not be getting setup correctly. I have also tried a few different ways of setting of the mock Logger object. It is my first time using argument captor, so hopefully I'm just missing something obvious.


Answer:

final Logger logger = mock(Logger.class);

This is a logger instance you have created locally for your test method; it will therefore not be used by the class you are testing. You need to at least spy() the actual logger instance.

What is more, you verify() after you execute (I guess here that _task.run() executes the code which will trigger the exception); which means that even if you spied on the correct Logger instance, at the time you verify() it, there will be nothing.

So:

  • actually mock, or spy, the actual logger used by _task;
  • verify mock/spy interactions (Mockito.verify() works for both) after you have executed the method.

Question:

We are using maven, jersey, Mockito in our project, with java.util.logging for Logs. While running Junit test with mocked objects, log.log() method throwing InvalidUseOfMatchersException. Below is the sample code.

import javax.inject.Inject;
import java.util.logging.Logger;
import java.util.logging.Level;

public class Sample{

    @Inject
    Logger log;

    public String runLog(String name){
        log.log(Level.INFO, "Name = "+name);
    return "name";
    }
}

public class SampleTest{

    @InjectMocks
    Sample sample;

    @Mock
    Logger log;


    public void setup() throws Exception(){
        MockitoAnnotations.initiMocks(this);
    }

    @Test
    public void testRunLog(){
        doNothing().when(log).log(any(Level.class), anyString());
        String s = sample.runLog(anyString());
        assertNotNull(s);
    }

}

Answer:

Here is the problem:

String s = sample.runLog(anyString());

You can use anyString (and all other matcher methods) only in verify and when methods.

If you don't care about exact value you pass then pass some constant or random string.

Question:

I am trying to do a full junit testing of my application and I am stuck when It comes to test the logger messages.

try {
    fillParameters(args);
} catch (ArgumentException e) {
    logger.error(e.getMessage(), e);
    return;
}

Here is the code which triggers the exception :

if (args.length > 3) {
    throw new ArgumentException("Wrong use of the command -> too many args"); 
}

One test :

@Test
public void testFillParametersWithTooManyArguments() {
    String[] args = { "...", "...", "...", "..." };
    Throwable e = null;
    try {
        testInstance.fillParameters(args);
    } catch (Throwable ex) {
        e = ex;
    }
    assertTrue(e instanceof ArgumentException); //this test is working as expected
}

when I take a look at the code coverage, the logger.error(e.getMessage(), e); part is not covered, how am I supposed to cover it? I assume I must mock the logger?


Answer:

Short Answer Test the code that you actually want to test.

Some Info The code in your first code block is in no way tested by the code in your example unit test. I assume that because it looks like Java code and the question is tagged as a Java question that the code in the first code block is actually in a method somewhere. You must unit that that method to get test coverage in the exception catch block in that method.

For Example:

public void IHateToTellPeopleMyMethodName(final String[] args)
{
    try
    {
        fillParameters(args);
    }
    catch (ArgumentException e)
    {
        logger.error(e.getMessage(), e);
        return;
    }
}

In order to get test coverage of the catch block in the IHateToTellPeopleMyMethodName method, you must test the IHateToTellPeopleMyMethodName method in your unit test.

This unit test method does nothing to test the IHateToTellPeopleMyMethodName method because it does not call the IHateToTellPeopleMyMethodName method.

@Test
public void testThatInNoWayTestsTheIHateToTellPeopleMyMethodNameMethod()
{
    String[] args = { "...", "...", "...", "..." };

    try
        {
        testInstance.fillParameters(args);
                fail("expected exception not thrown");
    }
        catch (Throwable ex)
        {
            assertTrue(e instanceof ArgumentException);
    }
}

Unlike the unit test code above, this unit test covers the IHateToTellPeopleMyMethodName method.

@Test
public void testTheIHateToTellPeopleMyMethodNameMethod()
{
    String[] args = { "...", "...", "...", "..." };

    testInstance.IHateToTellPeopleMyMethodName(args);

          verify(mockLogger).error(
                eq(EXPECTED_MESSAGE_TEXT),
                    any(ArgumentException.class));
}

Edit Note My bad, any() needs a class object as a parameter, not a class name.

Question:

I am getting the above exception when i am trying to mock the logger .

I want to verify the logs.

import javax.annotation.PostConstruct;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Autowired;

public class MedSlaveImpl implements MedSlaveInt {
    private static final Logger logger = LoggerFactory.getLogger(MedSlaveImpl.class);

@Override
    public void enterMode() {
        logger.info("muting the Manager");

    }

}

import static org.mockito.Matchers.any;
import static org.mockito.Mockito.verify;
import static org.powermock.api.mockito.PowerMockito.mock;
import static org.powermock.api.mockito.PowerMockito.mockStatic;
import static org.powermock.api.mockito.PowerMockito.when;

import org.junit.After;
import org.junit.Test;
import org.junit.runner.RunWith;
import org.powermock.core.classloader.annotations.PrepareForTest;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.test.context.ActiveProfiles;
import org.springframework.test.context.ContextConfiguration;
import org.springframework.test.context.TestPropertySource;
import org.springframework.test.context.junit4.SpringJUnit4ClassRunner;

import org.powermock.modules.junit4.PowerMockRunner;

import uk.org.lidalia.slf4jtest.TestLoggerFactory;

@RunWith(SpringJUnit4ClassRunner.class)
@ContextConfiguration({ "/context-test.xml", "/context.xml" })
@TestPropertySource("/config.properties")
@ActiveProfiles("mediator")
@PrepareForTest({ MedSlaveImpl.class, LoggerFactory.class })
public class MedModeTest {


    // For mediator
    @Test
    public void testStartService() throws Exception {


        mockStatic(LoggerFactory.class);
        Logger logger = mock(Logger.class);
        when(LoggerFactory.getLogger(any(Class.class))).thenReturn(logger);
        // TestLogger logger =
        // TestLoggerFactory.getTestLogger(MedSlaveImpl.class);

        mediatorImpl.enterMode();
        verify(logger).info("muting the Manager");
        // assertThat(logger.getLoggingEvents(),is(asList(info("muting theManager"))));
    }

    @After
    public void clearLoggers() {
        TestLoggerFactory.clear();
    }

}

I had spent whole day in to verify the logs in different approaches . like using

TestLogger logger, Mockitto , powermock . Finally i ended up with different exceptions.

And for the current approach i am getting the above exception .

Suggestions are greatly appreciated .Thanks for the help in advance


Answer:

The solution without mocking of logger factory.

Have a method for lazy loading of the logger:

public class MedSlaveImpl implements MedSlaveInt {
    private static Logger logger;

    // Package visible to override it in the tests.
    Logger getLogger() {
        if (logger == null) {
            logger = LoggerFactory.getLogger(MedSlaveImpl.class);
        }
        return logger;
    }

    @Override
    public void enterMode() {
        // All calls to the logger via getLogger() method.
        getLogger().info("muting the Manager");
    }
}

Your test has an instance of your service class with overridden getLogger() method:

@Test
public void testStartService() throws Exception {
    //Setup
    final Logger mockedLogger = mock(Logger.class);

    final MedSlaveImpl service = new MedSlaveImpl() {
        @Override
        Logger getLogger() {
            return mockedLogger;
        }
    }

    // When
    service.enterMode();

    // Then
    verify(mockedLogger).info("muting the Manager");
}