Home > basic, grails > Logging by Convention

Logging by Convention

Each Grails application uses a custom Log4J DSL [0] to configure logging settings. In a blank Grails application the grails-app/conf directory contains the Config.groovy file, which declares the log4j variable:

log4j = {
    // Example of changing the log pattern for the default console
    // appender:
    //
    //appenders {
    //    console name:'stdout', layout:pattern(conversionPattern: '%c{2} %m%n')
    //}


    error  'org.codehaus.groovy.grails.web.servlet',  //  controllers
	       'org.codehaus.groovy.grails.web.pages', //  GSP
	       'org.codehaus.groovy.grails.web.sitemesh', //  layouts
	       'org.codehaus.groovy.grails.web.mapping.filter', // URL mapping
	       'org.codehaus.groovy.grails.web.mapping', // URL mapping
	       'org.codehaus.groovy.grails.commons', // core / classloading
	       'org.codehaus.groovy.grails.plugins', // plugins
	       'org.codehaus.groovy.grails.orm.hibernate', // hibernate integration
	       'org.springframework',
	       'org.hibernate',
           'net.sf.ehcache.hibernate'

    warn   'org.mortbay.log'
}

Let me start my explanation of logging by convention by creating a new service class

grails create-service com.ast.service.Some

Leading to the following generated Groovy code:

package com.ast.service

class SomeService {

    boolean transactional = true

    def serviceMethod() {

    }
}

By default, each Grails artefact (services, controllers, domain classes and tag library classes) gets a getLog method injected on application bootstrap. The magic happens in LoggingGrailsPlugin which is currently part of the grails-core module:

// ...

def addLogMethod(artefactClass, handler) {
    // Formulate a name of the form grails.<artefactType>.classname
    // Do it here so not calculated in every getLog call 🙂
    def type = GrailsNameUtils.getPropertyNameRepresentation(handler.type)
    def logName = "grails.app.${type}.${artefactClass.name}".toString()

    def log = LogFactory.getLog(logName)

    artefactClass.metaClass.getLog << {-> log}
}

// ...

As you can see, Grails uses meta-programming to add a getLog method returning a log object of type org.apache.commons.logging.Log. But take a look at the log name which is used to create the log object with Apache Commons Logging LogFactory:

def logName = "grails.app.${type}.${artefactClass.name}".toString()

Grails prefixes the artefact’s class name with grails.app and its type (service, controller, taglib, domain). In fact, this is a pretty cool feature, since all artefacts are bundled in a common logging namespace.

E.g. to enable INFO logging on all application artefacts, developers just have to add the following line in Config.groovy:

log4j = {
    // ...
    info   'grails.app'
    // ...
}

Although this is a pretty cool feature, it can lead to confusion, and one can find multiple questions concerning this issue on mailing-lists, user groups etc.

Let’s assume that our application basically should use ERROR level and more detailed levels only for separate packages. We would modify the Log4J configuration to look like:

log4j = {
    // ...
    // maby defining additional appenders here
    // ...
    root {
        error()
    }
    // ...

If you want to fetch INFO logging output of com.ast.service.SomeService the following configuration snippet would not work:

log4j = {
    // ...
    info 'com.ast.service.MyService'
    // ...
}

The reason is that LoggingGrailsPlugin prefixes the artefacts type and class name with grails.app. The actual log instance’s log name in MyService was therefore configured to

grails.app.service.MyService

As a consequence, to enable logging on INFO level we should better use

log4j = {
    // ...
    info 'grails.app.service.com.ast.service.MyService'
    // ...
}

This is supposed to be a convenience feature, but can steal quite some time if you overlooked that section in the configuration documentation [0].

[0] Logging Configuration


Advertisements
Categories: basic, grails
  1. May 4, 2010 at 8:34 am

    Andre, are you sure that final code example is correct? I find I have to use the full type name after ‘grails.app’. In the case of your example, this would be:

    info ‘grails.app.service.com.ast.service.MyService’

    • May 4, 2010 at 9:06 am

      yeah, you’re right – i fixed it locally in my example project but did not alter the code sample in the blog… sorry!

  2. B Sreekanth
    June 23, 2010 at 12:34 pm

    thanks for your time writing this.. probably the best and complete explanation I found.. thanks

  1. May 2, 2010 at 5:31 am

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

%d bloggers like this: