Showing posts with label Log4j2. Show all posts
Showing posts with label Log4j2. Show all posts

Saturday, August 6, 2016

Log4j 2.x XSD is Not Fully Descriptive

In the blog post JAXB and Log4j XML Configuration Files, I discussed "nuances and subtleties associated with using JAXB to work with [Log4j 1.x and Log4j 2.x] XML configuration files via Java classes." In this post, I look at another challenge associated with generation of Log4j 2.x configuration XML via JAXB objects generated from the Log4j 2.x XML Schema file Log4j-config.xsd: it doesn't fully specify the Log4j 2.x components' configuration characteristics.

When working with Log4j 2.x XML configuration, one of the first distinctions that is important to make is which "flavor" of XML is to be used ("concise" or "strict"). The concise format may be easier because names of XML elements correspond to the Log4j 2 components they represent, but only the strict format is supported by the XSD. The implication here is that any XML marshaled from JAXB objects generated from the Log4j 2.x XSD will necessarily be of "strict" format rather than of "concise" format.

Unfortunately, the XSD (Log4j-config.xsd) currently provided with the Log4j 2.x distribution is not sufficient for generating the full "strict" XML configuration supported by Log4j 2. I demonstrate this here with discussion of the XSD-defined complex type "AppenderType" because it's one of the most extreme cases of a supported element lacking specification of its potential attributes in the XSD. The code listing below shows AppenderType's definition in the Log4j-config.xsd as of Log4j 2.6.2.

AppenderType Defined in Log4j 2.6.2's Log4j-config.xsd
<xs:complexType name="AppenderType">
   <xs:sequence>
      <xs:element name="Layout" type="LayoutType" minOccurs="0"/>
      <xs:choice minOccurs="0" maxOccurs="1">
         <xs:element name="Filters" type="FiltersType"/>
         <xs:element name="Filter" type="FilterType"/>
      </xs:choice>
   </xs:sequence>
   <xs:attribute name="type" type="xs:string" use="required"/>
   <xs:attribute name="name" type="xs:string" use="required"/>
   <xs:attribute name="fileName" type="xs:string" use="optional"/>
</xs:complexType>

The excerpt of the XSD just shown tells us that an appender described in XSD-compliant XML will only be able have one or more of the three attributes (type, name, and fileName). The "type" attribute is used to identify the type of appender it is (such as "File", "RollingFile", "Console", "Socket", and "Syslog"). The problem is that each "type" of appender has different properties and characteristics that ideally would be described by attributes on this AppenderType.

The Log4j 2.x documentation on Appenders lists characteristics of the different types of appenders. For example, this page indicates that the ConsoleAppender has seven parameters: filter, layout, follow, direct, name, ignoreExceptions, and target. The name is one of the attributes supported by the general AppenderType complex type and filter and layout are supported via nested elements in that AppenderType. The other four parameters that are available for a ConsoleAppender, however, have no mechanism prescribed in the XSD to define them.

Without even considering custom Log4j 2.x appenders, the built-in Log4j 2.x appenders don't share the same attributes and characteristics and most of them have more characteristics than the three attributes and two nested elements of the AppenderType specify. I discussed the seven parameters of a Console Appender previously and other examples include the RollingFileAppender with its twelve parameters (append, bufferedIO, bufferSize, filter, fileName, filePattern, immediateFlush, layout, name, policy, strategy, ignoreExceptions) the JDBCAppender with its seven parameters (name, ignoreExceptions, filter, bufferSize, connectionSource, tableName, columnConfigs), and the JMSAppender with its thirteen parameters (factoryBindingName, factoryName, filter, layout, name, password, providerURL, destinationBindingName, securityPrincipalName, securityCredentials, ignoreExceptions, urlPkgPrefixes, userName).

To describe each parameter available for a given appender type in the XSD would require the ability in XML Schema to write that a particular set of available attributes depends on the setting of the AppenderType's type attribute. Unfortunately, XML Schema doesn't readily support this type of conditional specification in which the available attributes of a given complex type are different based on one of the complex type's other attributes.

