Problem
Take an example with grails log.debug() call. Let’s say I want to log a very often executed code.
Long sum = 0
(1..1000).each { number ->
++sum
log.debug "Sum = ${sum}"
}
I use log.debug so my information is logged only if my project configuration allows that. That way if we turn off DEBUG, the logged line should not affect application speed. But is that really true?
Let’s check if the logged value is really not accessed? To do so we need to turn off DEBUG and modify the code:
Long sum = 0
(1..1000).each { number ->
log.debug "Sum = ${++sum}"
}
Well, after finishing the loop, sum value is 1000 - it was incremented even when information was not logged. That means that every time you log heavy operations like e.g. object.dump() - they will get executed, even if the log level is not suppose to show that line.
Solution
Possible solution is to add condition before logging.
Long sum = 0
(1..1000).each { number ->
if (log.debugEnabled) {
log.debug "Sum = ${++sum}"
}
}
Sum up
Turns out that logged value is accessed even when information is not logged. Keep that in mind since it may not only bring down performance of your application, it may be even a reason of a bug.
comments powered by Disqus