0

I went through the logging in my application and found that a lot of it was very messy because I used StringBuilders with appends and guard clauses to check whether or not to build the string.

ie 
StringBuilder globalSB = new StringBuilder();
//random other code

//place that needs to be logged
globalSB.setLength(0);
globalSB.append("something").append("other something").().().().append("end");  //<--imagine theres a lot of appending of variables/objects etc
LOGGER.info(globalSB.toString());

I recently came across this question and answer that suggests to use parameterized logging, though its not clear if its slf4j or log4j. Many other answers suggest to directly use slf4j,since it will check if the string concatenation needs to happen (logging level) before actually building the string; or to just directly use guard clauses regardless since the overhead of checking the debug level is insignificant.

I m kinda looking to find out what log4j2 can do instead of what slf4j can do, so I checked some other question/answer/comments and found that some suggest the newer versions of log4j2 support behavior similar to that of slf4j and the lazy(?) string building (using parameterized logging) as well as Java 8 lambda support for lazy logging. ie 1, 2.

Is it mandatory to use guard clauses (then use a stringbuilder etc), or does parameterized logging with lambdas for expensive method calls also provide same behavior (does not create the string unless log level dictates it is needed)? I m hoping to get an answer, because many of the other posts seems to have divided opinions. ie

byte[] rawIp; //assume it has some value
int port;  //assume it has some value
String msgReceived;//assume it has some value

LOGGER.debug("{},{} sent {}", ()->rawIp.convertToString(), port, msgReceived);

2 Answers2

1

When constructing the log message, you optimized using StringBuilder however the readability of your code went down. Even more, by configuration of the log level the log message may be discarded completely, which means having constructed the String was a total waste of time.

You can apply guard clauses like

//random other code

if (LOGGER.isDebugEnabled()) {
    StringBuilder globalSB = new StringBuilder();

     //place that needs to be logged
     globalSB.setLength(0);
     globalSB.append("something").append("other something").().().().append("end");  //<--imagine theres a lot of appending of variables/objects etc
     LOGGER.info(globalSB.toString());
}

but that adds even more distracting code in your source.

With parameterized logging all this is sent into the logging library. While log4j 1.x did not know about parameterized logging, both log4j2 and slf4j do know.

Queeg
  • 7,748
  • 1
  • 16
  • 42
1

Both SLF4J and Log4j 2.x API:

  • support parameterized logging. This was actually one of the features introduces in SLF4J that was missing in the previous APIs (Jakarta Commons Logging, java.util.logging and Log4j 1.x),
  • string concatenation is not performed if the message level is not specific enough,
  • string concatenation is not performed unless an appender is configured to send the message (appenders can also have filters). If you use Log4j 2.x Core as implementation (with either API) and garbage-free logging, no concatenated string is actually created: the pattern and the parameters are directly appended to a per-thread StringBuilder,
  • if the arguments are Suppliers, they are evaluated only when the message is logged. The ability to use suppliers is available since Log4j 2.4 (in both Logger and LogBuilder) and SLF4J 2.0 (only in LoggingEventBuilder).

Regarding the if (logger.isDebugEnabled()) guard clauses: they are not necessary and can actually alter your logging logic.

Imagine you use a marker for all your network related messages:

private static final Marker NET = MarkerManager.getMarker("NET");

Both Logback and Log4j 2.x Core allow you to log everything at least as specific as INFO or containing the NET marker (this requires turbofilters in Logback and global filters in Log4j 2.x Core). With such a configuration the following statement will not log anything (DEBUG is disabled):

if (logger.isDebugEnabled()) {
    logger.debug(NET, "Receiving incoming message: {}", message);
}

while the following message will be logged (NET messages should be logged):

logger.debug(NET, "Receiving incoming message: {}", message);
Piotr P. Karwasz
  • 12,857
  • 3
  • 20
  • 43