Logging debug messages with Drools

This article shows a neat way to log debug messages from rules in Drools Rule Language (DRL). This is a recipe from the Lunatech Drools Cookbook - recipes for effective Drools use.

Problem

It is very frequently useful to add debug-level log statements to rules. Each log statement needs to indicate which rule is being debugged, and the log message generally includes parameters.

Solution

Define a DRL ‘function’ for logging via Log4J that you can use in your rules. This is implemented in the following Java class.

package com.lunatech.drools;

import org.apache.log4j.Logger;
import org.drools.spi.KnowledgeHelper;

/**
 * Functions for use in DRL files.
 */
public class RuleFunctions {

    /**
     * Log a debug message from a rule, using the rule’s package and name as the Log4J
     * category.
     */
    public static void log(final KnowledgeHelper drools, final String message,
        final Object... parameters) {

        final String category = drools.getRule().getPackageName() + "."
            + drools.getRule().getName();
        final String formattedMessage = String.format(message, parameters);
        Logger.getLogger(category).debug(formattedMessage);
    }

To use this, first declare the function at the top of the DRL file in the import section.

import function com.lunatech.drools.RuleFunctions.log;

Then you can replace a logging statement such as:

rule "Total price"
when
   …
then
   …
   log.debug("Total price: " + items + " items, total price = " + price);
end

with:

rule "Total price"
when
   …
then
   …
   log(drools, "%d items, total price = %d", items, price);
end

How it works

The first argument is the drools object, which is an instance of org.drools.spi.KnowledgeHelper that provides access to the working memory that the logging function uses to get the rule context - the rule’s package name and rule name. The second argument is a log message, which may contain placeholders for the optional varargs arguments.

The log function joins the rule’s package name and rule name with a dot, to form the Log4J category name to use instead of the more usual fully-qualified Java class name. This makes it possible to use the Log4J configuration to filter the debug logging by package and rule.

Secondly, the log function uses java.lang.String.format to format the log message using the placeholders and arguments.

Finally, the log function uses Log4J to output the log message.