[hibernate-dev] logging

[Steve Ebersole]

As hopefully everyone is aware by now we have switched over to use JBoss 
Logging for our logging api in 4.0.  JBoss Logging provides 2 unique 
capabilities that we for sure wanted to leverage and I think I am just 
now starting to come to grasp with.  So I wanted to discuss some stuff 
related to them.

The first capability is built in i18n support.

The second is the idea of keyed messages.  Each message has a consistent 
alphanumeric key by by which you can, for example, refer to the 
condition that caused the particular log message in say documentation.

Additionally as with most logging frameworks, you have a notion of a 
logger or category.

All logging ends up targeting different audiences.  Some messages are 
meant directly for the developer and are meant to aid them during 
development ("hey you messed up this mapping construct").  Others are 
meant to help admin/support folks understand what is going on in a 
running system that might be causing problems.

In my opinion, there are other natural things to do here depending on 
which audience is being targeted.  Take category names, for example; for 
developer-centric messages I think using the name of the originating 
class (current scheme) makes the most sense; but for other audiences 
having consistently named categories that can survive package 
reorganization and so can be better documented in user docs is a bug win.

There is an inherent design decision in JBoss Logging that if you use 
the stuff in the most straight forward way, you end up limited to a 
single category scheme and limiting yourself to trace and debug logging 
for the developer audience and info/warn/error for "admin" audience.  So 
the question I ask is whether we want to just go that route, or if we 
want to invest in a quite possibly over-engineered approach were we 
cater to this idea of separate channels.

The big issue to me is the lack of granularity in "developer targeted 
messages".   This goes hand in hand with quick dev/test cycles.  As an 
illustration, I cranked up logging to (mostly) TRACE during a run of the 
hibernate-core test suite, which took approx 13 minutes.  Dropping that 
log level back down to INFO and the test suite ran in 2 minutes.  That 
is significant.

What would the alternative look like?

Well in JBoss Logging, i18n is provided by means of a proxied interface. 
  Hibernate defines this interface and provides it to JBoss Logging:

@MessageLogger( projectCode = "HHH" )
public interface CoreMessageLogger extends BasicLogger {
     @LogMessage(level=INFO)
     @Message(value="Hello %s", id=1)
     void sayHello(String name);
     ...
}

CoreMessageLogger log = Logger.getMessageLogger(
         CoreMessageLogger.class,
         this.getClass()
);

(the second argument is the category name, here our class name)

So again, with just those pieces we have the intended JBoss Logging 
setup.  You would have a boat load of messages at TRACE/DEBUG the 
develop needs to see so they still need to "crank up the logging".  Now 
luckily the category is still friendly here in that respect since they 
can define which classes/packages on which to crank up the logging.

So an alternative is to use this notion of channels:

@MessageLogger( projectCode = "HHH" )
public interface CoreAdminMessageLogger extends BasicLogger {
     @LogMessage(level=INFO)
     @Message(value="Hello %s", id=1)
     void sayHello(String name);
     ...
}

@MessageLogger( projectCode = "HHH" )
public interface CoreDevMessageLogger extends BasicLogger {
     @LogMessage(level=INFO)
     @Message(value="Loading the HelloComponent implementation %s", id=501)
     void loadingHelloComponent(String implementationName);
     ...
}

CoreAdminMessageLogger adminLog = Logger.getMessageLogger(
         CoreAdminMessageLogger.class,
         "org.hibernate.core.hello"
);

CoreDevMessageLogger devLog = Logger.getMessageLogger(
         CoreDevMessageLogger.class,
         this.getClass()
);

I realize this all seems over-engineered in many ways.  I do see *some* 
benefit.  I guess the decision I need help weighing is whether this 
amount of benefit out-weighs the "complexity".

Thoughts?


-- 
Steve Ebersole <steve at hibernate.org>
http://hibernate.org