[slf4j-dev] Benefits of Message objects?

Joern Huxhorn jhuxhorn at googlemail.com
Wed Sep 7 21:47:20 CEST 2011


Ok, huge post is incoming... ;)

To properly explain the reason for Message I should start with my redefinition of the Logger interfaces.

## core.BasicLogger

I created a BasicLogger interface ( https://github.com/huxi/slf4j/blob/slf4j-redesign/slf4j-n-api/src/main/java/org/slf4j/core/BasicLogger.java ) that merely defines the following methods:
	boolean isEnabled(T level);
	void log(T level, Message message);
	void log(T level, Message message, Throwable throwable);

As you can see, Message is already used in this interface. The idea is that several different Logger systems can be created extending it, e.g. Classic, Access or your Audit logger.

## core.Message

The Message interface ( https://github.com/huxi/slf4j/blob/slf4j-redesign/slf4j-n-api/src/main/java/org/slf4j/core/Message.java ) is also in this core package and serves several purposes:

- it is necessary as a marker interface so Message and also documents that the API isn't expecting just any Object here but an arbitrary Message implementation. The alternative of using just Object would also introduce an ambiguity in case of log(level, "Foo") (where "Foo" is supposed to be a message pattern without any optional arguments) and we don't want that. Beside that, it also enables auto-completion in IDEs.

- it defines a contract a little bit different than merely toString().
getFormattedMessage() is supposed to be lazily populated only once, i.e. the actual formatting takes place during the first call, subsequent calls should return the previously constructed message.

- it is the primary extension point of the API.
The "default implementation" in context of logback-classic is ParameterizedMessage ( https://github.com/huxi/slf4j/blob/slf4j-redesign/slf4j-n-api/src/main/java/org/slf4j/n/messages/ParameterizedMessage.java ). It encapsulates the whole logic of the currently used behaviour, i.e. {} replacement, and makes sure, that all parameters are converted to a String during creation of the message.
This is done to prevent issues in asynchronous appenders, e.g. LazyInitializationException in case of Hibernate. It also prevents that the logging is lying to the user. Suppose I call the log-method, logging is asynchronous & did not yet proceed, I change a member of one of the parameters in the thread that called the log-method and afterwards the asynchronous logging kicks in and logs the message with the already changed parameter. This is a very serious problem... a logging system can hardly perform worse.

Another implementation is SimpleMessage ( https://github.com/huxi/slf4j/blob/slf4j-redesign/slf4j-n-api/src/main/java/org/slf4j/n/messages/SimpleMessage.java ) that is used for messages logged without any parameters. We already know that formatting won't change anything so we can simply return the "pattern" without any further checks. (This is just a small optimization I planned but it isn't used, yet, in the abstract Logger implementation below.)

I also created JavaUtilFormatterMessage ( https://github.com/huxi/slf4j/blob/slf4j-redesign/slf4j-n-api/src/main/java/org/slf4j/n/messages/JavaUtilFormatterMessage.java ) already for the case where people would like to use the more powerful but significantly slower JUL-formatting. It was also meant as an example of the extensibility.

Those would be the default Messages that I'd already include in the basic SLF4J.

But now it gets interesting:

Suppose you'd like to format a MappedMessage like this:
The parameters are a Map<String, Object>, e.g. ["Foo": 1, "Bar": "Example", "Foobar": new SomeOtherObject()]
and the message pattern looks like this:
"{Foo} {Bar} {Foobar}"
getFormattedMessage() would return the formatted message as expected for every (already available) appender that requests it.

In addition to that, one could quite easily implement another custom appender that *knows* about the MappedMessage class and can therefore access the parameter map as well as contained parameters.
So it could, for example, put the "Foobar" instance of class SomeOtherObject in a specific database table - the main point here is that the instance has not been converted to a String yet.

You are absolutely free in the way you'll implement this custom Message type. 

You could create an additional Map<String, String> during creation of the Message to prevent the async-issues I described above while still keeping the original Map<String, Object> for further processing. It is a custom type that the developer can use in a custom appender so he will know what he is doing. He could, for example, not implement the appender asynchronously so he is not required to create the Map<String,String> at all.

Another very important use-case would be filtering via GEventEvaluator. It could evaluate the event in an arbitrarily complex way using duck-typing on the real parameters instead of their strings or the resulting formattedMessage.
As I said in #31, we do something like this quite effectively already by evaluating the unformatted messagePattern in our main application.

## n.Logger

The Logger interface ( https://github.com/huxi/slf4j/blob/slf4j-redesign/slf4j-n-api/src/main/java/org/slf4j/n/Logger.java ) extends core.BasicLogger and defines all the methods you'd expect from the original SLF4J Logger and additionally the following:
	org.slf4j.Logger getOldLogger();
	Threshold getThreshold();
	boolean isEnabled(Level level, Marker marker);
	void log(Level level, String messagePattern, Object... args);
	void log(Level level, Marker marker, String messagePattern, Object... args);
	void log(Level level, Message message);
	void log(Level level, Message message, Throwable throwable);
	void log(Level level, Marker marker, Message message);
	void log(Level level, Marker marker, Message message, Throwable throwable);

## n.helper.AbstractLoggerBase
Additionally, there is a AbstractLoggerBase ( https://github.com/huxi/slf4j/blob/slf4j-redesign/slf4j-n-api/src/main/java/org/slf4j/n/helpers/AbstractLoggerBase.java ) that implements most of the methods already. The only methods left are the following:
	public abstract Threshold getThreshold();
	public abstract boolean isEnabled(Level level, Marker marker);
	protected abstract void performLogging(Level level, Marker marker, Message message, Throwable throwable);

performLogging is called *after* relevance has already been determined by the wrapping methods.

## Examples

A very simple example implementation is done in ( https://github.com/huxi/slf4j/blob/slf4j-redesign/slf4j-n-api-new-integration-test/src/main/java/org/slf4j/n/test/TestLogger.java ) but it serves well to show the simplicity of doing a new implementation from scratch.

The code in 
https://github.com/huxi/slf4j/blob/slf4j-redesign/slf4j-n-api-old-integration-test/ , on the other hand, validates that SLF4J.n works as expected even if only an implementation of the old SLF4J API is available on the classpath.

In any case, the old SLF4J will always still be available. Either old SLF4J is wrapped to provide the new API or the new API is wrapped to provide the old API (this wrapper is retrieved by the getOldLogger() method in the n.Logger interface). This means that calling the old API while having an implementation of the new API in place will result in a very slight performance impact caused by one additional wrapper layer.

I consider this quite acceptable, though.

Hope this helps and explains my rationale behind all of this.

Cheers,
Joern.

On 07.09.2011, at 15:33, Ceki Gülcü wrote:

> Hi Joern,
> 
> With hindsight, could you provide a short list of benefits related to Message objects in your code?
> 
> Many thanks in advance,
> -- 
> Ceki
> _______________________________________________
> slf4j-dev mailing list
> slf4j-dev at qos.ch
> http://qos.ch/mailman/listinfo/slf4j-dev



More information about the slf4j-dev mailing list