Logging

Globale logs handling

It is important for a library which aims to integrate as a software component in an existing system to provide accurate and concise execution traces, adapted to the situation (development, qualification, production). It also has to integrate with the log system adopted by the master software without being intrusive, meaning without the necessity of third party library.

To meet these specifications, MRules has chosen to develop an internal log interface, redirecting log messages to an external interface.

Accepted external log interfaces cover the majority of applications. These are, in order of priority, slf4j, log4j and JDK-integrated java.util.logging library. No configuration is necessary: a search of available Logger is performed at initialization.

Regarding the verbosity of logs, different levels (DEBUG, INFO, WARN, and ERROR) will give different information, corresponding to the needs of the teams having to interpret them.

All logs generated by our products’ components use this intermediary log interface .

This interface can also be used for your own developments (whether it is for an MRules extension or for a business development). The following code snippet shows how to integrate it into your classes:

import com.massa.log.Log;
import com.massa.log.LogFactory;

/**
 * Logs an info at instantiation.
 */
public class LogExample {
  private static final Log LOG = LogFactory.getLog(LogExample.class.getName());

  public LogExample() {
    LOG.info("Building a new LogExample.");
  }
}

Busine Rule Engine logs

In order to easily trace the different stages of compilation or execution, all the execution logs of a given RuleSet instance are grouped within the same logger.

Compilation, optimization and Execution have three distinct loggers in order to be able to configure their log level independently. Logger names are build as follows by default:

  • com.massa.mrules.set.COMPILE.<RuleSet name>
  • com.massa.mrules.set.OPTIMIZE.<RuleSet name>
  • com.massa.mrules.set.EXECUTE.<RuleSet name>

Here is an extract of log4j configuration for tracing the execution of a particular rule engine instance if needed:

#Ruleset instance with logger name « ruleSetName » will have a TRACE log level.
log4j.logger.com.massa.mrules.set.EXECUTE.ruleSetName = TRACE, console
log4j.additivity.com.massa.mrules.set.EXECUTE.ruleSetName = false
log4j.logger.com.massa.mrules.set.OPTIMIZE.ruleSetName = TRACE, console
log4j.additivity.com.massa.mrules.set.OPTIMIZE.ruleSetName = false
log4j.logger.com.massa.mrules.set.COMPILE.ruleSetName = TRACE, console
log4j.additivity.com.massa.mrules.set.COMPILE.ruleSetName = false
#All other Ruleset instances will have a WARN log level.
log4j.logger.com.massa.mrules.set= WARN, console
log4j.additivity.com.massa.mrules.set= false
#All other MRules logs with level INFO and above will be printed.
log4j.logger.com.massa.mrules = INFO, console
log4j.additivity.com.massa.mrules = false
#This deactivates traces for property access and conversion.
log4j.logger.com.massa= ERROR, console
log4j.additivity.com.massa = false

And another similar configuration sample for logback :

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
  <appender name="consoleAppender" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{5} - %msg%n</pattern>
    </encoder>
  </appender>

  <logger name="com.massa.mrules.set.EXECUTE.rulesetName" level="trace" additivity="false">
    <appender-ref ref="consoleAppender" />
  </logger>

  <logger name="com.massa.mrules" level="WARN" additivity="false">
    <appender-ref ref="STDOUT" />
  </logger>

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

Moreover, as the logger is hold by the context, it is perfectly possible to override its default name for a given execution to trace it precisely.
A unique execution identifier can be generated and forced, programmatically, before each launch. This will make it easier to request a log aggregation tool for instance.
The following code snippet generates a  unique  identifier based on the ruleset name and the execution date / time:

import java.util.Date;

import com.massa.log.Log;
import com.massa.log.LogFactory;
import com.massa.mrules.context.execute.MExecutionContext;
import com.massa.mrules.exception.MExecutionException;
import com.massa.mrules.set.IMruleExecutionSet;

/**
 * Overrides logger name.
 */
public class LoggerNameExample {
  private static final Log LOG = LogFactory.getLog(LoggerNameExample.class.getName());

  public void execute() throws MExecutionException {
    IMruleExecutionSet ruleset = buildRuleset();
    final MExecutionContext<RulesetBean> ctx = new MExecutionContext<RulesetBean>(ruleset);
    // Generate the logger name
    String loggerName = ruleset.getName() + '.' + new Date().getTime();
    // Set the logger name. The dot tells it's a suffix and not the full name.
    ctx.setLoggerName('.' + loggerName);
    LOG.info("Launching ruleset with logger " + loggerName);
    ctx.execute();
  }
}