IFS framework for logging and debugging of IFS Applications is based upon standard Java framework available as of Java SE package java.util.logging. Basic concepts are described in the document Java Logging Overview.
IFS logging framework encapsulates standard
Loggers and Handlers and add configuration possibilities that are
better fitted for IFS Applications needs. Logging behavior can be defined
statically using configuration files or dynamically using, for example, Java console with support for JMX MBean configuration.
This section is intended to provide the information on how to set up and
configure server side logging framework.
IFS Logging framework is based upon two main concepts: Loggers and Handlers. A Logger is an object to which the application writes its logging and debugging statements. Loggers put their output to a common area in memory. Handlers read from this area and write to the output media. Both Loggers and Handlers use categories and logging levels to limit the amount of logged information. In addition Handlers can utilize filters to limit amount of information furthermore.
A Handler can collect information from several Loggers, but also information collected by a specific Logger can be processed by several Handlers. A Handler can never write more information than the amount that was supplied by Loggers, so, for example, setting handler level to 'debug' when logger level is 'error' will not bring more output.
A Logger in an object that is used for collecting logging and debugging output. A Logger instance is created per thread and category and is reused during subsequent calls to the same thread as long as the corresponding log level is unchanged. Logger instances are immutable, which means a new instance will be created on log level changes performed dynamically through the JMX MBean management console.
Handler can be seen as a destination for all the logging output.
Currently IFS logging framework defines two types of Handlers: console
handler that prints its output to the console window, which typically can be
captured by the actual application server, and file handler that writes the
output to a file.
There are two versions of file handlers: text handler writes its output as a
plain text and XML handler, which formats its output as an XML document.
It is possible to have several handlers defined, even of the same type.
It is possibly to add and remove Handlers dynamically through the JMX MBean management console. Such handlers are not persistent and will disappear once the current server is re-started or logging configuration re-read.
| Type | Description |
|---|---|
| console | Used for writing logging output to the console window |
| textfile | Used for writing its output to a plain text file |
| xmlfile | Used for writing output to an XML formatted file |
There are five levels of logging: error, warning, info, trace and debug.
| Level | Description |
|---|---|
| error | Typically used for logging of serious problems |
| warning | Used for logging of warnings in the system |
| info | Logging of messages of informational character |
| trace | Tracing of the system and light level debugging |
| debug | All the debug statements in the application code |
Levels works as filters controlling amount of information that is collected by Loggers and processed by Handlers. Levels can be changed permanently using configuration files, as described below, which requires restart of the application server, but it is also possible to change levels dynamically in a running system using application servers JMX MBean management console. Note however that because of the immutable nature of Loggers in use it can take some time before all running threads are updated with new values and new Logger instances are created.
A category defines a part or an area of the application or a type of event
that is about to be logged.
There are eleven categories defined in the system:
database, application, framework, gateway, integration, webclient,
batchprocessor, callsequence, request, response,
security.
| Category | Description |
|---|---|
| database | Is used for logging of the database calls |
| application | Dedicated for general purpose usage from the application code |
| framework | General purpose logging from the IFS Foundation1 framework code |
| gateway | Logging from the code of Client and SOAP Gateways |
| integration | Used for logging of different parts of the Integration area |
| batchprocessor | Used for logging of Batch Processor framework |
| callsequence | Is meant for tracing of the call sequence of methods |
| request | Is intended for tracing of client requests |
| response | Intended for tracing of response sent back to the client |
| security | Dedicated for all the security related logging events |
| timings | Used for timing measure of request |
Configuration files defining behavior of the logging framework have format of
typical Java properties file.
A properties file is a plain text file containing a list of pairs on form:
key=value
Each key-value pair occupies a single line. Lines starting with '#' character
are treated as comments. Empty lines are skipped.
More detailed documentation about the format is available
here.
Configuration files are optional. If no files are found, the logging framework will create a default console handler and set logging level to error.
During the start up process the framework will first search after a configuration file with name
ifs-logging.properties located in IFS configuration directory.
The directory can be specified directly using system property
fndext.configDir, otherwise it is assumed to be <ifs_home>/instance/<instance_name>/conf,
where <ifs_home> is given by a system
property fndext.home and <instance_name>
by system property fndext.instance.
After reading the first file (if present) the logging framework will make an
attempt to read a second one with name defined by system property
fndext.loggingConfig and located in the same, previously mentioned,
IFS configuration directory.
The second file, if present, will be read on top of the first one, which means that it is possible to complement and/or override definitions from the first configuration file.
Location of IFS configuration directory for an already set up system is normally
given by combination of <ifs_home> and
<instance_name>, which are also used for
location of other configuration files, e.g.
ifs.properties. Other applications that cannot execute from within
an <ifs_home> structure, like IFS
Installer, will be given location of configuration directory directly
through the system property fndext.configDir.
By default the Installer will add the mentioned system properties to all generated start scripts pointing out configuration files located in the directory <ifs_home>\instance\<instance_name>\conf of the current installation. The Installer will also create a configuration file for the application server and add system property specifying the configuration file name:
-Dfndext.loggingConfig=<file_name>
where <file_name> is normally j2ee-logging.properties.
Beside of the default configuration, the configuration file can contain some commented sections with template configuration. As by default the generated configuration file will cause creation of log and debug files in the directory <ifs_home>\instance\<instance_name>\logs\j2ee.
All configuration parameters are optional, but some of them can require presence of others.
Using the JMX MBean management console it is possible to re-read the configuration file without needing to restart the server.
Note that there is a risk for loosing some log entries for changed handlers when re-reading the configuration file. This is because all files (Handlers) that got their definitions changed have to be closed first before they can be open again based on the new definition.
There are two groups of parameters:
It is possible to define a global logging level for the entire system, but it is also possible to override this definition per category. But it is not possible to define a category specific logging level that would be less detailed than the global definition, for example if the global level is set to warning, a category specific level can be set to info, but not error. Such wrong definition will not generate any error, but will be ignored.
Level definitions in the configuration file can have one of the following two forms:
global.level=<level>
or
<category>.level=<level>
where <category> is one of the defined
categories and <level> represents a value of one of the defined
levels.
All level definition parameters are optional.
Level definitions will affect how much information is collected by corresponding
Loggers.
It is possible to define an arbitrary number of Handlers. Each Handler is identified by its own unique name. A Handler is defined by a group of parameters. By default a Handler will take care of all the output supplied by Loggers, but it is possible to filter the output by setting level per handler.
For example one can want to have a separate file for logging of errors only and yet another one for logging of all the output defined by the global level definition.
A section defining a Handler with all the possible parameters has a following form:
handler.<name>.type=<type> handler.<name>.filename=<filename> handler.<name>.level=<level> handler.<name>.filecount=<count> handler.<name>.maxsize=<limit> handler.<name>.perthread=true | false handler.<name>.pertag=true | false handler.<name>.categories=[!]<category_list> handler.<name>.includepackage=true | false handler.<name>.filter[.<no>]=[!]<filterclass>,<arguments>
where <name> is the name of the handler, <type> defines type of the handler and output format and can be one of defined handler types, <level> can be one of the defined logging levels and <filename> is the specification of the physical path to the log file, as described below.
The type definition is mandatory for a handler. For file handlers (of type textfile' and xmlfile) the file name specification is also mandatory. For console handler file specification will be ignored, but will not generate any error, if present. All the others parameters are optional.
Note: Usage of forward slashes ('/') as directory separators even on Windows when specifying handler file name.
Note: The XML handler generated XML files are referring to Document Type Definition file logger.dtd that is expected to be placed in the same directory as the XML log file itself. The DTD file can be downloaded from here. This is standard Java behavior.
File handlers support file rotation. Value of the filecount parameter denotes the number of files that will be used for file rotation and must be 1 or more. By default the file generation number will be added before file extension (or at the end of file name, if the file doesnt have any extension), but can be overridden by using %g placeholder in the file name.
Each time the application will start, the existing log files matching the file pattern will be rotated by one (up to <count>-1) and a new file will be created with generation number 0.
File rotation can also be based on the file size. In such a case the maxsize parameter has to specify the size of the file in bytes. Using modifiers K, M or G, meaning kilobytes, megabytes and gigabytes after the size specification is also supported. The size of zero means no limitation. By default file handlers will have file rotation enabled with 10 as a value of file count and no file size limitation.
In some circumstances it can be useful to create one log file per thread. To enable this set value of the perthread parameter to true. Then separate files will be created for each thread with thread ID (usually an integer number starting with 10) prefixing the file name. Similarly to the file rotation, there is a placeholder, %T, denoting the placement of the thread ID within the file name pattern.
It is also possible to create one log file per tag, which can be useful for example to separate log files per message queue in IFS Connect. To enable this set value of the pertag parameter to true. Then separate files will be created for each tag with tag name suffixing the file name. Similarly to the file rotation or thread handling, there is a placeholder, %G, denoting the placement of the tag name within the file name pattern.
The file name pattern consists of a string that includes the following special components that will be replaced at runtime:
| Placeholder | Description |
|---|---|
| / | The local pathname separator (all OS) |
| %t | The system temporary directory |
| %h | The value of the "user.home" system property |
| %g | The generation number to distinguish rotated logs |
| %u | An unique number to resolve conflicts |
| %T | The thread ID |
| %G | The tag name |
| %% | Translates to a single percent sign "%" |
File name pattern can also contain following substitution variables, which will be at replaced runtime with the current values of the corresponding system properties:
| Substitution variable | System property name |
|---|---|
| @IFS_HOME@ | fndext.home |
| @IFS_INSTANCE@ | fndext.instance |
| @IFS_MWS_SERVER@ | Name of the MWS Server |
| @IFS_CONFIG_DIR@ | fndext.configDir |
By default the handler will take care of all the output, but, beside of filtering based on the level, it is also possible to filter output based on the category. For that parameter categories has to be added and specify a comma separated list of categories that the handler should allow to pass through. If the list is preceded with an exclamation mark (!), the handler will instead exclude the output from the specified categories. A word 'classdebug' is also allowed as a category in the <category_list> specification.
The log/debug output lines can be quite long. Among other things they typically include the fully qualified class name, which, in the most of situations, is an unnecessary information. By using parameter includepackage that can have value true or false it is possible to specify if the class name should be written in its fully qualified form or only the class name itself.
The default behavior vary depending on handler type: console handlers will suppress the package names, but the file handlers will print out the fully qualified names.
Beside of filtering output based on level and/or category there is yet another mechanism for filtering. The logging framework supports concept of filters. An arbitrary number of filters can be connected to a handler. If only one filter is defined, it is enough to specify it using a single parameter filter, but if several filters should be defined, it is necessary to use a sequence number (an integer greater then 0) in conjunction to the parameter definition. The filters will be then applied according to the specified sequence number.
A filter specification consists of the filter class name followed by a comma separated list of arguments expected by the particular filter implementation. If the filter class name is preceded by an exclamation mark (!), the behavior of the filter will be the opposite it will block the output that should normally pass through and let all other output to pass through.
It is possible to design own filters according to the current needs, but the logging framework is supplied with three filter implementations:
handler.<name>.filter[.<no>]=[!]ifs.fnd.log.TagFilter,<tag_name>[,<tag_name>[,...]]
Log and debug outputs can be tagged with different identifiers, for example
queue or connector names. The purpose of this filter is to filter output based
on the tag value(s). This filter expects as argument a comma separated list of
tag names that in normal circumstances should be passed through. For example
handler configured to collect output from IFS Connect FILE_READER1 has following
filter specification:
handler.filereader1.filter=ifs.fnd.log.TagFilter,FILE_READER1
handler.<name>.filter[.<no>]=[!]ifs.fnd.log.TagTypeFilter,<tag_type>[,<tag_type>[,...]]
Tags can also be optionally grouped using the tag type. The purpose of this filter is to filter output based on the tag type value(s). This filter expects as argument a comma separated list of tag types that in normal circumstances should be passed through. This filter is supposed to be used together with the 'pertag' parameter and the '%G' placeholder denoting the tag name. Then there will be separate files, one per tag, but only for tags of the given type, e.g. tag type QUEUE will cause creation of separate log files, one per queue:
handler.queue.filter=ifs.fnd.log.TagTypeFilter,QUEUE
handler.<name>.filter[.<no>]=[!]ifs.fnd.log.ClassFilter,<class_name>[,<method_name>]
This filter can filter on class name and optionally method name. It expects
as the first and the only mandatory argument the class name. As a second,
optional, parameter it is possible to supply the filter with the method name.
Both class name and method name accept star (*) and question mark (?) as
wild cards. Output from classes or methods in classes that match the arguments
will be normally passed through. This filter can be very useful in conjunction
to class debugging, see below.
The logging framework supports an additional way of logging and debugging: class debugging.
Even if it is possible to use any log level in conjunction with this form of logging, the main purpose of this design pattern is to support debugging, which in normal circumstances shouldnt be logged by the normal loggers. It can be, for example, very heavy and detailed debugging that developers placed in the code that in normal cases is not so useful or will be to extensive, but which can be very useful when narrowing a specific problem, usually with support from the IFS staff.
To enable class debugging use the following syntax:
classdebug.<java-class-name>=<level>
where <java-class-name> is the fully qualified name of the java class
that should be debugged and <level> is one of the defined
levels, typically debug. The debug output will be
then send to any handler supporting the particular level and not filtering on
any category (except 'classdebug'), but by using filters (ifs.fnd.log.ClassFilter)
it is possible to customize a handler to filter outputs from a particular class
or method.
An example:
classdebug.ifs.fnd.tc.framework.executer.DynamicOperation=debug
Class loggers can be added and removed dynamically using the JMX MBean
management console.
There is a special Logger category, timings, for timing
of requests. Depending on the level Loggers of this category will
printout different amount of information to the connected Handlers:
All lines from this Logger category are tagged with REQID:<request_ID>.
The <request_ID> is an identifier generated based of the timestamp
since server start and together thread ID will uniquely identify the request.
The framework will also create a response HTTP header with name
Timings-Request-ID on form <managed_server>-<thread_ID>-<request_ID>,
e.g. Timings-Request-ID=ManagedServer1-71-44ea902. This makes it
possible to co-relate logging entries generated by this timer with entries in
the HTTP servers access log.
If the level is at least INFO, i.e. each SQL statement will generate at least one line in the log file, there will be also SQL ID and HASH VALUE shown on the statement's summary line.
As described above it is possible to define an arbitrary number of Handlers for server side debugging. Those handlers are defined globally, i.e. for the entire Java VM. But beside of those handlers there is one more, predefined, handler, which is defined per thread basis, which sends back its output to the calling client. This handler is used for the standard debugging functionality available through the Debug Console of the IFS Enterprise Explorer framework.
Server logging for applications deployed to an application server is exposed as a JMX MBean with name LoggingManager. With help of this MBean, log levels for the different categories can be changed at runtime using, for example, Jconsole. It is also possible to add/remove class specifications for class debugging using one of the two exposed methods. Also adding/removing Handlers and re-reading configuration file is supported through JMX.
Summary of available methods:
<java-class-name>=<level> as operation
parameter to add a class logger, e.g.: ifs.fnd.tc.framework.executer.DynamicOperation=debug<java-class-name>
as operation parameter to remove an existing class logger, e.g.: ifs.fnd.tc.framework.executer.DynamicOperationSystem initialization is always the most sensitive part of the flow. Problems that can occur during initialization of the logging framework are therefore quite difficult to debug. Of natural reasons it is impossible to debug the initialization sequence of the logging framework using the framework itself.
There are two system properties that can be set to true to make it easier
to debug the initialization sequence of the logging framework.
Those are:
| Property | Description |
|---|---|
| fndext.traceLoggingInit | Prints out information of found configuration files |
| fndext.debugLoggingInit | Prints out detailed information from the initialization |
Defining one of those properties or both before starting up the system will cause the initialization sequence of the logging framework to print out some messages to the standard output.
Example: It is also possible to add a property using the IFS Admin Console.
Sometimes, often due to errors in application server configuration, bugs or because of conflicts caused by the application server overriding standard java.util.logging.LogManager, it can turn out that the logging doesn't work. In such cases it it possible to shortcut the underlying standard logging framework and write logging output directly to a file.
Information collected by Loggers and send to Handlers is
encapsulated in LogRecords. By specifying path to a file using system
property fndext.logRecordSpoolFile, the logging framework will
write all LogRecords collected by Loggers to this file. Note
however that this functionality is synchronized and can affect performance. Thus
it should be avoided and be used only for troubleshooting.
A simple example of a definition file:
global.level=warning database.level=trace gateway.level=info handler.alert.type=xmlfile handler.alert.filename=C:/temp/ifsalert.xml handler.alert.level=error handler.log.type=textfile handler.log.filename=C:/temp/ifslog.log
The above definition will set a global logging level to warning, but override it for categories database and gateway. All the database calls will be logged with level trace and all the calls to Client and SOAP gateways will be logged with level info.
The definition file defines two files for logging: an XML file, which will
collect all errors, and another file, which will collect all the logging output.
If the example above represents contents of ifs-logging.properties and we have yet another file pointed by the
system property fndext.loggingConfig with the following contents:
security.level=debug handler.console.type=console handler.console.level=info handler.alert.level=warning
the result will be that the second file will override the global level warning to be debug for the category security, add yet another handler writing to the console with level info and change the behavior of the alert handler to include even warnings.