Posterous theme by Cory Watilo

Grails: Replacing log4j with logback

Logging configuration has long been a bit of a pain point for Grails development. We have the log4j configuration DSL, which is intended to simplify logging configuration for those unfamiliar with the powerful log4j logging framework. However, this configuration method falls short on a number of counts:

  • for those already familiar with log4j XML configuration syntax, the log4j DSL is not particularly intuitive
  • moderately complex logging configurations can be a pain to get right – usually this is a process of trial-and-error
  • creating a per-environment configuration isn’t simple
  • when the application is running in the production environment, it’s difficult to re-configure logging at runtime

Some of these problems can be solved by using certain plugins; there is the Log4j XML Plugin, which allows you to use a log4j.xml configuration file, and the Dynamic Logging Plugin, which allows you to modify the logging configuration or a running application.

Another promising solution is to ditch log4j altogether, and switch to it’s “successor”, logback. Logback offers both XML and Groovy configuration options, and as a bonus, can scan the configuration file at runtime for changes.

In theory, the switch to logback should be trivial; Grails uses the SLF4J logging facade under the hood, and logback is a direct implementation of the SLF4J API. You should be able to simply remove the log4j dependency JARs from your $GRAILS_HOME/lib folder, and replace them with their logback equivalents. However, the reality is not quite so simple. Grails seems to be coupled to the log4j API at a couple of points in it’s build and bootstrap phases, and will complain if the log4j classes cannot be found.

Switching out log4j dependencies for logback

After some experimentation, I found a reasonable solution: instead of adding/removing libraries from the $GRAILS_HOME/lib folder, the switch to logback can be achieved almost entirely within the BuildConfig.groovy configuration file. All we need to do is to exclude the slf4j-log4j12 dependency, and add some logback-specific dependencies to the build and runtime phases (see below).

UPDATE: By default, Grails will package lockback-test.xml into the application WAR file. You probably don’t want this, as the setting in logback.xml will be ignored. TO get around this, Grails must be instructed to remove logback-test.xml from the WAR staging dir. See the updated BuildConfig.groovy below for how to do this.

Note that I’m using logback version 0.9.17, not the latest version. This is because 0.9.17 is the latest version supported by the version of SLF4J (1.5.8) which ships with Grails 1.3.7.

Logback configuration

Now that we are using logback instead of log4j, we need to do away with the log4j configuration stanza in Config.groovy, and replace it with a logback.xml configuration. You can put your logback.xml into the grails-app\conf folder; this works fine when your application is executed from a WAR, but there are a couple of gotchas if you use run-app:

  • After creating the logback.xml file, it won’t be picked up the first time you run grails run-app. The first run copies the configuration to the ~/.grails/1.3.7/projects/<project name>/resources/ folder, but too late to be picked up by logback’s configurator. It is picked up from the second run onwards.
  • If you change the logback.xml configuration, you’ll need to run grails clean, then grails run-app twice to get the changes picked up. Frustrating.
  • logback’s scanning and auto re-loading of the config file doesn’t work, unless you make your edits to ~/.grails/1.3.7/projects/<project name>/resources/logback.xml

The solution is to configure your development environment to run grails with the system property logback.configurationFile set to the path of your logback.xml configuration file, e.g. <project root>/grails-app/conf/logback.xml. This will force logback to pick up the configuration from there, instead of the resources folder. Now, you can use logback’s configuration scanning feature to modify your logging configuration while the app is running. Nice!

You can also make use of the logback.configurationFile system property to externalize your logback configuration in your production environment. This allows you to easily re-configure logging on a running instance without having to delve into the exploded WAR folder.

Configuring logback with the Groovy DSL

Disappointingly, I couldn’t get the Groovy configuration to work at all. I tried putting logback.groovy into grails-app/conf, but it didn’t get copied over to the resources folder. I then tried putting it into src/groovy, but it still wasn’t picked up by the logback configurator. The logback.configurationFile system property trick doesn’t work either, because annoyingly logback expects that file to be XML rather than Groovy. If you know of a way to get Groovy configuration working, please share in the comments!

Conclusion

Without the ability to configure logging with Groovy, switching from log4j to logback isn’t as attractive a proposition as it could be. However, even with the XML configuration you still get the other benefits of using logback:

If you’d like the switching of logging frameworks to be simpler in future versions of Grails, please vote on the JIRA issue GRAILS-7588

For reference, here is a simple working logback.xml configuration:

Higher-order functions with Groovy

