View source | Discuss this page | Page history | Printable version   
Toolbox
Main Page
Upload file
What links here
Recent changes
Help

PDF Books
Add page
Show collection (0 pages)
Collections help

Search

How To Log

Contents

Introduction

This document provides some guidelines on what and how to log.

Openbravo generates a log file which serves different purposes:

It is intended to be consumed by technical staff such as system administrators, developers, support team, etc.

To learn how to configure logs, read this document.

How to log

Warn-icon.png   Standard output System.out, System.err or printStackTrace SHOULD NEVER BE USED.

They write log in a different file catalina.out, which has several inconvenients:

  • Having a single source of logs makes much easier to look for problems.
  • catalina.out is not automatically rotated, so it's size might increase without limit.
  • Important information is not automatically included: it does not include timestamp nor class generating the log.


Openbravo includes log4j as logging framework, so all logs should be written making use of it.

The following snippet shows how to write a warning line in log:

 
 import org.apache.log4j.Logger;
 
 private class Example {
   // gets logger for this class
   private static final Logger log = Logger.getLogger(Example.class);
 
   private void process(Invoice invoice) {
     // ...
     log.warn("Invoice " + invoice.getId() + " could not be processed because config XXX is missing");
   }
 }

Alternatively, it is possible to use slf4j API which finally will also use log4j. It provides, for example, param substitution. The following code is equivalent to previous:

 
 // note how different classes are imported...
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
 private class Example {
   // ... and getting logger is slighgtly different
   private static final Logger log = LoggerFactory.getLogger(Example.class);
 
   private void process(Invoice invoice) {
     // ...
 
     // it allows to define messages with paramaters
     log.warn("Invoice {} could not be processed because config XXX is missing", invoice.getId());
   }
 }

Dissecting a line of log

The log produced by any of the two previous snippets will look like follows:

1f923ef8 2017-07-21 10:03:22,971 [http-bio-8080-exec-4] WARN org.openbravo.example.Example - Invoice AAA could not be processed because config XXX is missing
-------- ----------------------- ---------------------- ---- -----------------------------   ----------------------------------------------------------------
 |        |                       |                      |    |                               |-> Actual message
 |        |                       |                      |    |-> Java class producing the message
 |        |                       |                      |-> Message level
 |        |                       |-> Thread name
 |        |-> Timestamp when the log was generated
 |-> Openbravo professional license ID

What to log

Logs are a very important part of the application, as such, it is key to carefully think what is the relevant information to be logged. Note that, usually, logs are going to be read time after they are created, so they should contain whatever it is needed to reproduce problems in future.

Level

Logging can be written at different levels. When a logging level is enabled, all messages written at that level or at any higher one will be saved in the log file. By default, INFO and higher levels are written skipping lower levels. This can be modified permanently or at runtime to a different level for every logger or for specific ones.

The available levels, ordered from higher to lowest priority are:

Context

As log should provide enough information to know what is going on, it's of paramount importance to include relevant context to every line of log. This context, will depend on what the code is doing, in general, it should include the relevant parameter values to allow to reproduce the execution.

For example:

 
  // DO NOT do this!
  log.warn("Could not process invoice.");

this code warns about an invoice that could not be processed, but it does not provide any information about which invoice and why it failed.

The following would be slightly better:

 
  log.warn("Invoice {} could not be processed", invoice.getId());

because it indicates the invoice that failed, so it would help to try to reproduce the problem. Depending on the process itself, it might also require to include some other parameters, for example:

 
  log.warn("Invoice {} could not be processed with action: {}", invoice.getId(), action);

Caveats

Logging can create performance overhead, be careful when selecting what to log at each level. For example, if you only have a Business Partner ID, it may be preferable to only log it than its name if it is necessary to retrieve it from database.

Be careful when logging context not to create new exceptions. For example, the following log line could throw a NullPointerException in case invoice variable is null when it is executed:log.debug("Processing invoice", invoice.getId());

Stack traces

Stack traces show the call stack of a thread in the moment they were generated, this is, recursively the line of code that was in execution as well as the line that invoked current method, the line that invoked that method and so on.

Some times, they can give a great context to developers to find causes of problems.

The following code will log an error message and the stack trace of that thread when it occurred:

 
  try {
    // ...
  } catch (MyException e) {
    log.error("could not process invoice " + invoice.getId(), e);
    // handle error here: just logging won't fix it
  }
Bulbgraph.png   Note the following code will not include any stack trace:
 
  } catch (MyException e) {
    log.error(e); // no stack trace!!
  }

as it is equivalent to:

 
  } catch (MyException e) {
    log.error(e.getMessage());  // no stack trace!!
  }

Although they can be useful in some occasions, they also tend to be very verbose. Log files with too many stack traces are usually difficult to read. So, as any other context information, it is required to carefully select whether to include them or not. As a basic guideline:

Include them for:

But do not include them for:

OBException

OBException is an unchecked exception. Before 3.0PR17Q4 when a new instance was created, it was logged by default including stack trace. It is possible to change this behavior using overloaded constructors:

 
  // Pre 3.0PR17Q4
  throw new OBException("Something failed"); // logs exception with stack trace
 
  throw new OBException("Something failed", false); // does not log anything
Bulbgraph.png   This feature is available starting from 3.0PR17Q4.

Since 3.0PR17Q4, default behavior has changed not to log by default.

 
  // Post 3.0PR17Q4
  throw new OBException("Something failed"); // does not log anything
 
  throw new OBException("Something failed", true); // logs exception with stack trace

It is possible, though, to automatically generate log whenever a new OBException instance is created by setting org.openbravo.base.exception.OBException logger at DEBUG level.

Retrieved from "http://wiki.openbravo.com/wiki/How_To_Log"

This page has been accessed 190 times. This page was last modified on 1 August 2017, at 05:44. Content is available under Creative Commons Attribution-ShareAlike 2.5 Spain License.