Implementing tracing, logging, and error handling in mediation modules using WebSphere Integration Developer and WebSphere ESB V7, Part 1

Strategies for designing error handling in mediation flows

This article describes different tracking, logging, and fault handling features in mediation modules created with WebSphere® Integration Developer V7. The runtime capabilities apply equally to mediations running in WebSphere Enterprise Service Bus and WebSphere Process Server.

Share:

Frank I. Toth (ftoth@us.ibm.com), Software Engineer, IBM

Frank Toth has 4 years of experience as a Software Developer at IBM and 6 years in customer support. His positions include resolving software-related problem reported by customers using WebSphere Integration Developer.



Dave Screen (dave.screen@uk.ibm.com), Software Engineer, IBM

Photo of Dave ScreenDave Screen is a Software Engineer and currently works as a BPM Consultant in IBM Software Services for WebSphere (ISSW) at the IBM Hursley Software Lab in the United Kingdom. He has 9 years of experience that includes areas in WebSphere, security, transactions, Java runtimes, and Eclipse.



24 November 2010

Also available in Chinese

Introduction

A mediation module is created with WebSphere Integration Developer V7 (hereafter called Integration Developer). Each mediation module can contain a number of mediation flow components. Each component can implement a number of operations defined on the Web Service (WSDL) interface. Each implementation of an operation is called a mediation flow. During execution of a mediation flow (a “mediation flow instance” or “flow” for short), different types of events can occur.

Consider the following failure scenarios:

  1. Data inside the message does not match rules expected by the application, such as an invalid account type.
  2. Web service invocation returns a fault message defined on its WSDL interface, such as the supplied account number is invalid.
  3. Input request is of an invalid data format, such as a malformed XML.
  4. Web service invocation failure occurs, such as an HTTP 404 status code response because the target service is down.
  5. Database row update fails because the database manager is offline.

Depending on the requirements of the solution, how to handle each of these failures might vary, such as the following:

  1. Logging an invalid data item in a database.
  2. Propagating a downstream fault back to the client of the mediation.
  3. Tracing the invalid data in a system log for diagnostic purposes.
  4. E-mailing an administrator to report a system failure.
  5. Allowing a database exception to propagate as a system failure because the application does not operate unless the database is functional.

This article uses the term “logging” to mean recording an event for the purposes of the application. Examples include auditing for the business, or keeping a record for reconciliation later. The term “tracing” means recording events for technical or diagnostic purposes. You can use "trace” to pinpoint a problem. Sometimes finer levels of tracing or debugging might be required. Mediation primitives, within the mediation flow, process messages as Service Message Objects (SMO). The mediation primitives and other features in conjunction with the SMO make it possible to both log data and to provide detailed information that can help to analyse and debug issues.

Part 1 of this article defines the available mediation primitives and runtime features and which are best suited to logging or tracing. In some cases, there is a grey area because you can use a primitive for either purpose.

When a mediation flow is implementing a web service or calling out to existing web services, there are choices on how to handle failures. For example, these failures can be “modeled” as declared faults on the WSDL interfaces, or “unmodeled” as system failures. A future article, Part 2, will demonstrate different ways to handle errors in mediation flows.


Tracing and logging features in WebSphere ESB mediations

Several different mediation flow primitives are available for logging and tracing. In the mediation flow editor, you can insert these primitives before or after any other mediation primitive that has an Input, Output, or Fail terminal. Let us differentiate between tracing and logging components by considering the environments in which they usually apply.

Tracing components are usually used for short term and temporary debugging purposes with a limited amount of data processed.

Logging components are for long-term data collection and storage. Their design is more performance-oriented for production use.

  • Cross component tracing (XCT): XCT lets you track messages through the SCA modules and components.
  • Integrated Test Client: Use this feature to test components or modules and view the data flow through mediation primitives.
  • Trace primitive: Use this primitive to trace messages to be logged to the server logs or to a file.
  • Message logger primitive: Use this primitive to store messages in a relational database, or in other storage mediums if you use the custom logging functionality.
  • Event emitter primitive: This primitive can create common base events containing none, some, or all of the message data.
  • Custom mediation transformation primitive, using Standard Visual Snippet utilities: Use these utility functions to log detailed data to the server's SystemOut.log file.

Tracing components in mediation flows

The following mediation features are available for tracing purposes.