Because of the limitations of the schema language, a person wanting to use JAXB to generate objects with full support for all of the provided appenders would need to change the XSD. One approach would be to change the XSD so that an AppenderType had all possible attributes of any of the built-in appenders available as optional attributes for the element. The most obvious downside of this is that that XSD would then allow any appender type to have any attribute even when the attribute did not apply to a particular appender type. However, this approach would allow for the JAXB-generated objects to marshal out all XML attributes for a given appender type. The next code snippet illustrates how this might be started. Some of the additional attributes different appenders need are specified here, but even this longer list doesn't contain all of the possible appender attributes needed to support attributes of all possible built-in appender types.

Some Appender Attributes Added to AppenderType

<xs:complexType name="AppenderType">
   <xs:sequence>
      <xs:element name="Layout" type="LayoutType" minOccurs="0"/>
      <xs:choice minOccurs="0" maxOccurs="1">
         <xs:element name="Filters" type="FiltersType"/>
         <xs:element name="Filter" type="FilterType"/>
      </xs:choice>
   </xs:sequence>
   <xs:attribute name="type" type="xs:string" use="required"/>
   <xs:attribute name="name" type="xs:string" use="required"/>
   <xs:attribute name="fileName" type="xs:string" use="optional"/>
   <!-- Attributes specified below here are not in Log4j 2.x Log4j-config.xsd -->
   <xs:attribute name="target" type="xs:string" use="optional"/>
   <xs:attribute name="follow" type="xs:string" use="optional"/>
   <xs:attribute name="append" type="xs:string" use="optional"/>
   <xs:attribute name="filePattern" type="xs:string" use="optional"/>
   <xs:attribute name="host" type="xs:string" use="optional"/>
   <xs:attribute name="port" type="xs:string" use="optional"/>
   <xs:attribute name="protocol" type="xs:string" use="optional"/>
   <xs:attribute name="connectTimeoutMillis" type="xs:integer" use="optional"/>
   <xs:attribute name="reconnectionDelayMillis" type="xs:string" use="optional"/>
   <xs:attribute name="facility" type="xs:string" use="optional"/>
   <xs:attribute name="id" type="xs:string" use="optional"/>
   <xs:attribute name="enterpriseNumber" type="xs:integer" use="optional"/>
   <xs:attribute name="useMdc" type="xs:boolean" use="optional"/>
   <xs:attribute name="mdcId" type="xs:string" use="optional"/>
   <xs:attribute name="mdcPrefix" type="xs:string" use="optional"/>
   <xs:attribute name="eventPrefix" type="xs:string" use="optional"/>
   <xs:attribute name="newLine" type="xs:boolean" use="optional"/>
   <xs:attribute name="newLineEscape" type="xs:string" use="optional"/>
</xs:complexType>

A second approach to changing the Log4j 2.x XSD to support all built-in appenders fully would be to change the XSD design from having a single AppenderType whose specific type was specified by the type attribute to having many different complex types each representing the different built-in appender types. With this approach, all the attributes for any given appender and only the attributes associated with that given appender could be enforced by the XSD. This approach of having an element type per appender is similar to how the "concise" XML format works, but there is no XSD support for that currently.

Note that I have intentionally focused on the built-in appender types here because that's what a static XSD could be expected to reasonably, adequately, and completely support. Aside: this could be supported by specifying arbitrary name/value pairs for attributes as is done for filters or with parameters, but these also lead to the ability to specify extra and even nonsense attributes without any ability for the schema to catch those. A third approach that would support custom types would be to not use a static XSD for describing the grammar, but instead use a generated XSD. One could hand-write such an XSD based upon the descriptions of Log4j 2.x components in the documentation, but a better approach might be to take advantage of the @PluginFactory, @PluginElement, and @PluginAttribute annotations used in the Log4j 2.x source code. The two code listings that follow are from the Apache Log4j 2.6.2 code base and demonstrate how these annotations describe what would be the elements and attributes of given types.

ConsoleAppender.createAppender() Signature

