Detailed Statistics - what does CPU time mean?
dhartford
time for sql calls.
HTTP/EJB detailed statistics - it looks like they have 'aggregate'
times for mean/max time. There is cpu time that I assume is
specific, but not sure if that reflects total time or just actual CPU
processing time. Here is the reason I'm asking:
HTTP mean time = sql time(s) + ejb time(s) + actual http time. What
was the direct/actual http time?
EJB mean time = sql time(s) + actual ejb time. What was the direct/
actual ejb time? (unless CPU time really does represent this...?)
So -- the question is, does CPU time represent only the actual CPU
processing time used, or does it include waiting for CPU cycles/lag/IO
latency delays/etc?
Usecase: I see some of my HTTP calls taking mean cpu times of ~130ms
(regular mean times ~600ms), when all they do is call (0-N) EJB method
(s) that then in turn call (0-N) SQL call(s) and get back the
results. Just want to make sure that the time spent in the servlet
layer is actually 130ms and 470ms are accounted for in EJB/SQL realm,
or if I'm mis-interpreting the results (or there is more in the non-
cpu time not related to SQL/EJB?).
p.s. I heavily used the Detailed Statistics, the rest of javamelody
may be nice for other people, but the detailed stats are huge for me.
-D
Emeric Vernat
My responses in the body of your mail.
dhartford a �crit :
> time for sql calls.
>
> HTTP/EJB detailed statistics - it looks like they have 'aggregate'
> times for mean/max time.
>
start to end including all, like sql requests for example.
> specific, but not sure if that reflects total time or just actual CPU
> processing time. Here is the reason I'm asking:
>
more precisely it is the delta of cpu time as given by the JVM from
start to end for the thread.
If we take a typical webapp with a database, a request with a mean time
of 1000 ms can have 200 ms of cpu time and 800 ms is just waiting for
some network or for the database (total time of sql requests is
certainly the key).
> was the direct/actual http time?
>
the server point of view. So I consider it is the most important time to
optimize. In order to optimize you can drill-down to see if it was ejb
time, sql time or not. The "http only" time is the http time - total ejb
time (or - sql time if there is no ejb)
> actual ejb time? (unless CPU time really does represent this...?)
>
> processing time used, or does it include waiting for CPU cycles/lag/IO
> latency delays/etc?
>
given by the JVM), and so without io latency and without waiting cpu
cycles, because a waiting or a sleeping thread does not consume cpu.
> (regular mean times ~600ms), when all they do is call (0-N) EJB method
> (s) that then in turn call (0-N) SQL call(s) and get back the
> results. Just want to make sure that the time spent in the servlet
> layer is actually 130ms and 470ms are accounted for in EJB/SQL realm,
> or if I'm mis-interpreting the results (or there is more in the non-
> cpu time not related to SQL/EJB?).
>
includes the total cpu time of 0-N ejb calls (I suppose here that those
ejb are local). You can look at the cpu times of each ejb calls in the
drill-down to see where the cpu was used.
So if 600ms is the mean time of the http request, 470 ms is the
'aggregated' time waiting for the network or the database or the hard
disk or something else. You can look at the mean times of ejb and sql
calls in the drill-down to see where it was waiting.
130ms of cpu time for 600ms of total time does not seems unusual to me.
It shows that with a lot of load, the java server can become cpu bound
and potentially needs upgrades or optimisations, of course if the
database keeps responding under the load.
> may be nice for other people, but the detailed stats are huge for me.
>
> -D
>
>
dhartford
Just to summarize, hopefully I have this right:
TOTAL TIME: % of cumulative time/mean time/max time for all detailed
statistic items are total visible time from start-to-finish until that
layer is complete (i.e. http request->ejb->sql->ejb->http response).
WORK TIME: % of cumulative cpu time/mean cpu time for HTTP, EJB are
only cpu processing time, excluding waits, garbage collection, io's,
etc. This measures the amount of *work* that item is doing.
===============
ITEMIZED TOTAL TIME: I don't see an ONLY column, I assume you meant
this more as a reference: "'http only' time is the http time - total
ejb
time (or - sql time if there is no ejb)"; if such a column is visible
in the new version, or is something that should/is a feature
enhancement, that would be great since you can't really manually
derive it as the 0-N EJB/sql calls (or EJB layer, 0-N sql calls) make
it impossible.
Example: If HTTP TOTAL TIME is 600ms, and HTTP ITEMIZED (only) time
is 130ms, and cpu time 130ms you know right away most of the time is
elsewhere, where as if an example was more like HTTP TOTAL TIME:
600ms, HTTP ITEMIZED (only) time is 350ms, but actual http cpu time is
130ms, there is something odd that needs investigating.
Emeric Vernat
In summary, displayed times and cpu times are cumulative (http times
includes ejb and sql times), and times includes waits but cpu times does
not includes them.
I did not have a feature request for an UI option to change display
between cumulative times and non-cumulative times, but it is doable with
arithmetics and I will note it.
(I think I will put a public TODO list in the wiki.)
bye, Emeric
Le 21/12/2009 15:32, dhartford a �crit :