You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-dev@logging.apache.org by "Remko Popma (JIRA)" <ji...@apache.org> on 2015/09/13 14:02:45 UTC
[jira] [Comment Edited] (LOG4J2-1120) LoggerConfig performance
improvements
[ https://issues.apache.org/jira/browse/LOG4J2-1120?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14742443#comment-14742443 ]
Remko Popma edited comment on LOG4J2-1120 at 9/13/15 12:02 PM:
---------------------------------------------------------------
Benchmark results:
iterMapXElement iterates over a ConcurrentHashMap<String,Long>.values() collection containing X elements, iterArraySet... iterates over a CopyOnWriteArraySet<Long>. There are benchmarks for a single element and three elements, since I assume that in most cases there will be one or at most a few appenders.
*1 thread*
{code}
Benchmark Mode Samples Score Error Units
o.a.l.l.p.j.LoggerConfigBenchmark.iterArraySet1Element sample 115366 34.429 ± 1.386 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.iterArraySet3Element sample 193159 31.368 ± 1.041 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.iterMap1Element sample 108869 79.615 ± 2.133 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.iterMap3Elements sample 184664 67.984 ± 1.660 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.logWithCountersAndLock sample 103840 139.756 ± 2.643 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.logWithCountersNoLocks sample 143068 102.707 ± 2.006 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.logWithoutCountersOrLocks sample 172408 84.748 ± 1.723 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.testBaseline sample 101878 19.656 ± 1.136 ns/op
{code}
*4 threads*
{code}
Benchmark Mode Samples Score Error Units
o.a.l.l.p.j.LoggerConfigBenchmark.iterArraySet1Element sample 487222 74.218 ± 0.938 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.iterArraySet3Element sample 391496 52.295 ± 0.915 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.iterMap1Element sample 456270 130.438 ± 1.790 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.iterMap3Elements sample 393511 137.019 ± 4.921 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.logWithCountersAndLock sample 466650 387.175 ± 6.982 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.logWithCountersNoLocks sample 583383 314.528 ± 2.917 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.logWithoutCountersOrLocks sample 425858 236.417 ± 26.062 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.testBaseline sample 708875 55.932 ± 0.732 ns/op
{code}
Iterating over a CopyOnWriteArraySet is quite a bit faster than iterating over ConcurrentHashMap.values(), both in single-threaded and multi-threaded scenarios.
Avoiding lock acquisition is significantly faster, even if the lock is not contended.
Finally, not updating the atomic counter can make a big difference and is worth doing if it is safe to do so.
was (Author: remkop@yahoo.com):
Benchmark results: (iterMapXElement iterates over a ConcurrentHashMap containing X elements, iterArraySet... iterates over a CopyOnWriteArraySet)
*1 thread*
{code}
Benchmark Mode Samples Score Error Units
o.a.l.l.p.j.LoggerConfigBenchmark.iterArraySet1Element sample 115366 34.429 ± 1.386 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.iterArraySet3Element sample 193159 31.368 ± 1.041 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.iterMap1Element sample 108869 79.615 ± 2.133 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.iterMap3Elements sample 184664 67.984 ± 1.660 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.logWithCountersAndLock sample 103840 139.756 ± 2.643 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.logWithCountersNoLocks sample 143068 102.707 ± 2.006 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.logWithoutCountersOrLocks sample 172408 84.748 ± 1.723 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.testBaseline sample 101878 19.656 ± 1.136 ns/op
{code}
*4 threads*
{code}
Benchmark Mode Samples Score Error Units
o.a.l.l.p.j.LoggerConfigBenchmark.iterArraySet1Element sample 487222 74.218 ± 0.938 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.iterArraySet3Element sample 391496 52.295 ± 0.915 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.iterMap1Element sample 456270 130.438 ± 1.790 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.iterMap3Elements sample 393511 137.019 ± 4.921 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.logWithCountersAndLock sample 466650 387.175 ± 6.982 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.logWithCountersNoLocks sample 583383 314.528 ± 2.917 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.logWithoutCountersOrLocks sample 425858 236.417 ± 26.062 ns/op
o.a.l.l.p.j.LoggerConfigBenchmark.testBaseline sample 708875 55.932 ± 0.732 ns/op
{code}
Iterating over a CopyOnWriteArraySet is roughly twice as fast as over ConcurrentHashMap.values(), both in single-threaded and multi-threaded scenarios.
Avoiding lock acquisition is faster, but not reading/updating the counters can make it even faster.
> LoggerConfig performance improvements
> -------------------------------------
>
> Key: LOG4J2-1120
> URL: https://issues.apache.org/jira/browse/LOG4J2-1120
> Project: Log4j 2
> Issue Type: Improvement
> Components: Core
> Affects Versions: 2.3
> Reporter: Remko Popma
> Assignee: Remko Popma
> Fix For: 2.4
>
>
> As discussed on the mailing list, I can see several ways to improve the performance of the hot path in LoggerConfig.
> # Pulling up the {{shutdown.get()}} check into {{afterLogEvent()}} will avoid acquiring the shutdownLock unnecessarily - only acquiring the lock if a shutdown is actually in progress.
> # Another performance improvement can be made by changing the data structure that holds the AppenderControl objects from ConcurrentHashMap to CopyOnWriteArraySet. Modifications on this data structure are extremely rare, and the array-based collection has much better iteration performance.
> # Finally, since {{clearAppenders()}} is only called after all appenders have been stopped, {{waitForCompletion()}} may no longer be necessary (unless I am missing something here). If so, the {{shutdownLock}}, {{shutdown}} and {{counter}} fields can be removed. Not incrementing the atomic counters with every event in the hot path should give better performance.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org