I have an issue with log4j2
logging.
(groovy-all 4.0.0, org.apache.logging.log4j 2.17.1, gmavenplus-plugin 1.13.0)
I have a big nested Map object (10 keys and one value is a 100-lengths list of Maps).
And I call the log like:
Map myNestedMap = (1..1500).collectEntries{ ["key-$it", "value-$it"] }
log.debug("Some message, $myNestedMap")
And this line works 10+ seconds...
While debugging I've found that this invoked:
//org.apache.logging.log4j.message.ReusableSimpleMessage
@Override
public void formatTo(final StringBuilder buffer) {
buffer.append(charSequence);
}
where charSequence
is GString
instance.
I've added some code to check the performance:
Map myNestedMap = ...
Closure measure = { String message, Closure cl ->
long start = Calendar.getInstance().getTimeInMillis()
cl.call()
long end = Calendar.getInstance().getTimeInMillis()
println("$message ${(end-start)/1000} sec")
}
measure('StringBuilder:(GString, but no cast)') {
new StringBuilder().append("$myNestedMap")
}
measure('StringBuilder:(cast to String)') {
new StringBuilder().append((String)"$myNestedMap")
}
measure('StringBuilder:(cast to CharSequence)') {
new StringBuilder().append((CharSequence)"$myNestedMap")
}
measure('StringBuilder:(cast to GString)') {
new StringBuilder().append((GString)"$myNestedMap")
}
Output:
StringBuilder:(GString, but no cast) 0.354 sec
StringBuilder:(cast to String) 0.296 sec
StringBuilder:(cast to CharSequence) 13.479 sec
StringBuilder:(cast to GString) 12.937 sec
So I'm asking for some advice, on how to deal with this.
I can do:
Map myNestedMap = ...
log.debug("Some message, $myNestedMap" as String)
But I don't want to cast all the log records to String within the whole project.
you could extend your logger and override debug and other logging methods.
or use metaclass to redefine methods for GString
do it once on project init:
Logger.metaClass.debug = {GString s-> delegate.debug(s as String) }