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: 4.0.1
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:
-
Download and unzip the source
or
-
Clone the Git repository:
git clone https://github.com/grails-guides/grails-mock-logging-slf4j-test.git
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 theinitial
folder.
To complete the guide, go to the initial
folder
-
cd
intograils-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
.
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:
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.
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.
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.
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.
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.
dependencies {
...
testCompile 'uk.org.lidalia:slf4j-test:1.1.0'
}
configurations {
testCompile.exclude group: 'ch.qos.logback', module: 'logback-classic'
}
In addition, we will be using the HttpClient
for testing. Add this dependency below.
dependencies {
...
testCompile "io.micronaut:micronaut-http-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:
-
Access the test logger.
-
Invoke the functionality.
-
Use the test logger to retrieve events.
-
Verify the events according to the scenario.
package example.grails
import com.google.common.collect.ImmutableList
import grails.gorm.transactions.Rollback
import grails.testing.mixin.integration.Integration
import grails.testing.spock.OnceBefore
import io.micronaut.http.HttpRequest
import io.micronaut.http.HttpResponse
import io.micronaut.http.HttpStatus
import io.micronaut.http.client.HttpClient
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
HttpClient client
@OnceBefore
void init() {
String baseUrl = "http://localhost:$serverPort"
this.client = HttpClient.create(baseUrl.toURL())
}
def cleanup() {
TestLoggerFactory.clearAll() (2)
}
void "test create person successful logs"() {
when:"a person is created"
HttpResponse<Map> resp = client.toBlocking().exchange(HttpRequest.GET("/person/createPerson?name=Nirav&age=40"), Map)
ImmutableList<LoggingEvent> loggingEvents = personControllerLogger.getAllLoggingEvents() (3)
then: "check the logging events"
resp.status == HttpStatus.OK
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.
void "test create person unsuccessful logs"() {
when:"a person is created, but has a input error"
HttpResponse<Map> resp = client.toBlocking().exchange(HttpRequest.GET("/person/createPerson?name=Bob&age=Twenty"), Map)
ImmutableList<LoggingEvent> loggingEvents = personControllerLogger.getAllLoggingEvents()
then: "check the logging events"
resp.status == HttpStatus.OK
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"
HttpResponse<Map> resp = client.toBlocking().exchange(HttpRequest.GET("/person/createPerson?name=John&age=35"), Map)
TestLogger ageAdvisorLogger = TestLoggerFactory.getTestLogger("example.grails.AgeAdvisor") (1)
when:"we ask for advice"
resp = client.toBlocking().exchange(HttpRequest.GET("/person/offerAdvice?name=John"), Map)
ImmutableList<LoggingEvent> loggingEvents = ageAdvisorLogger.getAllLoggingEvents()
then: "check the logging events"
resp.status == HttpStatus.OK
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.
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
.