@PluginFactory
public static ConsoleAppender createAppender(
   @PluginElement("Layout") Layout layout,
   @PluginElement("Filter") final Filter filter,
   @PluginAttribute(value = "target", defaultString = "SYSTEM_OUT") final String targetStr,
   @PluginAttribute("name") final String name,
   @PluginAttribute(value = "follow", defaultBoolean = false) final String follow,
   @PluginAttribute(value = "ignoreExceptions", defaultBoolean = true) final String ignore)

SysLogAppender.createAppender() Signature

@PluginFactory
public static SyslogAppender createAppender(
   // @formatter:off
   @PluginAttribute("host") final String host,
   @PluginAttribute(value = "port", defaultInt = 0) final int port,
   @PluginAttribute("protocol") final String protocolStr,
   @PluginElement("SSL") final SslConfiguration sslConfig,
   @PluginAttribute(value = "connectTimeoutMillis", defaultInt = 0) final int connectTimeoutMillis,
   @PluginAliases("reconnectionDelay") // deprecated
   @PluginAttribute(value = "reconnectionDelayMillis", defaultInt = 0) final int reconnectionDelayMillis,
   @PluginAttribute(value = "immediateFail", defaultBoolean = true) final boolean immediateFail,
   @PluginAttribute("name") final String name,
   @PluginAttribute(value = "immediateFlush", defaultBoolean = true) final boolean immediateFlush,
   @PluginAttribute(value = "ignoreExceptions", defaultBoolean = true) final boolean ignoreExceptions,
   @PluginAttribute(value = "facility", defaultString = "LOCAL0") final Facility facility,
   @PluginAttribute("id") final String id,
   @PluginAttribute(value = "enterpriseNumber", defaultInt = Rfc5424Layout.DEFAULT_ENTERPRISE_NUMBER) final int enterpriseNumber,
   @PluginAttribute(value = "includeMdc", defaultBoolean = true) final boolean includeMdc,
   @PluginAttribute("mdcId") final String mdcId,
   @PluginAttribute("mdcPrefix") final String mdcPrefix,
   @PluginAttribute("eventPrefix") final String eventPrefix,
   @PluginAttribute(value = "newLine", defaultBoolean = false) final boolean newLine,
   @PluginAttribute("newLineEscape") final String escapeNL,
   @PluginAttribute("appName") final String appName,
   @PluginAttribute("messageId") final String msgId,
   @PluginAttribute("mdcExcludes") final String excludes,
   @PluginAttribute("mdcIncludes") final String includes,
   @PluginAttribute("mdcRequired") final String required,
   @PluginAttribute("format") final String format,
   @PluginElement("Filter") final Filter filter,
   @PluginConfiguration final Configuration config,
   @PluginAttribute(value = "charset", defaultString = "UTF-8") final Charset charsetName,
   @PluginAttribute("exceptionPattern") final String exceptionPattern,
   @PluginElement("LoggerFields") final LoggerFields[] loggerFields, @PluginAttribute(value = "advertise", defaultBoolean = false) final boolean advertise)

This approach requires several steps because one would need to dynamically generate the XSD using knowledge of the main components of the Log4j 2.x architecture in conjunction with annotations processing and then use JAXB to generate the Java classes capable of marshaling the comprehensive Log4j 2.x XML.

Another option to be considered is to use "concise" XML or another form of Log4j 2.x configuration (such as JSON or properties files) and not use the XSD to generate JAXB objects for marshaling Log4j 2.x configuration. It's worth noting that XML configuration files used for Log4j 2.x with the "strict" format obviously do not need to validate against the Log4j-config.xsd or else the "strict" form of XML would not be able to fully specify the Log4j2 configuration. The implication of this is that the remaining value of even having the XSD is either for our own tools or scripts to use it to validate our XML configuration prior to using it with Log4j 2.x or for use in marshaling/unmarshaling Log4j 2.x XML with JAXB.

Conclusion

The Log4j-config.xsd provided with the Log4j2 distribution is not sufficient for validating all Log4j 2.x constructs in "strict" XML configuration and is likewise insufficient for generating JAXB objects to use to marshal Log4j2 strict XML. Developers wishing to use XSD for validation or JAXB class generation would need to manually change the XSD or generate one from the Log4j2 source code.

