[slf4j-dev] Benefits of Message objects?

Ceki Gulcu ceki at qos.ch
Sat Sep 10 15:50:20 CEST 2011



By accepting argument of type String[] in its constructor [1], 
ParameterizedMessage trades immutability for typing information. 
However, the typing information is required for filtering. So losing 
typing information is a relatively important loss. Is 
ParameterizedMessage typical or an unfortunate counter example?

As for immutability, a careless/malicious developer can still modify the 
contents of the String[] array. Thus, there is a limit to the level of 
protection gained from converting Object[] to String[].

Let's work on a concrete example. Let's say we are working on airspace 
control system which needs to log flight records.

Here is a very minimal impl:
FlightRecord {
   public String flightCode; // SA 457
   public long[] currentGPSCoordinates; // the GPS coordinate

   FlightRecord(String flightCode, long[] currentGPSCoordinates) { ... }
}

So given a FlightRecord:

  FlightRecord fr = new FlightRecord("SA 456", new long[] {1, 1, 1}}

using log4j we would write

   logger.info(fr);

and using SLF4J we would write

   logger.info("{}", fr);

In both approaches the FlightRecord instance is mutable.
We could write a wrapper, say FlightRecordWrapper, to render
FlightRecord immutable:

FlightRecordWrapper implements Message {
   final String flightCode;
   final long[] currentGPSCoordinates;

   FlightRecordWrapper(FlightRecord fr) {
      flightCode = fr.flightCode;
      currentGPSCoordinates = fr.currentGPSCoordinates.clone();
   }
}

If the Message interface were supported in SLF4J, we would write:

   logger.info(new FlightRecordWrapper(fr));

This is cleaner than

   logger.info("{}", new FlightRecordWrapper(fr));

I am still left with the feeling that the main inconvenience of the "{}" 
form is its ugliness.

--
Ceki

[1] 
https://github.com/huxi/slf4j/blob/slf4j-redesign/slf4j-n-api/src/main/java/org/slf4j/n/messages/ParameterizedMessage.java



On 10.09.2011 14:02, Joern Huxhorn wrote:
> Hi Ceki,
>
> You are right, the perceived behavior is the same in case of, say, a console appender.
>
> But the lazy evaluation is actually one of the issues that I'm trying to resolve.
>
> I'd like to prevent an issue like this at all costs:
> http://techblog.appnexus.com/2011/webkit-chrome-safari-console-log-bug/
>
> If the arguments are kept as Object[] instead of converting them to Strings in the same Thread and at the time of the logger call then stuff like this can happen in case of asynchronous appenders. Hibernate can also throw LazyInitializationException if lazy members are accessed outside of the surrounding transaction. My example of an appender that serves events to the view of a webapp in my previous mail would be one example of that. If a member of one of it's arguments is changed before the message is created then it would behave like the webkit bug above.
>
> Because of this, I convert all arguments to their String representation while creating the ParameterizedMessage (only after the checks have determined that the call should actually emit an event, obviously). This, in turn, means that the types/original objects are lost in the process, making it impossible to filter on them.
>
> Something similar must be done regardless of the existance of a Message interface/implementation. (I remember that we discussed this in the past but I don't know if I was able to convince you about how crucial I consider this - nothing is worse than a lying logging framework. Other than a logging framework crashing the application, of course, but I think we nailed that already in the MessageFormatter.)
>
> Since the creation of a Message instance is rather expensive I assume that a performance-conscious person will surround it with a isXxxEnabled() guard. I further assume that Message implementations take care of transforming critical/mutable Objects into String or some other thread-safe/immutable type during creation. Otherwise I'd consider that a bug in the Message implementation. I thought about adding a prepareForDeferredProcessing() method to the Message interface but decided against it. I'd instead document this necessity in the Message interface.
>
> In #148 Ralph requested the ability to log StructuredData without having to parse the String representation. This could be done using a StructuredDataMessage that contains the key/value pairs in a Map<String, String>, meaning it would still contain the Map but wouldn't contain any mutable instances anymore, making it thread-safe.
>
> Beside all this I really do like the expressiveness gained compared to the "workaround" of info("{}", sd).
> info(Message) is like an info(Object) method, but with a "type-safe documentation" attached by means of the Message interface.
> I'd, personally, consider it bad style to just dump any object in a log message. So I wouldn't allow or encourage this and therefore wouldn't want to add an info(Object) signature to the logger.
>
> Hope this explains the difference sufficiently,
> Joern.
>
> On 09.09.2011, at 23:54, Ceki Gülcü wrote:
>
>> Hi everyone,
>>
>> After reading this thread, I am still trying to establish whether the
>> Message interface is needed especially compared to the following
>> approach:
>>
>> StructuredData sd = new StructuredData(..., aMap, ...);
>> logger.info("{}", sd);
>>
>> Granted, the above is not intuitive but other than that:
>>
>> 1) it allows filtering on parameter type
>>
>> 2) formatting of StructuredData is done lazily using the toString
>> method of StructuredData
>>
>> 3) it requires no changes to SLF4J
>>
>> I do not wish to be obtuse and I apologize if this question was asked
>> previously. Unfortunately, I don't recall the answer. Seriously, what
>> is wrong with logger.info("{}", sd) ?
>>
>> Cheers,
>> --
>> Ceki
>> _______________________________________________
>> slf4j-dev mailing list
>> slf4j-dev at qos.ch
>> http://qos.ch/mailman/listinfo/slf4j-dev
>
> _______________________________________________
> slf4j-dev mailing list
> slf4j-dev at qos.ch
> http://qos.ch/mailman/listinfo/slf4j-dev


-- 
QOS.ch, main sponsor of cal10n, logback and slf4j open source projects, 
is looking to hire talented software engineers. For further details, see 
http://logback.qos.ch/job.html


More information about the slf4j-dev mailing list