Logging
Version: 17.07
Developer Guide
Overview
Logging is an important component of the development cycle. It offers several advantages. It provides precise context about a run of the application. Once inserted into the code, the generation of logging output requires no human intervention. Moreover, log output can be saved in persistent medium to be studied at a later time.
— Log4j2 Documentation
https://logging.apache.org/log4j/2.x/manual/index.html
https://logging.apache.org/log4j/2.x/manual/index.html
This guide takes you through details of logging configuration, logging in custom processing elements along with some other important points regarding logging in project-x.
Log4j 2.x and Logging Configuration
As already mentioned in the content titled Logging in Project-X in Architecture and Design section Project-X current x-logging implementation uses log4j2. Two major parts in log4j are logger and appender. In log4j2 Logger simply has a name and is associated with a LoggerConfig. It provide the ability to selectively enable or disable logging requests but logger itself performs no direct actions. Appenders are the ones that actually deliver the LogEvents. The ability of printing to multiple destinations is provided through the appenders. For extensive details on log4j2 architecture please refer Log4j2 Architecture Documentation.
Moving on to Project-X logging configuration, it is basically a log4j2 configuration and all the configuration is in an XML file by the name log4j2.xml which will be similar to what is shown below. It has seven loggers and five appenders defined with both the logger and the appender for the auditor processing element commented out.
<?xml version="1.0" encoding="UTF-8"?>
<!--
~ Copyright (c) 2010-2016 AdroitLogic Private Ltd. (http://adroitlogic.org). All Rights Reserved.
~
~ AdroitLogic PROPRIETARY/CONFIDENTIAL. Use is subject to license terms.
-->
<Configuration xmlns="http://logging.apache.org/log4j/2.0/config" shutdownHook="disable">
<Loggers>
<Logger name="org.adroitlogic" level="INFO"/> (1)
<Logger name="org.springframework" level="ERROR"/> (2)
<Logger name="org.elasticsearch" level="ERROR"/> (3)
<Logger name="sys-info" level="INFO" additivity="false"> (4)
<AppenderRef ref="SYS_INFO_APPENDER"/>
</Logger>
<Root level="ERROR"> (5)
<AppenderRef ref="LOG_APPENDER"/>
<AppenderRef ref="CONSOLE_APPENDER"/>
</Root>
<Logger name="org.elasticsearch" level="DEBUG" additivity="false"> (6)
<AppenderRef ref="ES_EMBEDDED_NODE_APPENDER"/>
</Logger>
<!-- Logger configuration for FileBasedAuditor -->
<!--<Logger name="AUDIT_LOGGER" level="ALL" additivity="false">-->
<!--<AppenderRef ref="AUDIT_APPENDER"/>-->
<!--</Logger>-->
</Loggers>
<Appenders>
<!-- RollingRandomAccessFile configuration for FileBasedAuditor -->
<!--<RollingRandomAccessFile name="AUDIT_APPENDER" fileName="logs/audit-x.log"
filePattern="logs/$${date:yyyy-MM}/audit-x-%d{MM-dd-yyyy}-%i.log.gz">
<PatternLayout>
<Pattern>%d{ISO8601} [%X{ip}-%X{host}] [%t] [%X{xc}] %5p %c{1} %m%n</Pattern>
</PatternLayout>
<Policies>
<SizeBasedTriggeringPolicy size="1 MB"/>
</Policies>
<DefaultRolloverStrategy max="10"/>
</RollingRandomAccessFile>-->
<RollingRandomAccessFile name="LOG_APPENDER" fileName="logs/ultraesb-x.log"
filePattern="logs/$${date:yyyy-MM}/ultraesb-x-%d{MM-dd-yyyy}-%i.log.gz"> (7)
<PatternLayout>
<Pattern>%d{ISO8601} [%X{ip}-%X{host}] [%t] [%X{xc}] %5p %c{1} %m%n</Pattern>
</PatternLayout>
<Policies>
<SizeBasedTriggeringPolicy size="1 MB"/>
</Policies>
<DefaultRolloverStrategy max="10"/>
</RollingRandomAccessFile>
<RollingRandomAccessFile name="SYS_INFO_APPENDER" fileName="logs/x-sys.log"
filePattern="logs/$${date:yyyy-MM}/x-sys-%d{MM-dd-yyyy}-%i.log.gz"> (8)
<PatternLayout>
<Pattern>%d{ISO8601} [%t] [%X{xc}] %5p %c{1} %m%n</Pattern>
</PatternLayout>
<Policies>
<SizeBasedTriggeringPolicy size="1 MB"/>
</Policies>
<DefaultRolloverStrategy max="10"/>
</RollingRandomAccessFile>
<RollingRandomAccessFile name="ES_EMBEDDED_NODE_APPENDER" fileName="logs/embedded-es.log"
filePattern="logs/$${date:yyyy-MM}/embedded-es-%d{MM-dd-yyyy}-%i.log.gz"> (9)
<PatternLayout>
<Pattern>%d{ISO8601} [%t] [%X{xc}] %5p %c{1} %m%n</Pattern>
</PatternLayout>
<Policies>
<SizeBasedTriggeringPolicy size="1 MB"/>
</Policies>
<DefaultRolloverStrategy max="10"/>
</RollingRandomAccessFile>
<Console name="CONSOLE_APPENDER" target="SYSTEM_OUT"> (10)
<PatternLayout pattern="%d{ISO8601} [%X{ip}-%X{host}] [%t] [%X{xsn}-%X{xsv}] [%X{xc}] %highlight{%5p %c{1} %m%n}{TRACE=white,DEBUG=green,INFO=blue,WARN=bright yellow,ERROR=bright red}"/>
</Console>
</Appenders>
</Configuration>| 1 | This is the logger for package org.adroitlogic which is set to INFO log level. |
| 2 | This is the logger for package org.springframework which is set to ERROR log level. |
| 3 | This is the logger for package org.elasticsearch which is set to ERROR log level. |
| 4 | sys-info logger is used to log details of the system running the UltraESB instance which include percentage of memory usage, cpu usage, thread count of the system and open files of the process. This logger is set to INFO log level. and is configured with the appender named "SYS_INFO_APPENDER". Notice the additional parameter additivity="false to prevent those log events from propagating to parent loggers. |
| 5 | This is the Root logger. The main differences between the root logger and other loggers are that root logger does not have a name attribute and it does not support the additivity attribute since it has no parent. Every configuration must have a root logger. In our configuration root logger is configured with "LOG_APPENDER" and "CONSOLE_APPENDER". |
| 6 | This is another logger defined for package "org.elasticsearch" set to DEBUG with additivity set to false and it is configured with "ES_EMBEDDED_NODE_APPENDER". |
| 7 | This is a RollingRandomAccessFile by the name "LOG_APPENDER". RollingRandomAccessFile writes to the File named in the fileName parameter and rolls the file over according the TriggeringPolicy and the RolloverPolicy.The triggering policy used is the SizeBasedTriggeringPolicy which causes a rollover once the file has reached the specified size. The size can be specified in bytes, with the suffix KB, MB or GB and in this case we have set it to 1 MB. The addition parameter filePattern is the file name of the archived log file. The format of the pattern is dependent on the RolloverPolicy that is used. The DefaultRolloverPolicy will accept both a date/time pattern compatible with SimpleDateFormat and/or a %i which represents an integer counter. Here the DefaultRolloverStrategy is used with maximum value of the counter set to 10. Once this max value is reached older archives will be deleted on subsequent rollovers. The PatternLayout is the layout to use to format the LogEvent. |
| 8 | This is a RollingRandomAccessFile by the name "SYS_INFO_APPENDER". |
| 9 | This is a RollingRandomAccessFile by the name "ES_EMBEDDED_NODE_APPENDER". |
| 10 | This is a ConsoleAppender which writes its output to either System.out or System.err with System.out being the default target. In the pattern layout following colours are used for each log level. TRACE=white, DEBUG=green, INFO=blue, WARN=yellow, ERROR=red. |
For information on log4j2 configuration syntax please refer log4j2 configuration documentation.
|
When you define custom elements make sure to add a Logger entry to those packages to enable logging. For example say you have defined a new package as "com.acme.esb", then you need to define a Logger as <Logger name="com.acme.esb" level="INFO"/> otherwise logging will not be enabled for that package. |
Logging in Custom Processing Elements/Connectors
First of all we’ll look at creating a logger instance. As discussed Logging in Project-X under Architecture and Design, project-x used X-Logging API for logging. To create an instance of x-logger instance the LoggerFactory should be used as shown below in the example. The logger factory has a set of static methods providing Logger instances for user API.
package com.acme.esb;
import org.adroitlogic.x.annotation.config.Processor;
import org.adroitlogic.x.api.ExecutionResult;
import org.adroitlogic.x.api.XMessageContext;
import org.adroitlogic.x.api.config.ProcessorType;
import org.adroitlogic.x.base.processor.AbstractSequencedProcessingElement;
import org.adroitlogic.x.logging.LogInfo;
import org.adroitlogic.x.logging.Logger;
import org.adroitlogic.x.logging.LoggerFactory;
@LogInfo(loggerId = 1, nextLogCode = 4)
@Processor(displayName = "CustomProcessingElement", type = ProcessorType.GENERIC, requireConfiguration = true)
public class CustomProcessingElement extends AbstractSequencedProcessingElement {
private static Logger logger = LoggerFactory.getLogger(CustomProcessingElement.class); (1)
@Override
protected ExecutionResult sequencedProcess(XMessageContext xMessageContext) {
//custom processing element logic
return ExecutionResult.SUCCESS;
}
}| 1 | Usage of Logger Factory |
In order for the logging to be compliant with the log code governance framework explained in Logging in Project-X in Architecture and Design section, there are a few things that needs to be done. First thing we need to do is that we need to add package-info.java files for each package and subpackages. A package-info file will look like below. In UltraStudio you can right click on the package, go to New and then select package-info.java and it will automatically a create package-info.java file.
@LogInfo(componentType = ComponentType.PROCESSOR, moduleId = 800, nextModuleId = 801, nextLoggerId = 2)
package com.acme.esb;
import org.adroitlogic.x.logging.ComponentType;
import org.adroitlogic.x.logging.LogInfo;|
The package-info.java is a Java file that can be added to any Java source package. Its purpose is to provide a home for package level documentation and package level annotations. |
Next we need to add LogInfo annotation in package-info file as well as in each class we define in that package. LogInfo annotation has following parameters.
|
An annotation with ElementType.PACKAGE as one of its targets is a package-level annotation. LogInfo annotation has both PACKAGE and CLASS as targets. Hence it can be used as a package-level annotation as well as a class-level annotation. |
Parameter Name |
Parameter Type |
Description |
||||||||||||||||||
componentType |
ComponentType |
component type of the logger or the module. ComponentType enum has following values defined.
|
||||||||||||||||||
moduleId |
int |
module identifier of the logger or the module. Maximum number of digits that can be used for the moduleId is 3. |
||||||||||||||||||
loggerId |
int |
logger identifier of the logger. Maximum number of digits that can be used for the moduleId is 2. |
||||||||||||||||||
nextLogCode |
int |
Next leaf level code that can be used by a logger created for the specific class, the maximum number of digits that can be used for a log code is 3 |
||||||||||||||||||
nextModuleId |
int |
Next moduleId is the module identifier that can be used for the next module in this root module. |
||||||||||||||||||
nextLoggerId |
int |
Next loggerId is the logger identifier that can be used for the next logger within the given module (package). |
|
The parameter nextModuleId, nextLoggerId and nextLogCode are not used when calculating the log code and there used to make it easy to keep track of the next Ids which can be used. |
Now when adding LogInfo annotation to package using package-info file, we only need to define the following. (See sample package-info file above)
-
componentType
-
moduleId
-
nextModuleId
-
nextLoggerId
Then each class should also need to have this LogInfo annotation and in that case we need to define the following. (See sample class above)
-
loggerId
-
nextLogCode
When using the x-logging api methods log code for each line should be passed as the first parameter as follows. It is recommended to use one log code for one line which will make it easy to separate out each log line using the generated log code. It is better to always keep nextLogCode defined as a best practice as it will be easy to figure out which log code to be used when a new log line is added to the same class.
package com.acme.esb;
import org.adroitlogic.x.annotation.config.Processor;
import org.adroitlogic.x.api.ExecutionResult;
import org.adroitlogic.x.api.IntegrationRuntimeException;
import org.adroitlogic.x.api.XMessageContext;
import org.adroitlogic.x.api.config.ProcessorType;
import org.adroitlogic.x.base.processor.AbstractSequencedProcessingElement;
import org.adroitlogic.x.logging.LogInfo;
import org.adroitlogic.x.logging.Logger;
import org.adroitlogic.x.logging.LoggerFactory;
import static org.adroitlogic.x.base.util.XBaseUtils.extractStringByReplacingPlaceHolders;
@LogInfo(loggerId = 1, nextLogCode = 4)
@Processor(displayName = "CustomProcessingElement", type = ProcessorType.GENERIC, requireConfiguration = true)
public class CustomLogger extends AbstractSequencedProcessingElement {
private static Logger logger = LoggerFactory.getLogger(CustomLogger.class);
@Override
protected ExecutionResult sequencedProcess(XMessageContext xMessageContext) {
try {
logger.debug(1, "Starting custom processing element operation");
//custom processing element logic
logger.info(2, "{}", () -> extractStringByReplacingPlaceHolders(xMessageContext, "@{message.payload}"));
} catch (Exception e) {
logger.errorOnDebugOrWarn(3, "Error occured while doing custom processing operation", e);
throw new IntegrationRuntimeException("Error occured while doing custom processing operation", e);
}
return ExecutionResult.SUCCESS;
}
}Module Ids for Custom Elements
In order to prevent conflicts from elements shipped with UltraESB, please make sure to use Module Ids starting from 800 and use component types accordingly.
|
Any log code conflict will result in build failures. |
If there is any log code conflict, project building task will fail giving logs similar to following.
[INFO] --- x-logging-plugin:17.01:loggingValidator (default-loggingValidator) @ sample-project --- [INFO] Validating the use of logging [ERROR] Encountered an error while processing the logging info [INFO] ------------------------------------------------------------------------ [INFO] BUILD FAILURE [INFO] ------------------------------------------------------------------------ [INFO] Total time: 4.543 s [INFO] Finished at: 2017-02-02T15:10:03+05:30 [INFO] Final Memory: 34M/768M [INFO] ------------------------------------------------------------------------ [ERROR] Failed to execute goal org.adroitlogic.x:x-logging-plugin:17.01-RC:loggingValidator (default-loggingValidator) on project sample-project: Logging validation failed: Logger com.acme.esb.CustomLogger has already registered for the code 51201 attempted by org.adroitlogic.x.processor.logger.LoggerProcessingElement -> [Help 1]
In this topic
In this topic