Cross component tracing

Cross component trace (XCT) lets you track messages through the SCA modules and components. It adds standard out trace statements that are parsed by a viewer in Integration Developer. WebSphere ESB tracks the progress of the message through individual primitives, instead of simply at the mediation component level. An example is shown in Figure 1.

Figure 1. Cross component tracing
Cross component tracing

One benefit of cross component trace over some of the other trace and logging mechanisms is that you can completely enable or disable it at runtime without the involvement of the development environment. This makes it applicable for test or production environments. XCT can track the interactions between primitives, components, and modules. You can also enable it on a per-module basis when set in the administration console. It also has the option of data snapshot, that is, to capture the data as well. To enable, use the toolbar on the Server Logs view, or in the administration console under Troubleshooting > Cross-Component Trace State (Figure 2). Logging is directed into the SystemOut log and these files can be consumed inside Integration Developer in the Server Logs view.

Figure 2. Cross component trace state
Cross component trace state

Integrated test client

The Integrated Test Client (ITC) connects directly with the server to launch tests and track execution of the flow (Figure 3). You can use it in two ways:

  • Test component/export/import: This invokes an operation using a message entered in the GUI editor.
  • Attach mode: This is the trace execution of requests not initiated by the ITC.

A strong benefit of the ITC is that tests (including input messages) can be stored and, hence, re-used in Test Trace files in Test projects. You can enter data as XML (for example, imported from a file), or graphically using a Business Object editor. It can send SOAP messages for Web Service Export bindings with an option to configure the endpoint (in the Transport tab). The data passing between the mediation primitives is available for inspection.

Another key feature is the ability to emulate references. This makes it possible to test components in isolation without requiring all of the backends.

The attach mode is useful for checking behavior when a mediation is driven by an external client, such as SOAPUI, or through messaging, such as WebSphere MQ messages being processed using a MQ/JMS Export.

Figure 3. Integrated Test Client testing a Web Service Export binding
Integrated Test Client testing a Web Service Export binding

Trace mediation primitive

Use the Trace mediation primitive to debug mediation flows and to specify trace messages to be logged to the server logs or to a file. The trace messages can contain service message object (SMO) message content and other information about the mediation flow.

The example in Figure 4 shows the Trace primitive that is configured to log a modeled web service call exception to a flat file, C:\WSTestTrace.log.

Figure 4. Trace mediation primitive
Trace mediation primitive

The following configurable properties are available for the Trace mediation primitive:

  • Enabled: Similar to other primitives, it enables or disables the primitive's functionality. It is a promotable property.
  • Destination: This specifies the location where the trace statement should be added, either Local Server Log (SystemOut.log), User Trace (UserTrace.log), or File (User-defined).
  • File path: This specifies the location of the trace file when the destination field is specified as File.
  • Message: This defines the message format that should be traced: {0} = time stamp, {1} = Message ID, {2} = Mediation name, {3} = Module name, {4} = Message defined by the root property, {5} = Version of the SMO. You can include additional explanatory text among the placeholders.
  • Root path: This is the XPath expression that identifies what section of the SMO should be serialized into the message.

Note that this primitive is not typically expected to be used in a production system because the MessageLogger or EventEmitter primitives are more suitable.

Logging components in mediation flows

Message logger primitive

Use the message logger mediation primitive to store messages to a relational database using an IBM-defined database schema (table structure). It can write to other storage mediums, such as flat files, through the use of the custom logging facility. You can use the messages later for data mining or auditing purposes.

Figure 5 shows the message logger primitive configured to a log modeled web service call exception to a preconfigured database using a JNDI name reference as "Data source name".

Figure 5. Message logger primitive
Message logger primitive

The following configurable properties are available for the Message logger primitive:

  • Enabled: This is similar to other primitives. It enables or disables the primitive's functionality. It is a promotable property.
  • Root: This is the XPath expression that identifies what section of the SMO is serialized into the message.
  • Transaction mode: "Same" causes the message to log under the current transaction. "New" causes the message to log under its own transaction.
  • Logging type: This specifies the location where the trace statement is added, either to a database by default, or use the user-defined handler described below.
  • Data source name: This specifies the preconfigured database, using the JNDI reference, when the logging type field is specified as “Database”.
  • Handler: This directs output somewhere other than the database, specifies a class that extends java.util.logging.Handler.
  • Formatter: This specifies the data formatter class, implementing java.util.logging.Formatter.
  • Filter: This specifies the data filtering handler class, implementing java.util.logging.Filter.
  • Literal: This defines the message format that is traced: {0} = time stamp, {1} = Message ID, {2} = Mediation name, {3} = Module name, {4} = Message defined by the root property, {5} = Version of the SMO. You can also include additional explanatory text.
  • Level: This specifies the trace level that is used to log the message. This is part of the log record passed to the handler.

