[logback-dev] How to avoid loading class when logging with a Throwable instance?

[Benimaur Gao]

Hi,
   When using logback(v1.1.1) in our application, I noticed that logback
would massively degrade TPS under high concurrency.

   It's ok with Logger.error(String msg), Logger.warn(String msg) //etc.
But when using Logger.error(String msg, Throwable t) (and any other
overrided log method with an additional Throwable instance). Logback seems
to try loading every class from StackTraceElement.

The stack trace in detail:
------
Thread Name :[BIZ-8-thread-464]
    java.lang.ClassLoader.loadClass(ClassLoader.java:405)
    groovy.lang.GroovyClassLoader.loadClass(GroovyClassLoader.java:676)

groovy.lang.GroovyClassLoader$InnerLoader.loadClass(GroovyClassLoader.java:424)
    groovy.lang.GroovyClassLoader.loadClass(GroovyClassLoader.java:786)
    groovy.lang.GroovyClassLoader.loadClass(GroovyClassLoader.java:774)

ch.qos.logback.classic.spi.PackagingDataCalculator.loadClass(PackagingDataCalculator.java:207)

ch.qos.logback.classic.spi.PackagingDataCalculator.bestEffortLoadClass(PackagingDataCalculator.java:226)

ch.qos.logback.classic.spi.PackagingDataCalculator.computeBySTEP(PackagingDataCalculator.java:138)

ch.qos.logback.classic.spi.PackagingDataCalculator.populateFrames(PackagingDataCalculator.java:101)

ch.qos.logback.classic.spi.PackagingDataCalculator.calculate(PackagingDataCalculator.java:57)

ch.qos.logback.classic.spi.ThrowableProxy.calculatePackagingData(ThrowableProxy.java:147)
    ch.qos.logback.classic.spi.LoggingEvent.<init>(LoggingEvent.java:124)

ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:440)
    ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:396)
    ch.qos.logback.classic.Logger.error(Logger.java:559)
... ...
------

when under high concurrency, this behavior will cause intensively competing
lock, and will slow down the business processing.

If I understand correctly, the only purpose of loading a class is
retrieving "version" and "codeLocation" info (written in
PackagingDataCalculator.computeBySTEP ). In our application, I think we can
afford discarding such info to get a performance promotion(IIRC, there is
no such info with log4j). Can logback implemention offer a related switch?

I also noticed there is a cache in PackagingDataCalculator. After loading a
class, a classname to Class map will be put in it. but (hope I am not
wrong) it's lifecycle is only in a LoggingEvent, hence not very helpful, I
think. Can we make this cache a global registry?
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.qos.ch/pipermail/logback-dev/attachments/20151008/4b8457db/attachment.html>