[
https://issues.apache.org/jira/browse/LOG4J2-1097?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14707368#comment-14707368
]
Remko Popma commented on LOG4J2-1097:
-------------------------------------
I updated the benchmark Ralph used for LOG4J2-812 to add variations with
CustomTimeFormat.
Initial results:
*One thread*
{noformat}
-f 1 -wi 5 -i 10 -t 1
Benchmark
Mode Samples Score Error Units
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.atomicCustomFormat
sample 178010 35.687 ± 2.866 ns/op
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.atomicFastFormat
sample 147793 32.311 ± 1.521 ns/op
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.baseline
sample 176461 22.765 ± 1.025 ns/op
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.cachedThreadLocalSimpleDateFormat
sample 144134 43.842 ± 1.516 ns/op
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.customFormat
sample 117000 118.140 ± 6.620 ns/op
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.fastFormat
sample 104110 430.294 ± 18.564 ns/op
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.synchronizedSimpleDateFormat
sample 123519 384.121 ± 23.734 ns/op
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.threadLocalSimpleDateFormat
sample 118879 381.424 ± 8.387 ns/op
{noformat}
*4 threads*
{noformat}
-f 1 -wi 5 -i 10 -t 4 -si true
Benchmark
Mode Samples Score Error Units
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.atomicCustomFormat
sample 612696 78.439 ± 48.246 ns/op
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.atomicFastFormat
sample 716081 63.732 ± 30.952 ns/op
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.baseline
sample 560381 22.520 ± 0.649 ns/op
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.cachedThrdLocalCustomFormat
sample 534278 57.030 ± 5.223 ns/op
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.cachedThrdLocalSimpleDateFmt
sample 558771 71.173 ± 0.923 ns/op
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.customFormat
sample 584554 171.373 ± 6.028 ns/op
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.fastFormat
sample 417938 799.719 ± 94.906 ns/op
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.synchronizedSimpleDateFmt
sample 585694 1762.350 ± 130.824 ns/op
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.threadLocalSimpleDateFmt
sample 440561 767.053 ± 20.028 ns/op
{noformat}
It looks as if CustomTimeFormat does a bit worse than FastDateFormat when using
the "atomic" cached value (which is the design we are implementing with
LOG4J2-812). However, this may be because the benchmark iterates so rapidly
that System.currentTime() has no time to advance and we are seeing mostly cache
hits.
In a real application I would expect cache hits to be more rare. I simulated
the other extreme where all attempts are cache misses by replacing
{{System.currentTimeMillis()}} with {{System.nanoTime()}} in the benchmark.
Results are below.
*4 threads*
{noformat}
Benchmark
Mode Samples Score Error Units
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.atomicCustomFormat
sample 511006 143.653 ± 72.151 ns/op
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.atomicFastFormat
sample 551012 1238.972 ± 83.788 ns/op
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.baseline
sample 623266 85.427 ± 1.934 ns/op
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.cachedThrdLocalCustomFormat
sample 715277 97.024 ± 31.505 ns/op
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.cachedThrdLocalSimpleDateFmt
sample 675473 1041.130 ± 65.373 ns/op
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.customFormat
sample 482624 192.361 ± 20.488 ns/op
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.fastFormat
sample 624070 1212.683 ± 162.718 ns/op
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.synchronizedSimpleDateFmt
sample 469788 3790.375 ± 1348.255 ns/op
o.a.l.l.p.j.ThreadsafeDateFormatBenchmark.threadLocalSimpleDateFmt
sample 673558 1023.361 ± 42.986 ns/op
{noformat}
With a cache miss, the performance of the cached variant is similar to the
variant without caching. Makes sense. :-)
What is interesting though is that regardless of cache hits or misses,
CustomTimeFormat that reuses a char[] array in a ThreadLocal
({{cachedThrdLocalCustomFormat}}) consistently gives the best performance.
Should we reconsider our decision to not use a ThreadLocal?
> [Perf] Custom TimeFormat
> ------------------------
>
> Key: LOG4J2-1097
> URL: https://issues.apache.org/jira/browse/LOG4J2-1097
> Project: Log4j 2
> Issue Type: Improvement
> Components: Layouts, Pattern Converters
> Affects Versions: 2.3
> Reporter: Remko Popma
> Assignee: Remko Popma
> Fix For: 2.4
>
>
> In addition to the work done for LOG4J2-812 (replace synchronized
> SimpleDateFormat with commons FastDateFormat) I see a way to improve
> performance for the timestamp even further.
> Ralph posted some very nice JMH benchmark results in LOG4J2-812, where the
> combination of caching, FastDateFormat and an AtomicReference was the winner.
> I believe this is the way to go, but we may be able to do even better. For
> some common date formats, it is possible to get a 5X speedup versus
> FastDateFormat.
> This is not as generic as FastDateFormat; at the moment it only supports
> {{HH:mm:ss,SSS}}. I would like to support the "common" DatePatternConverter
> formats ABSOLUTE, COMPACT, DATE_AND_TIME, DEFAULT, ISO8601_BASIC and ISO8601.
> For any other date format pattern we fall back to FastDateFormat.
> Performance results are below (benchmark is in git master):
> {noformat}
> Benchmark Mode
> Samples Score Error Units
> o.a.l.l.p.j.TimeFormatBenchmark.baseline sample
> 118021 18.783 ± 0.842 ns/op
> o.a.l.l.p.j.TimeFormatBenchmark.customBitFiddlingFormatString sample
> 157268 87.616 ± 1.557 ns/op
> o.a.l.l.p.j.TimeFormatBenchmark.customFormatString sample
> 170168 82.650 ± 1.326 ns/op
> o.a.l.l.p.j.TimeFormatBenchmark.customFormatStringBuilder sample
> 108884 67.825 ± 1.577 ns/op
> o.a.l.l.p.j.TimeFormatBenchmark.fastDateFormatString sample
> 148478 317.145 ± 1.850 ns/op
> o.a.l.l.p.j.TimeFormatBenchmark.simpleDateFormatString sample
> 173226 263.886 ± 10.615 ns/op{noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