Using the "New" transaction mode ensures that a successful message log to a database is always committed. That is, in "Same" mode, a message logged is not committed if the enclosing transaction is rolled-back. An example of the transaction not being committed is if the Fail mediation primitive is used, which triggers a ServiceRuntimeException.

The supplied WESBFileHandler logs to a file named MessageLog.log in the temporary directory.

To implement your own handler:

  • Extend java.util.logging.Handler and make your class available at runtime, for example, by including it directly in your project, or perhaps as a Jar in a library.
  • In your implementation, override publish(LogRecord) and use the getFilter() and getFormatter() methods to access the other classes specified.
  • Use getLevel() on the LogRecord argument to access the Level property from the mediation primitive.
  • If logging to a file, then use buffering, such as a new BufferedWriter(new FileWriter).

Event emitter primitive

The event emitter primitive defines the application specific event data that is placed into the extendedDataElements section of the common base event. This topic summarizes the mapping between the properties defined in the event emitter primitive and the elements of the common base event.

When you generate an event definition from a mediation flow that has an event emitter primitive, the generated event definition contains the primitive's properties in these locations:

  • The label property of the primitive becomes the name of the generated event.
  • The mediation module name is the ModuleName of extendedDataElement.
  • The primitive name is the MediationName of extendedDataElement.
  • The primitive's root property, for example, /body, is in the root of extendedDataElement.
  • The value of the elements in the message is contained in the message of extendedData.

Emitting common base events

You can emit a common base event at a significant point in a mediation flow by using an event emitter mediation primitive. You can also define the parts of the message that is contained in the event. Common base events are emitted to the CEI server, which is accessed by many different applications that consume the events.

When you create an event emitter primitive in a mediation flow, you specify a label for the event and the part of the message that is included in the event. At runtime, when the event emitter primitive runs the mediation flow, a common base event is emitted. The event label and message information is included in the Extended Data Elements of the common base event.

When not to use an event emitter

Consider where you place an event emitter in your flow, and what data you choose to be stored in the event. Avoid placing an event emitter in the normal run path of a flow because this affects performance by causing a large number of events to be generated.

When to use an event emitter

The event emitter primitive provides a way to generate significant business events from within a mediation flow. Think of an event emitter as a notification mechanism that is used to indicate an unusual event, such as a significant failure within a flow, or an unusual path in the flow. Avoid placing an event emitter in the normal path of a flow because this affects performance by causing a large number of events to be generated.

In the following flow shown in Figure 6, an event emitter is used when there is a failure in the message log. This is a significant failure in the flow.

Figure 6. Event emitter primitive
Event emitter primitive

Custom mediation primitive

This primitive can use the Standard Visual Snippet feature for various logging functions. We recommend to use one of the out-of-the-box primitives, such as the Trace primitive or Message logger primitive. These have some advantages, for example, having a built-in "enabled" property, that once promoted, can let the administrator enable or disable their function. One particular use of the custom mediation primitive is when conditional logic is required to determine what to log or whether to log.

For troubleshooting, the Custom Mediation transformation primitive has several built-in Standard Visual Snippet utility functions for this purpose. Once it is placed into the flow in the Mediation flow editor, the Properties tab > Details provides several Standard Visual Snippet utility options, which are described in the following sections:

  • print to log: This prints any text to the SystemOut log.
  • print BO to log: This prints a Business Object or Service Message Object to the SystemOut log.
  • print to logger: This prints text to the java.util.logging logger.
  • BO print to logger: This prints a Business Object or Service Message Object to the java.util.logging logger.
  • to text: This prints the toString() of a Java Object to the log.

print to log