Additional References

These references were linked to inline in the post above, but are listed here for emphasis.

Wednesday, July 20, 2016

JAXB and Log4j XML Configuration Files

Both Log4j 1.x and Log4j 2.x support use of XML files to specify logging configuration. This post looks into some of the nuances and subtleties associated with using JAXB to work with these XML configuration files via Java classes. The examples in this post are based on Apache Log4j 1.2.17, Apache Log4j 2.6.2, and Java 1.8.0_73 with JAXB xjc 2.2.8-b130911.1802.

Log4j 1.x : log4j.dtd

Log4j 1.x's XML grammar is defined by a DTD instead of an W3C XML Schema. Fortunately, the JAXB implementation that comes with the JDK provides an "experimental,unsupported" option for using DTDs as the input from which Java classes are generated. The following command can be used to run the xjc command-line tool against the log4j.dtd.

    xjc -p dustin.examples.l4j1 -d src -dtd log4j.dtd

The next screen snapshot demonstrates this.

Running the command described above and demonstrated in the screen snapshot leads to Java classes being generated in a Java package in the src directory called dustin.examples.l4fj1 that allow for unmarshalling from log4j.dtd-compliant XML and for marshalling to log4j.dtd-compliant XML.

Log4j 2.x : Log4j-config.xsd

Log4j 2.x's XML configuration can be either "concise" or "strict" and I need to use "strict" in this post because that is the form that uses a grammar defined by the W3C XML Schema file Log4j-config.xsd and I need a schema to generate Java classes with JAXB. The following command can be run against this XML Schema to generate Java classes representing Log4j2 strict XML.

    xjc -p dustin.examples.l4j2 -d src Log4j-config.xsd -b l4j2.jxb

Running the above command leads to Java classes being generated in a Java package in the src directory called dustin.examples.l4j2 that allow for unmarshalling from Log4j-config.xsd-compliant XML and for marshalling to Log4j-config.xsd-compliant XML.

In the previous example, I included a JAXB binding file with the option -b followed by the name of the binding file (-b l4j2.jxb). This binding was needed to avoid an error that prevented xjc from generated Log4j 2.x-compliant Java classes with the error message, "Property "Value" is already defined. Use <jaxb:property> to resolve this conflict." This issue and how to resolve it are discussed in A Brit in Bermuda's post Property "Value" is already defined. Use to resolve this conflict. The source for the JAXB binding file I used here is shown next.

l4j2.jxb

<jxb:bindings version="2.0"
              xmlns:jxb="http://java.sun.com/xml/ns/jaxb"
              xmlns:xsd="http://www.w3.org/2001/XMLSchema">
   <jxb:bindings schemaLocation="Log4j-config.xsd" node="/xsd:schema">
      <jxb:bindings node="//xsd:complexType[@name='KeyValuePairType']">
         <jxb:bindings node=".//xsd:attribute[@name='value']">
            <jxb:property name="pairValue"/>
         </jxb:bindings>
      </jxb:bindings>
   </jxb:bindings>
</jxb:bindings>

The JAXB binding file just shown allows xjc to successfully parse the XSD and generate the Java classes. The one small price to pay (besides writing and referencing the binding file) is that the "value" attribute of the KeyValuePairType will need to be accessed in the Java class as a field named pairValue instead of value.

Unmarshalling Log4j 1.x XML

A potential use case for working with JAXB-generated classes for Log4j 1.x's log4j.dtd and Log4j 2.x's Log-config.xsd is conversion of Log4j 1.x XML configuration files to Log4j 2.x "strict" XML configuration files. In this situation, one would need to unmarshall Log4j 1.x log4j.dtd-compliant XML and marshall Log4j 2.x Log4j-config.xsd-compliant XML.

