Exactly, their "solution" doesn't actually solve the problem people had. Also, {}? Why not:
logger.debug(String.format("Hi, %s %s", u.getA(), u.getB()));
If they wanted to have format capabilities in the logger, why didn't they just use pre-existing standards?Wouldn't u.getA() and u.getB() still be evaluated first so that their values can be passed to the debug method? Without the if statement, how is the debug method not being called?
Re:A new log4j 2.0
by politician on Thursday December 06, 2012 @11:11AM
(#4882276)
In the original code, the debug call is guarded by a condition:
if (log.isDebugEnabled()) {
log.debug("{}", expensiveOp(), debugModeOnlyOp());
}
But in the new code, the calls to expensiveOp and debugModeOnlyOp will be called every time this sequence of code is run regardless of the condition: log.debug("{}", expensiveOp(), debugModeOnlyOp());
which is equivalent to the old code: var x = expensiveOp();
var y = debugModeOnlyOp();
if (log.isDebugEnabled()) {
log.debug("{} {}", x, y);
}
In most languages that do not support macros, it's impossible to correctly state the dependency of expensiveOp & debugModeOnlyOp on the log.isDebugEnabled() flag using log4j's new API.
Re:A new log4j 2.0
by numbsafari on Thursday December 06, 2012 @11:12AM
(#4882283)
I think he's saying exactly that. His post is kinda confusing because of how he quoted the article.
u.getA() and u.getB() will still be evaluated. However I believe the conversion of A and B to strings will not be carried out if debug is disabled.
Often it is the conversion to string that is an expensive operation.
Incidentally with lots of lazy loading (Hibernate I'm looking at you...) this can lead to errors only appearing when debug is turned off - not a nice situation to be in.
Meh. The payoff in format-string conditional log statements is in avoiding the cost of string construction only to throw it away--NOT to avoid the cost of evaluating operands.
I have always preferred the NLog style, where the default .Debug, .Warn, etc., functions use good old .NET format strings and a params argument. logger.Debug("Thing {0} happened at {1:R}", thing, thing.CompletionDate);
No, the issue was:
log.Debug("Thing {0} happened", o.expensive_call())
could end up calling some method that took a very long time to run, only to be thrown away in the end. String construction isn't that big of a deal and their new API could avoiding doing it if the message won't be used.
They had a good reason to write it that way! Otherwise, `u.getA()` and `u.getB()` are evaluated and the values discarded when debugging is turned off. Evaluating these functions may be expensive (e.g. walking the stack), or may have debug-specific side effects.