Show Navigation

Grails Mock Logging with Slf4j Test

In this guide, we will learn how to mock and verify log statements in Grails.

Authors: Nirav Assar

Grails Version: 3.3.5

1 Grails Training

Grails Training - Developed and delivered by the folks who created and actively maintain the Grails framework!.

2 Getting Started

In this guide you are going to learn how to mock logging and verify logs events in a Grails Application by using the Slf4j Test library.

2.1 What you will need

To complete this guide, you will need the following:

  • Some time on your hands

  • A decent text editor or IDE

  • JDK 1.8 or greater installed with JAVA_HOME configured appropriately

2.2 How to complete the guide

To get started do the following:

or

The Grails guides repositories contain two folders:

  • initial Initial project. Often a simple Grails app with some additional code to give you a head-start.

  • complete A completed example. It is the result of working through the steps presented by the guide and applying those changes to the initial folder.

To complete the guide, go to the initial folder

  • cd into grails-guides/grails-mock-logging-slf4j-test/initial

and follow the instructions in the next sections.

You can go right to the completed example if you cd into grails-guides/grails-mock-logging-slf4j-test/complete

3 Writing the Application

We are going to write a simple application with logging. For a simple concept, we will create a Person domain object with a name and age. The application will log "friendly" advice for the person based on age. Through this contrived example, we will develop tests that verify the correct logging events occur.

First, let’s configure the application to only log items pertinent to the exercise. In logback.groovy, delete the line at the bottom of the file: root(ERROR, ['STDOUT']). Then add the below snippet. This will activate loggers in the package example.grails.

grails-app/conf/logback.groovy
logger("example.grails", DEBUG, ['STDOUT'])

3.1 Person Domain and Data Service

We will create a Domain class Person with properties name and age.

> grails create-domain-class Person

Edit the class to end up like this:

grails-app/domain/example/grails/Person.groovy
package example.grails

import groovy.transform.CompileStatic

@CompileStatic
class Person {
    String name
    Integer age

    String toString() {
        "name: $name, age: $age"
    }
}

In order to create and find a student, we will use GORM Data Services, which automatically implements an interface to provide data access logic. This can be injected into another Grails artefact such as a Controller.

grails-app/services/example/grails/PersonDataService.groovy
package example.grails

import grails.gorm.services.Service

@Service(Person)
interface PersonDataService {
    Person findPerson(String name)
    Person savePerson(String name, Integer age)
}

3.2 Create a Person

Let’s implement functionality to create a Person. We can inject the PersonDataService into a PersonController to save a person. Upon a successful save, log a message. On an unsuccessful save, catch the exception and log an error message. We have added static scaffold = Person to the controller for the convenience sake of a quick UI.

grails-app/controllers/example/grails/PersonController.groovy
package example.grails

import grails.validation.ValidationException
import groovy.transform.CompileStatic

@CompileStatic
class PersonController {

    static scaffold = Person

    PersonDataService personDataService

    def createPerson(String name, Integer age) {
        try {
            Person person = personDataService.savePerson(name, age)
            log.info "person saved successfully: ${person}"
            respond person, view: 'show'
        } catch (ValidationException e) {
            log.error "Error occurred on save!"
            redirect action: "index"
        }
    }
}

3.3 Offer Advice to a Person

Implement another method in the PersonController which will offer advice based on the name passed in. This method will first find a person by name, then use a POGO (Plain Old Groovy Object) called AgeAdvisor for logging "friendly" advice.

grails-app/controllers/example/grails/PersonController.groovy
    def offerAdvice(String name) {
        AgeAdvisor ageAdvisor = new AgeAdvisor()

        Person person = personDataService.findPerson(name)
        if (person) {
            ageAdvisor.offerAgeAdvice(person.age)
        } else {
            log.error "No person by name ${name} found."
        }
        redirect action: "index"
    }

The POGO is simple and uses @Slf4j groovy annotation to establish the logger.

src/main/groovy/example/grails/AgeAdvisor.groovy
package example.grails

import groovy.transform.CompileStatic
import groovy.util.logging.Slf4j

@Slf4j (1)
@CompileStatic
class AgeAdvisor {

    void offerAgeAdvice(Integer age) {
        if (age in 0..<30 ) {
            log.info ("You are a young and vibrant!")
            log.info ("Live life to the fullest.")
        } else if (30 <= age) {
            log.warn ("It's all downhill from here, sorry.")
        }
    }
}
1 Note the @Slf4j annotation - This is needed for POGOs, as only Grails artefacts have loggers injected by the Grails Framework.

4 Mock Logging with Slf4j Test

Slf4j Test is a test implementation of Slf4j that stores log messages in memory and provides methods to retrieving them for verification. It is basically a substitute implementation and should be the only one on the test classpath. To achieve this, declare the dependency and also exclude the Logback dependency from the testCompile build phase.

build.gradle
dependencies {
    ...
    testCompile 'uk.org.lidalia:slf4j-test:1.1.0'
}
build.gradle
configurations {
    testCompile.exclude group: 'ch.qos.logback', module: 'logback-classic'
}

In addition, we will be using the RestBuilder for testing. Add this dependency below.

build.gradle
dependencies {
    ...
    testCompile "org.grails:grails-datastore-rest-client"
}

4.1 Verify Logs in Controller

We can verify that log events occur in the Controller with Slf4j Test. We will create a Grails Integration test so the Data Service gets injected automatically without the worry of mocking. We will use RestBuilder to interact over HTTP with the controller methods.

The process is straightforward for each test:

  1. Access the test logger.

  2. Invoke the functionality.

  3. Use the test logger to retrieve events.

  4. Verify the events according to the scenario.