Use this snippet to print any text to the SystemOut log. Note: Heavy logging to SystemOut logs will decrease application performance.

  1. Select the Standard Visual Snippet utility print to log function, as shown in Figure 7.
    Figure 7. Select the Standard Visual Snippet utility function
    Select the Standard Visual Snippet utility function
  2. Drag and drop it in the Visual Snippet editor canvas, as shown in Figure 8.
    Figure 8. Visual Snippet editor
    Visual Snippet editor
  3. The generated runtime Java™ code is based on Java System.out.println() method, as shown in Listing 1.
    Listing 1. Generated Java code
    java.lang.String __result__5 = "Start logging - print to log";
    {// print to log
    	System.out.println(__result__5);
    }

print BO to log

Use this snippet to print a Business Object or Service Message Object to the SystemOut log. Note: Serializing business objects is computationally expensive and, therefore, can reduce application performance.

  1. Select the Standard Visual Snippet utility print BO to log function, as shown in Figure 9.
    Figure 9. Select the Standard Visual Snippet utility function
    Select the Standard Visual Snippet utility function
  2. Drag and drop it in the Visual Snippet editor canvas, as shown in Figure 10.
    Figure 10. Visual Snippet editor
    Visual Snippet editor
  3. The generated runtime Java code is based on commonj.sdo API interface, as shown in Listing 2.
    Listing 2. Generated Java code
    commonj.sdo.DataObject __smo = (commonj.sdo.DataObject)smo;
    try {
    	{// print BO to log
    	 com.ibm.websphere.bo.BOXMLSerializer srv = 
         (com.ibm.websphere.bo.BOXMLSerializer) new 
         com.ibm.websphere.sca.ServiceManager().locateService
    ("com/ibm/websphere/bo/BOXMLSerializer");
    	 commonj.sdo.Type type = __smo.getType();
    	 srv.writeDataObject(__smo, type.getURI(), 
    type.getName(), java.lang.System.out);
    	}
    }
    catch(java.io.IOException ex2){
    	{// print to log
    	 System.out.println(ex2);
    	}
    	}

print to logger

Use this snippet to print text to a java.util.logging logger. You can use trace levels so that messages are only output when the server is configured with particular trace settings.

  1. Select the Standard Visual Snippet utility print to logger function, as shown in Figure 11.
    Figure 11. Select the Standard Visual Snippet utility function
    Select the Standard Visual Snippet utility function
  2. Drag and drop it in the Visual Snippet editor canvas, as shown in Figure 12.
    Figure 12. Visual Snippet editor
    Visual Snippet editor
  3. The generated runtime Java code is based on java.util.logging.Logger class, as shown in Listing 3. You can set the Log level to produce various detailed level information:
    • Severe, Warning, Info, and Config messages are printed to SystemOut.log. They are also printed to the trace.log file of the server, if tracing is enabled on the server.
    • Fine, Finer, and Finest messages are only printed to the trace.log file and only if tracing is enabled on the server.
    • Setting the level to OFF or ALL causes the messages to always print to the SystemOut.log file.
      Listing 3. Generated Java code
      java.lang.String __result__17 = "Print to logger";
      commonj.sdo.DataObject __result__18 = __smo.getDataObject("body");
      {// Log Level: SEVERE
      	final String FQCN = getClass().getName();
      	java.util.logging.Logger l = java.util.logging.Logger.getLogger(FQCN);
      	if(l.isLoggable(java.util.logging.Level.SEVERE)) 
      	{
      	l.logp(java.util.logging.Level.SEVERE, FQCN.substring
           (FQCN.lastIndexOf('.') + 1), "snippet", 
      String.format("%s: %s",__result__17,java.lang.String.valueOf(__result__18)));
      	}
      	}

BO print to logger

