Using logging and tracing in the WebSphere Commerce custom code

Document options Document options requiring JavaScript are not displayed Discuss Sample code Rate this page Help us improve this content

Level: Intermediate

Andres Voldman (voldman@ca.ibm.com), Software Engineer, IBM
Samira Hafezi (shafezi@ca.ibm.com), Software Engineer, IBM

06 Feb 2008

This article shows how to use the logging facilities in WebSphere® Application Server V6 to quickly implement effective logging for your custom code in WebSphere Commerce.

Introduction

As members of the WebSphere Commerce Support and Services organization, we encounter implementations that do not provide appropriate logging and tracing to help troubleshoot various problems. Either the logging is missing, uses inadequate technologies, such as System.out, or relies on deprecated and reserved components, such as WC_EXTERN or WC_ORDER. This article will show how you can implement logging for your custom code in a matter of minutes. We will describe the logging facilities offered by WebSphere Application Server V6.0, provide examples, and offer best practices to make your logging effective.

Back to top

WebSphere logging facilities and Java logging

WebSphere Commerce V5.6.1.1 and V6.0 support WebSphere Application Server V6.0 (hereafter called Application Server). This version of Application Server fully integrates the Java™ logging API (java.util.logging), which was added in J2SE 1.4 to provide advanced control of informational output from applications. In Application Server V6.0, you can implement logging for your applications using the Java logging standard and take advantage of the WebSphere logging features, such as file management, runtime configuration, and administration through the Administrative Console or the wsadmin tool.

The JRas framework, which was the logging standard in WebSphere Application Server V5, has been deprecated. If you have implemented logging using JRas, your application will continue to work. However, if you face a new implementation, use Java logging instead.

Back to top

Adding logging to your code

Setting up logging and tracing in your own code is simple. The following example shows a generic WebSphere Commerce command that uses the logging APIs.

package com.mycompany.commerce;

import java.util.logging.Level;
import java.util.logging.Logger;

public class ExtGetContractUnitPriceCmdImpl extends
      GetContractUnitPriceCmdImpl {

  private static final String CLASS_NAME =
   ExtGetContractUnitPriceCmdImpl.class.getName();
  private static Logger logger = Logger.getLogger(CLASS_NAME);

  public void performExecute() throws ECException {
     final String methodName = "performExecute";

      if (logger.isLoggable(Level.FINER))
         logger.entering( CLASS_NAME, methodName,
               "userId= " + getCommandContext().getUserId());

      try {
         super.performExecute();
         boolean a = someOtherFuntion();
         if (logger.isLoggable(Level.FINE))
            logger.logp( Level.FINE, CLASS_NAME, methodName,
               "someOtherFunction returned " + a );
      } catch ( Exception e ) {
         logger.logp(Level.SEVERE, CLASS_NAME, methodName,
                     e.getClass().getName() + "Your Logging Message", e );
      }

      logger.exiting( CLASS_NAME, methodName );
   }
}

Back to top

Dissecting the example

This sections breaks down the sample code above and explains each section separately.

1. To begin, include the necessary imports:

   import java.util.logging.Level; import java.util.logging.Logger;

   
   
2. Next, you need to define the logger. Select any name for the logger. In this case, as a general practice, define the logger to match the fully qualified class name. This defines an implicit hierarchy that allows you to enable logging at the different package or class levels (more on this later). Also, in the example below, we follow the WebSphere Commerce standard of creating a final string for the class name that will be used by the logging API.

   private static final String CLASS_NAME = ExtGetContractUnitPriceCmdImpl.class.getName(); private static Logger logger = Logger.getLogger(CLASS_NAME);

   
   Grouping loggers by functionality is also a valid practice. In this case, you create loggers that match the functionality provided by the class, such as inventory, orders, or payments.
