You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@camel.apache.org by pmcb55 <mc...@dnb.com> on 2013/08/11 16:02:28 UTC

Bug with 'addEventNotifier' - fires two 'exchange sent' events for each Exchange sent.

Hi,

I'm using Camel 2.11.1 and the
*context.getManagementStrategy().addEventNotifier(new EventNotifierSupport()
{ ... });* to gather event timings for my Camel application.

Everything works fine except I get *two* events fired for every Exchange
sent to my trivial test route. The following test case shows this very
simply (notice it outputs 4 *ExchangeSentEvent*'s for just 2 requests sent,
and my test route only has 1 '.process()' call in it - adding more steps to
the route has no effect!):

OUTPUT:
---------
ID-UKDB1764398-51680-1376228112185-0-2 exchange Exchange[Message: [Body is
null]] sent to: Endpoint[direct://testRoute] took: 13 ms.
ID-UKDB1764398-51680-1376228112185-0-2 exchange Exchange[Message: [Body is
null]] sent to: Endpoint[direct://testRoute] took: 14 ms.
ID-UKDB1764398-51680-1376228112185-0-2 exchange Exchange[Message: [Body is
null]] sent to: Endpoint[direct://testRoute] took: 1 ms.
ID-UKDB1764398-51680-1376228112185-0-2 exchange Exchange[Message: [Body is
null]] sent to: Endpoint[direct://testRoute] took: 1 ms.


package com.example;

import java.util.EventObject;

import org.apache.camel.CamelContext;
import org.apache.camel.Exchange;
import org.apache.camel.Processor;
import org.apache.camel.ProducerTemplate;
import org.apache.camel.builder.RouteBuilder;
import org.apache.camel.impl.DefaultCamelContext;
import org.apache.camel.impl.DefaultExchange;
import org.apache.camel.management.event.ExchangeSentEvent;
import org.apache.camel.support.EventNotifierSupport;
import org.junit.Test;

public class SentEventTest {
	@Test
	public void testCamel() throws Exception {
        CamelContext context = new DefaultCamelContext();
        
        final String routeId = "direct://testRoute";
        context.addRoutes(new RouteBuilder() { 
            public void configure() {
                from(routeId)
                    .routeId(routeId)
                    .process(new Processor() {
                    	public void process(Exchange exchange) {
                    	};
                    });
            }
        });

        context.getManagementStrategy().addEventNotifier(
        		new EventNotifierSupport() {
        			@Override
        		    public void notify(final EventObject event) throws Exception {	
        				final ExchangeSentEvent sent = (ExchangeSentEvent) event;
        				System.out.println(sent);
        		    }
        		 
        		    public boolean isEnabled(final EventObject event) {
        		        return (event instanceof ExchangeSentEvent);
        		    }
        		 
        		    protected void doStart() throws Exception {
        		    }
        		 
        		    protected void doStop() throws Exception {
        		    }
        		});
        
        context.start();
        ProducerTemplate producer = context.createProducerTemplate();
        Exchange testExchange = new DefaultExchange(context);
        producer.send(routeId, testExchange);
        producer.send(routeId, testExchange);
        context.stop();
	}
}

 



--
View this message in context: http://camel.465427.n5.nabble.com/Bug-with-addEventNotifier-fires-two-exchange-sent-events-for-each-Exchange-sent-tp5737086.html
Sent from the Camel - Users mailing list archive at Nabble.com.

Re: Bug with 'addEventNotifier' - fires two 'exchange sent' events for each Exchange sent.

Posted by Claus Ibsen <cl...@gmail.com>.
Logged a ticket to allow turn off event notifier in the producer template
https://issues.apache.org/jira/browse/CAMEL-6628

On Mon, Aug 12, 2013 at 3:55 PM, pmcb55 <mc...@dnb.com> wrote:
> Well actually, our production code makes extensive use of the
> ProducerTemplate to make explicit calls from our application server code
> (which just supports a standard web application) to simple Camel routes that
> invoke on backend services that all expose HTTP endpoints (so of course we
> use the HTTP4 component in those routes a lot).
>
> So the example I gave above is actually very close to what we are currently
> doing in our Production system. In fact, this slightly simplified route is
> extremely close to what we have in Production today:
>
>       from("direct://GET_BEST_REPORT_FROM_THOSE_CURRENTLY_AVAILABLE")
>
> .enrich("http4://www.example.com/backend_services/GET_ALL_AVAILABLE_REPORTS",
> new MyAggregator())
>
> .enrich("http4://www.example.com/backend_services/PICK_BEST_REPORT", new
> MyAggregator())
>          .enrich("http4://www.example.com/backend_services/GO_GET_REPORT",
> new MyAggregator());
>
> That's the kind of simple Camel route we invoke (using
> '*producer.send("direct://GET_BEST_REPORT_FROM_THOSE_CURRENTLY_AVAILABLE",
> exchangeWithUserSpecifiedDataFromWebForm);*') from our web request
> processing code all the time! This has been working perfectly for a long
> time, and all I want to do now is gather timing stats for those PRODUCTION
> Camel routes :)
>
> (And as I said before, I know I could go to JMX, but the sample code I
> showed in my original post is so simple, and so intuitive (and so very
> nearly works perfectly!), that I'd love to just get it working for this
> simple use case.)
>
> Cheers,
>
> Pat.
>
>
>
> --
> View this message in context: http://camel.465427.n5.nabble.com/Bug-with-addEventNotifier-fires-two-exchange-sent-events-for-each-Exchange-sent-tp5737086p5737150.html
> Sent from the Camel - Users mailing list archive at Nabble.com.



-- 
Claus Ibsen
-----------------
Red Hat, Inc.
Email: cibsen@redhat.com
Twitter: davsclaus
Blog: http://davsclaus.com
Author of Camel in Action: http://www.manning.com/ibsen

Re: Bug with 'addEventNotifier' - fires two 'exchange sent' events for each Exchange sent.

Posted by pmcb55 <mc...@dnb.com>.
Well actually, our production code makes extensive use of the
ProducerTemplate to make explicit calls from our application server code
(which just supports a standard web application) to simple Camel routes that
invoke on backend services that all expose HTTP endpoints (so of course we
use the HTTP4 component in those routes a lot).

So the example I gave above is actually very close to what we are currently
doing in our Production system. In fact, this slightly simplified route is
extremely close to what we have in Production today:

      from("direct://GET_BEST_REPORT_FROM_THOSE_CURRENTLY_AVAILABLE")
        
.enrich("http4://www.example.com/backend_services/GET_ALL_AVAILABLE_REPORTS",
new MyAggregator())
        
.enrich("http4://www.example.com/backend_services/PICK_BEST_REPORT", new
MyAggregator())
         .enrich("http4://www.example.com/backend_services/GO_GET_REPORT",
new MyAggregator());

That's the kind of simple Camel route we invoke (using
'*producer.send("direct://GET_BEST_REPORT_FROM_THOSE_CURRENTLY_AVAILABLE",
exchangeWithUserSpecifiedDataFromWebForm);*') from our web request
processing code all the time! This has been working perfectly for a long
time, and all I want to do now is gather timing stats for those PRODUCTION
Camel routes :) 

