Effective Logging in Applications that Use Solace Messaging (part 2)

In an earlier post, I provided an overview of logging in applications using Solace messaging, different types of logging facilities available in Solace as well some recommended events to log in your application.

To recap, Solace provides implicit logging facilities in terms of API logging and Solace message router logging. As an application developer, you should equip your code to handle and log the following:

• Asynchronous Events
• Solace Exceptions

In this post, I will cover those in more detail along with code snippets to handle them. I will use JMS and Java APIs  for illustration. These are, however, not complete class definitions. Please refer to the sample code bundled with the Solace API package for working samples.

Some of the code snippets and sample events discussed here may require a deeper understanding of Solace concepts. I will cover some basic Solace concepts as the discussion topic requires. You can learn more about the core concepts and features of Solace technology on the Technology page.

Logging Solace Events

Session and Flow Events

Solace Session and Flow concepts are explained in the Solace API Concepts section in the Solace Feature Guide. In brief, a session is required for all client message operations (publish/subscribe both direct and guaranteed messages). Guaranteed messaging requires flows. Several consumer flows can be created in the session to establish a one-to-one mapping of client to endpoints. Flows are either managed implicitly by the API (e.g.: from publisher applications) or explicitly in the application (e.g.: Java queue consumers).  JMS APIs don’t expose flow concept to the application except in few cases (such as flow active state event) where they are provided as JMS extension. You will also find the “Persistence with Queues (Java)” Getting Started series of guides relevant and useful.

In APIs that support guaranteed messaging, guaranteed messages are sent and received inside the flow. Direct messages, on the other hand are handled in the session. Session and flow events are also dealt by individual event handlers separately.

This diagram shows the relationship between session and flow in Solace consumer API.

Solace asynchronous events are handled in the application by event handlers. The complete list of available event handlers to define in your application depends on the choice of API.  Most Solace APIs allow the application to define Session event handlers where the Solace events are received. Some APIs (e.g.: Java & C) also expose flow events thru a flow event handler. Additionally, some APIs (e.g.: Java) support event handlers for specific events such as reconnect events. Please check the Solace API document for event handler support specific to your API.

Event handlers are defined to take reactive steps to the Solace events. Logging these will help in troubleshooting and may be helpful to analyze systemic issues (e.g.: is there a network capacity issue?). A complete treatment of Solace event handling for various Solace APIs is beyond the scope of this post. Let’s review some events of interest and how they are handled generically here.

Solace Events in the Java API

Java applications have a few mechanisms to receive events from the Java API.  The Solace Java API defines the session event handler where all session related events are received. The Solace Java API also defines flow event handler where all flow related events are received. In addition, the Solace Java API also defines a reconnect event handler where applications can receive and log API reconnect events.

A sample session and flow event handler is listed here. As mentioned above, please refer the Java samples that come bundled with the Solace Java API package for complete and working class definition.

Sample Event Handler in Java

