Hi guys,

All System.out calls in drools production code have been replace by sl4j-api logging calls.
The unit tests and the examples use logback (which is the standard slf4j-api implementation) to output those calls to the console.

For example:
2012-08-08 21:23:41,101 [main] INFO  DroolsExamplesApp started.

Where can I configure the logging?

Notice that drools-core does not depend on logback (unlike it's tests) or any other logging implementation:
the user can easily bridge the drools logs to his favorite logging system (for example with slf4j-jcl).

What can I display in my log?

Everything that gets logged, not just from drools, but also from any other dependency (*).
(*) if they don't use slf4j, logging can be unified by bridges (for example with jcl-over-slf4j).

Here's an example that logs on debug level of drools and springframework and on warn level for all other dependencies:

<configuration>
  <logger name="org.drools" level="debug"/>
  <logger name="org.springframework" level="debug"/>
  <logger name="org.drools.foo.bar.MyReallyVerboseDebugClass" level="info"/>

  <root level="warn">
    <appender-ref ref="consoleAppender" />
  </root>
</configuration>

How do I use logging in my classes?

public class MyFoo {

    protected static transient Logger logger = LoggerFactory.getLogger(MyFoo.class);

    public void bar() {
         logger.trace("Something in a loop happened.");
         logger.debug("Something happened");
         logger.info("DroolsExamplesApp started.");
         logger.warn("That rule is pointless.");
         logger.error("Don't divide by zero.", myException); // it's probably better to only throw a RuntimeException to the user code and let him log it
    }

}

How do I make logging fast?

1) Keep the Logger a static field: that way it's creation cost is independent of how many instances of your class are created

2) Avoid String concatenating when trace is disabled:
Slower:
  logger.trace("String a is " + a + " and string b is " + b + "."); // slow
Faster:
  logger.trace("String a is {} and string b is {}.", a, b);
Because it checks if trace is enabled first, before concatenating the String.
When performance matters, trace logging will be very likely disabled.

3) Don't use System.out or System.err.
Such an operation always synchronizes on a printstream and the user is unable to disable that performance cost.
Use logging instead, so the user can configure it to discard the messages and their performance cost.

What best practices should I follow?

1) Don't use custom flags to disable/enable logging:
                    boolean hideWarnings = Boolean.getBoolean( "drools.schema.hidewarnings" );
                    if ( !hideWarnings ) {
                        System.out.println( "Your SAX parser is not JAXP 1.2 compliant - turning off validation." );
                    }
Just do this instead:
    logger.warn( "Your SAX parser is not JAXP 1.2 compliant - turning off validation." );
which outputs as for example:
   ... org.drools.MySaxParserClass WARN Your SAX parser is not JAXP 1.2 compliant - turning off validation.
Now, the user can easily hide that warning in the typical log configuration way:
  <logger name="org.drools.MySaxParserClass" level="error"/>
Instead of having to learn about "drools.schema.hidewarnings" and set that parameter somewhere.

2) Prefer logger.debug() (or logger.trace()) instead of logger.info().
Most log messages are not interesting enough to get the level info. Fight verbosity.
A good rule of thumb: Running your code for an hour should not output more than 10 info messages if nothing failed.

The logging is too big for my console

Use a fileAppender temporary for yourself, but don't add it to the default logback-test.xml configuration:

  <appender name="fileAppender" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>local/log/drools.log</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">
      <fileNamePattern>local/log/drools.%i.log.zip</fileNamePattern>
      <minIndex>1</minIndex>
      <maxIndex>3</maxIndex>
    </rollingPolicy>
    <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
      <maxFileSize>5MB</maxFileSize>
    </triggeringPolicy>
    <encoder>
      <pattern>%d [%t] %-5p %m%n</pattern>
    </encoder>
  </appender>

  <root level="warn">
    <appender-ref ref="consoleAppender" />
    <appender-ref ref="fileAppender" />
  </root>
-- 
With kind regards,
Geoffrey De Smet