Logging systems

Petals ESB uses two distinct logging systems. Most of the container apart from the registry uses the logger provided by the JDK, while the registry uses Apache log4j.

The Petals ESB logger configuration is splitted into two files, one for each logging system:

the JDK Logging system is configured according to the following ordered rules:
1. the file defined as value of the Java system property petals.container.log.config.file to set on the Java command line through the environment file, ie. env.sh|bat,
2. the file defined as value of the property petals.container.log.config.file of the local container configuration, ie. server.properties,
3. the file 'loggers.properties' located in the same path than the local container configuration, ie. server.properties.

log4j.properties: is configured through the file 'log4j.properties' located in the same directory than the local container configuration file, ie. server.properties.

An issue JIRA already exists to merge both logging systems: PETALSESBCONT-227

Each property value of the JDK logging system configuration file can contain reference to other properties using a placeholder as:

org.ow2.petals.log.handler.PetalsFileHandler.basedir=${petals.log.dir}

Available properties to use as placeholder are:

the system properties including all properties defined on the java command line using the flag '-D',
the properties of the container configuration file, ie. server.properties.

Think to use the environment file, ie. env.sh|bat, instead of updating the Petals startup script to set your system properties.

Table of contents

1 Logging systems
2 Petals Logging specificities

2.1 Log levels
2.2 Default levels
2.3 Petals formatter
2.4 Splitting log files
2.5 Debuging process execution
2.6 Using your own log handler
2.7 Enabling logging traces of the JMX server

3 Tuning your logging configuration
4 Known problems

4.1 No trace more precise than INFO level are logged in the log file

Contributors

No contributors found for: authors on selected page(s)

Petals Logging specificities

You can find more informations about few concepts mentioned below in glossary.

Log levels

Petals defines a new specific level: MONIT. This level is used to trace the process activities and permit to deduce the process execution launched by an initial request.

The level MONIT is inserted between levels CONFIG and FINE:

SEVERE (highest value): An error occurs when the service can not be provided:
- In a Petals ESB container point of view, an error is something that stops the processing of an internal component. Consequently, the Petals ESB is stopped because it can assume its functions,
- In a component (BC/SE) point of view, an error is something that stops the processing of the SE or BC, but other components are always running correctly. Consequently, the component could be stopped,
- In a service (service-unit) point of view, an error is something that stops the processing of a service, each service invocation will fail, but other services deployed on the same component are correctly running. Consequently, the service could be stopped,
WARNING: A warning occurs when the service is partially provided and is compensated by a default behavior or it could be hot-fixed without restart or re-installation,
INFO: The information level highlights the provided service. Such a trace is logged parsimoniously. For example, service life cycle states are logged with this level,
CONFIG: All parameter values are logged with this level,
MONIT: This level is used to trace incoming and outgoing service messages to be able to monitor process executions in a business point of view,
FINE: All traces that can help a problem analysis are logged with this level.
FINER: All traces that can help a problem analysis are logged with this level.
FINEST (lowest value) : All traces that can help a problem analysis are logged with this level.

This new level comes with dedicated information. So, to be printed, a new formatter was created: org.ow2.petals.log.formatter.LogDataFormatter. This formatter can be used with standard handlers as java.util.logging.ConsoleHandler.

To trace exchange activities into files, it is better to have a policy based on one log file per process instance instead of having one big file. One file by process instance is more human readable. So a new file handler is also provided: org.ow2.petals.log.handler.PetalsFileHandler.

The MONIT level permits also to dump the message exchange content using another dedicated file handler: org.ow2.petals.log.handler.PetalsPayloadDumperFileHandler. It is based on the file handler 'org.ow2.petals.log.handler.PetalsFileHandler' adding it capabilities to dump the payload of message exchanges.

Default levels

The default root logger level is WARNING. It means that all classes log only SEVERE and WARNING information.

The default Petals root logger level is INFO. That's why all Petals components will log only SEVERE, WARNING and INFO information.

The default components level is MONIT.

You can enable logging and specify a specific level for each module (container, component, cdk...). Here is how you would set debugging from Petals. You would need to ensure the Handler's level is also set to collect this threshold, so FINEST or ALL should be set.

##Petals level
Petals.level = FINEST

