Instrument Java Code for Logging

This document explains how to add logging and tracing to MicroEJ applications and libraries with three different solutions. The aim is to help developers to report precise execution context for further debugging and monitoring.

Intended Audience

The audience for this document is application developers who are looking for ways to add logging to their MicroEJ applications and libraries.

It should also be of interest to Firmware engineers how are looking for adjusting the log level while keeping low memory footprint and good performances.

Introduction

One straightforward way to add logs in Java code is to use the Java basic print methods: System.out.println(…).

However, this is not desirable when writing production-grade code, where it should be possible to adjust the log level:

  • without having to change the original source code,
  • at build-time or at runtime, as application logging will affect memory footprint and performances

Overview

In this tutorial, we will describe 3 ways for logging data:

  • Using Trace library: a real-time event recording library designed for performance and interaction analysis.
  • Using Message library: a lightweight and simple logging library.
  • Using Logging library: a complete and highly configurable standard logging library.

Through this tutorial, we will illustrate the usage of each library by instrumenting the following code snippet:

public class Main {

   enum ApplicationState {
      INSTALLED, STARTED, STOPPED, UNINSTALLED
   }

   private static ApplicationState currentState;
   private static ApplicationState previousState;

   public static void main(String[] args) {
      currentState = ApplicationState.UNINSTALLED;
      switchState(ApplicationState.INSTALLED);
   }

   public static void switchState(ApplicationState newState) {
      previousState = currentState;
      currentState = newState;
   }
}

Finally, the last section describes some techniques to remove logging related code in order to reduce the memory footprint.

Log with the Trace Library

The ej.api.trace Trace library provides a way of tracing integer events. Its features and principles are described in the Event Tracing section.

Here is a short example of how to use this library to log the entry/exit of the switchState() method:

  1. Add the following dependency to the module.ivy:

    <dependency org="ej.api" name="trace" rev="1.1.0"/>
    
  2. Start by initializing a Tracer object:

    private static final Tracer tracer = new Tracer("Application", 100);
    

    In this case, Application identifies a category of events that defines a maximum of 100 different event types.

  3. Next, start trace recording:

    public static void main(String[] args) {
       Tracer.startTrace();
    
       currentState = ApplicationState.UNINSTALLED;
       switchState(ApplicationState.INSTALLED);
    }
    
  4. Use the methods Tracer.recordEvent(…) and Tracer.recordEventEnd(…) to record the entry/exit events in the method:

    private static final int EVENT_ID = 0;
    
    public static void switchState(ApplicationState newState) {
       tracer.recordEvent(EVENT_ID);
    
       previousState = currentState;
       currentState = newState;
    
       tracer.recordEventEnd(EVENT_ID);
    }
    

    The Tracer object records the entry/exit of method switchState with event ID 0.

  5. Finally, to enable the MicroEJ Core Engine trace system, set the core.trace.enabled option to true. This can be done from a launch configuration: check Runtime > Enable execution traces option.

    ../_images/tuto_microej_trace_property.png

This produces the following output:

[TRACE: Application] Event 0x0()
[TRACE: Application] Event End 0x0()

Note

The default Platform implementation of the Trace library prints the events to the console. See Platform Implementation for other available implementations such as SystemView tool.

Log with the Message Library

The ej.library.runtime.message Message library was designed to enable logging while minimizing RAM/ROM footprint and CPU usage. For that, logs are based on message identifiers, which are stored on integers instead of using of constant Strings. In addition to a message identifier, the category of the message allows the user to find the corresponding error/warning/info description. An external documentation must be maintained to describe all message identifiers and their expected arguments for each category.

Principles:

  • The MessageLogger type allows for logging messages solely based on integers that identify the message content.
  • Log a message by using methods MessageLogger.log(…) methods, by specifying the log level, the message category, and the message identifier. Use optional arguments to add any useful information to the log, such as a Throwable or contextual data.
  • Log levels are very similar to those of the Logging library. The class ej.util.message.Level lists the available levels.
  • Loggers rely on the MessageBuilder type for message creation. The messages built by the BasicMessageBuilder follow this pattern: [category]:[LEVEL]=[id]. The builder appends the specified Object arguments (if any) separated by spaces, then the full stack trace of the Throwable argument (if any).
  • The FilterMessageLogger allows to filter messages actually logged based on a threshold level (defaults to INFO). The threshold level can be modified dynamically with FilterMessageLogger.setLevel(). Use the system FilterMessageLogger.INSTANCE or create a new logger to configure the level of logged messages per instance.

Here is a short example of how to use this library to log the entry/exit of the switchState() method:

  1. To use this library, add this dependency line in the module.ivy:

    <dependency org="ej.library.runtime" name="message" rev="2.1.0"/>
    
  2. Call the message API to log some info:

    private static final String LOG_CATEGORY = "Application";
    
    private static final int LOG_ID = 2;
    
    public static void switchState(ApplicationState newState) {
       previousState = currentState;
       currentState = newState;
    
       FilterMessageLogger.INSTANCE.log(Level.INFO, LOG_CATEGORY, LOG_ID, previousState, currentState);
    }
    

This produces the following output:

Application:I=2 UNINSTALLED INSTALLED

Log with the Logging Library

The ej.library.eclasspath.logging Logging library implements a subset of the standard Java java.util.logging package and follows the same principles:

  • There is one instance of LogManager by application that manages the hierarchy of loggers.
  • Find or create Logger objects using the method Logger.getLogger(String). If a logger has already been created with the same name, this logger is returned, otherwise a new logger is created.
  • Each Logger created with this method is registered in the LogManager and can be retrieved using its String ID.
  • A minimum level can be set to a Logger so that only messages that have at least this level are logged. The class java.util.logging.Level lists the available standard levels.
  • The Logger API provides multiple methods for logging:
    • log(…) methods that send a LogRecord to the registered Handler instances. The LogRecord object wraps the String message and the log level.
    • Log level-specific methods, like severe(String msg), that call the aforementioned log(...) method with the correct level.
  • The library defines a default Handler implementation, called DefaultHandler, that prints the message of the LogRecord on the standard error output stream. It also prints the stack trace of the Throwable associated with the LogRecord if there is one.

Here is a short example of how to use this library to log the entry/exit of the switchState() method:

  1. Add the following dependency to the module.ivy:

    <dependency org="ej.library.eclasspath" name="logging" rev="1.1.0"/>
    
  2. Call the logging API to log some info text:

    public static void switchState(ApplicationState newState) {
       previousState = currentState;
       currentState = newState;
    
       Logger logger = Logger.getLogger(Main.class.getName());
       logger.log(Level.INFO, "The application state has changed from " + previousState.toString() + " to "
             + currentState.toString() + ".");
    }
    

This produces the following output:

main INFO: The application state has changed from UNINSTALLED to INSTALLED.

Note

Unlike the two other libraries discussed here, the Logging library is entirely based on Strings (log IDs and messages). String operations can lead to performance issues and String objects use significant ROM space. When possible, prefer using a logging solution that uses primitive types over Strings.