Grails Log to Database with Custom Log4J Appender

When you move to more asynchronous processing with Grails (e.g. as with quartz jobs), there’s no user-visible error when something goes wrong. There’s only the logs, and those aren’t the most prominent place for putting failures of mission-cricital jobs.

In a nutshell

  • there’s a Grails domain that holds the log data
  • a custom log4j appender writes to that domain
  • the appender is configured in Config.groovy
  • logging to the database like this only works after Bootstrap.init has run

So here’s the code for directly logging to the database with Grails. For data storage, we use a Grails domain which holds the data (you could use log4j’s JDBCAppender as well, but we’re in the Grails world …)

/**
 * Contains log entries that the tech staff should have a look at
 */
class EventLog {
 
    final static int SOURCE_MAXSIZE = 255
    final static int MESSAGE_MAXSIZE = 1000
    final static int DETAILS_MAXSIZE = 4000
 
    Date dateCreated
 
    String message
    String details
    String source
 
    // did someone look at this error?
    boolean cleared = false
 
    static constraints = {
        source(blank: false, nullable: false, maxSize: SOURCE_MAXSIZE)
        message(blank: false, nullable: false, maxSize: MESSAGE_MAXSIZE)
        details(blank: true, nullable: true, maxSize: DETAILS_MAXSIZE)
    }
 
    static mapping = {
        sort "dateCreated"
    }
}

This EventLog is written to by a custom log4 appender, the EventLogAppender.
Because Grails’ database access is only available from a certain point after the start of the application, database logging is only attempted when the application is initialized.

/**
 * Log4j appender that writes its entries to the EventLog
 */
class EventLogAppender extends org.apache.log4j.AppenderSkeleton
implements org.apache.log4j.Appender {
 
    static appInitialized = false
 
    String source
 
    @Override
    protected void append(LoggingEvent event) {
        if (appInitialized) {
            //copied from Log4J's JDBCAppender
            event.getNDC();
            event.getThreadName();
            // Get a copy of this thread's MDC.
            event.getMDCCopy();
            event.getLocationInformation();
            event.getRenderedMessage();
            event.getThrowableStrRep();
 
            def limit = { string, maxLength -> string.substring(0, Math.min(string.length(), maxLength))}
 
            String logStatement = getLayout().format(event);
            // use new transaction so that the log entry will be written even if the currently running transaction is rolled back
            EventLog.withNewTransaction {
                EventLog eventLog = new EventLog()
                eventLog.message = "Log4 Error Log"
                eventLog.details = limit((logStatement ?: "Not details available, something is wrong"), EventLog.DETAILS_MAXSIZE)
                eventLog.source = limit(source ?: "Source not set", EventLog.SOURCE_MAXSIZE)
                eventLog.save()
            }
        }
    }
 
    /**
     * Set the source value for the logger (e.g. which application the logger belongs to)
     * @param source
     */
    public void setSource(String source) {
        this.source = source
    }
 
    @Override
    void close() {
        //noop
    }
 
    @Override
    boolean requiresLayout() {
        return true
    }
}

When the init closure in Bootstrap.groovy runs, you can be sure that you can write to the database, thus enable the logger there.

class BootStrap {
 
    def init = { servletContext ->
        EventLogAppender.appInitialized = true
        //...
    }
}

Last but not least, you need to enable the custom logger in Config.groovy:

log4j = {
 
    appenders {
        //EnhancedPatternLayout is needed in order to support the %throwable logging of stacktraces
        appender new EventLogAppender(source:'YourApp', name: 'eventLogAppender', layout:new EnhancedPatternLayout(conversionPattern: '%d{DATE} %5p %c{1}:%L - %m%n %throwable{500}'), threshold: org.apache.log4j.Level.ERROR)
        console name:'stdout'
    }
 
    root {
        error 'eventLogAppender'
        info 'stdout'
    }
    // ... more logging config
}

Now you’re up and running with a custom database logger.

This entry was posted in Software. Bookmark the permalink.

