Unit test logger messages using specs2 + scalalogg

问题:

I have a little problem here and really have no idea how to implement unit testing for logger messages. Of course, it sounds a little weird, but for me it's really interesting topic. But let me be more specific.

I have some scala class and test specification:

class Testable extends Logging {
  def method() = {
    // some method calls
    logger.info("Message1")
  }
}

class TestableSpec extends Specification with ShouldMatchers with Mockito {
  "Testable instance" should {
    // some important tests 

    "print proper log message during method call" in {
      // And how to test that logger really prints proper message ("Message1")? 
    }
  }
}

My first thought was to intercept underlying logger engine messages but it seems a little hard thing to implement due to usage of mixins in Testable class, therefore any ideas to do such things would be very helpful.

UPDATE: I finally implemented a test and decided to share my solution with community. We cannot mock scalalogging.Logger class directly because it's final but we still can mock underlying slf4j Logger. To clarify an idea:

class Testable extends Logging {
    def foo() = {
        // ...
        logger.info("Foo has been called")
    }
}

// Another imports are omitted.
import com.typesafe.scalalogging.slf4j.Logger
import org.slf4j.{Logger => Underlying}

class TestableSpec extends Specification with Mockito with ShouldMatchers {
    def initTestable(mocked: Underlying): Testable = {
        new Testable() {
            override lazy val logger = Logger(mocked)
        }
    }

    "Testable instance" should {
        "invoke logger with a proper message" in {
            val mocked = mock[Underlying]
            mocked.isInfoEnabled returns true // Should be set to true for test
            initTestable(mocked).foo()

            there was one(mocked).info("Foo has been called")
        }
    }
}

Thanks Eric for his help. His answer was a key to the solution.

回答1:

One possibility is to use Mockito to check method calls:

class Testable extends Logging {
  def method() = {
    // some method calls
    logger.info("Message1")
  }
}

class TestableSpec extends Specification with ShouldMatchers with Mockito {
   "Testable instance" should {
     "print proper log message during method call" in {
       val mockLogger = mock[Logger]
       val testable = new Testable {
         // switch the logger with a mock instance
         override val logger = mockLogger
       }
       testable.method()
       there was one(mockLogger).info("Message1")
     }
  }
}

This is the main idea but you might have to adapt it depending on your exact traits and logging framework:

• logger must be overridable
• the info method must not be final (one of Mockito's limitations)

回答2:

Good question... and good answer ! I had some trouble with the Mockito mixin. So I am using Eric's approach with the Java DSL for Mockito. If anyone is interested in this variation, here is the slightly modified code:

import com.typesafe.scalalogging.{LazyLogging, Logger, StrictLogging}
import org.mockito.Mockito
import org.mockito.Mockito._
import org.slf4j.{Logger => Underlying}

class Testable extends LazyLogging {
    def foo() = {
    logger.info("Foo has been called")
    }
}

import org.junit.runner.RunWith
import org.scalatest.{BeforeAndAfterEach, FunSuite}
import org.scalatest.junit.JUnitRunner
import org.scalatest.matchers.ShouldMatchers


@RunWith(classOf[JUnitRunner])
class  LoggerTest
  extends FunSuite with ShouldMatchers with BeforeAndAfterEach {


    def initTestable(mocked: Underlying): Testable = {
    new Testable() {
        override lazy val logger = Logger(mocked)
    }
    }

  test("the mockito stuff") {
    val mocked = Mockito.mock(classOf[Underlying])
    when(mocked.isInfoEnabled()).thenReturn(true)
    initTestable(mocked).foo()
    verify(mocked).info("Foo has been called")
  }
}