SQL Profiler and high reads

Hi

I am facing a strange situation with a prepared query sent from Java application, SQL profiler is showing a very high reads about 250 000 pages (CPU:63155, duration 63400 ms), when I look in the Query plan captured by SQL profiler there is no table or index scan, there are about 5 main tasks with

cost : between 15 and 20%

Actual number of rows : between 1 and 400

Physical access : Clustered or Index seek

I am trying to figure out what is causing the 250 000 pages reads without success, since this a prepared query this is hard to reproduce the issue

Here is what looks like the query : exec sp_execute 95503,325138,...

with the handle 95503 I am able to find the prepared query and when I run the query on Management studio the number of reads is low just 380 pages and duration is only 345 ms compared to the original one 63640 ms

the reads in SQL profile will incude the read from the cache but this will not explain the very high of the reads, any idea how to track the root cause of this very high reads ?

July 1st, 2015 10:46am

.with the handle 95503 I am able to find the prepared query and when I run the query on Management studio the number of reads is low just 380 pages and duration is only 345 ms compared to the original one 63640 ms

Ok I guess you when you say you see read is 380 pages you go it by physically enabling set statistics IO ON can you once again run the query with statistics IO ON and post the output frim message section. I would like to see what read you are referring to there are physical, logical and read aheads  all means different. If you can post the output I would explai
Free Windows Admin Tool Kit Click here and download it now
July 1st, 2015 12:15pm

Hi,

Here the stats when I run the query in management studio,

SQL Profiler is showing in this case : CPU/Reads : 468 / 9664 pages, this is very far from the original query executed from the application with prepared statment  63155 / 250 000 pages

Table 'CMLOCALES'. Scan count 1, logical reads 2, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'Worktable'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'CMOBJPROPS14'. Scan count 0, logical reads 1286, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'CMREFNOORD2'. Scan count 0, logical reads 1286, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'CMOBJPROPS54'. Scan count 0, logical reads 1286, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'CMOBJECTS'. Scan count 553, logical reads 1764, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table '#CMTMPIDS___________________________________________________________________________________________________________0000000000A3'. Scan count 33, logical reads 2, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'CMREFORD1'. Scan count 1235, logical reads 3705, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

Best regards

July 1st, 2015 12:53pm

Table 'CMOBJECTS'. Scan count 553, logical reads 1764, physical reads 0, read-ahead reads 0, lob
Table 'CMREFORD1'. Scan count 1235, logical reads 3705, physical reads 0, read-ahead reads 0, lob

Mohamed B.

Notice the SCAN COUNT. These operators are running many times.

Take a look at the <PARAMETERS> section of the plan XML and see what the compiled vs runtime parameters are. I'd bet that the first value had many more rows than what you are running.

I hope you found this helpful! If you did, please vote it as helpful on the left. If it answered your question, please mark it as the answer below. :)

Free Windows Admin Tool Kit Click here and download it now
July 1st, 2015 1:44pm

One possibility is that you are using scalar functions that does data access. Having such in a SELECT will cause this to be executed *once per row*, and can sum up to a huge number. The "traditional" ways to look at plan and cost (statistics io) doesn't show the work done from scalar UDF. But a trace does!
July 1st, 2015 3:31pm

Hi Tibor,

There is no scalar function in the query, we are facing perf issue with very high reads only when the query is executed from a Java application with prepared statement, running the same query in management studio (after replacing parameters with real values) will generate only 9 664 pages instead of 250 000 pages, but in both cases the query plan is showing only Clustered or Index seek no table/index scan is performed.

Free Windows Admin Tool Kit Click here and download it now
July 1st, 2015 5:01pm

Although Logical reads are mostly harmless but its difficult to say why there is so much difference in Logical reads

I can only say that if you can show us the query we can try to reproduce it

July 2nd, 2015 12:08am

Can you capture  the execution plans when you run the Java application and SSMS? Are they identical?
Free Windows Admin Tool Kit Click here and download it now
July 2nd, 2015 1:34am

This topic is archived. No further replies will be accepted.

Other recent topics Other recent topics