14 Responses to Grails Log to Database with Custom Log4J Appender

  1. Octavio Renteria says:

    Hi

    How can i implement EventLogAppender ?

    i followed the instructions but, the table in DataBase is empty

    any error has not been saved

  2. Sti says:

    Hi Octavio,

    You can try the following things
    * manually trigger an error e.g. by throwing an exception in a controller and see if there’s an entry in the db
    * set a breakpoint at the start of the append method to see whether the EventLogAppender is even called
    * check the logging config
    * if you can’t get it working, you might consider using log4j’s JDBCAppender

    one additional thing I’ve stumbled upon – if the EventLogAppender is changed while the application is running, Grails class reloading will cause the appInitialized variable to be reset to its inital state (because the class is reloaded)

    • Octavio renteria says:

      Hi thanks for reply

      I had already tried launching a mistake and put a breakpoint in the append method of the class, but nothing happens not saved in the database and does not enter the method , I wanted to use this example because I found it understandable appender, do you think I have omitted some step in the configuration? or it may be what you mentioned that the class is reloaded, how can I fix that?

      this is my ocnfiguration:
      // log4j configuration
      log4j = {
      environments {
      development {
      grails.logging.jul.usebridge = true
      appenders {
      appender new EventLogAppender(source:’FONDONET’, name: ‘eventLogAppender’, layout:new EnhancedPatternLayout(conversionPattern: ‘%d{DATE} %5p %c{1}:%L – %m%n %throwable{500}’), threshold: org.apache.log4j.Level.ERROR)

      }

      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’

      root {
      // appender objects
      error’eventLogAppender’

      }
      }
      production {
      grails.logging.jul.usebridge = false
      // TODO: grails.serverURL = “http://www.changeme.com”
      }
      }
      }

      regards

  3. Sti says:

    Hi

    there’s two things broken with your logging config:

    * The way you have configured things, the EventLogAppender ist the *only* appender now – you most likely don’t want that, as you won’t have any logging to text/console logs. The EventLogAppender is intended (as with the stdout appender as shown in the example config) to be used alongside other appenders. You could use it as the only appender, but I wouldn’t recommend it – in that case you’d probably want to adapt the threshold setting of EventLogAppender
    * the grails.logging.jul.usebridge settings (and the serverurl settings which is commented out) don’t belong to the log4j config section, but to the general Grails config (at least in Grails 2.2.2)

    I tried it with one of my projects (Grails 2.2.2) – with your logging config, nothing goes to the console, but errors are actually logged to the EventLogAppender’s table

    The classloading issue I mentioned only happens if you edit the EventLogAppender itself while the application is running, and won’t stop the debugger from reaching a breakpoint set in the first line of the method, it only will have the appInitialized variable reset to false.

    • Octavio renteria says:

      Hello
      still no log errors, even removing the settings you mentioned,
      I put the class (EventLog) in section domain, however I put the class (EventLogAppender) in another section that is not domain that matter? where you put it? I think that is the only thing that could be because I try everything

      I do not know what I did wrong that no logs errors, I tried several times

      regards

  4. Sti says:

    Hi Octavio,

    your setup seems correct – the EventLog is a domain class and thus belongs in the domain section, and the EventLogAppender belongs to src/groovy
    But if the EventLogAppender isn’t even invoked, this can’t be the problem, it’s more likely in the logging configuration. What version of Grails do you use?

    Bit of a stupid question, but I’ll ask it anyway… did you actually try logging an error? (e.g. with log.error(“test”), or by throwing an uncaught exception)

  5. Just wanted to say thanks. I incorporated your write up into a grails application version 2.4.3 in just a few minutes. Works like a charm!

    Thanks again!

    • Sti says:

      You’re welcome. One thing you might want to do if you have multiple instances running – provide an instance id (e.g. via a system property) and add this to the log as well

  6. Efrain Salomon says:

    Hi Sti,

    I am trying to run this code, but it is throwing an exception, maybe you can help me to find the problem.

    I am using grails 2.4.3, the code compile well but when I run the application displays this message:

    | Error Exception in thread “main”
    | Error org.apache.catalina.LifecycleException: Failed to start component [StandardServer[-1]]
    | Error at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:154)
    ….
    | Error Caused by: java.lang.IllegalStateException: Method on class [author.logging.EventLog] was used outside of a Grails application. If running in the context of a test using the mocking API or bootstrap Grails correctly.

    Do you have any idea about what I am doing wrong?
    Thanks in advance.

    • Sti says:

      Hi Efrain,

      you’re likely logging an error before the grails application is already fully initialized – have you put this line

      EventLogAppender.appInitialized = true

      in Bootstrap.groovy? (when this is called, the application should be initialized all right).
      You can also add a “println logStatement ” prior to the withNewTransaction block, so you can see on the console what’s the actual error that’s causing the problem

  7. Efrain Salomon says:

    Hi Sti,

    Thanks for your answer, I fixed the first error and walk around the second error, I think maybe the problem is in other place.

    I had placed EventLog.groovy file in author.logging package, I just move to Domain root folder and the LifecycleException error was fixed.

    By the way, I have ‘EventLogAppender.appInitialized = true’ line in Bootstrap.groovy file, and I added ‘println logStatement’ line, it print the log message, but the problem still remains.

    In some where in my code it tries to save an EventLog objet and it complains about that code is outside of a Grails application, if I use logging in ‘warn’ level and there is no problem, however if I use logging in ‘info’ level it throws the exception message.

    I added a try catch-block and now the application does not crash when I use logging in ‘info’ level, and this are the messages that throws the ‘Method on class [EventLog] was used outside of a Grails application’ message:

    java.lang.IllegalStateException: Method on class [EventLog] was used outside of a Grails application. If running in the context of a test using the mocking API or bootstrap Grails correctly.
    2014-12-11 11:07:21,186 [localhost-startStop-1] INFO domain.GrailsDomainClassCleaner – Clearing static property instanceGormInstanceApi in EventLog

    Regards.

    • Sti says:

      It should be no problem to find out where the EventLog is being saved and the error occurs (just print a stacktrace in EventLogAppender). The only reason I can think of why the “used outside Grails application” error happens is that it’s too early and the grails app is not fully initialized yet – bu that should be prevented by setting the appInitialized = true only when this is the case

  8. Dominik says:

    Thank you very much for your great post.

    I wanted to go a few steps further but am not really sure, how to do that. I have the following situation:

    I start several (concurrent) jobs from a Grails application. Each job consists of several subsequent steps. Now, I want to save a reference to the job and the step where an EventLog object is created. Further, the Log-Level of the saved message should be saved in the database, too. Do you have any hints for me, how I could possibly solve these issues?

    Thank you very much in advance!

    • Sti says:

      Grüssi Dominik,

      I’m glad that the stuff is useful to you as well (it’s very useful for me 🙂 )
      For your requirements, you need to adapt the threshold in the logging config to the level you need, and somehow pass the information concerning the job and step. Maybe there’s also some way to channel this through Log4j and read it in the EventLogAppender (e.g. abusing the Throwable parameter that you can pass in the log methods would work, but that’s obviously ugly), but the first thing that comes to my mind is to use a ThreadLocal, in which you set the job and step info when you enter the step, and read when you perform the logging. Take care that the modified EventLogAppender works for code outside your jobs, too, otherwise it might break logging elsewhere.

Comments are closed.