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 2014/09/14 18:04:33 UTC
[jira] [Resolved] (LOG4J2-753) CachedClock performs badly when
contended by many threads
[ 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: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org