Enterprise Integration Zone is brought to you in partnership with:

Ir. Charles Moulliard is a Sr. FuseSource Architect - Consultant and Apache Committer with more than 18 years of expertise in design of solution based on J2EE / .NET technologies. As a Solution Architect, he has been involved in system integration of client projects in Financial and Banking world. The skills (Methodology, UML, RUP, Project Management - Prince2, Telecommunication, Network, Security, Web Development, Programming languages, RDBMS, Architecture - J2EE/SOA, Middleware) that he acquires during its career path have help him to address business, functional, security and infrastructure requirements and transpose them into operable and efficient solutions. He is also fascinated to train people on new emerging technologies like SOA, OSGI, J2EE and ESB and provide consultancy for FUSE clients. As an Apache Committer he contributes since several years on the projects Apache Camel, Karaf and ServiceMix and uses these technologies as standards for integration projects. He is the author of the Camel Bindy DataFormat. Charles has posted 8 posts at DZone. You can read more from them at their website. View Full User Profile

Measure Elapsed Time With Camel

07.26.2012
| 3744 views |
  • submit to reddit

With the last version of Apache Camel, we provide a event notifier support class which allow to keep information about what happen on Exchange, Route and Endpoint. One of the benefit of this class is that you can easily audit messages created in Camel Routes, collect information and report that in log by example.

When developing an application, it is very important to calculate/measure elapsed time on the platform to find which part of your code, processor or system integrated which is the bad duck and must be improved.

In three steps, I would show you How to enable this mechanism to report :
- Time elapsed to call an endpoint (could be another camel route, web service, ...)
- Time elapsed on the route exchange

STEP 1 - Create a Class implementing the EventNotifierSupport

public class AuditEventNotifier extends EventNotifierSupport {

public void notify(EventObject event) throws Exception {
  if (event instanceof ExchangeSentEvent) {
      ExchangeSentEvent sent = (ExchangeSentEvent) event;
      log.info(">>> Took " + sent.getTimeTaken() + " millis to send to external system : " + sent.getEndpoint());
  }

  if (event instanceof ExchangeCompletedEvent) {;
      ExchangeCompletedEvent exchangeCompletedEvent = (ExchangeCompletedEvent) event;
      Exchange exchange = exchangeCompletedEvent.getExchange();
      String routeId = exchange.getFromRouteId();
      Date created = ((ExchangeCompletedEvent) event).getExchange().getProperty(Exchange.CREATED_TIMESTAMP, Date.class);
      // calculate elapsed time
      Date now = new Date();
      long elapsed = now.getTime() - created.getTime();
      log.info(">>> Took " + elapsed + " millis for the exchange on the route : " + routeId);
  }
}

public boolean isEnabled(EventObject event) {
  return true;
}

protected void doStart() throws Exception {
  // filter out unwanted events
  setIgnoreCamelContextEvents(true);
  setIgnoreServiceEvents(true);
  setIgnoreRouteEvents(true);
  setIgnoreExchangeCreatedEvent(true);
  setIgnoreExchangeCompletedEvent(false);
  setIgnoreExchangeFailedEvents(true);
  setIgnoreExchangeRedeliveryEvents(true);
  setIgnoreExchangeSentEvents(false);
}

protected void doStop() throws Exception {
  // noop
}

}

Not really complicated and the code is explicit. Check the doStart() method to enable/disable the events for which you would like to gather information.

This example uses only Exchange.CREATED_TIMESTAMP property but the next version of Camel 2.7.0 will provide you the property exchange.RECEIVED_TIMESTAMP and so you will be able to calculate more easily the time spend by the exchange to call the different processors till it arrives at the end of the route.

This example collects Date information but you can imagine to use this mechanism to check if your route processes the message according to SLA, ....

STEP 2 - Instantiate the bean in Camel Spring XML

<!-- Event Notifier -->
<bean id="auditEventNotifier" class="com.sfr.audit.AuditEventNotifier">
</bean>

By adding this bean definition, Camel will automatically register it to the CamelContext created.

STEP 3 - Collect info into the log

18:10:46,060 | INFO  | tp1238469515-285 | AuditEventNotifier               | ?                                   ? | 68 - org.apache.camel.camel-core - 2.6.0.fuse-00-00 | >>> Took 3 millis for the exchange on the route : mock-HTTP-Server
18:10:46,062 | INFO  | tp2056154542-293 | AuditEventNotifier               | ?                                   ? | 68 - org.apache.camel.camel-core - 2.6.0.fuse-00-00 | >>> Took 25 millis to send to external system : Endpoint[http://localhost:9191/sis]
18:10:46,077 | INFO  | tp2056154542-293 | AuditEventNotifier               | ?                                   ? | 68 - org.apache.camel.camel-core - 2.6.0.fuse-00-00 | >>> Took 103 millis for the exchange on the route : ws-to-sis

Published at DZone with permission of its author, Charles Moulliard. (source)

(Note: Opinions expressed in this article and its replies are the opinions of their respective authors and not those of DZone, Inc.)