Let SLF4J do the Log4j2 Message formatting as needed

[Benjamin Krahl]

Currently SLF4JLogger in Log4j 2 will format all messages before it passes
these to SLF4J. I think this does not need to be the case.

SLF4J FAQ  states that:
"Assuming complexObject is an object of certain complexity, for a log
statement of level DEBUG, you can write:

logger.debug("{}", complexObject);

The logging system will invoke complexObject.toString() method only after
it has ascertained that the log statement was enabled. Otherwise, the cost
of complexObject.toString() conversion will be advantageously avoided."

When Log4j 2 wraps the Message, SLF4J can invoke the formatting
conditionally by a call of the overridden toString().

I would like to provide a pull request if this is an acceptable change.
Example sketch:
Slf4jMessageAdapter messageToBeFormatted = new Slf4jMessageAdapter(message);
// ...
logger.debug(slf4jMarker, "{}", messageToBeFormatted, t);

private static class Slf4jMessageAdapter {

  private Message message;

  private Slf4jMessageAdapter(Message message) {
this.message = message;
  }

  @Override
  public String toString() {
return message != null ? message.getFormattedMessage() : null;
  }
}

Cheers!

Benjamin

Re: Let SLF4J do the Log4j2 Message formatting as needed

[Piotr P. Karwasz]

Hi Benjamin,

On Thu, 10 Aug 2023 at 14:45, Benjamin Krahl  wrote:
>
> Currently SLF4JLogger in Log4j 2 will format all messages before it passes
> these to SLF4J. I think this does not need to be the case.
>
> SLF4J FAQ  states that:
> "Assuming complexObject is an object of certain complexity, for a log
> statement of level DEBUG, you can write:
>
> logger.debug("{}", complexObject);
>
> The logging system will invoke complexObject.toString() method only after
> it has ascertained that the log statement was enabled. Otherwise, the cost
> of complexObject.toString() conversion will be advantageously avoided."
>
> When Log4j 2 wraps the Message, SLF4J can invoke the formatting
> conditionally by a call of the overridden toString().

Both the Log4j API and SLF4J behave in the same way: the message is
formatted into a string if and only if it is going to be logged.
Therefore, in the current implementation `Object#toString()` is called
only if it is necessary.
Moreover, since the formatting performed by the Log4j API is
garbage-free (under certain conditions), while most SLF4J backends are
not, the overall user experience should be better.

The only disadvantage of the current implementation of
`log4j-to-slf4j` is that the argument array is not passed to the SLF4J
backend. If the backend makes use of this array (e.g. it transforms it
to JSON), the information is lost. I see two approaches to solve this:
* we can delegate formatting to SLF4J for some kinds of messages
(ParameterizedMessage, ReusableParameterizedMessage) by passing to
SLF4J `Message#getFormat()` and `Message#getParameters()`. I don't
like this solution since statistically it will generate more garbage
and we can not apply it to all messages: e.g. an ObjectMessage should
rather be logged with a format `{}` and a single object parameter,
* since the introduction of `LoggingEventAware` in SLF4J 2.x, we could
create our own `LoggingEvent` that wraps Log4j's `Message` and log it
directly to SLF4J.

If you are willing to submit a PR, I think this is the latter is the way to go.

Piotr

[1] https://www.slf4j.org/api/org/slf4j/spi/LoggingEventAware.html