I did look at few examples. In your case, from looking at the log, it looks like it's wrapped twice, that's why is executed twice. The second number is always larger than the first. Since the Trace is an interceptor too, it looks like you got an instrument(trace(instrument(processor))). I will take a look today and see where the problem lies. In any event, your assumption is correct, instrumentation should not happen twice, and if does it is a bug.
Thanks for pointing this out, Hadrian On Dec 3, 2010, at 7:15 AM, ext2 wrote: > Sorry, I forget to attach my tracing result; > > I am sure , it's wrapped twice; > Because the Instrument Processor will trace the time only after > processing. But one processor 's instrument result is traced twice; > > Following is my tracing output, you can check it. > > - bean: Recording duration: 23 millis for exchange: Exchange[Message: plain > text] > - bean: Recording duration: 52 millis for exchange: Exchange[Message: plain > text] > - to: Recording duration: 11 millis for exchange: Exchange[Message: plain > text] > - to: Recording duration: 18 millis for exchange: Exchange[Message: plain > text] > - bean: Recording duration: 11 millis for exchange: Exchange[Message: plain > text] > - bean: Recording duration: 48 millis for exchange: Exchange[Message: plain > text] > - route: Recording duration: 160 millis for exchange: Exchange[Message: > plain text] > > -----Original ----- > Sender: ext2 [mailto:x...@tongtech.com] > Date: 2010-12-3 19:23 > Receiver: users@camel.apache.org > Subject: Re: Wast performance? Instrument Interceptor is wrapped twice for > each processor. > > Thanks Harian Zbarcea: > Instrument will be useful. But being wrapped and execute twice for > single processor will be a waste; > Actually, I found this problem while debug and tracing a spring > configured camel route. At least in Camel 2.4.0 and using spring, it real > does wrap twice. > Maybe you could take a moment to debug and tracking a camel route , > you will see it. > Or,you can turning on the "TRACE" level for logging, and checking > the Instrument Processor's output. You could see it; > Following is my route: > <route> > <from uri="direct:from" /> > <bean id="id0" ref="bean1" method="normal" /> > <to id="id0_1" uri="mock:result" /> > <bean id="id1" ref="bean1" method="raiseError" /> > </route> > But the trace result is : 2 of first bean, 2 of the "to" endpoint, > 2 of the second bean and 1 for route; > > -----Origin ----- > Sender: Hadrian Zbarcea [mailto:hzbar...@gmail.com] > Date: 2010/12/2 22:21 > Receiver: users@camel.apache.org > Subject: Re: Wast performance? Instrument Interceptor is wrapped twice for > each processor. > > The InstrumentationProcessor is a delegate processor (aka interceptor) that > allows you do do before and after processing. > It is not really invoked twice (or I have to see a test case that does that, > the unit tests in camel I am aware of don't). It is invoked once, takes a > start timestamp, it delegates processing to the inner processor and then > takes the time diff and records it. > > Now with a DelegateProcessor all this call is synchronous. Being actually a > DelegateAsyncProcessor, the call to the inner processor is done by the async > engine (see AsyncProcessorHelper.process()) which calls asynchronously on > the done() method. I assume this is what you see and interpret as a second > call. > > This design is not wasting performance, quite to the contrary. It ensures a > better use of resources and scales much better with higher message volume. > > I hope this helps, > Hadrian > > > On Dec 1, 2010, at 9:53 PM, ext2 wrote: > >> Hi: >> Each camel processor will be wrapped with Instrument Interceptor >> twice. So for each process , the Instrument interceptor will be executed >> twice. >> It seems no use but waste performance; >> Why? Or a bug? >> Thanks for any suggestion. >> >> >> > > > > >
