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
(usi
I understand the impact of this, but we should keep in mind that there are
some important points where it is worse if you can't change the logging on
the fly for a few moments to check something and switch back.
For the test my understanding is that you use
- the logger.tracef direct
- check logge
Wolf, the isTraceEnabled() is called only once during class
initialization (if that's a static field) or instance creation, but it
is usually stored as final field and therefore the JVM is likely to
optimize the calls.
It's possible to change final fields, and in this case it's not as
unsafe (
Yes, exactly - Radim is correct.
I added also one test - "if(logger.isTraceEnabled()) logger.trace(...)".
The results look like the following:
Benchmark Mode Cnt Score
Error Units
MyBenchmark.noVariable thrpt 20 725265655.062 ±
1777607.124
On 09/30/2016 01:53 AM, Sebastian Laskawiec wrote:
> 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 f
Ok,
thanks for clarifying it.
So there is a factor of 3 for the test if no trace is enabled, just for
checking.
It makes sense to use it.
But my concern is still that it is sometimes good to have the possibility
to enable debug for some important information in production just on the
fly and swit
Hey David!
It's Java Util Logging (so the JDKLogger implementation).
Thanks
Sebastian
On Fri, Sep 30, 2016 at 1:53 PM, David M. Lloyd
wrote:
> On 09/30/2016 01:53 AM, Sebastian Laskawiec wrote:
> > Hey!
> >
> > A while ago I asked Radim and Dan about these kind of constructs [1]:
> >
> > priva
I should stress that we only cache `isTraceEnabled()` in a static
field. Debug logging can still be enabled or disabled on the fly.
Cheers
Dan
On Fri, Sep 30, 2016 at 3:14 PM, Wolf Fink wrote:
> Ok,
>
> thanks for clarifying it.
>
> So there is a factor of 3 for the test if no trace is enabled
this discussion appears on this mailing list approximately every 2 years :)
On 30 September 2016 at 13:41, Dan Berindei wrote:
> I should stress that we only cache `isTraceEnabled()` in a static
> field. Debug logging can still be enabled or disabled on the fly.
>
>
> Cheers
> Dan
>
>
> On Fri, S
As Wolf noted, caching the trace flag is bad when trying to debug issues.
Don't do it! It's not worth breaking the logging semantics for a
nano-second level performance difference. (if your trace is being
called enough for that tiny impact to make any real difference, that
trace logging is going
The performance problem that this trick is meant to resolve is really a
problem in the logging backend. It *should* be faster inside of
WildFly, where JBoss LogManager is used, because that project just
checks a single volatile field for the level check... and the path to
that code *should* be
Dennis, this has been done in Infinispan ever since 4.0, so feel free
to open a BZ :)
Cheers
Dan
On Fri, Sep 30, 2016 at 7:16 PM, Dennis Reed wrote:
> As Wolf noted, caching the trace flag is bad when trying to debug issues.
>
> Don't do it! It's not worth breaking the logging semantics for a
On Fri, Sep 30, 2016 at 10:15 PM, David M. Lloyd wrote:
> The performance problem that this trick is meant to resolve is really a
> problem in the logging backend. It *should* be faster inside of
> WildFly, where JBoss LogManager is used, because that project just
> checks a single volatile field
Hey!
Adding James to this thread.
@Dennis - I think Dan has a point here. The trick with checking a field in
a class is 3 times faster. Most of the checks are done in core so they are
executed multiple times per operation. Changing all those places is
probably not an option.
@David - Let me run
Hey!
Please have a look at the latest perf test results [1][2]:
Benchmark Mode Cnt Score
Error Units
MyBenchmark.noVariable thrpt 20 *681131269.875* ±
3961932.923 ops/s
MyBenchmark.withIsTraceEnabledCheck thrpt 20 *676307984.921* ±
Hi Sebastian
I modified your benchmark so that the logger and the trace field are
static final and looked at the generated assembly with JITWatch [1].
Based on the attached assembly listings, caching isTraceEnabled() in a
constant field is "infinitely faster", because there are no assembly
instruc
Awesome Dan! May I ask for a Pull Request:
https://github.com/slaskawi/jboss-logging-perf-test?
On Mon, Oct 3, 2016 at 2:40 PM, Dan Berindei wrote:
> Hi Sebastian
>
> I modified your benchmark so that the logger and the trace field are
> static final and looked at the generated assembly with J
I've not looked at any such details but I always assumed that since the
logger frameworks (any of them) need to be able to change the logging
level, there must be some way of switching state - at least a volatile
read?
And while that could be very cheap, I doubt it would be as easily optimised
as
On Mon, Oct 3, 2016 at 3:58 PM, Sanne Grinovero wrote:
> I've not looked at any such details but I always assumed that since the
> logger frameworks (any of them) need to be able to change the logging level,
> there must be some way of switching state - at least a volatile read?
>
> And while tha
Aren't we investing a bit too much time to this? The trace level was
cached for ages, has anyone ever complained? Turning on trace level is
completely impractical in production, but that info (or, I'd say 80% of
that) is very useful when debugging race conditions etc., so it makes
sense to keep
On 10/03/2016 08:43 AM, Radim Vansa wrote:
> Aren't we investing a bit too much time to this? The trace level was
> cached for ages, has anyone ever complained?
I have. https://issues.jboss.org/browse/JBCACHE-1625
Looks like I just never copied it over to the ISPN JIRA. :)
> Turning on trace
On 10/03/2016 07:31 PM, Dennis Reed wrote:
> On 10/03/2016 08:43 AM, Radim Vansa wrote:
>> Aren't we investing a bit too much time to this? The trace level was
>> cached for ages, has anyone ever complained?
> I have. https://issues.jboss.org/browse/JBCACHE-1625
>
> Looks like I just never copied
I think we reached the point where we mention the same arguments over and
over again...
So let me try to sum it up and possibly iron an action plan out:
- The main reason we cache the "isTraceEnabled" value is speed. It's
more than 3 times faster then checking it before each trace invocatio
On Tue, Oct 4, 2016 at 10:44 AM, Sebastian Laskawiec
wrote:
> I think we reached the point where we mention the same arguments over and
> over again...
>
> So let me try to sum it up and possibly iron an action plan out:
>
> The main reason we cache the "isTraceEnabled" value is speed. It's more t
ahhh, for some reason I missed that. Sorry guys...
In that case there's probably not much we can do. The only missing bit is
what to do with JBCACHE-1625?
On Tue, Oct 4, 2016 at 12:24 PM, Dan Berindei
wrote:
> On Tue, Oct 4, 2016 at 10:44 AM, Sebastian Laskawiec
> wrote:
> > I think we reached
25 matches
Mail list logo
