[infinispan-dev] if (trace) logger.tracef - it makes sense

[Sebastian Laskawiec]

Hey!

A while ago I asked Radim and Dan about these kind of constructs [1]:

private boolean trace = logger.isTraceEnabled(); //stored in a field

... called in some method ...
    if(trace)
        logger.tracef(...);
...

At first they seemed wrong to me, because if one changes logging level
(using JMX for example), the code won't notice it. I also though it's quite
ok to use tracef directly, because JIT will inline and optimize it.

Unfortunately my benchmarks [2] show that I was wrong. Logger#tracef indeed
checks if the logging level is enabled but since JBoss Logging may use
different backends, the check is not trivial and is not inlined (at least
with default settings). The performance results look like this:
Benchmark                  Mode  Cnt           Score          Error  Units
MyBenchmark.noVariable    thrpt   20   *717252060.124* ± 13420522.229  ops/s
MyBenchmark.withVariable  thrpt   20  *2358360244.627* ± 50214969.572  ops/s

So if you even see a construct like this: logger.debuf or logger.tracef -
make sure you check if the logging level is enabled (and the check result
is stored in a field).

That was a bit surprising and interesting lesson :D

Thanks
Sebastian

[1] https://github.com/infinispan/infinispan/pull/4538#discussion_r80666086
[2] https://github.com/slaskawi/jboss-logging-perf-test
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.jboss.org/pipermail/infinispan-dev/attachments/20160930/59a29117/attachment.html