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

Remko Popma resolved LOG4J2-753.
--------------------------------
       Resolution: Fixed
    Fix Version/s: 2.1

CachedClock assumes that some of the "jumps" or gaps in the timestamp are 
caused by the updater background thread being starved. It tries to reduce the 
timestamp gaps by forcing regular timestamp updates on the caller thread.

This was implemented with a volatile field, and updating this field with every 
call itself became a source of contention.

Removing the volatile keyword improved the performance considerably. This 
removes the restriction that every thread's update must be visible to all other 
threads, so the caches no longer need to be synchronized on every call, 
reducing the inter-cache traffic.

Benchmark results:
*8 threads*
{code}
java -jar log4j-perf\target\microbenchmarks.jar ".*ClocksBen.*" -t 8 -f 1 -wi 
10 -i 10

Benchmark                                               Mode   Samples         
Mean   Mean error    Units
o.a.l.l.p.j.ClocksBenchmark.baseline                  sample    560304       
22.958        0.601    ns/op
o.a.l.l.p.j.ClocksBenchmark.coarseCachedClock         sample    550280       
23.972        0.649    ns/op
o.a.l.l.p.j.ClocksBenchmark.systemClock               sample    550963      
157.133      270.416    ns/op
o.a.l.l.p.j.ClocksBenchmark.cachedClock               sample    715130      
204.227      258.307    ns/op
o.a.l.l.p.j.ClocksBenchmark.oldCachedClock            sample    537132      
306.809      452.187    ns/op
{code}

*1 thread*
{code}
java -jar log4j-perf\target\microbenchmarks.jar ".*ClocksBen.*" -t 1 -f 1 -wi 
10 -i 10

Benchmark                                               Mode   Samples         
Mean   Mean error    Units
o.a.l.l.p.j.ClocksBenchmark.baseline                  sample    146712       
18.105        0.897    ns/op
o.a.l.l.p.j.ClocksBenchmark.coarseCachedClock         sample    115812       
20.075        1.049    ns/op
o.a.l.l.p.j.ClocksBenchmark.systemClock               sample    134645       
20.540        1.002    ns/op
o.a.l.l.p.j.ClocksBenchmark.cachedClock               sample    162196       
20.189        1.000    ns/op
o.a.l.l.p.j.ClocksBenchmark.oldCachedClock            sample     96522       
45.996        1.707    ns/o
{code}

> CachedClock performs badly when contended by many threads
> ---------------------------------------------------------
>
>                 Key: LOG4J2-753
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-753
>             Project: Log4j 2
>          Issue Type: Improvement
>          Components: Core
>    Affects Versions: 2.0
>            Reporter: Remko Popma
>            Assignee: Remko Popma
>             Fix For: 2.1
>
>
> See  LOG4J2-744 comments for JMH benchmarks highlighting the issue.



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]

Reply via email to