MessageAlerts in JBossESB 4.7

Is One of My Services or Actions Clogging Things Up?

JBossESB 4.7 includes some great new features. In this post, I wanted to highlight a feature that can help answer the above question.

The new feature feature is "MessageAlerts" (org.jboss.soa.esb.listeners.message.MessageAlerts). This feature enables you to collect fine grained information on the processing time or number of bytes that a specific service, or a specific action in a service requires to process a single message.

You use MessageAlerts by defining processing time and byte total thresholds on a per service and/or action basis. When the service or action in question takes longer than the defined time threshold to process a message, a WARNING is written to the server log and made available in the JMX console. You define the thresholds with these properties:

alertTimeThreshold="420"
alertLengthThreshold="10"

The time-related threshold is measured in milliseconds. The length-related threshold is measured in bytes.

When would you use the byte total threshold? This can be useful if, for example, the service or action that you are watching performs transformations, and suddenly begins processing way more bytes than you're expecting that it should.

An Example in a Quickstart

The MessageAlerts feature is demonstrated in a quickstart named, appropriately enough, "messagealert." If you've ever run the "helloworld" quickstart, then this quickstart should be familiar. The only changes are the addition of the org.jboss.soa.esb.samples.quickstart.messagealerts.DelayAction action class (as you can guess by the name, this class introduces a delay to cause the alertTimeThreshold to be reached, and the changes in the jboss-esb.xml file listed below:

1:   <services>
2:    <service
3:     category="FirstServiceESB"
4:      name="SimpleListener"
5:      description="Hello World"
6:      alertTimeThreshold="420"
7:      alertLengthThreshold="10"
8:      >
9:     <listeners>
10:      <jms-listener name="JMS-Gateway"
11:       busidref="quickstartGwChannel"
12:       is-gateway="true"
13:      />
14:       <jms-listener name="helloWorld"
15:        busidref="quickstartEsbChannel"
16:      />
17:     </listeners>
18:     <actions mep="OneWay">
19:      <action name="action1"
20:       class="org.jboss.soa.esb.samples.quickstart.messagealerts.MyJMSListenerAction"
21:       process="displayMessage"
22:      />
23:      <action name="action2" class="org.jboss.soa.esb.actions.SystemPrintln">
24:      <property name="printfull" value="false"/>
25:     </action>
26:     <action name="action3"
27:      class="org.jboss.soa.esb.samples.quickstart.messagealerts.DelayAction"
28:      process="delayMessage"
29:      alertTimeThreshold="30"
30:      alertLengthThreshold="50">
31:     </action>
32:    </actions>
33:   </service>
34:  </services>

The changes related to MessageAlerts are:

• Lines 6-7: These set the service thresholds at 420 milliseconds in time and 10 bytes in length.
  
• Lines 29-30: And, these set the action thresholds at 30 milliseconds in time and 50 bytes in length.
  

When we deploy and run the quickstart, the following is written to the server.log:

 22:00:28,833 INFO [STDOUT] &&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&
22:00:28,837 INFO [STDOUT] Body: Message Alerts
22:00:28,837 INFO [STDOUT] &&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&
22:00:28,850 INFO [STDOUT] Message structure:
22:00:28,850 INFO [STDOUT] [Message Alerts].
22:00:31,852 WARN [ServiceMessageCounter] jboss.esb:category=MessageCounter,deployment=Quickstart_messagealerts.esb,service-category=FirstServiceESB,service-name=SimpleListener service, action3 action alert time 3001 took longer than 30 ms
22:00:31,853 WARN [ServiceMessageCounter] jboss.esb:category=MessageCounter,deployment=Quickstart_messagealerts.esb,service-category=FirstServiceESB,service-name=SimpleListener service, action3 action message size 2960 was larger than 50 bytes
22:00:31,853 WARN [ServiceMessageCounter] jboss.esb:category=MessageCounter,deployment=Quickstart_messagealerts.esb,service-category=FirstServiceESB,service-name=SimpleListener service alert time 3007 took longer than 420 ms
22:00:31,854 WARN [ServiceMessageCounter] jboss.esb:category=MessageCounter,deployment=Quickstart_messagealerts.esb,service-category=FirstServiceESB,service-name=SimpleListener service message size 2960 was larger than 10 bytes

And, the same information is available in the JMX log under jboss.esb, service=MessageAlerts:


As you can see in this screenshot, you can reset the counters through the JMX console. (And, yes, as you can also see in this screenshot, I'm staying up way too late at night writing about this stuff.)

You can also access the same information from the jboss.esb mbean directly:

sh ./twiddle.sh get "jboss.esb:service=MessageAlerts"

And, for extra credit, you can access the MessageAlerts service programatically. To do this, first, we'll modify the quickstart's jboss-esb.xml file to move the action that prints information to the server log to happen after the delay (and therefore after the MessageAlerts have been generated).

Then, we'll replace the code in MyJMSListenerAction.java with this:

1:   package org.jboss.soa.esb.samples.quickstart.messagealerts;  
2:    
3:   import org.jboss.soa.esb.actions.AbstractActionLifecycle;  
4:   import org.jboss.soa.esb.helpers.ConfigTree;  
5:   import org.jboss.soa.esb.message.Message;  
6:    
7:   import javax.management.ObjectName;  
8:   import javax.management.MBeanServer;  
9:   import javax.management.MalformedObjectNameException;  
10:    
11:   import org.jboss.mx.util.MBeanProxyExt;  
12:   import org.jboss.mx.util.MBeanServerLocator;  
13:   import org.jboss.soa.esb.actions.AbstractActionPipelineProcessor;  
14:   import org.jboss.soa.esb.actions.ActionProcessingException;  
15:    
16:   import java.util.Vector;  
17:    
18:   public class MyJMSListenerAction extends AbstractActionLifecycle  
19:   {  
20:    
21:   protected ConfigTree _config;  
22:    
23:   public MyJMSListenerAction(ConfigTree config) { _config = config; }  
24:    
25:   public Message displayMessage(Message message) throws Exception{  
26:    
27:   MBeanServer server = org.jboss.mx.util.MBeanServerLocator.locateJBoss();  
28:   Vector theAlertsVector = (Vector)server.getAttribute(new ObjectName("jboss.esb:service=MessageAlerts"), "Alerts");  
29:    
30:   for (int i = 0; i < theAlertsVector.size(); i++ ) {  
31:   System.out.println("******Data returned from MessageAlert[" + i + "] = " + theAlertsVector.elementAt(i) + "\n" );  
32:   }  
33:    
34:   System.out.println("&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&");  
35:   System.out.println("Body: " + message.getBody().get()) ;  
36:   System.out.println("&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&");  
37:   return message;  
38:   }  
39:    
40:  }  

• Line 27: Locates the MBeanServer - this is easy as we are running in the same JVM as the server
  
• Line 28: Retrieves the Vector of MessageAlerts from the jboss.esb MessageAlerts service
  
• Lines 30-33: and prints them out
  

Closing Thoughts

The ability to building your own services and custom actions with JBossESB is one characteristic of its overall flexibility. With MessageAlerts, you can more easily track the efficiency of those services and actions, at a fine grained level. The message alert feature makes it simple.

Acknowledgements

Thanks to Tom Cunningham for his input to this post and his patient responses to my many questions!