The following code listing demonstrates how the Log4j 1.x XML might be unmarshalled using the previously generated JAXB classes.

   /**
    * Extract the contents of the Log4j 1.x XML configuration file
    * with the provided path/name.
    *
    * @param log4j1XmlFileName Path/name of Log4j 1.x XML config file.
    * @return Contents of Log4j 1.x configuration file.
    * @throws RuntimeException Thrown if exception occurs that prevents
    *    extracting contents from XML with provided name.
    */
   public Log4JConfiguration readLog4j1Config(final String log4j1XmlFileName)
      throws RuntimeException
   {
      Log4JConfiguration config;
      try
      {
         final File inputFile = new File(log4j1XmlFileName);
         if (!inputFile.isFile())
         {
            throw new RuntimeException(log4j1XmlFileName + " is NOT a parseable file.");
         }

         final SAXParserFactory spf = SAXParserFactory.newInstance();
         final SAXParser sp = spf.newSAXParser();
         final XMLReader xr = sp.getXMLReader();
         
         final JAXBContext jaxbContext = JAXBContext.newInstance("dustin.examples.l4j1");
         final Unmarshaller unmarshaller = jaxbContext.createUnmarshaller();
         final UnmarshallerHandler unmarshallerHandler = unmarshaller.getUnmarshallerHandler();
         xr.setContentHandler(unmarshallerHandler);

         final FileInputStream xmlStream = new FileInputStream(log4j1XmlFileName);
         final InputSource xmlSource = new InputSource(xmlStream);
         xr.parse(xmlSource);

         final Object unmarshalledObject = unmarshallerHandler.getResult();
         config = (Log4JConfiguration) unmarshalledObject;
      }
      catch (JAXBException | ParserConfigurationException | SAXException | IOException exception)
      {
         throw new RuntimeException(
            "Unable to read from file " + log4j1XmlFileName + " - " + exception,
            exception);
      }
      return config;
   }

Unmarshalling this Log4j 1.x XML was a bit trickier than some XML unmarshalling because of the nature of log4j.dtd's namespace treatment. This approach for dealing with this wrinkle is described in Gik's Jaxb UnMarshall without namespace and in Deepa S's How to instruct JAXB to ignore Namespaces. Using this approach helped avoid the error message:

UnmarshalException: unexpected element (uri:"http://jakarta.apache.org/log4j/", local:"configuration"). Expected elements ...

To unmarshall the Log4j 1.x that in my case references log4j.dtd on the filesystem, I needed to provide a special Java system property to the Java launcher when running this code with Java 8. Specifically, I needed to specify
     -Djavax.xml.accessExternalDTD=all
to avoid the error message, "Failed to read external DTD because 'file' access is not allowed due to restriction set by the accessExternalDTD property." Additional details on this can be found at NetBeans's FaqWSDLExternalSchema Wiki page.

Marshalling Log4j 2.x XML

Marshalling Log4j 2.x XML using the JAXB-generated Java classes is fairly straightforward as demonstrated in the following example code:

   /**
    * Write Log4j 2.x "strict" XML configuration to file with
    * provided name based on provided content.
    *
    * @param log4j2Configuration Content to be written to Log4j 2.x
    *    XML configuration file.
    * @param log4j2XmlFile File to which Log4j 2.x "strict" XML
    *    configuration should be written.
    */
   public void writeStrictLog4j2Config(
      final ConfigurationType log4j2Configuration,
      final String log4j2XmlFile)
   {
      try (final OutputStream os = new FileOutputStream(log4j2XmlFile))
      {
         final JAXBContext jc = JAXBContext.newInstance("dustin.examples.l4j2");
         final Marshaller marshaller = jc.createMarshaller();
         marshaller.setProperty(Marshaller.JAXB_FORMATTED_OUTPUT, true);
         marshaller.marshal(new ObjectFactory().createConfiguration(log4j2Configuration), os);
      }
      catch (JAXBException | IOException exception)
      {
         throw new RuntimeException(
            "Unable to write Log4 2.x XML configuration - " + exception,
            exception);
      }
   }

