Sample Grails usage tracking filter. Optimized for splunk logging with its key=value separation.

UsageTrackingFilters.groovy

package myapp

import org.apache.commons.logging.Log
import org.apache.commons.logging.LogFactory
import org.apache.log4j.MDC

class UsageTrackingFilters {
    private static final Log LOG = LogFactory.getLog('usagetracking')

    private static final String REQUEST_ID = "requestId"

    def filters = {
        /**
         * Log the user all of this thread's logging activity, and record the duration of the view.
         */
        all(controller: '*', action: '*', uriExclude: '/health/**') {
            before = {
                MDC.put 'username', request.userPrincipal?.name ?: ''
                MDC.put 'startTime', System.currentTimeMillis()
            }
            after = {}
            afterView = {
                LOG.info("event_id=access, url=$request.forwardURI${request.queryString ? ", params=" + request.queryString : ""}, action=$actionName, duration=${System.currentTimeMillis() - MDC.get('startTime')}")
                MDC.remove 'username'
                MDC.remove 'startTime'
                // the removal of requestId *should* be in the apiControllers afterView, but that is being called
                // before the all.afterView.  http://jira.grails.org/browse/GRAILS-9499
                MDC.remove REQUEST_ID
            }
        }

        /**
         * Correlate all API usage to more easily track metrics and debug issues.
         */
        apiControllers(uri: '/api/**') {
            before = {
                String requestId = request.getHeader(REQUEST_ID) ?: UUID.randomUUID()
                response.addHeader(REQUEST_ID, requestId)
                MDC.put REQUEST_ID, requestId
            }
            after = {}
            afterView = {}
        }

    }

}