public class MyAsyncQueueSub {
     // Message Listener with exception handler
     static class MyMessageListener implements XMLMessageListener {
        public void onReceive(BytesXMLMessage msg) {
           log.info ("Consumer received message delivered to " + 
                  msg.getDestination());
        }
        public void onException(JCSMPException e) {
           log.severe ("Consumer received exception " + e.getMessage());
        }
     } 
     // Flow Event Handler
     static class MyFlowEventHandler implements FlowEventHandler {
        public void handleEvent(Object source,  FlowEventArgs event) {
           log.info ("Got Flow Event : " + event);
        }
     }
     // Skipping details on populating properties,  etc        
     public static void main(String... args) throws JCSMPException { 
     try
     {    
        final JCSMPProperties properties = new JCSMPProperties();
        JCSMPSession session = 
             JCSMPFactory.onlyInstance().createSession(properties, 
                null,   // Use default context
                new MySessionEventHandler());
        // Create topic subscriber 
        String topicName;
        topic = JCSMPFactory.onlyInstance().createTopic(topicName);
        final XMLMessageConsumer cons = session.getMessageConsumer(
                new MyReconnectEventHandler(), 
                new MyMessageListener());
        session.addSubscription(topic);
        cons.start();
        // Create Queue consumer
        String queueName;
        final EndpointProperties endpointProps = 
                new EndpointProperties();
        final Queue queue = 
             JCSMPFactory.onlyInstance().createQueue(queueName);
        final ConsumerFlowProperties flow_props = 
            new ConsumerFlowProperties();
        flow_props.setEndpoint(queue);
        EndpointProperties endpoint_props = 
            new EndpointProperties();
        final FlowReceiver flow = session.createFlow (
            new MyMessageListener(), 
            flow_props, 
            endpoint_props, 
            new MyFlowEventHandler());
        flow.start();
        catch (Exception e) { // … }
    }
}

Here are some sample events to consider logging in Java applications as they affect the message flow or may be useful for book keeping and troubleshooting.

• FlowEvent.FLOW_ACTIVE & FlowEvent.FLOW_INACTIVE
  These two events are associated with flow active status change notification in Java. It is recommended that these events are logged since this affects the message flow.
• JCSMPStreamingPublishCorrelatingEventHandler
  This event is received when a non-blocking asynchronous publisher receives an acknowledgement for a guaranteed message published. Logging this on a high traffic publishing application may consume significant resources, so consider logging this carefully.
• JCSMPReconnectEventHandler
  The Solace Java API calls this event hander whenever an API reconnect is triggered after successful initial connection. Applications provide preReconnect and postReconnect methods to handle and log the reconnect event. Any messages published during the reconnection are buffered in the API, but logging these will help troubleshoot any eventual publisher backlog.

Solace Events in JMS API

JMS applications use a session event handler to receive all asynchronous events. The concept of Solace flow is not exposed in the Solace JMS API and hence both session and flow events are received at the same event handler.

Unlike the Solace Java API, the Solace JMS API is less chatty and doesn’t expose many events to the application event handler. For e.g., the reconnect related events are not exposed to the application now (It is, however changing and in future versions of SolOS, this will be exposed to the Application. So, if you are looking forward to handling reconnect events in JMS, hang in there!).

Sample event handler in JMS

// Event Listener
class MyEventListener implements SolEventListener {  
    // Log and handle events
    public void handleEvent(SolEventSource source,  SolEvent event) {
        log.info ("Got event : "+ event.toString());
        // handle events
        if (event.getEventType() == 
          SolEvent.SOLEVENT_TYPE_ACTIVE_FLOW_INDICATION) {
          // handle the flow status event
        }
}

// Message Listener
class MyMessageListener implements MessageListener {  
      // …
}

public void run() {
   // CF,  Connection setup and other details skipped
   ConnectionFactory connectionFactory = null ; 
   String queueJNDIName = “my/queue” ;

   Connection connection = connectionFactory.createConnection();
   Session session = connection.createSession(false,  
       Session.AUTO_ACKNOWLEDGE);
   Queue queue = (Queue)initialContext.lookup(queueJNDIName);

   SolEventSource eventSource = (SolQueueReceiver)consumer;
   eventSource.addSolEventListener(new MyEventListener());

   MessageConsumer consumer = session.createConsumer(queue);
   consumer.setMessageListener(new MyMessageListener());

   // start the JMS Connection.
   connection.start();
}

Here is an event that is worth logging in JMS applications as it may impact the message flow.

• SOLEVENT_TYPE_ACTIVE_FLOW_INDICATION
  This event is received at JMS Session eventHandler when the active flow status of the consumer has changed form Active to Inactive or vice-versa. This can happen when multiple consumers are bound to the non exclusive queue and their connection status changes (e.g.: one of the consumers closed connection). Depending on the flow status received (active or inactive), your consumer application will start or stop receiving messages after this event occurs. As this affects the message flow, it’s a good idea to log this event.

Logging Solace Exceptions

Solace APIs throw various Exceptions to handle exceptions related to the operation of the Solace APIs and these should be handled in your application. Logging the exception details also makes a good source of information for troubleshooting.

JMS Exceptions

JMSException is the root class for all JMS API exceptions that are thrown to JMS applications by the Solace JMS API. The Exception also has the reason string and Solace provided error code that can be logged. This is subclassed into specific Exceptions such as InvalidClientIDException, InvalidDestinationException, InvalidSelectorException, JMSSecurityException. Please refer the JMSException  documentation for list of supported subclasses.

Besides JMSException, a JMS application can also receive NamingException which will be thrown when JNDI object lookup fails. If your JMS application uses JNDI Connection Factories and JNDI stores for destination name translation, you should also catch NamingException and log them.

JMS also provides an onException listener that is used to communicate exceptions which happen asynchronously. If your application is an asynchronous consumer, you should define and register the onException listener with adequate logging included. This exception listener is the only mechanism for the API to communicate exceptions such as connection errors. An example would be “unknown flow event” which can happen when the connection between your application and the Solace message router was lost and API auto retry failed to reconnect.

Sample Exception Handler in JMS

public class MyConsumer implements ExceptionListener {
    
    public void onException(JMSException e) {
        if ((e != null) && (e.getErrorCode() ==
            SolJMSErrorCodes.EC_UNKNOWN_FLOW_NAME_ERROR)) {
            // log exception
            log.info("Invalid flow. resetting connection",  e);
            // handle exception
        } else {
            e.printStackTrace();
        }
    }
    
    private void createConsumer {
        try {
            String destinationJNDIName = "my/jndi/destination";
            // Context,  connection and session creation skipped
            Destination destination =
                (Destination)initialContext.lookup(destinationJNDIName);
            MessageConsumer consumer =
                session.createConsumer(requestDestination);
        }
        // Handle messaging exceptions
        catch (NamingException e)
        {
            // log exception
            log.error("JNDI lookup exception occured : " + 
                e.toString());
            // handle exception
        }
        catch (JMSException e) {
            // log exception
            log.error("JMS exception "+ e.getErrorCode() + 
                " occured while creating consumer : " +
                e.toString());
              e.printStackTrace();
            // handle exception
        }
        // Handle other exceptions
        catch (Exception e) {
            System.out.println(e.getMessage());
        }
    }
}   

Java Exceptions

The Solace Java API defines JCSMPException which serves as base class for all Java Exceptions. Similar to JMSException, several subclasses are available such as JCSMPStateException, JCSMPTransportException. Please refer the JCSMPException documentation for list of all supported subclasses.  Your application should handle the applicable subclass exceptions.

Logging Configuration

As discussed in my previous post, all Solace APIs have implicit logging through natively supported language features and extensions. This logging, including format and the desired level of logging is controlled by the config files.  A sample log4j config file is provided below.

Sample log4j properties

# Set root logger level for Appender A1
log4j.rootLogger=INFO,  A1

# Define Rolling File Appender 
log4j.appender.A1=org.apache.log4j.RollingFileAppender
log4j.appender.A1.MaxFileSize=1MB
log4j.appender.A1.MaxBackupIndex=5
log4j.appender.A1.File=jms-samples.log
log4j.appender.A1.layout=org.apache.log4j.PatternLayout
log4j.appender.A1.layout.ConversionPattern=%d %-5p [%c] (%t) %m%n

# Categories (with A1 enabled)
# Valid values: FATAL,  ERROR,  WARN,  INFO,  DEBUG,  TRACE
# Default value if missing is INFO (based on above rootLogger)
# Note: Values below set all logging level to DEBUG
# please adjust based on your requirement and environment.
log4j.logger.com.solacesystems.jcsmp=DEBUG, A1
log4j.logger.com.solacesystems.jms=DEBUG, A1
log4j.logger.com.solacesystems=DEBUG, A1

Click here for more information on tuning log4j properties file.

Happy Logging!

I hope these posts give you a better appreciation and understanding for logging Solace events and exceptions in your application. It’s hard to cover all required background material in a short post like this. You can check out the following links for more details.

• Solace Technical Documentation (in particular Developer Guides)