(And as I said before, I know I could go to JMX, but the sample code I
showed in my original post is so simple, and so intuitive (and so very
nearly works perfectly!), that I'd love to just get it working for this
simple use case.)

Cheers,

Pat.



--
View this message in context: http://camel.465427.n5.nabble.com/Bug-with-addEventNotifier-fires-two-exchange-sent-events-for-each-Exchange-sent-tp5737086p5737150.html
Sent from the Camel - Users mailing list archive at Nabble.com.

Re: Bug with 'addEventNotifier' - fires two 'exchange sent' events for each Exchange sent.

Posted by Claus Ibsen <cl...@gmail.com>.
Remember you are doing a test and in real life you wont use producer
template to send a message to a direct Camel route. Your routes would
be other components such as files / http / cxf / activemq etc.



On Mon, Aug 12, 2013 at 2:38 PM, pmcb55 <mc...@dnb.com> wrote:
> Hi Claus - thanks again for the response, but I'm still unclear. I've been
> playing with my test code, and I think this version might illustrate the
> problem better (I now define endpoints instead of my simpler original that
> only had a 'Processor()', and I've added 'Thread.sleep()' to the endpoints
> to show timings).
>
> Notice that the output is *almost* perfect - the only problem is that I get
> one extra (spurious to my mind!) event being fired (by the ProducerTemplate,
> as your first reply made clear), which of course screws up invocation counts
> and average timings for the overall route [direct://testRouteTest].
>
> I know I could probably jump to JMX for all this, but first is there any
> easy way to eliminate this last event being fired? As you can see from the
> output, everything would be perfect otherwise - i.e. this code is extremely
> simple and intuitive, and I'd like to keep it that way if possible.
>
>
> OUTPUT (perfect except for last event, in *bold*):
> --------
>
> Route 1
> ID-UKDB1764398-61884-1376310614400-0-2 exchange Exchange[Message: [Body is
> null]] sent to: Endpoint[direct://testRoute1] took: 307 ms.
> Route 2
> ID-UKDB1764398-61884-1376310614400-0-2 exchange Exchange[Message: [Body is
> null]] sent to: Endpoint[direct://testRoute2] took: 0 ms.
> Route 3
> ID-UKDB1764398-61884-1376310614400-0-2 exchange Exchange[Message: [Body is
> null]] sent to: Endpoint[direct://testRoute3] took: 200 ms.
> ID-UKDB1764398-61884-1376310614400-0-2 exchange Exchange[Message: [Body is
> null]] sent to: Endpoint[direct://testRouteTest] took: 530 ms.
> *ID-UKDB1764398-61884-1376310614400-0-2 exchange Exchange[Message: [Body is
> null]] sent to: Endpoint[direct://testRouteTest] took: 530 ms.*
>
>
> package com.dnb.core.integration.utils.eip;
>
> import java.util.EventObject;
>
> import org.apache.camel.CamelContext;
> import org.apache.camel.Exchange;
> import org.apache.camel.Processor;
> import org.apache.camel.ProducerTemplate;
> import org.apache.camel.builder.RouteBuilder;
> import org.apache.camel.impl.DefaultCamelContext;
> import org.apache.camel.impl.DefaultExchange;
> import org.apache.camel.management.event.ExchangeSentEvent;
> import org.apache.camel.support.EventNotifierSupport;
> import org.junit.Test;
>
> /**
>  * @author McBennettP
>  *
>  * I just created this test case to post to the Camel user list - looks like
>  * a bug to me...!?
>  */
> public class SentEventTest {
>         @Test
>         public void testCamel() throws Exception {
>         CamelContext context = new DefaultCamelContext();
>
>         context.addRoutes(new RouteBuilder() {
>             public void configure() {
>                 from("direct://testRoute1")
>                 .routeId("direct://testRoute1")
>                 .process(new Processor() {
>                         public void process(Exchange exchange) {
>                                 System.out.println("Route 1");
>                                 try { Thread.sleep(300); } catch (InterruptedException e)
> { }
>                         };
>                 });
>
>                 from("direct://testRoute2")
>                 .routeId("direct://testRoute2")
>                 .process(new Processor() {
>                         public void process(Exchange exchange) {
>                                 System.out.println("Route 2");
>                         };
>                 });
>
>                 from("direct://testRoute3")
>                 .routeId("direct://testRoute3")
>                 .process(new Processor() {
>                         public void process(Exchange exchange) {
>                                 System.out.println("Route 3");
>                                 try { Thread.sleep(200); } catch (InterruptedException e)
> { }
>                         };
>                 });
>
>                 from("direct://testRouteTest")
>                 .routeId("direct://testRouteTest")
>                 .to("direct://testRoute1")
>                 .to("direct://testRoute2")
>                 .to("direct://testRoute3");
>             }
>         });
>
>         context.getManagementStrategy().addEventNotifier(
>                         new EventNotifierSupport() {
>                                 @Override
>                             public void notify(final EventObject event) throws Exception {
>                                         final ExchangeSentEvent sent = (ExchangeSentEvent) event;
>                                         System.out.println(sent);
>                             }
>
>                             public boolean isEnabled(final EventObject event) {
>                                 return (event instanceof ExchangeSentEvent);
>                             }
>
>                             protected void doStart() throws Exception {
>                             }
>
>                             protected void doStop() throws Exception {
>                             }
>                         });
>
>         context.start();
>         ProducerTemplate producer = context.createProducerTemplate();
>         Exchange testExchange = new DefaultExchange(context);
>         producer.send("direct://testRouteTest", testExchange);
>         context.stop();
>         }
> }
>
>
>
> --
> View this message in context: http://camel.465427.n5.nabble.com/Bug-with-addEventNotifier-fires-two-exchange-sent-events-for-each-Exchange-sent-tp5737086p5737143.html
> Sent from the Camel - Users mailing list archive at Nabble.com.



-- 
Claus Ibsen
-----------------
Red Hat, Inc.
Email: cibsen@redhat.com
Twitter: davsclaus
Blog: http://davsclaus.com
Author of Camel in Action: http://www.manning.com/ibsen

Re: Bug with 'addEventNotifier' - fires two 'exchange sent' events for each Exchange sent.

Posted by pmcb55 <mc...@dnb.com>.
Hi Claus - thanks again for the response, but I'm still unclear. I've been
playing with my test code, and I think this version might illustrate the
problem better (I now define endpoints instead of my simpler original that
only had a 'Processor()', and I've added 'Thread.sleep()' to the endpoints
to show timings).

Notice that the output is *almost* perfect - the only problem is that I get
one extra (spurious to my mind!) event being fired (by the ProducerTemplate,
as your first reply made clear), which of course screws up invocation counts
and average timings for the overall route [direct://testRouteTest].

I know I could probably jump to JMX for all this, but first is there any
easy way to eliminate this last event being fired? As you can see from the
output, everything would be perfect otherwise - i.e. this code is extremely
simple and intuitive, and I'd like to keep it that way if possible.


OUTPUT (perfect except for last event, in *bold*):
--------

Route 1
ID-UKDB1764398-61884-1376310614400-0-2 exchange Exchange[Message: [Body is
null]] sent to: Endpoint[direct://testRoute1] took: 307 ms.
Route 2
ID-UKDB1764398-61884-1376310614400-0-2 exchange Exchange[Message: [Body is
null]] sent to: Endpoint[direct://testRoute2] took: 0 ms.
Route 3
ID-UKDB1764398-61884-1376310614400-0-2 exchange Exchange[Message: [Body is
null]] sent to: Endpoint[direct://testRoute3] took: 200 ms.
ID-UKDB1764398-61884-1376310614400-0-2 exchange Exchange[Message: [Body is
null]] sent to: Endpoint[direct://testRouteTest] took: 530 ms.
*ID-UKDB1764398-61884-1376310614400-0-2 exchange Exchange[Message: [Body is
null]] sent to: Endpoint[direct://testRouteTest] took: 530 ms.*


package com.dnb.core.integration.utils.eip;

import java.util.EventObject;

import org.apache.camel.CamelContext;
import org.apache.camel.Exchange;
import org.apache.camel.Processor;
import org.apache.camel.ProducerTemplate;
import org.apache.camel.builder.RouteBuilder;
import org.apache.camel.impl.DefaultCamelContext;
import org.apache.camel.impl.DefaultExchange;
import org.apache.camel.management.event.ExchangeSentEvent;
import org.apache.camel.support.EventNotifierSupport;
import org.junit.Test;

/**
 * @author McBennettP
 *
 * I just created this test case to post to the Camel user list - looks like
 * a bug to me...!?
 */
public class SentEventTest {
	@Test
	public void testCamel() throws Exception {
        CamelContext context = new DefaultCamelContext();
        
        context.addRoutes(new RouteBuilder() { 
            public void configure() {
                from("direct://testRoute1")
                .routeId("direct://testRoute1")
                .process(new Processor() {
                	public void process(Exchange exchange) {
                		System.out.println("Route 1");
                		try { Thread.sleep(300); } catch (InterruptedException e)
{ }
                	};
                });
                
                from("direct://testRoute2")
                .routeId("direct://testRoute2")
                .process(new Processor() {
                	public void process(Exchange exchange) {
                		System.out.println("Route 2");
                	};
                });
                
                from("direct://testRoute3")
                .routeId("direct://testRoute3")
                .process(new Processor() {
                	public void process(Exchange exchange) {
                		System.out.println("Route 3");
                		try { Thread.sleep(200); } catch (InterruptedException e)
{ }
                	};
                });
                
                from("direct://testRouteTest")
                .routeId("direct://testRouteTest")
                .to("direct://testRoute1")
                .to("direct://testRoute2")
                .to("direct://testRoute3");
            }
        });

        context.getManagementStrategy().addEventNotifier(
        		new EventNotifierSupport() {
        			@Override
        		    public void notify(final EventObject event) throws Exception {
        				final ExchangeSentEvent sent = (ExchangeSentEvent) event;
        				System.out.println(sent);
        		    }
        		 
        		    public boolean isEnabled(final EventObject event) {
        		        return (event instanceof ExchangeSentEvent);
        		    }
        		 
        		    protected void doStart() throws Exception {
        		    }
        		 
        		    protected void doStop() throws Exception {
        		    }
        		});
        
        context.start();
        ProducerTemplate producer = context.createProducerTemplate();
        Exchange testExchange = new DefaultExchange(context);
        producer.send("direct://testRouteTest", testExchange);
        context.stop();
	}
}



--
View this message in context: http://camel.465427.n5.nabble.com/Bug-with-addEventNotifier-fires-two-exchange-sent-events-for-each-Exchange-sent-tp5737086p5737143.html
Sent from the Camel - Users mailing list archive at Nabble.com.

Re: Bug with 'addEventNotifier' - fires two 'exchange sent' events for each Exchange sent.

Posted by Claus Ibsen <cl...@gmail.com>.
Well timings for individual endpoints you would need to send the
exchange to an endpoint in your route - which yo do NOT do, as you use
a processor instead.

The event notifier only emits event for exchanges being sending/sent
to endpoints, not for processors etc.

If you want fine grained metrics, then thats already there with the JMX.



On Mon, Aug 12, 2013 at 12:36 PM, pmcb55 <mc...@dnb.com> wrote:
> Hi Claus,
>
> Ok, great. But you seem to be implying that this is 'correct' behaviour -
> which I don't quite understand. What is the value of the events fired from
> the ProducerTemplate when the underlying code fires the same events anyway?
> I guess maybe I'm still missing something here...
>
> So how would I 'fix' my very simple, and intuitive test code above?? In
> other words, how would I record only 1 event per Exchange sent to my
> endpoint? i.e. how do I filter out the pesky ProducerTemplate events so that
> I just get 'real' timings (and invocation counts) for endpoint invocations?
>
> I've tried with '*ExchangeCompletedEvent*'  and using the property
> '*Exchange.CREATED_TIMESTAMP*' too (as explained here:
> http://cmoulliard.blogspot.ie/2011/02/measure-elapsed-time-with-camel.html),
> but that just gives me a timing for the entire route - it won't give me
> timings for individual endpoints in a route with multiple '.to()' parts.
>
> Thanks,
>
> Pat.
>
>
>
>
> --
> View this message in context: http://camel.465427.n5.nabble.com/Bug-with-addEventNotifier-fires-two-exchange-sent-events-for-each-Exchange-sent-tp5737086p5737138.html
> Sent from the Camel - Users mailing list archive at Nabble.com.



-- 
Claus Ibsen
-----------------
Red Hat, Inc.
Email: cibsen@redhat.com
Twitter: davsclaus
Blog: http://davsclaus.com
Author of Camel in Action: http://www.manning.com/ibsen

Re: Bug with 'addEventNotifier' - fires two 'exchange sent' events for each Exchange sent.

Posted by pmcb55 <mc...@dnb.com>.
Hi Claus,

Ok, great. But you seem to be implying that this is 'correct' behaviour -
which I don't quite understand. What is the value of the events fired from
the ProducerTemplate when the underlying code fires the same events anyway?
I guess maybe I'm still missing something here...

So how would I 'fix' my very simple, and intuitive test code above?? In
other words, how would I record only 1 event per Exchange sent to my
endpoint? i.e. how do I filter out the pesky ProducerTemplate events so that
I just get 'real' timings (and invocation counts) for endpoint invocations?

I've tried with '*ExchangeCompletedEvent*'  and using the property
'*Exchange.CREATED_TIMESTAMP*' too (as explained here:
http://cmoulliard.blogspot.ie/2011/02/measure-elapsed-time-with-camel.html),
but that just gives me a timing for the entire route - it won't give me
timings for individual endpoints in a route with multiple '.to()' parts.

Thanks,

Pat.




--
View this message in context: http://camel.465427.n5.nabble.com/Bug-with-addEventNotifier-fires-two-exchange-sent-events-for-each-Exchange-sent-tp5737086p5737138.html
Sent from the Camel - Users mailing list archive at Nabble.com.

Re: Bug with 'addEventNotifier' - fires two 'exchange sent' events for each Exchange sent.

Posted by Claus Ibsen <cl...@gmail.com>.
The producer template also emits the events, so that is why you see more.

On Sun, Aug 11, 2013 at 4:02 PM, pmcb55 <mc...@dnb.com> wrote:
> Hi,
>
> I'm using Camel 2.11.1 and the
> *context.getManagementStrategy().addEventNotifier(new EventNotifierSupport()
> { ... });* to gather event timings for my Camel application.
>
> Everything works fine except I get *two* events fired for every Exchange
> sent to my trivial test route. The following test case shows this very
> simply (notice it outputs 4 *ExchangeSentEvent*'s for just 2 requests sent,
> and my test route only has 1 '.process()' call in it - adding more steps to
> the route has no effect!):
>
> OUTPUT:
> ---------
> ID-UKDB1764398-51680-1376228112185-0-2 exchange Exchange[Message: [Body is
> null]] sent to: Endpoint[direct://testRoute] took: 13 ms.
> ID-UKDB1764398-51680-1376228112185-0-2 exchange Exchange[Message: [Body is
> null]] sent to: Endpoint[direct://testRoute] took: 14 ms.
> ID-UKDB1764398-51680-1376228112185-0-2 exchange Exchange[Message: [Body is
> null]] sent to: Endpoint[direct://testRoute] took: 1 ms.
> ID-UKDB1764398-51680-1376228112185-0-2 exchange Exchange[Message: [Body is
> null]] sent to: Endpoint[direct://testRoute] took: 1 ms.
>
>
> package com.example;
>
> import java.util.EventObject;
>
> import org.apache.camel.CamelContext;
> import org.apache.camel.Exchange;
> import org.apache.camel.Processor;
> import org.apache.camel.ProducerTemplate;
> import org.apache.camel.builder.RouteBuilder;
> import org.apache.camel.impl.DefaultCamelContext;
> import org.apache.camel.impl.DefaultExchange;
> import org.apache.camel.management.event.ExchangeSentEvent;
> import org.apache.camel.support.EventNotifierSupport;
> import org.junit.Test;
>
> public class SentEventTest {
>         @Test
>         public void testCamel() throws Exception {
>         CamelContext context = new DefaultCamelContext();
>
>         final String routeId = "direct://testRoute";
>         context.addRoutes(new RouteBuilder() {
>             public void configure() {
>                 from(routeId)
>                     .routeId(routeId)
>                     .process(new Processor() {
>                         public void process(Exchange exchange) {
>                         };
>                     });
>             }
>         });
>
>         context.getManagementStrategy().addEventNotifier(
>                         new EventNotifierSupport() {
>                                 @Override
>                             public void notify(final EventObject event) throws Exception {
>                                         final ExchangeSentEvent sent = (ExchangeSentEvent) event;
>                                         System.out.println(sent);
>                             }
>
>                             public boolean isEnabled(final EventObject event) {
>                                 return (event instanceof ExchangeSentEvent);
>                             }
>
>                             protected void doStart() throws Exception {
>                             }
>
>                             protected void doStop() throws Exception {
>                             }
>                         });
>
>         context.start();
>         ProducerTemplate producer = context.createProducerTemplate();
>         Exchange testExchange = new DefaultExchange(context);
>         producer.send(routeId, testExchange);
>         producer.send(routeId, testExchange);
>         context.stop();
>         }
> }
>
>
>
>
>
> --
> View this message in context: http://camel.465427.n5.nabble.com/Bug-with-addEventNotifier-fires-two-exchange-sent-events-for-each-Exchange-sent-tp5737086.html
> Sent from the Camel - Users mailing list archive at Nabble.com.



-- 
Claus Ibsen
-----------------
Red Hat, Inc.
Email: cibsen@redhat.com
Twitter: davsclaus
Blog: http://davsclaus.com
Author of Camel in Action: http://www.manning.com/ibsen