There is one subtlety in this marshalling case that may not be obvious in the just-shown code listing. The classes that JAXB's xjc generated from the Log4j-config.xsd lack any class with @XmlRootElement. The JAXB classes that were generated from the Log4j 1.x log4j.dtd did include classes with this @XmlRootElement annotation. Because the Log4j 2.x Log4j-config.xsd-based Java classes don't have this annotation, the following error occurs when trying to marshal the ConfigurationType instance directly:

MarshalException - with linked exception: [com.sun.istack.internal.SAXException2: unable to marshal type "dustin.examples.l4j2.ConfigurationType" as an element because it is missing an @XmlRootElement annotation]

To avoid this error, I instead (line 18 of above code listing) marshalled the result of invoking new ObjectFactory().createConfiguration(ConfigurationType) on the passed-in ConfigurationType instance and it is now successfully marshalled.

Conclusion

JAXB can be used to generate Java classes from Log4j 1.x's log4j.dtd and from Log4j 2.x's Log4j-config.xsd, but there are some subtleties and nuances associated with this process to successfully generate these Java classes and to use the generated Java classes to marshal and unmarshal XML.

Thursday, October 15, 2015

Better Performing Non-Logging Logger Calls in Log4j2

Using logging guards is a common practice when using Log4j 1.x and wanting to avoid the additional performance impact that can occur on some occasions even if the message is not actually logged. One of the most attractive features that Simple Logging Facade for Java (SLF4J) brought to Java logging was the ability to reduce the number of circumstances in which these log level checks are necessary. In this post, I look at how one can use Log4j 2.x's logging API changes to achieve a similar benefit.

The next code listing demonstrates logging long-running operations. The first example implicitly calls to toString() method on an instance whose name is "slow". The second logging example invokes a method that is long-running.

Traditional, Unguarded Logging

// Will implicitly invoke slow's toString() method
logger.debug("NORMAL: " + slow);
// Will explicitly invoke the long-running method expensiveOperation()
logger.debug(expensiveOperation());

In the previous example, both logging operations will take a long time even when no logging is actually performed. The logging statements in the previous code listing will only actually log when the logging level is DEBUG or a less specific log level such as TRACE, but their expensive operations will be run even when nothing is logged.

There are two ways to deal with this in Log4j 1.x. One approach, and often the best approach, is to try to re-write the log statement so that no long-running operations are involved. When that is impractical (such as when one needs the context associated with the long-running operation for the log message to be useful), logging guards can be used. This approach that works in Log4j 1.x is demonstrated next.

Traditional, Guarded Logging

if (logger.isDebugEnabled())
{
   logger.debug("GUARDED: " + slow);
   logger.debug(expensiveOperation());
}

Logging guards, as shown in the previous code listing, are effective in preventing long-running operations from being called even when no message would have been logged anyway. However, using logging guards does introduce some disadvantages. Perhaps the most significant disadvantage is the extra (some would say bloated) code that is introduced. Another potential disadvantage is much less common, but much more serious: with the extra scope introduced by the conditional and associated block, it's more susceptible to errant code being introduced in the conditional that could potentially even introduce side effects in a logging-level-dependent block of code.

One of the most common situations in which log calls that do not actually log anything but significantly impact performance is when an object's toString() method is explicitly or implicitly called when an object is passed to the logger call or concatenated with a string passed to the logger call. This situation was demonstrated in the two above code listings with the string passed to the logger call by concatenating the string literal "GUARDED: " to the implicitly invoked toString() method of the variable named "slow".

SLF4J has popularized the concept of parameterized logging calls and Log4j 2 provides similar support in its logging API. The code that follows demonstrates how this is used.

Parameterized Logging

logger.debug("PARAMETERIZED: {}", slow);
logger.debug("{}", expensiveOperation());

When the parameterized logging example above is executed with a log level more specific than DEBUG, the implicit toString() on the "slow" variable will not be attempted thanks to the parameterized logging. However, parameterized logging cannot help the other logging situation as the method expensiveOperation() will be invoked despite the parameterized logging. Note also that while parameterized logging helps in the case of implicit toString() calls, it does not help with explicit toString() calls. Even if the logging level is more specific than DEBUG, a call to slow.toString() in a logger statement would still incur a performance hit.

