[jira] [Commented] (LOG4J2-2675) Performance issue with stack traces containing generated classes

["Carter Kozak (JIRA)" <ji...@apache.org>]

    [ https://issues.apache.org/jira/browse/LOG4J2-2675?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16909532#comment-16909532 ] 

Carter Kozak commented on LOG4J2-2675:
--------------------------------------

Tracking this in https://issues.apache.org/jira/browse/LOG4J2-2391 though unfortunately I've been busy lately and haven't had a great deal of time to devote to it.
There's a workaround, if you don't mind losing jar information: https://issues.apache.org/jira/browse/LOG4J2-2391?focusedCommentId=16668846&page=com.atlassian.jira.plugin.system.issuetabpanels%3Acomment-tabpanel#comment-16668846

 

We've discussed adding a cache, but there are subtle gotchas involving shared environments with child classloaders loading different classes with the same fully qualified name. Producing an incorrect source jar in the logs would lead to a great deal of unnecessary confusion, however that wouldn't be the case for generated classes. Unfortunately, some workflows create unbounded proxies, which we would need to handle gracefully.

> Performance issue with stack traces containing generated classes
> ----------------------------------------------------------------
>
>                 Key: LOG4J2-2675
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-2675
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 2.12.1
>            Reporter: Ryan Schmitt
>            Priority: Major
>
> We've noticed a performance problem with stack traces that contain certain types of generated classes. For example:
> {noformat}
> 16 Aug 2019 15:54:33,470 [INFO]  (main) com.example.LoggingIntegrationTest: Exception thrown
> java.lang.reflect.InvocationTargetException: null
> 	at jdk.internal.reflect.GeneratedConstructorAccessor10.newInstance(Unknown Source) ~[?:?]
> 	at jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[?:?]
> 	at java.lang.reflect.Constructor.newInstance(Constructor.java:490) ~[?:?]
> 	at com.example.LoggingIntegrationTest.construct(LoggingIntegrationTest.java:25) ~[classes/:?]
> {noformat}
> In this example, {{jdk.internal.reflect.GeneratedConstructorAccessor10}} is a class generated by the JDK in order to optimize the reflective {{Constructor#newInstance}} call. One quirk of these classes (called "inflated constructors" within the JDK) is that [they get loaded in their very own classloader|https://github.com/frohoff/jdk8u-jdk/blob/master/src/share/classes/sun/reflect/ClassDefiner.java#L39-L65]. Since Log4j2 has no hope of finding this classloader, it also cannot [resolve the class name to a Class object|https://github.com/apache/logging-log4j2/blob/de6593f5f3b5acbb2cdb4ee91e4e1f472db5dcbb/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/ThrowableProxyHelper.java#L197-L233] in {{ThrowableProxyHelper#loadClass}}. This means that every stack trace containing such a class, when it is rendered, will cause the entire classpath to be scanned.
> It seems that {{ThrowableProxyHelper}} should have some sort of negative caching in order to optimize this case.



--
This message was sent by Atlassian JIRA
(v7.6.14#76016)