Use this snippet to print a Business Object or Service Message Object to the java.util.logging logger.

  1. Select the Standard Visual Snippet utility BO print to logger function, as shown in Figure 13.
    Figure 13. Select the Standard Visual Snippet utility function
    Select the Standard Visual Snippet utility function
  2. Drag and drop it in the Visual Snippet editor canvas, as shown in Figure 14.
    Figure 14. Visual Snippet editor
    Visual Snippet editor
  3. The generated runtime Java code is based on commonj.sdo API interface and java.util.logging.Logger class, as shown in Listing 4. You can set the Log level to produce various detail level information:
    • Severe, Warning, Info, and Config messages are printed to SystemOut.log. They are also printed to the trace.log file on the server, if tracing is enabled on server.
    • Fine, Finer, and Finest messages are only printed to the trace.log file and only if tracing is enabled on server.
    • Setting the level to OFF or ALL causes the messages to always print to the SystemOut.log file.
      Listing 4. Generated Java code
      java.lang.String __result__3 = "BO print to logger";
      try {
      	{// Log Level: ALL
      	 final String FQCN = getClass().getName();
      	 java.util.logging.Logger l = java.util.logging.Logger.getLogger(FQCN);
      	 if(l.isLoggable(java.util.logging.Level.ALL))
      	  {
      	 com.ibm.websphere.bo.BOXMLSerializer serializer =
           (com.ibm.websphere.bo.BOXMLSerializer) com.ibm.websphere.sca.
           ServiceManager.INSTANCE.locateService
           ("com/ibm/websphere/bo/BOXMLSerializer");
      	 java.io.ByteArrayOutputStream stream = new java.io.
           ByteArrayOutputStream();
      	 serializer.writeDataObject(__smo,__smo.getType().getURI(),
           __smo.getType().getName(),stream);
      	 l.logp(java.util.logging.Level.ALL, FQCN.substring(FQCN.lastIndexOf('.') 
             + 1), 
           "snippet", String.format
      ("%s: %s",__result__3 ,stream.toString() ));
      		}
      	}
      }
      catch(java.io.IOException ex){
      	{// print to log
      		System.out.println(ex);
      	}
      	}

to text

Use this snippet to print the toString() of a Java Object to the log.

  1. Select the Standard Visual Snippet utility to text function, as shown in Figure 15.
    Figure 15. Select the Standard Visual Snippet utility function
    Select the Standard Visual Snippet utility function
  2. Drag and drop it in the Visual Snippet editor canvas, as shown in Figure 16.
    Figure 16. Visual Snippet editor
    Visual Snippet editor
  3. The generated runtime Java code uses Java object.toString() method and based on Java System.out.println() method, as shown in Listing 5.
    Listing 5. Generated Java code
    java.lang.String __result__20;
    {// to text
    	__result__20 = __smo.toString();	
    }
    {// print to log
    	System.out.println(__result__20);
    }

Performance considerations

All tracing and logging features have some performance impact that you need to consider. For example, is it necessary to log the entire message? In particular, outputting to log files can drastically reduce the execution speed and becomes a performance bottleneck.

If you use trace to log files for testing, remove it completely for performance test or production, or devise a mechanism to enable or disable. The trace mediation primitive has a promotable property called “Enabled”. You can use this to have a trace property available for the administrator in the Integrated Solutions Console (under Enterprise Applications > SCA Modules > <moduleName> > Properties). The cost of leaving a disabled primitive in the mediation flow is relatively insignificant.


Conclusion

This article described the available mediation primitives for tracing and logging in a mediation module using WebSphere Integration Developer V7 and running on a WebSphere ESB V7 server. The detailed description of the mediation primitives and their behavior can help you select the right primitive in the mediation flow for your project design.

Resources

Learn

Discuss

Comments

developerWorks: Sign in

Required fields are indicated with an asterisk (*).


Need an IBM ID?
Forgot your IBM ID?


Forgot your password?
Change your password

By clicking Submit, you agree to the developerWorks terms of use.

 


The first time you sign into developerWorks, a profile is created for you. Information in your profile (your name, country/region, and company name) is displayed to the public and will accompany any content you post, unless you opt to hide your company name. You may update your IBM account at any time.

All information submitted is secure.

Choose your display name



The first time you sign in to developerWorks, a profile is created for you, so you need to choose a display name. Your display name accompanies the content you post on developerWorks.

Please choose a display name between 3-31 characters. Your display name must be unique in the developerWorks community and should not be your email address for privacy reasons.

Required fields are indicated with an asterisk (*).

(Must be between 3 – 31 characters.)

By clicking Submit, you agree to the developerWorks terms of use.

 


All information submitted is secure.

Dig deeper into WebSphere on developerWorks


static.content.url=http://www.ibm.com/developerworks/js/artrating/
SITE_ID=1
Zone=WebSphere, SOA and web services
ArticleID=588462
ArticleTitle=Implementing tracing, logging, and error handling in mediation modules using WebSphere Integration Developer and WebSphere ESB V7, Part 1
publish-date=11242010