Log4j 2.4 introduces a Lambda-based mechanism that can be used to defer invocation of methods passed to a logger call such that they don't need to be executed at all if the statement is being logged at a level less specific than the current log level. This is demonstrated in the next code listing where the toString() method is explicitly called on the "slow" variable's object via lambda expression and the expensiveOperation method is invoked via method reference.

Lambda Expression Logging

logger.debug("LAMBDA: ", () -> slow.toString());
logger.debug("{}", this::expensiveOperation);

When the above code is executed with a log level set to a level more specific than DEBUG, neither the "slow" object's toString() method nor the expensiveOperation method will be invoked thanks to the lambda expression based lazy loading. In other words, similar to how the example worked with guards, the use of lambda expressions prevents unnecessary execution of potentially long-running methods unless their results are really going to be logged. This lambda expression support was added to Log4j with version 2.4 and, of course, requires Java 8.

Summary

Log4j 2 (2.4) provides multiple approaches for avoiding the performance impact of log statements when the messages aren't actually logged.

  1. Log statements can be re-written such that expensive methods (including expensive toString() calls) are not logged at all.
  2. Logging guards can be used to ensure that a log statement's long-running methods invocations are only executed if the message is to actually be logged.
  3. Log4j 2's parameterized (formatted) logger API can be used to eliminate the invocation of implicit toString() methods unless the message is really being logged.
  4. Log4j 2.4's lambda expression logger API can be used to to eliminate the invocation of any operations (implicit or explicit) needed for the logged message unless the message is really being logged.

Thursday, October 8, 2015

Easy and Consistent Log4j2 Logger Naming

In the post Portable Logger Names with Java 7 Method Handles, I wrote about using Java 7's method handles to name classes' loggers. I stated in that post that advantages of that approach included consistency in logger naming and avoiding accidental copying and pasting of code that might lead to a different class's name being used for the logger name. In this post, I look at how Log4j 2 provides an approach for achieving these same benefits.

Log4j 2 recognizes the prevalent approach to naming loggers based off of classes' names. The "Logger Names" section of the "Log4j 2 API" page in the Log4j 2 Manual states, "In most cases, applications name their loggers by passing the current class's name to LogManager.getLogger. Because this usage is so common, Log4j 2 provides that as the default when the logger name parameter is either omitted or is null."

The following very simple Calculator class demonstrates this, creating a Logger with a parameter-less LogManager.getLogger() call. Because no parameter is passed to the getLogger() method, the logger will be named after the class in which the Logger is created. The Javadoc comment for method LogManager.getLogger() confirms this behavior: "Returns a Logger with the name of the calling class."

Calculator.java

package dustin.examples.log4j;

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

import java.util.Arrays;


/**
 * Simple calculator class that is intended more for demonstration
 * of Log4j2 than for calculating anything.
 */
public class Calculator
{
   private static final Logger logger = LogManager.getLogger();

   public String getLoggerName()
   {
      return logger.getName();
   }

   /**
    * Add the provided operands together and provide their sum.
    *
    * @param operands Operands to be added together.
    * @return Sum of the provided operands.
    */
   public long add(final long ... operands)
   {
      long sum = 0;
      for (final long operand : operands)
      {
         sum += operand;
      }
      logger.debug("The sum of " + Arrays.toString(operands) + " is " + sum);
      return sum;
   }
}

With the Calculator class implemented as shown above, the class's logger's name, available by call to Logger.getName() as demonstrated in the Calculator method getLoggerName(), is "dustin.examples.log4j.Calculator". Although not shown here, a Logger retrieved with parameter-less LogManager.getFormatterLogger() will also use "the fully qualified name of the calling Class as the Logger name."

Conclusion

The Log4j 2 approach discussed and demonstrated in this post for naming loggers is easy to use and makes it easy to have consistent and correct logger names, assuming that the chosen logger naming scheme is to use the fully qualified package and class name. This approach is briefer and arguably even more readable than the method handles approach to naming loggers, but this approach is specific to Log4j 2 while the method handles approach can be used with multiple logging frameworks and libraries.