Saturday, April 2, 2016

Extending log4j2 format with plugins

The log4j2 PatternLayout has the rich set of the build-in format specifiers and attributes.
A log file of desired format may be produced without a single line of code - just with a configuration file.
If the build-in format solutions are not sufficient for particular needs, the log4j2 plugins allow extending of the logging patterns.

You may find examples of format specifiers in log4j2 PatternLayout manual.

If you are new with log4j2 plugins, start you reading from this blog and then read log4j2 plugins manual.

This and following posts explain, how to implement extensions to the log file in order to fulfill the following requirements:
  • Put at the beginning of each log specific JVM parameters and application configuration values.
  • Put to each log message execution context tags.
  • Output critical errors into a separate log in the format quite different from the regular log.

The whole solution was implemented with several log4j2 elements:

The configuration lookup


The log4j2 lookup is the way to add a value to the log.
A lookup should be put into the format string of the PatternLayout as ${[lookup-tag]:[lookup-key]}. This format specifier is interpolated into appropriate string prior to output to the log.

The log4j2 provides the lookups for jvm properties, system properties etc. - see log4j2 lookups manual.

A custom lookup should be done as a plugin that implements the StrLookup interface.

The configuration lookup causes an application configuration to be put into a log file header.
When log file rolling happens, each new log has a header with configuration.

The implementation includes:
  1. A lookup of type config is implemented with the class ConfigurationLookup.
    The lookup is interpolated into configuration toString() method.
    The configuration must be set explicitly by a business logic.
    In case of null configuration the lookup is interpolated into a default message.
    @Plugin(name = "config", category = "Lookup")  
     public class ConfigurationLookup implements StrLookup {  
          private static final String PREFIX="Application configuration:\n";  
          private static final String NULL_CONFIGURATUION="";  
          private static RsvpConfiguration configuration;  
          public static void setAppConfiguration(AppConfiguration configuration) {  
               ConfigurationLookup.configuration = configuration;  
          }  
          @Override  
          public String lookup(String key) {  
               return getConfig();  
          }  
          @Override  
          public String lookup(LogEvent event, String key) {  
               return getConfig();  
          }  
          public String getConfig() {  
               if (null != configuration) {  
                    StringBuilder configString = new StringBuilder(PREFIX);  
                    configString.append(configuration.toString()).append("\n");  
                    return configString.toString();  
               }  
               else return NULL_CONFIGURATUION;  
          }       
     }  
    

  2. File layout pattern in log4j2.xml contains the header definition, which includes the config lookup:
     <header>  
        ${java:runtime} ${sys:line.separator} ${java:vm} ${sys:line.separator} ${java:os} ${sys:line.separator} ${java:hw}  
        ${sys:line.separator} $${config:all} ${sys:line.separator}  
     </header>  
    

  3. The double sign $$ before the config lookup serves for dynamic configuration: interpolation of configuration happens each time the header should be printed into the log file. Note: a single sign $ before the config lookup will cause configuration interpolation only once upon a program startup.

Initialization order matters

The configuration lookup interpolated value depends on the application configuration to be initialized. If the application configuration is not initialized, the interpolated value is NULL_CONFIGURATION.
The initialization order of the application configuration and the log configuration must be done in the proper sequence: the application configuration should be initialized prior to the first call to the logger.
This sometimes may be tricky.

A normal practice is to use the static logger initialization in a class:
 private static final Logger LOG = LogManager.getLogger();  

The lookup interpolation happens on the load of the first class with the static logger initialization.
If the class is loaded before the call to ConfigLookup.setAppConfiguration, the first lookup will be interpolated to the NULL_CONFIGURATION value.

Custom header and footer


In terms of logging a header is a piece of text, which is put on the top of each log file. A footer is a piece of text, which is put in the bottom of each log file.

Header and footer may be added to the log file with the attribute header/footer of the PatternLayout.
Since this is about the log file, header/footer attributes are effective only if
they are used inside the PatternLayout of the FileAppender and do nothing for the ConsoleAppender.

The header/footer may contain just static content:
 <PatternLayout>   
 <header>  
    This is the log header            
 </header>  
  <footer>  
    This is the end of file  
 </footer>  
  <pattern>  
    %d %p (%c{1.}.%M:%L) - %m%n  
  </pattern>  
 </PatternLayout>  

In order to put into the header/footer dynamic content one must use lookups.
Note, that pattern converter does not work when it is put inside the header/footer. The header/footer cannot be accessed from the java code as well.

Dynamic header


