Unreasonable values for sql monitoring

[GoogleCodeExporter]

Sorry for not being able to provide a test case, but been helping a company out 
with some performance testing and getting unreasonable values in the sql 
output. Provided a screenshot 

What is the expected output? What do you see instead?
The values for "max time ms" for ("exec sp_session_starta 60","exec 
sp_session_forlang") is 156 298 ms/ 169 511 ms. Shouldn't be possible with that 
high values since the maxtime for serving the whole jsp pages is just 
14 266 ms. 

What version of the product are you using? On what application server, JDK,
operating system?
Jdk1.6, mssql server 2005, Windows server 2003. Javamelody 1.19.0. 

Any ideas what the causes could be for these values. The total page for 
accessing the jsp pages is just a few seconds.

Original issue reported on code.google.com by pether.s...@gmail.com on 29 Sep 2010 at 6:32

• Blocked on: Maximum values in statistics can be incorrect #59

Attachments:

• javamelody.JPG

[GoogleCodeExporter]

Hi Pether,

First, importance of max values is often over-estimated by managers in my 
experience: what they see is a fact that some users have long waits sometimes, 
but in fact if the long waits are rare (one among thousands hits) these long 
waits may have gone almost unnoticed and without much importance.
That's why there is a "standard deviation" number next to the "max time" in the 
report: if the standard deviation is low relative to the max time, then long 
waits are rare. And it is the case for you here: standard deviations are 42 / 6 
for 156 298 ms / 169 511 ms max times. So these max times seems very rare, 
perhaps one in a million executions.

Second, web servers and java in particular are mostly based on best effort (you 
are certainly not using real time java and moreover your are using a database). 
And so waits can happen sometimes for thousands of reasons, among which many 
are out of reach for the java guy in the shop. Lowering waits can be easy at 
first, but lowering long waits below one in a million executions can be very 
very expensive (we do not put hard real time java everywhere for a good 
reason). For example, a major GC or some memory/disk access errors or a backup 
of the database can happen sometimes: one life critical application which I was 
involved with was quite slow some days, until we discovered later that desktop 
admins have scheduled a defragmentation of hard disks every Friday for all 
desktops in the enterprise.

So these high numbers are rare occurences in your case and their importance 
should really not be overestimated, but we could try to explain them:
- in javamelody, the max time "156 298 ms" is not the max for "exec 
sp_session_starta 60" when executed by SchemaSignatur.jsp. It is the max time 
for all the "exec sp_session_starta 60" executions in your application. 
Perhaps, this sql query was used for the selected period elsewhere in your 
application: you can try to find where by opening the detail for "exec 
sp_session_starta 60" and then by clicking "find usages". And this could 
explain why max times are high for this sql but not so high for this jsp.
- for the same reason, a long execution can be recorded and displayed for the 
sql but not yet for the jsp. For example, long sql executions can be recorded 
and for whatever reason the server is killed, the jsp execution will never end 
and be recorded.
- then these max times can be real or they can be a false measure. If it is 
real, there are thousands of reasons for that in the java server or in the 
database (remember: one in a million).
- and duration are based on wall clock time, so a synchronization of the clock 
in the OS between the begin and the end of the sql can introduced rare false 
measures: the measured time can be very long or it can be negative (but 
negatives are changed to 0 by javamelody). Synchronisation of clock time is 
enabled by default in Windows.
(- and hopefully an error in javamelody computations can't happen)

So your case is in fact possible, but probably not important given your 
standard deviations.

Original comment by evernat@free.fr on 29 Sep 2010 at 8:54

[GoogleCodeExporter]

Thanks for the rapid response. Understand now more about the standard 
deviations and might been possible that the server was shutdown during some of 
the request. 

Original comment by pether.s...@gmail.com on 29 Sep 2010 at 6:25

[GoogleCodeExporter]

ok, I suppose that it was a shutdown during a request.
(please reopen if needed)
bye

Original comment by evernat@free.fr on 4 Oct 2010 at 7:59

• Changed state: Invalid

[GoogleCodeExporter]

Original comment by evernat@free.fr on 9 Nov 2010 at 7:04

• Changed state: Accepted

[GoogleCodeExporter]

Original comment by evernat@free.fr on 9 Nov 2010 at 7:05

[GoogleCodeExporter]

Reasons above are valid, but still there was on maximum values in statistics as 
said in issue 59, which is now fixed.

So setting this issue as fixed as the possible reason of it was finally the 
issue 59 and the executions of days and weeks before.

Thanks

Original comment by evernat@free.fr on 9 Nov 2010 at 7:12

• Changed state: Fixed