[ 
https://issues.apache.org/jira/browse/LOG4J2-2389?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

LIU WEN updated LOG4J2-2389:
----------------------------
    Description: 
* fix the CacheEntry map in ThrowableProxy#toExtendedStackTrace to be put and 
gotten with same key
 * stackTraceElement.toString() returns a string representation of this stack 
trace element, just as MyClass.mash(MyClass.java)
 * stackTraceElement.getClassName() returns the fully qualified name of the 
Class, just as org.apache.logging.log4j.MyClass
{code:java}
final String className = stackTraceElement.getClassName();
……
final CacheEntry cacheEntry = map.get(className);
if (cacheEntry != null) {
      final CacheEntry entry = cacheEntry;
      extClassInfo = entry.element;
      if (entry.loader != null) {
             lastLoader = entry.loader;
      }
} else {
      final CacheEntry entry = this.toCacheEntry(stackTraceElement,
      this.loadClass(lastLoader, className), false);
      extClassInfo = entry.element;
      map.put(stackTraceElement.toString(), entry);
      if (entry.loader != null) {
             lastLoader = entry.loader;
      }
}
{code}

 - The main impact of the problem was that it would increase of frequency of 
loading classes ,which led to the execution of the program be slow down, 
because of the synchronization mechanism in the method loadClass
 - In addition to fixing the problem, I think cache map could be made global, 
instead of a new one for each exception instance. 
{code:java}
private ThrowableProxy(final Throwable throwable, final Set<Throwable> visited) 
{
    ...
    final Map<String, CacheEntry> map = new HashMap<>();
    this.extendedStackTrace = this.toExtendedStackTrace(stack, map, null,      
    throwable.getStackTrace());
    ...
 }
{code}
- We made the benchmark test to  compares the performance of ThrowableProxy 
optimizations for different exception
        -  baseline: test `ThrowableProxy` in log4j2, not optimized, with bug, 
for comparison consideration.
        -  bugfixed: fixed bug in `ThrowableProxy` accessing the cache.
        -  optimized: make the cache global, instead of a new one for each 
exception instance.

Then we see
* more than `10` times improvement when the bug is fixed for exceptions with 
stack element class duplicated many times.
* and about `2` times further improvement when make the cache global (compared 
with log4j2, more than `20` times improvement).
- detail: https://github.com/liuwenchn/log4j2-throwableproxy-benchmark
 

  was:
* fix the CacheEntry map in ThrowableProxy#toExtendedStackTrace to be put and 
gotten with same key
 * stackTraceElement.toString() returns a string representation of this stack 
trace element, just as MyClass.mash(MyClass.java)
 * stackTraceElement.getClassName() returns the fully qualified name of the 
Class, just as org.apache.logging.log4j.MyClass
{code:java}
final String className = stackTraceElement.getClassName();
……
final CacheEntry cacheEntry = map.get(className);
if (cacheEntry != null) {
      final CacheEntry entry = cacheEntry;
      extClassInfo = entry.element;
      if (entry.loader != null) {
             lastLoader = entry.loader;
      }
} else {
      final CacheEntry entry = this.toCacheEntry(stackTraceElement,
      this.loadClass(lastLoader, className), false);
      extClassInfo = entry.element;
      map.put(stackTraceElement.toString(), entry);
      if (entry.loader != null) {
             lastLoader = entry.loader;
      }
}
{code}

 - The main impact of the problem was that it would increase of frequency of 
loading classes ,which led to the execution of the program be slow down, 
because of the synchronization mechanism in the method loadClass
 - In addition to fixing the problem, I think cache map could be made global, 
instead of a new one for each exception instance. 
{code:java}
private ThrowableProxy(final Throwable throwable, final Set<Throwable> visited) 
{
    ...
    final Map<String, CacheEntry> map = new HashMap<>();
    this.extendedStackTrace = this.toExtendedStackTrace(stack, map, null,      
    throwable.getStackTrace());
    ...
 }
{code}
- We made the benchmark test to  compares the performance of ThrowableProxy 
optimizations for different exception
        -  baseline: test `ThrowableProxy` in log4j2, not optimized, with bug, 
for comparison consideration.
        -  bugfixed: fixed bug in `ThrowableProxy` accessing the cache.
        -  optimized: make the cache global, instead of a new one for each 
exception instance.

Then we see
* more than `10` times improvement when the bug is fixed for exceptions with 
stack element class duplicated many times.
* and about `2` times further improvement when make the cache global (compared 
with log4j2, more than `20` times improvement).

 


> fix the CacheEntry map in ThrowableProxy#toExtendedStackTrace to be put and 
> gotten with same key
> ------------------------------------------------------------------------------------------------
>
>                 Key: LOG4J2-2389
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-2389
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 2.6.2, 2.7, 2.8, 2.8.1, 2.8.2, 2.9.0, 2.9.1, 2.10.0, 
> 2.11.0
>            Reporter: LIU WEN
>            Priority: Major
>
> * fix the CacheEntry map in ThrowableProxy#toExtendedStackTrace to be put and 
> gotten with same key
>  * stackTraceElement.toString() returns a string representation of this stack 
> trace element, just as MyClass.mash(MyClass.java)
>  * stackTraceElement.getClassName() returns the fully qualified name of the 
> Class, just as org.apache.logging.log4j.MyClass
> {code:java}
> final String className = stackTraceElement.getClassName();
> ……
> final CacheEntry cacheEntry = map.get(className);
> if (cacheEntry != null) {
>       final CacheEntry entry = cacheEntry;
>       extClassInfo = entry.element;
>       if (entry.loader != null) {
>              lastLoader = entry.loader;
>       }
> } else {
>       final CacheEntry entry = this.toCacheEntry(stackTraceElement,
>       this.loadClass(lastLoader, className), false);
>       extClassInfo = entry.element;
>       map.put(stackTraceElement.toString(), entry);
>       if (entry.loader != null) {
>              lastLoader = entry.loader;
>       }
> }
> {code}
>  - The main impact of the problem was that it would increase of frequency of 
> loading classes ,which led to the execution of the program be slow down, 
> because of the synchronization mechanism in the method loadClass
>  - In addition to fixing the problem, I think cache map could be made global, 
> instead of a new one for each exception instance. 
> {code:java}
> private ThrowableProxy(final Throwable throwable, final Set<Throwable> 
> visited) {
>     ...
>     final Map<String, CacheEntry> map = new HashMap<>();
>     this.extendedStackTrace = this.toExtendedStackTrace(stack, map, null,     
>  
>     throwable.getStackTrace());
>     ...
>  }
> {code}
> - We made the benchmark test to  compares the performance of ThrowableProxy 
> optimizations for different exception
>         -  baseline: test `ThrowableProxy` in log4j2, not optimized, with 
> bug, for comparison consideration.
>         -  bugfixed: fixed bug in `ThrowableProxy` accessing the cache.
>         -  optimized: make the cache global, instead of a new one for each 
> exception instance.
> Then we see
> * more than `10` times improvement when the bug is fixed for exceptions with 
> stack element class duplicated many times.
> * and about `2` times further improvement when make the cache global 
> (compared with log4j2, more than `20` times improvement).
> - detail: https://github.com/liuwenchn/log4j2-throwableproxy-benchmark
>  



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)

Reply via email to