Projects:Upgrade to Log4j2/Specs

Contents 1 Requirements 1.1 Overview 1.2 Logging in Openbravo with log4j 1.x 1.2.1 Configuration 1.2.2 Logging events 1.2.3 Logger configuration in backoffice 1.3 Logging in Openbravo with log4j 2.x 1.3.1 Configuration 1.3.2 Logging events 1.3.3 Logger configuration in backoffice 2 Code migration 3 Found issues 3.1 Invalid byte tag in constant pool: 19 3.2 Java 11 Support issues 3.2.1 Tomcat 3.2.2 Ant 3.3 <Properties> location in config

Requirements

Overview

At the beginning of this project, the log4j used in Openbravo was 1.2.16, which was released around april 2010. Since then the Apache Software Foundation rewrote the library from scratch and added a number of new features and improvements and released it as Log4j 2.

The main goal of this project is to upgrade the log4j library to the latest version available and simplify the current logging infrastructure.

Having the latest version is convenient for developers as it makes it easier to report bugs and to avoid having bugs in the code that has already been reported and fixed by the library maintainers, not to mention that we may take advantage of the new features introduced. As of november 2018, the latest stable version is 2.11.1.

For more info about the new features introduced in Log4j 2.x, see [1]

Logging in Openbravo with log4j 1.x

Logger configuration was scattered throughout all the project and could be performed in basically 2 ways:

• Log configuration files (log4j.lcf/properties): There were 10 configuration files in the backoffice project. Most of them have little to no changes with each other.
• Programmatic configuration: There were some cases that the configuration of the logger is set by code instead of using the config files. Examples of this were found in OBBaseTest or DalInitializingTask

Configuration

For the web application running in a container, console output is disabled by default. Console appender should be appended to the root level logger in order to see log messages.

Apart from the console output if enabled, logs are stored in two files: openbravo.log for general log messages, and openbravo_hibernate.log for Hibernate-specific messages. Both logfiles are stored in ${CATALINA_BASE}/logs. Files are limited to 10MB and there can only be 1 backup file at a time.

For testing, a TestLogAppender is appended to the root logger in order to save certain log messages in a in-memory structure and is used to make assertions on log messages in some tests. This is used for example in ErrorTextParserIntegrationTest.

For build tasks there are another appender called OBRebuildAppender which stores log output in the ad_error_log table. This log is stored both from builds executed from the command line and for system rebuilds executed from the Module Management window.

Logging events

The main usage of log4j in Openbravo is for logging events in the appenders defined in configuration. For log4j this is done the following way

import org.apache.log4j.Logger;
...
private static final Logger log = Logger.getLogger(<classname>.class);
...
log.info("Message to log");

or, if using slf4j API:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
...
private static Logger log = LoggerFactory.getLogger(<classname>.class);
...
log.info("Message to log");

Logger configuration in backoffice

It is possible to set a log level for a particular logger in a live Openbravo instance. In Session Preferences window there is a "Change Logs" button that shows a list with all loggers and lets you change the level of the logger one by one.

Logging in Openbravo with log4j 2.x

Logger configuration is greatly simplified and centralized. Now we consider 3 main logging scenarios, and thus now we have only 3 config files:

• Build process: This includes both the ant build via command line and the system rebuild launched by Module Management window. Configured using config/log4j2.xml.
• Testing: For test execution. Configured using src-test/src/log4j2-test.xml.
• Running in web application container: Used for code executed from a web container like Tomcat. Configured using config/log4j2-web.xml.

Configuration

Logging configuration is done in the files mentioned above, and programmatic configuration has been reduced to a minimum. The exceptions are:

• For testing environment, there is a ConfigurationFactory class configured to use as a factory which adds to the file configuration a TestLogAppender as a appender for the Root level logger. This way we ensure the TestLogAppender will be always present regardless the content of the log4j2-test.xml file.

The openbravo_hibernate.log is removed from configuration and now all logs will be stored on openbravo.log. For this file the rollover policy changes as well:

• The maximum file size is raised to 1GB. When this size is reached, file is archived and compressed using gzip.
• Logs are archived on a daily basis as well. Archived files will be removed when their last modified date is older than 7 days until there is a maximum of 7 files.

OBRebuildAppender is set in the build config.

Logging events

The new way to create and use a logger is as follows:

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
...
// This call uses the current class name as the logger name
private static Logger log = LogManager.getLogger();
...
// Logger can be called just as usual
log.info("Message to log");
// you can use placeholders in the string, just like slf4j
log.debug("This is used {} times", i);

