Using Log4j with Grails Apps on JBoss
Getting Grails apps to use log4j under JBOSS won’t drive you insane if you have a simple reference application to get you started. In this post I present an example which will hopefully help you avoid some of the traps I ran into (as well as the dumb mistakes I made).
Installing and Running JBoss and the Demo App
Download the sample Grails application from this link.
Run the application stand-alone (in jetty), by typing:
- cd <root-of-grails-app-unzip-dir>
- grails run-app
- To access the app, hit the URL: http://localhost:8080/books/book/list
To deploy the sample application to Jboss:
- Download Jboss from http://www.jboss.org/jbossas/downloads. The direct link as of this writing is here:
- Let <JBOSS_ROOT> = <folder-where-you-downloaded-jboss>/jboss-4.2.3.GA
- cd <root-of-grails-app-unzip-dir>
- grails war
- cp target/books-0.1.war JBOSS_ROOT/server/default/deploy/
- cd <JBOSS_ROOT>/bin
- sh run.sh
- verify the application is running by hitting the URL: http://localhost:8080/
Grails App Logging Configuration
The logging related code in the demo application is in the com.blah.BlookController class in the statements below:
import org.apache.log4j.Logger;
class BookController {
private static org.apache.log4j.Logger loggy =
Logger.getLogger(BookController.class);
def list = {
println("__ xxx println Logging ...")
log.debug("+++ >>logging with logger injected by Grails");
loggy.debug(". >>== debug logging with " +
" traditional log4j logger (non injected) ");
loggy.info(". >>== info level logging with " +
" traditional log4j logger (non injected) ");
// more lines follow - not relevant to logging....
}
When running your application in jetty ( via ‘grails run-app’ ), the log4j DSL in Config.groovy controls your logging configuration. In the demo application there is a commented out line which, if enabled, will turn on logging both for the automatically injected logger (’log’), and enable debug level logging for the logger that was manually added to the BookController class (’loggy’).
After unzipping the demo application start it up, and and navigate to http://localhost:8080/books/book/list. Don’t uncomment the line in Config.groovy just yet. You will see the error level statement from the loggy logger, but not the output from ‘log’ and, no debug level statements from ‘loggy’.
You should see something like this (lines wrapped for readability):
2009-12-13 19:21:33,989 [http-8080-1] ERROR blah.BookController - . >>== error level logging with traditional log4j logger (non injected)
To force all logging output to appear, uncomment out this line:
//debug ‘grails.app.controller.com.blah.BookController’, ‘com.blah.BookController’
Note that the injected logger was configured by the name
‘grails.app.controller.’ + <fully-qualified-name-of-controller-class
That is:
‘grails.app.controller.com.blah.BookController
Run the application again and you should see logging statements that include
logging with injected logger
. >>== debug logging with traditional log4j logger (non injected)
. >>== info level logging with traditional log4j logger (non injected)
As I was getting this to work I made the mistake of assuming that the injected logger could be configured by the name of the fully qualified class into which it was injected. I thank Ian Roberts from the Department of Computer Science at University of Sheffield (UK) for reminding me that for Grails injected loggers in either domain or controller classes you need to prefix your logger name with ‘grails.app.controller’ or ‘grails.app.domain’
Now that you have everything working in Grails under Jetty, its time to deploy the demo app to JBoss.
Deploying the Sample Application to JBOSS and Getting Logging To Work
- Deploy the app
- cp target/books-0.1.war <JBOSS_ROOT>/server/default/deploy
- Start up Jboss
- export JBOSS_HOME=<JBOSS_ROOT>
- cd $JBOSS_HOME/bin
- sh run.sh
- Access the book controller via the following URL: http://localhost:8080/books-0.1/
The logging statements emitted to the console will only include the error level logging from the loggy logger.
19:06:08,573 ERROR [STDOUT] 19:06:08,573 ERROR [BookController] . >>== error level logging with traditional log4j logger (non injected)
At least we know some logging going on. Having one log statement configured to emit at the error level is a good trick to use when you are trying to figure out why your log4j configuration is not taking effect as expected.
Another good debugging tool is to start your application with the system property setting -Dlog4j.debug=true. This will give you some information as to what log4j is doing internally.
What’s happening is that there are three things preventing logging from working:
1) The Groovy log4j DSL is ignored when you run your application in JBOSS.
You need to crack open the JBoss log4j config file in $JBOSS_HOME/server/default/conf/jboss-log4j.xml, and stick the following lines of configuration right after the comment block that contains the line <!– Limit categories –>
<category name="grails.app.controller.com.blah.BookController"> <priority value="DEBUG"/> </category> <category name="com.blah.BookController"> <priority value="DEBUG"/> </category>
2) The Threshold setting of the CONSOLE appender configured in the jboss-log4j.xml file is set to INFO, which will cause debug level statements to be ignored. Change the setting to:
<appender name="CONSOLE"> ... <param name="Threshold" value="DEBUG"/>
3) Finally, JBoss logging is not compatible with the log4j jar that is packaged
as part of your application in the default war creation process.
You need to strip out that file by including the following lines of configuration
in grails-app/conf/BuildConfig.groovy
grails.war.resources = {stagingDir ->
delete(file: "$stagingDir/WEB-INF/lib/log4j-1.2.15.jar")
}
The above lines have been commented out in the sample Grails app. You just need to re-enable them.
Other Resources:
The Grails FAQ has some advice on getting Grails and Log4J working on JBoss.
The log4j manual has a good tutorial on basic logging concepts.
on December 22nd, 2009
FYI You do not have to edit the jboss log4.xml you can configure your logging using only the grails logging dsl. The key is setting up appenders that log to a file instead of logging to the console. The console logging is not included in the jboss server.log.
Personally I prefer having a separate log file for my application.
on February 7th, 2010
I think, it’s advisable to have the server (i.e. its admins) take care of logging altogether. Grails can be instructed to step-aside and just delegate the “real” logging to JBoss or any other servlet container. See http://blog.saddey.net/2010/02/07/grails-how-to-use-native-server-logging-configuration-eg-tomcat-glassfish-jboss/
on February 7th, 2010
Reiner.. good stuff. thanks !
I like your technique for post processing and touching up the web.xml and hooking in with build events.
on March 6th, 2010
[...] Build Lackey Blog – Using Log4j with Grails Apps on JBoss [...]
on March 6th, 2010
I’ve prepared a follow-up that includes full source for Grails 1.2.1 and JBoss 5.1.0GA and a sketch outlining Grails logging architecture at http://blog.saddey.net/2010/03/06/how-to-deploy-a-grails-application-to-jboss-5/