I'll admit, higher-order functions sounds like link bait for over-achievers. Trust me, I didn't invent the term :-) A Higher-order function is a concept from mathematics where a function accepts other functions as its arguments, and can return functions as results.

Higher-order functions are related to functional programming but higher-order functions != functional programming. In computer science higher-order functions consists of two things: closures and currying. Groovy supports both :-)

So what's a closure then? Closures are not unique to Groovy. Ruby, Lisp, JavaScript and D have closures as do many other languages.

A closure in Groovy is three things:

  1. a block of code that can access variables in the scope where it is declared.
  2. a function that can take arguments and always returns a result (may be null)
  3. an object that has properties and methods with and without side-effects

Calling a closure if thread-safe if the implementation is thread-safe. Here's an example of a closure:

1.def x = { println it }

And here's how you call it (two options):

1.x('Hello, world!')
2.x.call('Hello, world')

Closures can take arguments, including other closures:

1.def isList = { i -> i instanceof List }
2.if (isList([])) {
3.    println "This is a List"
4.}

Closure arguments can be typed:

1.def prefix = {
2.    String s ->
3.    while (s.length() < 17) {
4.        s = "0$s"
5.    }
6.    s // return keyword is not required
7.}
8.def id = prefix "1234" // parentheses are not required

Closures can be passed as arguments, for example to the each() method on java.util.Map:

1.System.properties.each { println it }

And a closure can call itself recursively:

1.// Thanks to Sergey Bondarenko for this one-liner
2.def fac = { int i -> i == 1 ? 1 : i * call(i - 1) }
3.println fac(10) // parentheses are required for fac since I call println without

Closures can access the variables in the scope where they are declared:

1.def pi = 22 / 3
2.def calcSurface = { radius -> pi * (radius * radius) }
3.def surface = calcSurface 10

Currying is closely related to closures. With curring you can construct programs by appending argument values to closures:

01.def appendForLength = {
02.    int length, String charachter, String toBeAppended ->
03. 
04.    while (toBeAppended.length() < length) {
05.        toBeAppended = "${character}${toBeAppended}"
06.    }
07.    return toBeAppended
08.}
09.def myKindOfId = appendForLength.curry 17, "0"
10.assert "00000000000012345" == myKindOfId("12345")

The call to the curry() method on line 9 passes two arguments to the appendForLength closure and returns a new closure. This new closure takes one argument which is actually the third argument of the appendForLength closure.

And with currying you can go beyond Groovy closures, you can also curry any Java method. First you need to know how to turn a method into a closure. You add the ampersand (&) character in front of the method name:

1.def getProperty = System.&getProperty

The value that is returned is a closure:

1.def getProperty = System.&getProperty
2.getProperty("java.version")

And since it's a closure you can curry it:

1.def getProperty = System.&getProperty
2.def javaVersion = getProperty.curry("java.version")
3.assert "1.5.0_04" == javaVersion()

Higher-order functions simplify programs. It's closely related to functional programming. You've learned how to convert regular Java methods to higher-order functions. You can also do the inverse: convert higher-order functions to Java interface methods. This and other techniques will be the subject of the second installment.

Update: part two has been posted too. Happy coding!
0

Average: 3.8 (6 votes)

Nice three-part series on higher-order function (read: closures) from Steven Devijver over on DZone. Gives a nice explanation of currying (including an interesting example of currying Java methods), and one of the clearest explanations of closure delegates I've read. Definitely worth a read!

Monitoring a Grails app using Splunk

Grails + Splunk = happy

Splunk is a popular, enterprise-grade tool for IT infrastructure monitoring. If you haven’t come across it before, I’d take 5 minutes to check out this introductory video. In a nutshell, Splunk indexes any form of time-series data, and provides an interface for searching, analysing and reporting on these data.

The enterprise version of Splunk can be used to provide real-time info on all aspects of the operation of entire data clusters, and as you can imagine it has an enterprise-sized price tag to match. However, the good news is that there’s also a version which is free to use if you’re indexing less than 500MB of data a day and don’t require some of the advanced functions such as real-time alerts. This makes Splunk a great tool for small shops and early-stage startups to use for web-app monitoring and performance analysis.

Splunk can consume pretty much any logs your server can produce: syslog, database, Apache, mail, log4j, top – you name it, if it’s a plain-text time-stamped log file, Splunk will index it. However, in this introductory post, I’m going to keep things simple and describe how to get Splunk up and running to provide real-time monitoring of the log4j logs produced by a Grails application.

