Logging systems Petals ESB uses the logging system provided by the JDK. The logger configuration is determined according to the following ordered rules: the file defined as value of the Java system property petals.container.log.config.file (set on the Java command line through the environment file, ie. env.sh|bat), the file defined as value of the property petals.container.log.config.file of the local container configuration, ie. server.properties, the file 'loggers.properties' located in the same path than the local container configuration, ie. server.properties. 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 Debugging process execution 2.6 Disabling log file hierarchy 2.7 Performances 2.8 Using your own log handler 2.9 Enabling logging traces of the JMX server 3 Tuning your logging configuration 3.1 How to set the log level of components separately 3.2 Petals ESB automatically started on Debian-based system 3.3 Petals ESB manually started or installed through ZIP archive 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.

According to the log level of the logger, the debug traces generated with log level FINE, FINER and FINEST can be extended with class and method name where the trace occurs:

• FINE:
  • all traces except debug traces are printed without class and method name,
  • the debug traces are printed without class and method name, and no method entrance traces 'start'/'end'/'call' are generated,
• FINER:
  • all traces except info and debug traces are printed without class and method name,
  • the info and debug traces are printed with class and method name, and no method entrance traces 'start'/'end'/'call' are generated,
• FINEST:
  • all traces except info and debug traces are printed without class and method name,
  • info traces, debug traces and method entrance traces 'start'/'end'/'call' are printed with class and method name.

The new level MONIT 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 :

For a process activity, the log message is composed of several fields as key/value depending on the JBI component and activity. See Monitoring processes with their 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:

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 split 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 ...

Debugging 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.

In order to dump message, this log handler needs to maintain a pool of object helping it to transform in-memory XML representation of the payload to text.
Depending on the configuration, this can impede performances: it will restrict the number of concurrent dump to disk, but the default value should be ok, only change it in case of problems.

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:

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

Disabling log file hierarchy

By default, the Petals ESB configuration uses the log handler org.ow2.petals.log.handler.PetalsFileHandler that manages a log files hierarchy. If you don't use log trace MONIT, you have always this file hierarchy that could contains warning or severe errors. In some case, you will prefer to have only one global log file instead of this hierarchy to avoid a potential huge number of files. Simply replace the log handler org.ow2.petals.log.handler.PetalsFileHandler by, for example, java.util.logging.FileHandler:

# Configuration of the log handlers
#####################################
handlers=java.util.logging.ConsoleHandler, java.util.logging.FileHandler

# Configuration of the handler FileHandler
##################################################
java.util.logging.FileHandler.level=CONFIG
java.util.logging.FileHandler.pattern=/var/log/petals/petals%u-%g.log
java.util.logging.FileHandler.limit=50000
java.util.logging.FileHandler.count=10
java.util.logging.FileHandler.formatter=org.ow2.petals.log.formatter.LogDataFormatter

To be able to print correctly MONIT traces, you must use the formatter org.ow2.petals.log.formatter.LogDataFormatter

Performances

Performances decrease when activating MONIT log level, and mainly if the log handler org.ow2.petals.log.handler.PetalsPayloadDumperFileHandler is enabled. To reduce the performance impact, you can apply an asynchronous pattern, for example using the log handler java.util.logging.MemoryHandler linked to org.ow2.petals.log.handler.PetalsFileHandler:

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

java.util.logging.MemoryHandler.level=FINEST
java.util.logging.MemoryHandler.size=1000
java.util.logging.MemoryHandler.target=org.ow2.petals.log.handler.PetalsFileHandler

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 to 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 system-extensions 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

How to set the log level of components separately

Each binding component instance or service engine instance have its own logger that you can configure separately. The logger name has the following pattern: Petals.Container.Components.<component-jbi-identifier>, where <component-jbi-identifier> is the unique identifier of the component that you can find in its JBI descriptor.

With the following configuration, all components installed will log with a MONIT level, except the BC SOAP 'petals-bc-soap' and the BC SQL 'petals-bc-sql-1' that uses the level INFO. The second BC SQL 'petals-bc-sql-2' will use the level FINE:

...
Petals.Container.Components.level=MONIT
Petals.Container.Components.petals-bc-soap.level=INFO
Petals.Container.Components.petals-bc-sql-1.level=INFO
Petals.Container.Components.petals-bc-sql-2.level=FINE
...

Petals ESB automatically started on Debian-based system

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

Petals ESB manually started or installed through ZIP archive

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.