FWD

Logging Infrastructure¶

• Logging Infrastructure
  • “Poor Man's” Logging
  • “Proper” Logging
  • Performance Considerations
  • Changing Logging Levels

This chapter is about how logging can be added to Java code from a developer's perspective.

Whether you are investigating an issue in FWD runtime code or in business logic, a well-placed logging statement can be a low impact mechanism to look inside the state of your application or the runtime environment. Logging statements should be added with careful consideration for performance impacts and readability of the resulting log information.

In the FWD environment a logging infrastructure based on the J2SE logging environment is available to the developer.

For details about how to deploy and configure logging, see Logging and Logging Configuration.

“Poor Man's” Logging¶

• System.out.print, System.out.println, System.err.print, System.err.println;
• throwable.printStackTrace.

All occurrences of the above-mentioned quick prints should be reworked to use “proper” logging.

The current version of FWD supports the character mode user interface (CHUI) as an interactive client. This implementation uses the terminal's stdout stream to render its user interface, so calls to System.out.println for example, are not recommended in the client code base, as they will cause screen corruption which likely will get in the way of any debugging efforts.

System.err.println can be used for temporary debug logging statements, where you do not want to leave a permanent logging statement behind in the code, but it is very important to remove any such statements after a debugging effort is complete. Such logs can be forwarded to a file on process start:

java {JVM options} com.goldencode.p2j.main.ClientDriver {program options} 2>client.log

When leaving permanent debugging options in the code “proper” logs with a debug logging level are recommended.

“Proper” Logging¶

This section assumes the reader already is familiar with the configuration of the logging facilities available for the FWD server. If not, please review Installation, Configuration and Administration Guide. Here we discuss how to add new logging statements to FWD runtime code or to application code.

The foundation of logging in the FWD environment is based on the logging infrastructure added to the Java platform in J2SE 1.4, the public API for which is in the java.util.logging package. FWD takes advantage more specifically of the following components:

• java.util.logging.Level
• java.util.logging.FileHandler

The core of the logging in FWD is CentralLogger class, instances of which are worker objects used to log messages for specific system or application components. Loggers are named using a dot-separated, hierarchical namespace, which typically corresponds with a specific package or class name. This is the convention followed in FWD.

Log messages are each assigned a level of severity. This table is in order of least verbose logging to most verbose logging:

Configuration Value	Logging Level	Semantics
OFF	Level.OFF	Logging disabled
SEVERE	Level.SEVERE	Critical exception
WARNING	Level.WARNING	Important issue
INFO	Level.INFO	Important message
FINE	Level.CONFIG	Configuration details
FINE	Level.FINE	Debug message
FINER	Level.FINER	Debug/trace message
FINEST	Level.FINEST	Trace message
ALL	Level.ALL	Lowest level

These are checked against configuration values associated in the FWD directory with the names of individual CentralLogger instances or against default global settings. This check determines whether a given log message is recorded/displayed or not.

The central logging class in the FWD runtime source is com.goldencode.p2j.util.logging.CentralLogger. Its factory method returns the appropriate FWD instance runtime and defines the logging interface. Typically, a CentralLogger instance is retrieved and stored in a static member variable of the class which will use it, as in:

package com.myorg.myapp.abc;

import com.goldencode.p2j.util.logging.CentralLogger;

public class MyClass
{
   private static CentralLogger log1 = CentralLogger.get(MyClass.class);

   private static CentralLogger log2 = CentralLogger.get("some-random.hierarchical.name");

   ...
}

The first assignment above uses the CentralLogger.get(Class) method to obtain a named CentralLogger whose name is the fully qualified name of MyClass including the package name (in this case com.myorg.myapp.abc.MyClass). It stores that object in the class member log1.

The second assignment uses an overloaded version of the same CentralLogger method, in this case, CentralLogger.get(String). It retrieves a named CentralLogger whose name is some-random.hierarchical.name and stores that object in the class member log2. The name passed to this method could be any text value. The desired naming hierarchy is defined by separating nested namespaces with a dot (.). Thus, in the example above, an administrator could configure different severity levels for the logging namespaces some-random, some-random.hierarchical, and some-random.hierarchical.name, if desired. This logger would use the setting for the most granular of those namespaces.

Since the log1 and log2 variables are static, they are initialized once and once only, when MyClass is first loaded by the Java class loader. The CentralLogger objects are then available for use throughout MyClass to check their configured, logging severity levels, and to write messages to the log as needed.

The first assignment in the example above is typical of the most common idiom used throughout the FWD runtime code. Granularity of logging is most often along package lines, though there are exceptions.

Using a CentralLogger instance is fairly straightforward. Its interface provides flexibility in logging messages on different logging levels, using formatting specifiers and including exception stacktraces.

Here is an example of getting and using a CentralLogger instance, excerpted from the com.goldencode.p2j.net.Conversation class, with minor modifications:

import java.util.logging.*;
import com.goldencode.p2j.util.logging.*;

...

public class Conversation
{
   /** Logger */
   private static final CentralLogger LOG = CentralLogger.get(Conversation.class);

