Estimated release 5.5.0.Beta1 soon (in week of 3th September)
by Geoffrey De Smet
Guys,
The Drools 5.5.0.Beta1 and jbpm 5.4.0.Beta1 release in about a week and
a half (week of 3th September). Michael's the release guy for 5.5.x (and
jbpm).
Hudson looks good except for droolsjbpm-integration that still has 53
failing tests related to jbpm's TaskLifeCycle.
Let's keep hudson blue.
Don't forget to add your stuff to the N&N.
11 years, 8 months
Logging: howto show logging + best practices of slf4j
by Geoffrey De Smet
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?*
* Production code (such as drools-core/src/main/java) isn't executed
directly and therefor has no logging configuration.
* For a unit test, configure your logging desires in
src/test/resources/logback-test.xml
* For an example application, configure your logging desires in
src/main/resources/logback.xml
* For a war, configure your logging desires in
src/main/resources/logback.xml
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
11 years, 8 months