#Handler Configuration
java.util.logging.ConsoleHandler.level = FINEST

Example of configuration to debug (Level FINEST) petals-bc-soap component:

##Petals level
Petals.level = INFO #Log level for all petals services
Petals.Container.Components.level = MONIT #log level for all components
Petals.Container.Components.petals-bc-soap.level = FINEST #Log level for petals-bc-soap component

#Handler Configuration
java.util.logging.ConsoleHandler.level = FINEST

Petals formatter

The Petals formatter org.ow2.petals.log.formatter.LogDataFormatter is used for both standard traces of the Petals ESB container and process activity traces. The format of the logged message is :

Petals Node Name YYYY/MM/DD HH:MM:SS,FFF GMT LOG LEVEL [+LOGGER NAME+] : LOG MESSAGE

For a process activity, the log message is composed of several fields as key/value depending on the JBI component and activity. See Monitoring Petals ESB Flows with its logs for more information on fields.

Example of logging output with the Petals formatter:

sample-0 2013/03/07 10:31:31,084 GMT+0100 INFO [Petals.Communication.RMIConnector] : JMX RMI server started at : service:jmx:rmi:///jndi/rmi://localhost:7700/jmxRmiConnector
...
sample-0 2013/03/07 10:31:32,459 GMT+0100 MONIT [Petals.Container.Components.petals-bc-soap] : traceCode = 'consumeFlowStepBegin',flowInstanceId = '62cdea40-cf20-11e0-bdfa-000c29523cc7',flowStepId = '62ce3860-cf20-11e0-bdfa-000c29523cc7',flowInterfaceName = '{[http://usecase1/bpel-P12/]}interfaceName1',flowServiceName = '{[http://usecase1/bpel-P12/]}serviceName1',flowEndpointName = 'endpointName1',flowOperationName = '{[http://usecase1/bpel-P12/]}process',client = '192.168.1.157',requestedURL = 'http://192.168.1.196:8084/petals/services/soap-C1'

Splitting log files

Petals ESB allow to split its log records into a log files hierarchy. Thanks to the Petals file handler 'org.ow2.petals.log.handler.PetalsFileHandler' which can redirect log records to separate files according to their nature:

if the log record is generated into a process activity context, it is redirected in the log file dedicated to the process instance,
otherwise, the log record is sent into the global log file.

The default log files hierarchy is the following one:

basedir
- petals.log: The global log file in which log records that are not generated into a process activity context are logged,
- flow-monitoring: Directory in which log files of log records associated to process activities are written,
  - <uid>: Directory of log files associated to the activities of only ONE process instance,
    - petals.log: The log file of process activities of only ONE process instance.

In addition to the standard properties (level and formatter), the specific configuration properties of the Petals file handler are:

Property	Default value	Description
`xxx.basedir`	The value of the system property '`petals.log.dir`'	The absolute root directory of the log file hierarchy
`xxx.flows-subdir`	`flow-monitoring`	The name of the directory contained in the directory `basedir` where log files of log records associated to process activities are written. If the value is a relative, it will be relative to the base directory. Absolute value is accepted.
`xxx.logFilename`	`petals.log`	The name of log files. It's a relative filename value, without directory

where xxx is the name of the log handler: org.ow2.petals.log.handler.PetalsFileHandler or org.ow2.petals.log.handler.PetalsPayloadDumperFileHandler.

The Petals file handler processes all log record according to their log level and its own log level. So splitted files can be generated containing only traces with log level SEVERE, WARNING or INFO when the min log level is set to INFO. To have no splitted files (ie. no traces about process execution), you must disable the Petals log handler, and add the default log file handler of the JDK logging system java.util.logging.FileHandler to retain a global log file:

handlers=java.util.logging.ConsoleHandler, java.util.logging.FileHandler

java.util.logging.ConsoleHandler.level=FINEST
java.util.logging.ConsoleHandler.formatter=org.ow2.petals.log.formatter.LogDataFormatter

java.util.logging.FileHandler.level=FINEST
java.util.logging.FileHandler.pattern=%h/petals-esb-enterprise-edition/petals-esb/logs/petals.log
java.util.logging.FileHandler.formatter=org.ow2.petals.log.formatter.LogDataFormatter

...

Debuging process execution