Logger configuration in backoffice

The old Change Log Window has been removed and replaced by General Setup|Application|Log Management. This window shows all Loggers and their corresponding log level depending on the Log Configuration. This screen allows sorting, filtering and selecting multiple entries.

As a note, for log4j2 a Logger is a object that logs events following a series of rules (minimum log levels, destination appenders...). These rules are the Log Configuration and there is always a base configuration which is called the Root logger and extending from this a series of configurations for specific packages/classes. This window will create a log configuration with the desired level for each selected class if not already exists.

Code migration

To make the migration of all existing code as fast as possible, a script was implemented to automatically migrate all log4j 1.x/slf4j Logger creation to use the new log4j2 API. The script can be found here [2].

This script will scan all .java files in the backoffice code and all modules and automatically changes the Logger creation code in all files where found. The only exception is when Logger is created using a custom name instead of using the class name:

private static Logger log = Logger.getLogger("customName");

In that case, a warning will be shown in the output and the file won't be modified. In any case, it is recommended to double check and find compilation errors/warnings after passing the script and before pushing the code in case there are a corner case the script couldn't handle.

Found issues

Invalid byte tag in constant pool: 19

When starting Openbravo with log4j2 in Tomcat 7.0 and Java 8, the following error appears when Tomcat restarts:

Nov 19, 2018 9:19:20 AM org.apache.catalina.startup.ContextConfig processAnnotationsJar
SEVERE: Unable to process Jar entry [META-INF/versions/9/module-info.class] from Jar [jar:file:/home/openbravo/Projects/log4j2/pi-merge/out/artifacts/openbravo_war_exploded/WEB-INF/lib/log4j-api-2.11.1.jar!/] for annotations
org.apache.tomcat.util.bcel.classfile.ClassFormatException: Invalid byte tag in constant pool: 19
	at org.apache.tomcat.util.bcel.classfile.Constant.readConstant(Constant.java:97)
	at org.apache.tomcat.util.bcel.classfile.ConstantPool.<init>(ConstantPool.java:54)
	at org.apache.tomcat.util.bcel.classfile.ClassParser.readConstantPool(ClassParser.java:174)
	at org.apache.tomcat.util.bcel.classfile.ClassParser.parse(ClassParser.java:83)
	at org.apache.catalina.startup.ContextConfig.processAnnotationsStream(ContextConfig.java:2119)
	at org.apache.catalina.startup.ContextConfig.processAnnotationsJar(ContextConfig.java:1981)
	at org.apache.catalina.startup.ContextConfig.processAnnotationsUrl(ContextConfig.java:1942)
	at org.apache.catalina.startup.ContextConfig.processAnnotations(ContextConfig.java:1927)
	at org.apache.catalina.startup.ContextConfig.webConfig(ContextConfig.java:1332)
...

This is caused by a bug in older versions of Tomcat when a library contains Java 9 module info. This should be fixed in Tomcat starting from 7.0.76, 8.0.42, 8.5.12 or 9.0.0.M18 onwards. Bug info can be found here [3].

Java 11 Support issues

Log4j2 is packaged as a multi-release JAR, which is a new feature introduced in Java 9 which lets a JAR to have multiple versions of the same class file and load them depending on the JVM version used. Log4j uses this feature to provide multiple implementations of StackLocator, which originally uses sun.reflect.Reflection.getCallerClass, but starting from Java 9 uses another implementation, as this call is deprecated and removed starting from Java 11. When this new implementation is not loaded, it might result in a crash when executing this code in Java 11+.

Tomcat

Tomcat added support to these kind of JARs starting from the following versions:

• 7.0.83
• 8.0.48
• 8.5.24
• 9.0.2

Older versions won't start if using Java 11+.

Ant

As of version 1.10.5, ant does not support multi-release JARs for custom Ant Tasks. This issue have been reported and will be fixed starting from ant 1.10.6. Until Openbravo uses the newer version of ant, the following parameter must be added to ANT_OPTS variable in order to force support of MRJARs and make build works when compiling using Java 11+:

ANT_OPTS="-Djdk.util.jar.enableMultiRelease=force"

<Properties> location in config

It is not documented in log4j docs, but if declaring properties, it is required that they have to be place at the beginning of the document, just after <Configuration> tag. This is reported and aknowledged as a documentation issue. See [4].