Logging and Grails
Many developer use logs just to resolve problems and bugs that they stumble in, and many other use logs like there is no tomorrow polluting the code.Anyone has his own style and there are many guidelines and best practices to follow, so what I want to show in this post is how do I approach logging while I'm coding Grails.
Logging is possible in almost all Grails artifacts using
log property, and can be easily turned on and off per Class and packages using log4j configuration in Config.groovy.But there are some performance issues to keep in mind. One connected to how Java works and one connected to how Groovy works.
Java related one:
if we write log.debug('bravo') everything is super fast.
if we do log.debug("bravo ${preFormattedString}") things becomes to be really slow.
Why? Because before calling any method java must evaluate arguments, and GString evaluation using ${..} notation is quite heavy.
And all this evaluation time will be thrown away if the log for that piece of code is disabled.
Groovy related one:
And here comes Groovy's problem: Groovy power automagically give us the property log.debugEnabled from the method log.isDebugEnabled().
This is syntactic sugar but it's super damn computational heavy: 5/6 time more haeavy!
So it's pointless to optimize your code if you waste so much CPU time for logging that may be not even enabled.
Conclusion:
So use every time this kind of syntax:if (log.isDebugEnabled()){
log.debug("bravo ${s}")
}
These are some Gist and relative time consumption to help to understand the problem:
seconds: 0.04017
seconds: 0.03903 seconds: 0.14995 seconds: 0.19269 seconds: 0.03884
That's all. Please comments: all help, corrections and suggestions are welcome.
Credits to: http://burtbeckwith.com/blog/?p=81