3. It is a common practice to define a string to contain the method name because it is used inside the method. The next line, logger.entering(), is a convenient method that is used to log the entry to the method using the FINER level. We recommend using isLoggable() because you lower the footprint of tracing by not concatenating the strings or creating objects if the message is not logged.

   final String methodName = "performExecute"; if (logger.isLoggable(Level.FINER))logger.entering( CLASS_NAME, methodName, "userId= " + getCommandContext().getUserId());

   
   
4. Produce a log entry if the logging is set to FINE or higher. The logger object provides different signatures. In this case, print the class and method name from where the message was originated.

   if (logger.isLoggable(Level.FINE)) logger.logp( Level.FINE, CLASS_NAME, methodName, "someOtherFunction returned " + a );

   
   
5. Finally, log the method exit. This is recommended if you logged the entry event. Alternatively, you can also include a message, such as the result of the method or the value to be returned.

   logger.exiting( CLASS_NAME, methodName );

   
   

Back to top

Using adequate logging levels

When logging a message, pay special consideration to the logging level that the message will be using. You can log messages using any of the following levels:

• SEVERE
• WARNING
• INFO
• CONFIG
• FINE
• FINER
• FINEST

Recommendations

This section highlights a few best practices to help you use the logging features in your custom code and also discusses pitfalls that you can avoid.

• Avoid the "all or nothing approach", where you either get full tracing in your application or no messages at all.
• The INFO level is not meant for debugging purposes and it is usually enabled by default. Use this level carefully because too much logging affects the performance of your application. For example, do not use INFO levels for commands, such as OrderItemAdd, that are executed from the store front because they can flood the trace logs with messages.
• Three different levels are provided for tracing: FINE, FINER, FINEST. One way of deciding which level to use is considering their impact while the trace is enabled. For example, you can organize your messages so that FINE is enabled in production without a significant performance impact. However, only enable FINEST while a particular situation is occurring because the negative impact in performance will be significant. If you use the entering or existing convenience methods, the messages are logged using FINER.
• The impact of adding logging to your application is minor if its level is not being logged. For this, remember to use the Logger.isLoggable(Level) approach when you need to create objects to log the entry. The most common scenario is when you concatenate strings that are then passed as parameters to the loggers.
• Always log errors and exceptions using SEVERE or WARNING. This ensures that the errors are logged when running with the INFO level. If the exception needs to be propagated, use the WebSphere Commerce Command error handling framework, which creates internationalized messages and specifies an error view.

Back to top

Tracing in WebSphere Application Server

Now that your code implements logging, let’s see how tracing is enabled and administered in Application Server.

Using the WebSphere Administrative console

Using the WebSphere Administrative console, you can view and edit the trace specification. The console shows you two tabs, Configuration and Runtime. Configuration trace takes effect during startup and requires a restart. Runtime trace sets a new trace on a running server. The server returns to the trace specification defined under the Configuration tab the next time it is restarted. Figure 1 shows the Runtime tab of the Administrative console.

For more information about how to enable tracing, see the following WebSphere Application Server Information Center links:

• Enabling trace at server startup
• Enabling trace on a running server

Using the wsadmin tool to specify a new trace

Alternatively, WebSphere also allows you to control the trace through scripting using the wsadmin tool. This is the best option when you do not have access to the Administrative console or you want to automate tracing during certain events.

1. Follow the instructions in the WebSphere Application Server Information Center to start the wsadmin tool.
2. Ensure that the wsadmin utility is connected to the WebSphere Commerce server. When the wsadmin utility starts, it prints out the server to which it is connected.

   [root@idefix bin]# ./wsadmin.sh WASX7209I: Connected to process "server1" on node WC_demo_node using SOAP connector; The type of process is: UnManagedProcess WASX7029I: For help, enter: "$Help help"wsadmin>

   
   
3. Create a reference to the TraceService object:

   set traceServ [$AdminControl completeObjectName type=TraceService,*]

   
   
4. Print and save the current trace specification:

   set spec [$AdminControl getAttribute $traceServ traceSpecification] puts "Current runtime trace specification: $spec"

   
   