   ...

   public void run()
   {
      ...

      try
      {
         ...
      }

      catch (ApplicationRequestedStop exc)
      {
         // normal termination of the queue
         if (LOG.isLoggable(Level.FINE))
         {
            LOG.logp(Level.FINE, "Conversation", "run", exc.getMessage());
         }
      }
      ...
   }
   ...
}

Near the top of the example, we use the variant of the overloaded CentralLogger.get method which accepts a Class parameter. By passing the fully qualified name of the Conversation class, we get a CentralLogger instance specific to the namespace defined by the name of the enclosing class: com.goldencode.p2j.net.Conversation.

By requesting a CentralLogger instance for only the com.goldencode.p2j.net.Conversation namespace, we can control the level of this logger independently of all the other classes in the com.goldencode.p2j.net package and produce a more readable log file with content tailored to our area of interest.

At the bottom of the example, we catch an ApplicationRequestedStop exception, which is thrown upon normal termination of a client's session with the FWD server. This code would log a message about that event if the logging level for the com.goldencode.p2j.net.Conversation logger were set to FINE (or more granular), similar to the following:

23/05/29 12:32:19.057+0100 | FINE    | com.goldencode.p2j.net.Conversation [Conversation.run()] | ThreadName:Conversation, Session:00000002, Thread:00000013, User:7mrz549n7889iung | Queue stop is requested by application

Inside a conditional block which checks if our desired level of logging is enabled, the message is composed.

Finally, the log message is sent to the log, at the target logging level set in the CentralLogger.logp method (in this case, Level.FINE).

LOG.logp(Level.FINE, "Conversation", "run", exc.getMessage());

This variant of the CentralLogger.logp method accepts a logging level, the names of the enclosing class and method, respectively, and the message text. All of this information is formatted into the final message written to the log. If the logger is configured to a less detailed logging level than that specified in the CentralLogger.logp call, the message will not be written.

Here is an example of using a slightly different variant of the CentralLogger.logp method, excerpted from com.goldencode.p2j.main.StandardServer, with minor modifications. Import statements, the class definition, definition of the LOG member, and method declarations have been omitted from this example, as they are not significantly different than in the Conversation class example above.

catch (Throwable thr)
{
   LOG.logp(Level.SEVERE,
            "StandardServer",
            "hookTerminate",
            "terminate() failed!",
            thr);
}

Note that this variant of CentralLogger.logp accepts as its last parameter an instance of Throwable. This last argument differentiates this variant of the method from the one used in the previous example. In this case, when the Throwable object thr is caught, we will log a message similar to the following:

23/05/29 12:32:19.057+0100 | SEVERE    | com.goldencode.p2j.main.StandardServer [StandardServer.terminate()] | ThreadName:Conversation, Session:0000001E, Thread:0000020A, User:user2 | terminate() failed!

Immediately after this entry, the stack trace from the Throwable object thr will be logged.

Performance Considerations¶

When composing the log message, the recommended idiom when logging a message is to enclose the entire logging operation, within a conditional block, which only executes if the logger is configured to log messages at our desired level of logging detail (or at a lower/finer level). This is why the logging code is enclosed in the test:

if (LOG.isLoggable(Level.FINE))

It might appear that this check is redundant, since Logger.logp already filters messages by logging level. However, the isLoggable check is important when considering performance. Composing the text of a log message typically requires string concatenation, generally an expensive operation. Retrieval of information needed for the log message may involve other, relatively costly operations as well. Taken together, the overhead of this work can be considerable, compared to the actual work of the enclosing code. We do not want to incur this overhead unless absolutely necessary, since logging should be as transparent as possible from a performance standpoint. The simple act of introducing logging should not introduce a performance bottleneck.

The isLoggable check is thus very valuable to avoid this work when it is unnecessary. The Logger.isLoggable call itself is relatively inexpensive, as it only requires one or two integer comparisons between the target level and instance data within the Logger object. That being said, no method call is completely without cost, so be careful not to introduce logging into extremely performance-sensitive sections of code, such as very tight loops. Even the fastest method can slow down performance when it is invoked millions of times.

Admittedly, the isLoggable check is not strictly necessary in the FWD runtime examples above, since neither is part of a performance-critical section of code. The ApplicationRequestedStop exception is not thrown often, nor at a point in the life cycle of a user session where performance is particularly important. Likewise, StandardServer.hookTerminate only runs as a session is ending, when the performance of handling an error is not of great concern. Nevertheless, the isLoggable check is a best practice that is used throughout FWD runtime code.

Changing Logging Levels¶

Currently, the administration client has no support for dynamic changes to the logging levels of individual loggers, nor to the default logging settings for the FWD server as a whole. In order to change logger settings today, the server must be stopped, the logging configuration changed in the FWD server directory, and the server must then be restarted. Please refer to the Installation, Configuration and Administration Guide for a description of how to configure logging.

This limitation may be removed in a future version of the FWD Project.

---

© 2004-2023 Golden Code Development Corporation. ALL RIGHTS RESERVED.