The example shows the fragment of the log4j2 configuration with header and footer for RollingFileAppender.

The header contains several lookups for JVM parameters and application configuration lookup $${config:all} (from the paragraph lookups). The double $$ is used in front of the lookup to cause lookup interpolation on each header creation (dynamic lookup).
The lookup ${sys:line.separator} is used to produce the end-line inside the header.
The footer is just a message “End of file”.
 <appenders>  
      <RollingFile name="RollingFile" fileName="${logDir}/${logFile}.log"  
           filePattern="${logDir}/${logFile}-%d{yyyy-MM-dd}-%i.log">  
           <PatternLayout>   
                <header>  
                     ${java:runtime}${sys:line.separator}${java:vm}${sys:line.separator}${java:os}${sys:line.separator}${java:hw}  
                     ${sys:line.separator}$${config:all}${sys:line.separator}  
                </header>  
                <footer>  
                     End of file  
                </footer>  
                <pattern>  
                     %d %p (%c{1.}.%M:%L) - %m%n  
                </pattern>  
           </PatternLayout>  
           <Policies>  
                <TimeBasedTriggeringPolicy/>  
           </Policies>  
      </RollingFile>  
 </appenders>  

The header in the log file will look like:
 Java(TM) SE Runtime Environment (build 1.7.0_55-b13) from Oracle Corporation  
 Java HotSpot(TM) 64-Bit Server VM (build 24.55-b03, mixed mode)  
 Windows 7 6.1 Service Pack 1, architecture: amd64-64  
 processors: 4, architecture: amd64-64, instruction sets: amd64  
 Application configuration:  
 property1=one   
 property2=two  

Summary and usage notes

  • Header/footer dynamic content may be interpolated with lookups, but not with a pattern convertor.
  • The double $$ before the lookup causes lookup value interpolation on each header/footer output. The single $ before the lookup causes interpolation only on the first output.
  • Header and footer attribute are effective only for the PatternLayout of the FileAppender and do nothing for the ConsoleAppender.
  • The lookup ${sys:line.separator} produces the end-line inside the header (multi-line header).

The configuration pattern converter


The PatternLayout is defined with the format pattern string similar to the format string of String.format. Each format specifier within the pattern is interpolated into an appropriate string.
The log4j2 provides a plenty of format specifiers.

A custom pattern convertor should be implemented defined as a plugin and may be used inside the pattern format as %{[converter-key]}.

The pattern convertor in the example was developed during my research of how to put configuration to the log header.
It has no the great practical value, since it used for interpolation the configuration toString() method, which provides multi-string output. Nobody want to add to each log message several more strings.
Still it demonstrates the custom conversion implementation.
  1. A converter is implemented with the class ConfigConverter. This converter is interpolated into configuration toString() method. The configuration must be set explicitly by a business logic. In case of null configuration it is interpolated into a default message. The converter is identified with the key of type config
     @Plugin(name = "config", category = "Converter")  
     @ConverterKeys({"config"})  
     public class ConfigConverter extends LogEventPatternConverter {       
          private static final String FORMAT_KEY="config";  
          private static final String PREFIX="\nActive configuration:\n";  
          private static final String NULL_CONFIGURATUION="null - check the execution flow";  
          private static RsvpConfiguration configuration;  
          protected ConfigConverter(String[] options) {  
               super(FORMAT_KEY, FORMAT_KEY);  
          }  
          public static ConfigConverter newInstance(final String[] options) {  
               return new ConfigConverter(options);  
          }  
          public static void setRsvpConfiguration(RsvpConfiguration configuration) {  
               ConfigConverter.configuration = configuration;  
          }  
          @Override  
          public void format(LogEvent arg0, StringBuilder toAppendTo) {  
               toAppendTo.append(getConfig());  
          }  
          public String getConfig() {  
               StringBuilder configString = new StringBuilder(PREFIX);  
               if (null == configuration) {  
                    configString.append(NULL_CONFIGURATUION);  
               }  
               else {  
                    configString.append(configuration.toString());  
               }  
               return configString.toString().replace('\n', ' ');  
          }       
     }  
    
  2. The pattern layout which contains the config converter:
       <pattern>  
          %d %p (%c{1.}.%M:%L) - %config %m%n  
       </pattern>  
    

All the sources on Git.

No comments :

About the author

My Photo
I trust only simple code and believe that code should be handsome. This is not a matter of technology, but professional approach, consolidated after years of software development. I enjoy to cause things working and feel very happy, when I manage to solve a problem.
Back to Top