Splunk is fairly lightweight, so can usually be run on the same server as your Grails app. However, I’m going to take a slightly different approach and run Splunk on my development machine, to avoid having to install any new software on my app server.

First thing is to download and install Splunk. Head over to this page, and choose the appropriate distribution for your machine. Installation is painless and only takes 5 minutes, but if you run into trouble, check out the help pages on the Splunk site. That’s another great thing about Splunk: the documentation is really, really good. Extremely comprehensive and well-written. They even run a Q&A forum using the StackOverflow API.

Once you’re installed, start up Splunk by running

/opt/splunk/bin/splunk start --accept-license

(on Ubuntu/Debian – your system may differ). Load up the web front-end by going to http://localhost:8000/, and log in as admin (password “changeme”).

Okay, now Splunk is up and running we need some data to feed it. The simplest way is to point Splunk at a log file and tell it to tail it. If you’re running Splunk on the same machine as you’re app, this is simple. If not, we need to do an extra step to get the log file onto our development machine. I decided to go with tried-and-trusted cron and rsync:

* * * * * rsync -e ssh -avlq {remote-user}@{remote-host}:{absolute-path-to-remote-log-file} {absolute-path-to-local-log-file} >/dev/null 2>&1

(replace text in curly brackets as appropriate). Thus my application log will be sync’d to my development machine every minute. Remember, this method will only work if you have your development machine registered as an allowed host on your production server.

Now, go to http://localhost:8000/manager/search/data/inputs/monitor and click ‘New’ to add your log file as a new input. Here are the options you want:

  • Source: {absolute-path-to-local-log-file}
  • Host: {remote-host} // but fine to leave as the default
  • Source type: Automatic // Splunk will auto-detect the log4j format
  • Index: default
  • Advanced options: Follow tail: checked

Click ‘Save’, and Splunk will now begin to index the log file, and monitor it for changes.

Now that the set-up is complete, the fun begins. Head over to http://localhost:8000/app/search/dashboard – this is where you can get a visualization of the contents of your log file, filter the contents, search for events, and build reports. The guys at Splunk do a better job of demonstrating these features than I could, so at this point I’ll direct you to one of the many demo videos on the Splunk site. Alternatively, check out the search tutorial in the docs.

Hopefully I’ve showed you how easy it is to set up Splunk and get it analysing the logs of your running Grails app – without having to make a single change to your production server!

Groovy goodness: force synchronized access to non-synchronized method with metaprogramming

Say you’ve got a singleton instance of some class to which you’d like to enforce synchronized access. No need for sub-classing, proxies or related tomfoolery with Groovy: just hack that metaclass!

Enforce synchronized access to all methods of a single instance
def resource = FactoryClass.getSingleton()
def lock = new ReentrantLock()
resource.metaClass.invokeMethod = { String name, args ->
    def result
    def metaMethod = delegate.metaClass.getMetaMethod(name, args)
    if (metaMethod) {
        lock.lock()
        try { result = metaMethod.doMethodInvoke(delegate, args) }
        finally { lock.unlock() }
    } else {
        throw new MissingMethodException(name, delegate.class, args)
    }
    return result
}

// ... and later, from multiple threads ...
resource.doSomething() // <- call will be synchronized

Get the latest mongodb cheatsheet straight to your terminal

I've been really getting into the mongodb document-oriented database recently.  For those of you yet to join the NoSQL party, mongodb is a fast, easy to use JSON-based document store.  For a nice, quick overview, check out this slideshow:

The mongodb command set isn't huge, but it's always useful to have a cheatsheet to hand when you're learning a new technology.  I found the one at http://cheat.errtheblog.com/s/mongo to be pretty good.  I thought about saving it to a text file for easy access when working in a terminal - then I noticed that the author has been refreshing the cheatsheet as mongodb matures and the command-set changes.  Now, an out-of-date cheat-sheet isn't much good, so I thought I'd knock together a quick shell script to deliver the latest version to my terminal.

The script is implemented using curl and a Groovy one-liner. The wonderful @Grab annotation is great for this kind of thing - I've built up a bunch of Perl one-liners like this over the years, but I'm starting to discover that Groovy trumps Perl for many little text-processing jobs like this.

Append this line to your .bashc script, then the next time you can't quite remember the syntax of a mongodb command, simply enter mongocheat | less

(Note: The first time you run this, it'll probably take a while, since Groovy may have to download the NekoHTML libraries.  Subsequent executions will be much faster!)