Over a million developers have joined DZone.
{{announcement.body}}
{{announcement.title}}

Ratpacked: Log Request Duration

DZone's Guide to

Ratpacked: Log Request Duration

Need to set up a RequestLogger? Here's a great example of accomplishing that feat in Groovy.

Free Resource

Evolve your approach to Application Performance Monitoring by adopting five best practices that are outlined and explored in this e-book, brought to you in partnership with BMC.

In a previous post we learned how to log request information in common log or NCSA format. But we can also provide our own implementation of a RequestLogger to log for example the time spent in processing a request. One of the easiest ways to do this is by using the RequestLogger.of method. We can provide a lambda expression or closure for this method with an argument type RequestOutcome. The RequestOutcome class has properties to access the request and sent response objects. And it also contains a Duration object which has the duration of the time spent for the total request (all handlers in the chain). This doesn't include the necessary time to send the request to the client.

import ratpack.handling.RequestLogger

import static ratpack.groovy.Groovy.ratpack

ratpack {

    handlers {

        // Here we use the of method to implement
        // custom request logging.
        all(RequestLogger.of { outcome ->

            // Only log when logger is enabled.
            if (RequestLogger.LOGGER.infoEnabled) {

                // Log how long the request handling took.
                RequestLogger.LOGGER.info(
                        'Request for {} took {}.{} seconds.',
                        outcome.request.uri,
                        outcome.duration.seconds,
                        outcome.duration.nano)
            }
        })

        get {
            render 'Ratpack rules!'
        }

    }

}

Instead of using the RequestLogger.of method we can write our own implementation of the RequestLogger interface. We only have to override the log method that has the argument type RequestOutcome. Let's rewrite our previous example and use a new class RequestDurationLogger:

// File: src/main/groovy/com/mrhaki/ratpack/request/logging/RequestDurationLogger.groovy
package com.mrhaki.ratpack.request.logging

import groovy.transform.CompileStatic
import groovy.util.logging.Slf4j
import ratpack.handling.RequestLogger
import ratpack.handling.RequestOutcome

/**
 * Custom implementation of the {@link RequestLogger} to
 * log how much time is spent on processing a request.
 * The time spent doesn't include the time spent in
 * transportation from and to the client.
 */
@Slf4j(value = 'logger', category = 'ratpack.request.duration')
@CompileStatic
class RequestDurationLogger implements RequestLogger {

    /**
     * Log the duration in seconds spent on processing a request.
     *
     * @param outcome Information about the request and send response, including duration
     */
    @Override
    void log(final RequestOutcome outcome) throws Exception {
        // Only log when logger is enabled.
        if (logger.infoEnabled) {
            // Log how long the request handling took.
            logger.info(
                    'Request for {} took {}.{} seconds.',
                    outcome.request.uri,
                    outcome.duration.seconds,
                    outcome.duration.nano)
        }
    }
}

In the Groovy DSL of our Ratpack application we now use our new class:

import com.mrhaki.ratpack.request.logging.RequestDurationLogger

import static ratpack.groovy.Groovy.ratpack

ratpack {

    handlers {

        // Here we use our RequestLogger implementation.
        all(new RequestDurationLogger())

        get {
            render 'Ratpack rules!'
        }

    }
}

When we look at some sample logging output we see how much time is spent to handle a request:

[ratpack-compute-5-8] INFO ratpack.request.duration - Request for / took 0.1000000 seconds.


Written with Ratpack 1.0.0.

Learn tips and best practices for optimizing your capacity management strategy with the Market Guide for Capacity Management, brought to you in partnership with BMC.

Topics:
performance ,logging ,ratpack ,groovy

Published at DZone with permission of Hubert Klein Ikkink, DZone MVB. See the original article here.

Opinions expressed by DZone contributors are their own.

THE DZONE NEWSLETTER

Dev Resources & Solutions Straight to Your Inbox

Thanks for subscribing!

Awesome! Check your inbox to verify your email so you can start receiving the latest in tech news and resources.

X

{{ parent.title || parent.header.title}}

{{ parent.tldr }}

{{ parent.urlSource.name }}