src/integration-test/groovy/example/grails/PersonControllerIntSpec.groovy
package example.grails

import com.google.common.collect.ImmutableList
import grails.gorm.transactions.Rollback
import grails.plugins.rest.client.RestBuilder
import grails.plugins.rest.client.RestResponse
import grails.testing.mixin.integration.Integration
import spock.lang.Shared
import spock.lang.Specification
import uk.org.lidalia.slf4jext.Level
import uk.org.lidalia.slf4jtest.LoggingEvent
import uk.org.lidalia.slf4jtest.TestLogger
import uk.org.lidalia.slf4jtest.TestLoggerFactory

@Integration
@Rollback
class PersonControllerIntSpec extends Specification {

    @Shared
    TestLogger personControllerLogger = TestLoggerFactory.getTestLogger("example.grails.PersonController") (1)
    @Shared
    RestBuilder rest = new RestBuilder()

    def cleanup() {
        TestLoggerFactory.clearAll() (2)
    }

    void "test create person successful logs"() {
        when:"a person is created"
        RestResponse resp = rest.get("http://localhost:${serverPort}/person/createPerson?name=Nirav&age=40")
        ImmutableList<LoggingEvent> loggingEvents = personControllerLogger.getAllLoggingEvents() (3)

        then: "check the logging events"
        resp.status == 200
        loggingEvents.size() == 1 (4)
        loggingEvents[0].message == "person saved successfully: name: Nirav, age: 40" (5)
        loggingEvents[0].level == Level.INFO
    }

}
1 Retrieve the test logger from TestLoggerFactory by using the logger name.
2 Clear in-memory logging events between tests.
3 Retrieve logging events so we can verify them.
4 Assert the size of the logging events.
5 Verify the message, and subsequently the log level.

4.2 Verify More Logs

Add two more tests to cover the other scenarios.

src/integration-test/groovy/example/grails/PersonControllerIntSpec.groovy
    void "test create person unsuccessful logs"() {
        when:"a person is created, but has a input error"
        RestResponse resp = rest.get("http://localhost:${serverPort}/person/createPerson?name=Bob&age=Twenty")
        ImmutableList<LoggingEvent> loggingEvents = personControllerLogger.getAllLoggingEvents()

        then: "check the logging events"
        resp.status == 200
        loggingEvents.size() == 1
        loggingEvents[0].message == "Error occurred on save!"
        loggingEvents[0].level == Level.ERROR
    }

    void "test offerAdvice to old person"() {
        given: "A person is already created"
        RestResponse resp = rest.get("http://localhost:${serverPort}/person/createPerson?name=John&age=35")
        TestLogger ageAdvisorLogger = TestLoggerFactory.getTestLogger("example.grails.AgeAdvisor") (1)

        when:"we ask for advice"
        resp = rest.get("http://localhost:${serverPort}/person/offerAdvice?name=John")
        ImmutableList<LoggingEvent> loggingEvents = ageAdvisorLogger.getAllLoggingEvents()

        then: "check the logging events"
        resp.status == 200
        loggingEvents.size() == 1
        loggingEvents[0].message == "It's all downhill from here, sorry."
        loggingEvents[0].level == Level.WARN
    }
1 Notice we are accessing the logger for example.grails.AgeAdvisor. The factory is able to access any logger to verify activity.

4.3 Verify Logs in Groovy POGO

Slf4j Test handles POGO objects in the same fashion. In AgeAdvisor, recall the logger is established with the @Slf4J annotation. This does not alter the approach to verifying logs events.

src/test/groovy/example/grails/AgeAdvisorSpec.groovy
package example.grails

import com.google.common.collect.ImmutableList
import example.grails.AgeAdvisor
import spock.lang.Shared
import spock.lang.Specification
import uk.org.lidalia.slf4jext.Level
import uk.org.lidalia.slf4jtest.LoggingEvent
import uk.org.lidalia.slf4jtest.TestLogger
import uk.org.lidalia.slf4jtest.TestLoggerFactory

class AgeAdvisorSpec extends Specification {

    @Shared
    AgeAdvisor ageAdvisor = new AgeAdvisor()
    @Shared
    TestLogger logger = TestLoggerFactory.getTestLogger("example.grails.AgeAdvisor") (1)

    def cleanup() {
        TestLoggerFactory.clear()
    }

    void "verify young age logs"() {

        when: "method is invoked"
        ageAdvisor.offerAgeAdvice(15)
        ImmutableList<LoggingEvent> loggingEvents = logger.getLoggingEvents()

        then: "check the logging events"
        loggingEvents.size() == 2 (2)
        loggingEvents[0].message == "You are a young and vibrant!"
        loggingEvents[0].level == Level.INFO
        loggingEvents[1].message == "Live life to the fullest."
        loggingEvents[1].level == Level.INFO
    }

    void "verify old age logs"() {

        when: "method is invoked"
        ageAdvisor.offerAgeAdvice(31)
        ImmutableList<LoggingEvent> loggingEvents = logger.getLoggingEvents()

        then: "check the logging events"
        loggingEvents.size() == 1
        loggingEvents[0].message == "It's all downhill from here, sorry."
        loggingEvents[0].level == Level.WARN
    }
}
1 In a POGO which uses @Slf4j Annotation, we simply retrieve the logger in the same manner.
2 Note we are able to validate multiple log events.

5 Running the Application

To run the application use the ./gradlew bootRun command which will start the application on port 8080.

To run the tests use ./gradlew check.

6 Help with Grails

Object Computing, Inc. (OCI) sponsored the creation of this Guide. A variety of consulting and support services are available.

OCI is Home to Grails

Meet the Team