[slf4j-dev] Better printing method signatures?

[Ceki Gülcü]

Hi Niclas,


The runtime handling of arguments, code completion pop-ups, easy
learning curve are very important considerations. At the very least,
it should be possible to document the API in a way which is easy to
understand and to retain. I also complete adhere to the "Simple stuff
simple and complex stuff possible" principle, which is probably one of
the drivers of this discussion. Your thoughtful comments got me
thinking about the problem some more.

Let us review the motivations for having parameters of type Object. If
we consider the method debug(String, Object), as I understand it, there
are two motivations for the second Object parameter. One motivation is
to allow parameterized log messages à la printf or
java.util.Formatter. For example, to allow the user to write

  logger.debug("The user id is {}.", user.getId());

instead of

    logger.debug("The user id is "+user.getId()+".");

assuming user.getId() returns an object of type java.lang.Long.

The former form is called the parameterized form. The latter form
incurs the cost of parameter construction which can be very high
relative to computational cost of the debug method, especially if the
debug statement is disabled. In case you are wondering, the first form
easily be 100 times faster than the second form (for disabled
statements).

Performance conscious users could also write

   if(logger.isDebugEnabled() {
     logger.debug("The user id is "+user.getId()+".");
   }

which is not as nice or easy to write as the parameterized form.

Passing the parameter as an Object defers the cost of the
Object.toString() call up until we can make sure that it is actually
needed, that is if the statement is enabled. For disabled log
statements, the toString() conversion cost can be avoided completely.


The second motivation for the Object parameter is to allow the logging
system to take in parameter values of any type, with the hope that
some inner component (e.g. Layout, Appender) has special knowledge to
deal with objects of certain types. Basically, the idea is to allow
maximum flexibility with the hope that someone (someday) would want
take advantage of this flexibility.

Increased flexibility was the reason why the debug(String) method was
changed to debug(Object) in an early version of log4j, even before
log4j joined the ASF in December 2000. However, as far as I can tell,
no known component takes advantage of the fact the message is
available (as an Object) exactly as originally passed to log4j.

At this juncture, I am quite inclined to discard the "flexibility"
argument. No one uses it, so why bother?

On generic log() methods
========================

SLF4J leaves the definition of the Level class to implementations. You
have suggested the following signature taking an int as the first
parameter.

   log( int level, String message );

The int parameter can be quite problematic because we can't prevent
the user from passing bogus integer values. Leaving the API vulnerable
to such abuse seems much worse than he subtlety of the problems we
are trying to address initially.

Having said this, we could introduce the Level class within the SLF4J
API. Level is implemented more or less in the same way in log4j and
java.util.logging, even there are differences in the set of levels
present in each system.


Remember that SLF4J While SLF4J can adapt to existing logging systems
by wrapping, it is actually intended to be implemented *directly* by
logging systems. Direct implementations tend to be measurably faster
with significantly lower memory footprints per logger. Moreover, there
are other fundamental problems with the wrapping approach in relation
with the logging separation problem. These problems disappear by themselves
in direct or "native" implementations.

So, if we expect logging systems to implement org.slf4j.Logger, then
if the Level class is present in the o.slf4j.Logger interface, then it
follows that the org.slf4j.Level must be present and used in native
implementations.

Although feasible, I would be reluctant to impose an org.slg4j.Level
class on native implementations, unless absolutely necessary.

Revised signatures
==================

In light of the above, here is a new proposal with revised signatures.

(rA) debug(String msg);
(rB) debug(String msg, Throwable t);
(rC) debug(String msg, Object param1);
(rD) debug(String msg, Object param1, Object param2);

Consequences
------------

- The method (rA) enforces the fact that logging systems are about
   decorating logging messages of type String.

- The only way to log an exception is through (rB), which goes to
   enforce the idiom that every exception should have an accompanying
   explanatory message.

- The parameterized printing method (rC) and (rD) are present
   only for performance reasons.

- Since Object[] is also an Object, if 3 or more parameters need
   to be passed, (rC) can be used. For example,

      logger.debug("User {} with email {} has id {}.",
        new Object[] { user.getName(), user.getEmail{}, user.getId()});

- In relatively rare cases where the message to be logged is the
   string form of an object, then (rC) can be used

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

   The logging system will invoke complexObject.toString() only after
   it has established that the log statement was enabled. Otherwise,
   the cost of toString() conversion will not be incurred.

- If a user needs to log an exception with a parameterized description
   message, then the parameterized description will be logged first,
   followed by the description. As in,

    logger.error("User {} could not be found", user.getName());
    logger.error("Exception follows.", exception);


Hopefully, the above proposal is compatible the aforementioned goals
of ease of learning. However, I think that it firmly fixes the message
type as String. In my opinion, a logging system is about decorating
and handling String messages. A logging system is *not* about handling
messages of arbitrary types.

Is there a use case I am missing? Comments?


At 06:36 AM 6/17/2005, Niclas Hedhman wrote:
>On Friday 17 June 2005 04:30, Ceki Gülcü wrote:
> > I think nhD and nhE are ambiguous. For example, the following statement
> > will not compile.
> >
> >     debug("hello", new Object[] {}, new Object[] {});
> >
> > Moreover, I fail to see a need for nhD or nhE, if you have nhC.
>
>Slight misunderstanding. I should have been more clear :o)
>I was not talking in terms of method signatures, but in terms of possible
>arguments for the generic method signatures that you propose, how they are
>handled (i.e runtime) and how we are going to document it in a 'friendly'
>manner (i.e. taking into account how IDEs do javadoc popups, code completions
>and such).
>
>You proposed;
>   void debug(Object msg);
>   void debug(Object msg, Object param1);
>   void debug(Object msg, Object param1, Object param2);
>
>So, I can feed that with any arbitrary 1 to 3 arguments of any non-primitive
>types.
>
>Read nhA as;
>
>    String message = "abc";
>    Object arg1 = new SomeArbitraryObject();
>    Throwable exc = new NiclasNotClearEnoughException();
>    logger.debug( message, arg1, exc );
>
>and for instance nhE as;
>    String message = "abc";
>    Object arg1 = new SomeArbitraryObject();
>    Object[] array = new Object[]{ "abc", "def" };
>    logger.debug( message, array, arg1 );
>
>and so forth...
>
>Hope this is as explicit as it can get.
>
>Spending a bit more thinking on it, I think I am in the camp of "very 
>explicit
>method signatures" and compile time determination of behaviour, but possibly
>reduce to the 'common cases' for the named methods, and a few more in
>'variable level' methods.
>
>For instance;
>debug( String message );
>debug( String message, String arg );
>
>info( String message );
>info( String message, String arg );
>
>warning( String message );
>warning( String message, String arg );
>
>error( String message );
>error( String message, String arg );
>error( String message, String arg, Throwable exc );
>
>log( int level, String message );
>log( int level, String message, String arg1 );
>log( int level, String message, String arg1, String arg2 );
>log( int level, String message, Throwable exc );
>log( int level, String message, String arg1, Throwable exc );
>log( int level, String message, String arg1, String arg2, Throwable exc );
>log( int level, String message, Object[] args );
>log( int level, String message, Object[] args, Throwable exc );
>
>i.e. Principle of "Simple stuff simple and complex stuff possible".
>But then again, I am probably in the camp that would only use the "log()"
>methods, and have my own facade with more explicit names.
>
>
>Cheers
>Niclas

-- 
Ceki Gülcü

   The complete log4j manual: http://www.qos.ch/log4j/