3 ms·

"In old days, people wrote things like this: if(logger.isDebugEnabled()) { logger.debug("Hi, " + u.getA() + “ “ + u.getB()); } "Many have complained

"In old days, people wrote things like this: if(logger.isDebugEnabled()) { logger.debug("Hi, " + u.getA() + “ “ + u.getB()); } "Many have complained about it: it is very unreadable. The log4j 2.0 team thought about things like that and improved the API. Now you can write the same like that: logger.debug("Hi, {} {}", u.getA(), u.getB()); ~~~~ 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.

umjames 14y ago
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?
- politician 14y ago
  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.
- numbsafari 14y ago
  I think he's saying exactly that. His post is kinda confusing because of how he quoted the article.
- pablobaz 14y ago
  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.
tburch 14y ago
slf4j has had placeholders for a while
sk5t 14y ago
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);
- flyinRyan 14y ago
  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.
SCdF 14y ago
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?

umjames 14y ago

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?

politician 14y ago
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.
numbsafari 14y ago
I think he's saying exactly that. His post is kinda confusing because of how he quoted the article.
pablobaz 14y ago
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.

tburch 14y ago

slf4j has had placeholders for a while

sk5t 14y ago

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);

flyinRyan 14y ago
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.

SCdF 14y ago

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?