In the previous paragraph, you see how to get traces about process instance executions. For a debugging or replaying purpose, it is interesting to get the content of messages exchanged. This is possible using another Petals file log handler: org.ow2.petals.log.handler.PetalsPayloadDumperFileHandler based on the previous file log handler org.ow2.petals.log.handler.PetalsFileHandler.

The content of the messages are dumped in the log files hierarchy defined above in the directory dedicated to the current process instance. One dump file is created for each message sent or received containing its XML payload. The path of the dump file is logged, if possible as a relative path to basedir, in the MONIT trace through a dedicated field: payloadContentDumpFile.

This Petals file log handler org.ow2.petals.log.handler.PetalsPayloadDumperFileHandler has the same configuration properties than its parent and extends it with the following parameters:

Property	Default value	Description
`xxx.dump-basedir`	The default value is the flows sub-directory	The name of a root directory that will contain all dump files organized by flow using an intermediate sub directory associated to the flow. If the value is a relative, it will be relative to the flows sub-directory. Absolute value is accepted.

where xxx is the name of the log handler: org.ow2.petals.log.handler.PetalsPayloadDumperFileHandler.

An issue JIRA already exists to dump the whole content of messages, including properties and attachments: PETALSESBCONT-228

Using your own log handler

Since the version 4.2 of Petals ESB, custom log handlers are supported. See the source project code of Petals provided log handlers to write your own.

If you want redirect the MONIT traces elsewhere than into log files, you can use your own log handler. Just put its JAR file and dependencies into the Petals library directory, and configure your log handler into the logging configuration file.

Enabling logging traces of the JMX server

To enable logging traces of the Petals Container JMX server (MX4J), uncomment the property 'mx4j.log.priority' in the environment configuration file:

# Uncomment following line to enable logging of the JMX Server of Petals
# Available priorities are: trace, debug, info, warn, error, fatal
PETALS_JAVA_OPTS="$PETALS_JAVA_OPTS -Dmx4j.log.priority=debug"

Possible values for the property are: fatal, error, warn, info, debug, trace

Tuning your logging configuration

If your Petals ESB containers used in production are:

installed on Debian-based systems through Debian packages,
and, running in automatic mode,

you can disable the log handler 'console' for which all generated traces on the standard output are discarded, and used only a log handler 'file' (java.util.logging.FileHandler, org.ow2.petals.log.handler.PetalsFileHandler or org.ow2.petals.log.handler.PetalsPayloadDumperFileHandler according to your needs about the flow monitoring).

# Configuration of the log handlers
#####################################
#handlers=java.util.logging.ConsoleHandler, org.ow2.petals.log.handler.PetalsFileHandler
handlers=org.ow2.petals.log.handler.PetalsFileHandler

If your Petals ESB installation does not satisfy the previous criteria (not running in automatic mode on a Debian-based system), you can improve performance decreasing the level of the log handler 'console':

# Configuration of the handler ConsoleHandler
##################################################
java.util.logging.ConsoleHandler.level=INFO
java.util.logging.ConsoleHandler.formatter=org.ow2.petals.log.formatter.LogDataFormatter

You can also remove the log handler 'console' but it's disturbing because no more trace will be printed.

Known problems

No trace more precise than INFO level are logged in the log file

Operating system: Debian-based Linux

Symptoms:

Petals ESB is installed with the Debian packages,
A Petals ESB container is started through the automatic startup (sudo service petals-esb start), or when booting the host,
The log configuration file defines level FINEST for JBI component, or equivalent,
No trace with level FINEST are flushed in the global log file (/var/log/petals-esb/<container-name>/petals.log)

Solutions to try:

Change the log level of the log handler org.ow2.petals.log.handler.PetalsFileHandler or org.ow2.petals.log.handler.PetalsPayloadDumperFileHandler and set it the value FINEST.

Explanations:
By default, the log configuration set a log level FINEST to the log handler 'console', and the standard output of Petals ESB container is redirected to /dev/null by the SysV init.
The global log file is the file generated by the log handler org.ow2.petals.log.handler.PetalsFileHandler or org.ow2.petals.log.handler.PetalsPayloadDumperFileHandler.

Petals ESB 4.2 Wiki

Helpful links

Logging in Petals