5. Specify new trace specification by issuing the following command. The new trace takes effect immediately.

   $AdminControl setAttribute $traceServ traceSpecification com.ibm.websphere.commerce.WC_ORDER=all:com.mycompany. orders=all

   
   
6. When the trace specification has been changed, the following line is printed in SystemOut.log and the trace is written to the trace file:

   [1/10/08 10:49:22:500 EST] 0000002e ManagerAdmin ITRAS0018I: The trace state has changed. The new trace state is *=info:com.ibm. websphere.commerce.WC_ORDER=all:com.mycompany.orders=all.

   
   
7. Reproduce the problem.
8. To restore the original trace specification, issue the following command:

   $AdminControl setAttribute $traceServ traceSpecification $spec puts "Current runtime trace specification: $spec"

   
   
9. Exit the wsadmin utility by invoking the quit command.

Using the JACL script to enable tracing

In the download section, you will find the tracespec.jacl script in the code_sample.zip file. This script helps you automate the steps described above.

Where does the trace go?

Your trace goes to two different files, SystemOut.log and trace.log, which is the same as when using the WebSphere Application Server or WebSphere Commerce tracing. You can find the trace logs in the following locations:

Depending on the level used when logging the message, these files are written to the following logs:

Back to top

Creating the trace specification

If you use the Administrative console, the console writes the trace specification for you as you select the different components. Alternatively, you can also enter the trace in the text area. To specify a trace, you need to enter the name of the logger followed by an equal sign and the logging level desired. You can specify multiple components by separating them with colons (:). Figure 2 shows the logger’s tree that is displayed in the console.

If the name of the logger corresponds to Java packages and classes, you can use the asterisk (*) as a wildcard to indicate that you want to trace all the components that begin with a certain name. For example, by setting the following trace, you enable full tracing for all the WebSphere Commerce customizations made by your company:

com.mycompany.commerce.*=all

When you enable logging at a certain level, you are also enabling all the levels above it. The following list was extracted from java.util.logging.Level:

For example, if logging is set to INFO, messages that use SEVERE and WARNING are also logged.

Back to top

Tracing WebSphere Commerce components

WebSphere Commerce provides a number of trace components for which you can enable tracing. In contrast with the example provided above, WebSphere Commerce does not have loggers that match the fully qualified class name. Instead, WebSphere Commerce loggers are grouped by functionality. For instance, the commands that are used to manage orders use com.ibm.websphere.commerce.WC_ORDER, contracts com.ibm.websphere.commerce.WC_CONTRACT, and so on. For example, to enable tracing for the runtime engine and the scheduler, use the following string.

com.ibm.websphere.commerce.WC_ORDER=all:com.ibm.websphere.
commerce.WC_SCHEDULER=all

Avoid these practices:

• Never use the WebSphere Commerce components to log messages from the custom code.
• Do not use WC_EXTERN, which is deprecated. Instead, always define your own loggers.

Back to top

Conclusion

Implementing logging and tracing by using the Java Logging framework is a straightforward process. This article showed that following a few best practices and using the tracing tool can significantly improve the serviceability of the code.

Back to top

Download

	Information about download methods

Resources

• Participate in the discussion forum.
  
  
• Package java.util.logging
  
  
• JSR 47: Logging API Specification
  
  
• WebSphere Application Server Information Center: Adding logging and tracing to your application
  
  
• WebSphere Commerce Information Center: Trace components

About the authors

		Andres Voldman is a Software Engineer at the IBM Toronto Lab, Canada. He is part of the WebSphere Commerce Advanced Technical Services team, which specializes in performance and stability.

		Samira Hafezi is a Software Engineer at the IBM Toronto Lab. She is with the WebSphere Commerce Support team.

Rate this page

Please take a moment to complete this form to help us better serve you. Did the information help you to achieve your goal? Yes No Don't know   Please provide us with comments to help improve this page:   How useful is the information? 1 2 3 4 5 Not useful Extremely useful

Back to top