You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@hivemind.apache.org by "David J. M. Karlsen" <da...@davidkarlsen.com> on 2005/03/01 13:33:23 UTC
Timing interceptor?
Would it be interesting to create an interceptor that gives timing
information? (Time to enter and leave a method).
--
David J. M. Karlsen - +47 90 68 22 43
http://www.davidkarlsen.com
http://mp3.davidkarlsen.com
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
Re: Timing interceptor?
Posted by Achim Huegen <ah...@gmx-topmail.de>.
I agree. I wouldn't mix those concerns.
Take a look here (http://wiki.apache.org/jakarta-hivemind/JmxPreview)
for a screenshot that shows the way a jmx management console can display
the aggregated statistical data. It is even possible to display the
duration over time as graph.
And moreover using jmx monitors you can get notified if a critical value
is exceeded.
The population via jmx should be only one option so I will have a look
at my code to see how easy it is to plugin different statistic services.
Achim
Jean-Francois Poilpret wrote:
> Except if we consider the benefits of separating concerns.
> The question is: is logging concern equivalent to performance measurement
> concern?
> Personally, I really prefer to have 2 different interceptors for this.
> In particular, I would probably want to check performance _without_ logging
> enabled (since logging would degrade the real performance).
>
> I already thought about writing such an interceptor, but I am not sure it is
> as easy as it sounds: I don't think it would be a good idea to just store
> somewhere the duration of ONE call to a method. It is generally better to
> have some kind of "statistics" (like: number of calls, average duration, min
> and max duration), and for this you need some additional configuration for
> your interceptor (in addition to where you want the information logged).
>
> Or maybe a better solution would be to have a simple interceptor that calls
> a "statistics" service at the end of each method call, passing it the method
> signature, the service-point, and the exec duration. Then it is up to the
> statistics service to do whatever it wants with that, from the simplest to
> the most complex. We could then provide "minimal" implementations for such a
> service.
>
> Cheers
>
> Jean-Francois
>
> -----Original Message-----
> From: James Carman [mailto:james@carmanconsulting.com]
> Sent: Tuesday, March 01, 2005 8:13 PM
> To: hivemind-user@jakarta.apache.org
> Subject: RE: Timing interceptor?
>
> It still couldn't hurt to add this to the logging interceptor.
>
> -----Original Message-----
> From: Achim Huegen [mailto:ahuegen@gmx-topmail.de]
> Sent: Tuesday, March 01, 2005 8:10 AM
> To: hivemind-user@jakarta.apache.org
> Subject: Re: Timing interceptor?
>
>
> I've included a performance interceptor in my hivemind jmx code. It measures
> duration of service calls and provides the results (min,
> max, avg etc.) via jmx.
>
> The code will be available during the next days as jira patch.
>
> Achim Huegen
>
> David J. M. Karlsen wrote:
>
>>Would it be interesting to create an interceptor that gives timing
>>information? (Time to enter and leave a method).
>>
>>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
> For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
> For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
>
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
> For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
>
>
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
RE: Timing interceptor?
Posted by James Carman <ja...@carmanconsulting.com>.
I guess I envisioned the original request as more of a "rude and crude"
implementation, where you wouldn't really have to worry about the hardware
timer deficiencies, rather than a full-blown one. As for being able to
ascertain the duration from the log messages, not everyone logs the time to
the level of detail you would need to calculate the time in milliseconds.
-----Original Message-----
From: Jean-Francois Poilpret [mailto:jfpoilpret@hcm.vnn.vn]
Sent: Tuesday, March 01, 2005 10:40 AM
To: hivemind-user@jakarta.apache.org
Subject: RE: Timing interceptor?
The major problem with calculating (after - before) duration is the
precision of the timer in your hardware and with your OS. AFAIR, on WinXP,
it is 10ms, so this means that for short methods you will always have either
0ms or 10ms. I don't remember what's the timer precision on Linux, maybe
more accurate. If you run after performance, then a 0-10ms precision brings
you nothing at all.
Of course, if the time of the method you measure is about 1s, then
10ms-precision is perfectly acceptable.
Now, if you base the duration calculus on statistics, this generally
alleviates the timer-precision problem.
If I need this only in the context of debugging (ie for a few methods only
and in a one-shot test), then the current logging fits me (I can mentally do
the difference between the ENTER and LEAVE points that have been logged).
Although this could also be easily added to the LoggingInterceptor, this
would certainly not relieve the need for better performance monitoring
through another -dedicated- interceptor.
Cheers
Jean-Francois
-----Original Message-----
From: James Carman [mailto:james@carmanconsulting.com]
Sent: Tuesday, March 01, 2005 9:58 PM
To: hivemind-user@jakarta.apache.org
Subject: RE: Timing interceptor?
Jean-Francois,
I would agree that a fancy statistics collecting service would be VERY cool!
In fact, if you want any help, let me know. It would be nice for a
monitoring application to identify "hotspots" in the application which might
need to be addressed. Now you've got me thinking! But, for simple
debugging purposes, it might be overkill. I think we can do something
like...
// Do begin logging
final long before = System.currentTimeMillis();
// Call method.
final long duration = System.currentTimeMillis() - before;
// Do end logging printing out the duration.
This would eliminate the effects of the logging on the actual duration
calculation. I don't see how this could really cause a problem and I think
it would be a nice feature. I agree that we're not separating concerns
really, but I've done this in the past (separated it) and it's kind of
annoying to have multiple logging messages when one could have sufficed.
Also, you have to add two interceptors to each service as opposed to one
(easier to do with Groovy descriptors).
James
-----Original Message-----
From: Jean-Francois Poilpret [mailto:jfpoilpret@hcm.vnn.vn]
Sent: Tuesday, March 01, 2005 9:40 AM
To: hivemind-user@jakarta.apache.org
Subject: RE: Timing interceptor?
Except if we consider the benefits of separating concerns.
The question is: is logging concern equivalent to performance measurement
concern? Personally, I really prefer to have 2 different interceptors for
this. In particular, I would probably want to check performance _without_
logging enabled (since logging would degrade the real performance).
I already thought about writing such an interceptor, but I am not sure it is
as easy as it sounds: I don't think it would be a good idea to just store
somewhere the duration of ONE call to a method. It is generally better to
have some kind of "statistics" (like: number of calls, average duration, min
and max duration), and for this you need some additional configuration for
your interceptor (in addition to where you want the information logged).
Or maybe a better solution would be to have a simple interceptor that calls
a "statistics" service at the end of each method call, passing it the method
signature, the service-point, and the exec duration. Then it is up to the
statistics service to do whatever it wants with that, from the simplest to
the most complex. We could then provide "minimal" implementations for such a
service.
Cheers
Jean-Francois
-----Original Message-----
From: James Carman [mailto:james@carmanconsulting.com]
Sent: Tuesday, March 01, 2005 8:13 PM
To: hivemind-user@jakarta.apache.org
Subject: RE: Timing interceptor?
It still couldn't hurt to add this to the logging interceptor.
-----Original Message-----
From: Achim Huegen [mailto:ahuegen@gmx-topmail.de]
Sent: Tuesday, March 01, 2005 8:10 AM
To: hivemind-user@jakarta.apache.org
Subject: Re: Timing interceptor?
I've included a performance interceptor in my hivemind jmx code. It measures
duration of service calls and provides the results (min,
max, avg etc.) via jmx.
The code will be available during the next days as jira patch.
Achim Huegen
David J. M. Karlsen wrote:
> Would it be interesting to create an interceptor that gives timing
> information? (Time to enter and leave a method).
>
>
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
RE: Timing interceptor?
Posted by Jean-Francois Poilpret <jf...@hcm.vnn.vn>.
The major problem with calculating (after - before) duration is the
precision of the timer in your hardware and with your OS.
AFAIR, on WinXP, it is 10ms, so this means that for short methods you will
always have either 0ms or 10ms. I don't remember what's the timer precision
on Linux, maybe more accurate.
If you run after performance, then a 0-10ms precision brings you nothing at
all.
Of course, if the time of the method you measure is about 1s, then
10ms-precision is perfectly acceptable.
Now, if you base the duration calculus on statistics, this generally
alleviates the timer-precision problem.
If I need this only in the context of debugging (ie for a few methods only
and in a one-shot test), then the current logging fits me (I can mentally do
the difference between the ENTER and LEAVE points that have been logged).
Although this could also be easily added to the LoggingInterceptor, this
would certainly not relieve the need for better performance monitoring
through another -dedicated- interceptor.
Cheers
Jean-Francois
-----Original Message-----
From: James Carman [mailto:james@carmanconsulting.com]
Sent: Tuesday, March 01, 2005 9:58 PM
To: hivemind-user@jakarta.apache.org
Subject: RE: Timing interceptor?
Jean-Francois,
I would agree that a fancy statistics collecting service would be VERY cool!
In fact, if you want any help, let me know. It would be nice for a
monitoring application to identify "hotspots" in the application which might
need to be addressed. Now you've got me thinking! But, for simple
debugging purposes, it might be overkill. I think we can do something
like...
// Do begin logging
final long before = System.currentTimeMillis();
// Call method.
final long duration = System.currentTimeMillis() - before;
// Do end logging printing out the duration.
This would eliminate the effects of the logging on the actual duration
calculation. I don't see how this could really cause a problem and I think
it would be a nice feature. I agree that we're not separating concerns
really, but I've done this in the past (separated it) and it's kind of
annoying to have multiple logging messages when one could have sufficed.
Also, you have to add two interceptors to each service as opposed to one
(easier to do with Groovy descriptors).
James
-----Original Message-----
From: Jean-Francois Poilpret [mailto:jfpoilpret@hcm.vnn.vn]
Sent: Tuesday, March 01, 2005 9:40 AM
To: hivemind-user@jakarta.apache.org
Subject: RE: Timing interceptor?
Except if we consider the benefits of separating concerns.
The question is: is logging concern equivalent to performance measurement
concern? Personally, I really prefer to have 2 different interceptors for
this. In particular, I would probably want to check performance _without_
logging enabled (since logging would degrade the real performance).
I already thought about writing such an interceptor, but I am not sure it is
as easy as it sounds: I don't think it would be a good idea to just store
somewhere the duration of ONE call to a method. It is generally better to
have some kind of "statistics" (like: number of calls, average duration, min
and max duration), and for this you need some additional configuration for
your interceptor (in addition to where you want the information logged).
Or maybe a better solution would be to have a simple interceptor that calls
a "statistics" service at the end of each method call, passing it the method
signature, the service-point, and the exec duration. Then it is up to the
statistics service to do whatever it wants with that, from the simplest to
the most complex. We could then provide "minimal" implementations for such a
service.
Cheers
Jean-Francois
-----Original Message-----
From: James Carman [mailto:james@carmanconsulting.com]
Sent: Tuesday, March 01, 2005 8:13 PM
To: hivemind-user@jakarta.apache.org
Subject: RE: Timing interceptor?
It still couldn't hurt to add this to the logging interceptor.
-----Original Message-----
From: Achim Huegen [mailto:ahuegen@gmx-topmail.de]
Sent: Tuesday, March 01, 2005 8:10 AM
To: hivemind-user@jakarta.apache.org
Subject: Re: Timing interceptor?
I've included a performance interceptor in my hivemind jmx code. It measures
duration of service calls and provides the results (min,
max, avg etc.) via jmx.
The code will be available during the next days as jira patch.
Achim Huegen
David J. M. Karlsen wrote:
> Would it be interesting to create an interceptor that gives timing
> information? (Time to enter and leave a method).
>
>
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
RE: Timing interceptor?
Posted by James Carman <ja...@carmanconsulting.com>.
Jean-Francois,
I would agree that a fancy statistics collecting service would be VERY cool!
In fact, if you want any help, let me know. It would be nice for a
monitoring application to identify "hotspots" in the application which might
need to be addressed. Now you've got me thinking! But, for simple
debugging purposes, it might be overkill. I think we can do something
like...
// Do begin logging
final long before = System.currentTimeMillis();
// Call method.
final long duration = System.currentTimeMillis() - before;
// Do end logging printing out the duration.
This would eliminate the effects of the logging on the actual duration
calculation. I don't see how this could really cause a problem and I think
it would be a nice feature. I agree that we're not separating concerns
really, but I've done this in the past (separated it) and it's kind of
annoying to have multiple logging messages when one could have sufficed.
Also, you have to add two interceptors to each service as opposed to one
(easier to do with Groovy descriptors).
James
-----Original Message-----
From: Jean-Francois Poilpret [mailto:jfpoilpret@hcm.vnn.vn]
Sent: Tuesday, March 01, 2005 9:40 AM
To: hivemind-user@jakarta.apache.org
Subject: RE: Timing interceptor?
Except if we consider the benefits of separating concerns.
The question is: is logging concern equivalent to performance measurement
concern? Personally, I really prefer to have 2 different interceptors for
this. In particular, I would probably want to check performance _without_
logging enabled (since logging would degrade the real performance).
I already thought about writing such an interceptor, but I am not sure it is
as easy as it sounds: I don't think it would be a good idea to just store
somewhere the duration of ONE call to a method. It is generally better to
have some kind of "statistics" (like: number of calls, average duration, min
and max duration), and for this you need some additional configuration for
your interceptor (in addition to where you want the information logged).
Or maybe a better solution would be to have a simple interceptor that calls
a "statistics" service at the end of each method call, passing it the method
signature, the service-point, and the exec duration. Then it is up to the
statistics service to do whatever it wants with that, from the simplest to
the most complex. We could then provide "minimal" implementations for such a
service.
Cheers
Jean-Francois
-----Original Message-----
From: James Carman [mailto:james@carmanconsulting.com]
Sent: Tuesday, March 01, 2005 8:13 PM
To: hivemind-user@jakarta.apache.org
Subject: RE: Timing interceptor?
It still couldn't hurt to add this to the logging interceptor.
-----Original Message-----
From: Achim Huegen [mailto:ahuegen@gmx-topmail.de]
Sent: Tuesday, March 01, 2005 8:10 AM
To: hivemind-user@jakarta.apache.org
Subject: Re: Timing interceptor?
I've included a performance interceptor in my hivemind jmx code. It measures
duration of service calls and provides the results (min,
max, avg etc.) via jmx.
The code will be available during the next days as jira patch.
Achim Huegen
David J. M. Karlsen wrote:
> Would it be interesting to create an interceptor that gives timing
> information? (Time to enter and leave a method).
>
>
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
RE: Timing interceptor?
Posted by Jean-Francois Poilpret <jf...@hcm.vnn.vn>.
Except if we consider the benefits of separating concerns.
The question is: is logging concern equivalent to performance measurement
concern?
Personally, I really prefer to have 2 different interceptors for this.
In particular, I would probably want to check performance _without_ logging
enabled (since logging would degrade the real performance).
I already thought about writing such an interceptor, but I am not sure it is
as easy as it sounds: I don't think it would be a good idea to just store
somewhere the duration of ONE call to a method. It is generally better to
have some kind of "statistics" (like: number of calls, average duration, min
and max duration), and for this you need some additional configuration for
your interceptor (in addition to where you want the information logged).
Or maybe a better solution would be to have a simple interceptor that calls
a "statistics" service at the end of each method call, passing it the method
signature, the service-point, and the exec duration. Then it is up to the
statistics service to do whatever it wants with that, from the simplest to
the most complex. We could then provide "minimal" implementations for such a
service.
Cheers
Jean-Francois
-----Original Message-----
From: James Carman [mailto:james@carmanconsulting.com]
Sent: Tuesday, March 01, 2005 8:13 PM
To: hivemind-user@jakarta.apache.org
Subject: RE: Timing interceptor?
It still couldn't hurt to add this to the logging interceptor.
-----Original Message-----
From: Achim Huegen [mailto:ahuegen@gmx-topmail.de]
Sent: Tuesday, March 01, 2005 8:10 AM
To: hivemind-user@jakarta.apache.org
Subject: Re: Timing interceptor?
I've included a performance interceptor in my hivemind jmx code. It measures
duration of service calls and provides the results (min,
max, avg etc.) via jmx.
The code will be available during the next days as jira patch.
Achim Huegen
David J. M. Karlsen wrote:
> Would it be interesting to create an interceptor that gives timing
> information? (Time to enter and leave a method).
>
>
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
RE: Timing interceptor?
Posted by James Carman <ja...@carmanconsulting.com>.
It still couldn't hurt to add this to the logging interceptor.
-----Original Message-----
From: Achim Huegen [mailto:ahuegen@gmx-topmail.de]
Sent: Tuesday, March 01, 2005 8:10 AM
To: hivemind-user@jakarta.apache.org
Subject: Re: Timing interceptor?
I've included a performance interceptor in my hivemind jmx code. It measures
duration of service calls and provides the results (min,
max, avg etc.) via jmx.
The code will be available during the next days as jira patch.
Achim Huegen
David J. M. Karlsen wrote:
> Would it be interesting to create an interceptor that gives timing
> information? (Time to enter and leave a method).
>
>
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
Re: Timing interceptor?
Posted by Achim Huegen <ah...@gmx-topmail.de>.
I've included a performance interceptor in my hivemind jmx code.
It measures duration of service calls and provides the results (min,
max, avg etc.) via jmx.
The code will be available during the next days as jira patch.
Achim Huegen
David J. M. Karlsen wrote:
> Would it be interesting to create an interceptor that gives timing
> information? (Time to enter and leave a method).
>
>
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
RE: Timing interceptor?
Posted by James Carman <ja...@carmanconsulting.com>.
It would be better to extend the LoggingInterceptor to include total time
spent in the method, no? If you want, since it was your idea, you can enter
an enhancement request into JIRA and I'm sure one of us would be able to get
to that (it should be quite straightforward). If you're really industrious
(and you understand Javassist), you may even attach a patch to the JIRA
issue and one of us will apply it (and give you credit of course).
-----Original Message-----
From: David J. M. Karlsen [mailto:david@davidkarlsen.com]
Sent: Tuesday, March 01, 2005 7:33 AM
To: hivemind-user@jakarta.apache.org
Subject: Timing interceptor?
Would it be interesting to create an interceptor that gives timing
information? (Time to enter and leave a method).
--
David J. M. Karlsen - +47 90 68 22 43 http://www.davidkarlsen.com
http://mp3.davidkarlsen.com
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: hivemind-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: hivemind-user-help@jakarta.apache.org