Link to home
Start Free TrialLog in
Avatar of marrowyung
marrowyung

asked on

measuring the speed of SQL query

Dear expertist,

Right now we want to implement some change to our SQL server, we pick some long running query and test the speed of it.

IT seems that some DMV will show out the esplased time and return time of a query, how many phyysical read, write and logical write will show out.

What is the DMV for this?

if you were me, how you guy measure the improvement after changing the SQL setting ? other than reading the figure in the lower right hand conner of the SSMS ?

DBA100.
SOLUTION
Avatar of s___k
s___k
Flag of Georgia image

Link to home
membership
This solution is only available to members.
To access this solution, you must be a member of Experts Exchange.
Start Free Trial
Also you can use SET STATISTICS IO ON which shows reads and writes
SOLUTION
Link to home
membership
This solution is only available to members.
To access this solution, you must be a member of Experts Exchange.
Start Free Trial
A good  hands on book about  DMV's is this http://www.manning.com/stirk/
PS: sample chaper's and code examples available
ASKER CERTIFIED SOLUTION
Link to home
membership
This solution is only available to members.
To access this solution, you must be a member of Experts Exchange.
Start Free Trial
And in 2008 you can limit DBCC FREEPROCCACH to only your database  
DBCC FLUSHPROCINDB(@dbid) .
But as mentioned higher, don't do this on production. while this will clear the cached plans so they cannot be reused and they are the source of your dmv's to find the history of that query
Avatar of marrowyung
marrowyung

ASKER

jogos:

Thanks for that.

But it seems like the one I use for finding top xx slowest query:

SELECT TOP 20 SUBSTRING(qt.text, (qs.statement_start_offset/2)+1,
 ((CASE qs.statement_end_offset
 WHEN -1 THEN DATALENGTH(qt.text)
 ELSE qs.statement_end_offset
 END - qs.statement_start_offset)/2)+1),
 qs.execution_count,
 qs.total_logical_reads, qs.last_logical_reads,
 qs.min_logical_reads, qs.max_logical_reads,
 qs.total_elapsed_time, qs.last_elapsed_time,
 qs.min_elapsed_time, qs.max_elapsed_time,
 qs.last_execution_time,
 qp.query_plan
 FROM sys.dm_exec_query_stats qs
 CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) qt
 CROSS APPLY sys.dm_exec_query_plan(qs.plan_handle) qp
 WHERE qt.encrypted=0
 ORDER BY qs.total_logical_reads DESC

right?


But what if the developer will give me some query they don't like and I would like to measure the different before and after my change ?

Can you give example like what s___k does?
s___k:

like this:

USE SomeDB;
GO      
SET STATISTICS TIME ON
SET STATISTICS TIME IO
GO
SELECT * FROM SomeTable WHERE SomeColumn = SomeValue; ( I need to replace this one with mind, I knew that ! thanks)

GO
SET STATISTICS TIME OFF;
SET STATISTICS IO ON

?

Any other information can be add? I would like to turn on more useful statistics information. This change is to format the SQL data/log disk from 4k to 64k.

DBA100.


Dear all,

How many clear cache we can have?  what is the command ?

DBCC DROPCLEANBUFFERS
GO
DBCC FREEPROCCACHE
GO

and ? I knew there are 2 more.

DBA100.

Looks familiar indeed. Everything you ask for is in that sql you have i think, only it's cumulated on all executions and the filter does not focus on your query.

On an isolated database in development it's easy, you clear the cache and you only get it from last execution, before and after will be different lines so that's easy.
In the real world the trick can be saving the statistics in a table created for that purpose execute the old statement again and the difference between the statistics saved in table and the one you get now is the number of resources that last execution. Check exectuion_count that it's only one execution though!

Filter you have the qt.text in your query so that can be used to filter only your query out of all the rest .
Session and system cache
 http://msdn.microsoft.com/en-us/library/ms188796.aspx

But playing with the cache do it on your priviate environment. On shared environments (and certainly production) you can damage performance (no cache) and other peoples statistics. The maybe  trying similar things but depending on a the statistics of a longer time.
And there is always SQL Profiler where you can monitor the same info and filter it on database, comming from your PC, ....

The SET STATISTICS are easy to use  and readable  when you have a sql to test in a management studio (or sqlcmd) but it's more difficult to reuse the results or save them to be compared with other executions.
And not usable in a production environment to measure the average statistics of that same query after you have defragmented an index or some index. By saving result of your dmv-query in a monitoring table on a frequently basis you have a baseline to check if your performance is realy degrading and even in which queries it is and in which it is't.  
Advantage of SET STATISTICS is you can use it perfectly in a sql-window on a production server. But then again they will give the results using a cached plan and so the result of a cached query and a non cached are not comparable.
jogos:

We will not use in on production but staging, thanks for you all suggestion. we don't even want to touch the production and right now we are in the POC staging for a new change.

If this doens't provide the SQL query speed ( the worse one) thne we don't go ahead.

we have more testing on it and the reason I ask is we need a way to provide more information on individual query, not just by reading information at the lower right hand conner of the SSMS windows, which tells how may sec. it rans.


It seems that there are 4 x clear cache SP:

DBCC DROPCLEANBUFFERS
DBCC FREEPROCCACHE
DBCC FREESESSIONCACHE
DBCC FREESYSTEMCACHE

do I really need all to test the test the query ?

DBA100.





jogos:

"On an isolated database in development it's easy, you clear the cache and you only get it from last execution, before and after will be different lines so that's easy.
In the real world the trick can be saving the statistics in a table created for that purpose execute the old statement again and the difference between the statistics saved in table and the one you get now is the number of resources that last execution. Check exectuion_count that it's only one execution though!
"

What is "Check exectuion_count that it's only one execution though!"? you mean focus on "qs.execution_count" field and see if it is 1? what if it is not 1? the cache is not free?


"Filter you have the qt.text in your query so that can be used to filter only your query out of all the rest . "

 What is that mean? it seem I don't have this value in my script.

you mean this: CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) qt? and I have to replace the value of <qs.sql_handle> using my query?  what if  my query is very long, then it might not find it, right?


it seems that DBCC FREESYSTEMCACHE can't be run alone to clear all system cache, right?



jogos:


IN summary, what should I do is:

1)
Run
DBCC DROPCLEANBUFFERS
DBCC FREEPROCCACHE
DBCC FREESESSIONCACHE

2)
Run this"
SET STATISTICS TIME ON
SET STATISTICS TIME IO
GO
<my query>

GO
SET STATISTICS TIME OFF;
SET STATISTICS IO ON

3) then this one:

SELECT TOP 20 SUBSTRING(qt.text, (qs.statement_start_offset/2)+1,
 ((CASE qs.statement_end_offset
 WHEN -1 THEN DATALENGTH(qt.text)
 ELSE qs.statement_end_offset
 END - qs.statement_start_offset)/2)+1),
 qs.execution_count,
 qs.total_logical_reads, qs.last_logical_reads,
 qs.min_logical_reads, qs.max_logical_reads,
 qs.total_elapsed_time, qs.last_elapsed_time,
 qs.min_elapsed_time, qs.max_elapsed_time,
 qs.last_execution_time,
 qp.query_plan
 FROM sys.dm_exec_query_stats qs
 CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) qt
 CROSS APPLY sys.dm_exec_query_plan(qs.plan_handle) qp
 WHERE qt.encrypted=0
 ORDER BY qs.total_logical_reads DESC

To find out he rest of the information?

DB100.
"qs.execution_count"
tells you how many executions there where so the statistics are the cumulated value of that number of executions. When first run (or after clear) it should be 1, but mostly you will know that and so the best use of that count is when you periodicaly save the value's of your dmv in a reporting table so you can use it to know what the average is. If you save statistics just before and just after you expect only your execution is monitored, but to be sure the execution_count may only differ 1

"qt.text" you already use in first result-column, that column reflects the executed statement, the qt.text the complet context of that statement. To filter is using it in a where, but it's possible that you will have more results if your query is part of a batch (that's why the subbstring with the offset is used in your first column).
 
WHERE .... and qt.text LIKE '% select * from myheavyquerytable %'
An example of that filtering you can find in this link where it is used to specificly clearing only the cache from a specified statement at header 'A. Clearing a query plan from the plan cache' http://msdn.microsoft.com/en-us/library/ms174283.aspx

For your resume
1) freeing cache , yes but not on production and not on any other system without knowlede of the dba
2) and 3) basicly should give same information, only 2) will give it in your query environment as additional output for that execution only and 3) will stay queryable (until cleared) and are more practical for use to fill your own statisics table , measure more excecutions to have an average.....  and are usable in production

And to add your query also returns the query plan, where you can learn some warnings 'missing index' and a breakdown of your query in which part consumes the most .... but won't elaborate on that http://www.codeproject.com/KB/database/sql-tuning-tutorial-1.aspx
1) ""qs.execution_count"
tells you how many executions there where so the statistics are the cumulated value of that number of executions. When first run (or after clear) it should be 1, but mostly you will know that and so the best use of that count is when you periodicaly save the value's of your dmv in a reporting table so you can use it to know what the average is. If you save statistics just before and just after you expect only your execution is monitored, but to be sure the execution_count may only differ 1"

So you means that after I clear all the cache, execution_count =1? it wil also focuse the table read from physical disk again but not buffer?

2) As are we now change the disk allocation unit from 4k to 64k including the volume of tempdb, will that also means that the cached figure will be better also. I tried before that after changing to 64k, and I press F5 3 times of the same query in order to get a means value, will that help and true figure ?

3)
"WHERE .... and qt.text LIKE '% select * from myheavyquerytable %'
An example of that filtering you can find in this link where it is used to specificly clearing only the cache from a specified statement at header 'A. Clearing a query plan from the plan cache' http://msdn.microsoft.com/en-us/library/ms174283.aspx
"

So this means after the change, the script will become:

SELECT TOP 20 SUBSTRING(qt.text, (qs.statement_start_offset/2)+1,
 ((CASE qs.statement_end_offset
 WHEN -1 THEN DATALENGTH(qt.text)
 ELSE qs.statement_end_offset
 END - qs.statement_start_offset)/2)+1),
 qs.execution_count,
 qs.total_logical_reads, qs.last_logical_reads,
 qs.min_logical_reads, qs.max_logical_reads,
 qs.total_elapsed_time, qs.last_elapsed_time,
 qs.min_elapsed_time, qs.max_elapsed_time,
 qs.last_execution_time,
 qp.query_plan
 FROM sys.dm_exec_query_stats qs
 CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) qt
 CROSS APPLY sys.dm_exec_query_plan(qs.plan_handle) qp
 WHERE qt.encrypted=0 and and qt.text LIKE '% <my query> %'
 ORDER BY qs.total_logical_reads DESC




jogos:

Basically, if I just tried to focus the query to reload all table from disk, what clean cache command I should use?

I clear too much probably make the 64k change slower, this is what I think, do you agree?

DBA100.
Dear all,

SET STATISTICS PROFILE ON seems not very much use, it return so much information? what should I look at ?

DBA100.
Dear all,

Once I turn on
SET STATISTICS TIME ON
SET STATISTICS IO on

there are some counter I don't understand:

Scan count
logical reads
physical reads
read-ahead reads
lob logical reads
lob physical reads
lob read-ahead reads

Please help to clarify what it is and which one high is not good.

DBA100.
So many questions and allways : there is an answer to that question allone and there is one with changing context from other questions. It's getting messy.
1)
yes it has the number of executions, so if only 1 time it is definitly 1. Andrest of values is what is done, from buffer or disk, that depends on other settings, but that link to the DMV-description higher will learn that the dmv will  give you everything you want about that .... physical reads....

2)
executing the query 3 times will (without initialising in between) will give it first time with recompilation (if....)  and reading from disk (if........)  and next 2 time will be more efficient.
Don't know what you mean by 'true figure' and don't know if you mean results from DMV or from STATISTICS IO..... so this is going nowhere answering this with all posibilities

changing other options is some example why you should preserve the info of dmv's to a permanent table so you can use it as a permanent reference ..... and not only for your single query because optimising one query can degrade another (insert is slower with more indexes....)

3)
yes you copied the example well if you pay attention to not putting spaces before and after

Basically, if I just tried to focus the query to reload all table from disk, what clean cache command I should use?
Ok we try to guide you to the good direction with comments and links to the detailled documentation of the dmv's and set-functions.
if you know see that the dmv returns you both physical and logical reads .... I guess a little reading and experementing yourself will learn you more than answering this question.

I clear too much probably make the 64k change slower, this is what I think, do you agree?
Yep, that's why its cache and one of the reasons why I keep repeading no problem on your PC, but don't do this on a shared environment where it could matter .... and others are tuning their sql and are getting the most unexpected degrade where it should be a faster query :)

"executing the query 3 times will (without initialising in between) will give it first time with recompilation (if....)  and reading from disk (if........)  and next 2 time will be more efficient.
Don't know what you mean by 'true figure' and don't know if you mean results from DMV or from STATISTICS IO..... so this is going nowhere answering this with all posibilities
"

Executing  3 times I mean to find the mean value of the query finish time. So  I think for this I have to clear the buffer 3 times in each of test to get the mean value, make sense ? This is the case of non cached.

for cached resuilt as the cached probably faster also. then I have to press the F5 again 3 times to get the cache mean vaule to compare that. This round I don't clear buffer.




Press F5 again 3 times ....  if you put a numberr after your GO the statement(s) it wil  be executed that number of   times.  
 
select * from dbo.x
GO 100  --  previous statement executed 100 times
select count'(*) from dbo.y
select * from dbo.x
GO 10  -- previous statemnts executed 10 times

Open in new window

jogos:

Thanks. good to hear that. but will the elapsed time sum up which is the total time to run the query 3 times? not the average?

Also do you know any counter to measure the disk latency so that we know after changing to 64k, the disk latency will be lower, magnetic head's move becoming less, and thus, transfer rate increase?

DBA100.
It's the total time, but the execution_count contains the number of times run so that you need to get your average.

For pefmon counters to measure IO
- http://flippingbits.typepad.com/blog/2011/03/perfmon-counter-of-the-week-disk-latency.html
- serie of presentations about perfmon counters (attention for SAN!)
http://searchsqlserver.techtarget.com/Monitor-SQL-Server-disk-I-O-with-PerfMon-counters

But disk IO, advantage of cache, ... only shows relevant figures when the system is stressed in a mixed way (only large processes, only small processes on mixed data, mixed small and large).

Read ahead is good, if you make use of the additional data that is read.  If not, it's just data read for nothing.
jogos:

I will test tomorrow and let you know very soon. I just have this thinking on what if other counter not good, or similiar, I want to present more to present the good of changing to 64k.
jogos:

One question, right now we would like to find out all query has been ran since last time SQL server started.

Is there anyway to run a script/dmv to find all ran SQL queries and save execution plans of all of them into a table (text base), then after we change to 64k and run for a while, we try to compare the execution plan of the same query again,

if I want to find all query SQL has executed, I use the followings ?


SELECT
        qs.total_worker_time/qs.execution_count as [Avg CPU Time],qs.total_physical_reads, --Added
        qs.total_logical_writes, --added
        SUBSTRING(qt.text,qs.statement_start_offset/2,
                  (case when qs.statement_end_offset = -1
                  then len(convert(nvarchar(max), qt.text)) * 2
                  else qs.statement_end_offset end -qs.statement_start_offset)/2)
            as query_text,
            qt.dbid, dbname=db_name(qt.dbid),
            qt.objectid ,
            pa.pa_dbid,
            qp.query_plan
FROM sys.dm_exec_query_stats qs
cross apply sys.dm_exec_sql_text(qs.sql_handle) as qt
CROSS APPLY sys.dm_exec_query_plan(qs.plan_handle) qp
OUTER APPLY (select value as pa_dbid from sys.dm_exec_plan_attributes(plan_handle) where attribute = 'dbid') AS pa
ORDER BY [Avg CPU Time] DESC


Then how can I make sure that I compare the execution plan of the same query  later on?

We need to create 2 x table, one for before and one for after changing to 64k?



DBA100.
or using this one and insert it to a table ? This query return all rans query on a SQL instance ?

select * FROM sys.dm_exec_query_stats qs
CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) qt
CROSS APPLY sys.dm_exec_query_plan(qs.plan_handle) qp
INNER JOIN sys.dm_exec_cached_plans cp
      ON qs.plan_handle=cp.plan_handle

this query return too much but we just need to most meaningful information for this 4k to 64k project.


But the main point still, how can we check back the SAME QUERY rans before and see what is the improvement after some time after changing to 64k, this is hardest part.

By the same SQL_handle?  Anway to write down the execution plan in text and then save it to a table to later comparsion?




DBA100.
jogos:


What should be the schema of the table that can store all these information?


DBA100.
>>jogos:

One question,<<
And I think I see a question or 5.  While the initial question 'how to measure speed' is already answered.  This topic can't go on forever.

>>What should be the schema of the table that can store all these information?<<
Best to make a dedicated database for your db-management tables, views and procedures.

>>
Then how can I make sure that I compare the execution plan of the same query  later on?

We need to create 2 x table, one for before and one for after changing to 64k?
<<
The text of the sql will be the same, or it's not the same sql anymore.
Store it in the same table, but with the timestamp of that moment so you can create 100 measuring points and see the evolution of average consumption of that same query + the period on wich it's most used....

>> plan on text<<
here it's xml and you've got other topic for this,
jogos:

I have some question pending and I can't create ticket anymore. I would like to but I can't, please help.

I get a new request but has to done that in these 2 days.

"The text of the sql will be the same, or it's not the same sql anymore.
Store it in the same table, but with the timestamp of that moment so you can create 100 measuring points and see the evolution of average consumption of that same query + the period on wich it's most used....
"
HOw can I do this ? you do it day by day ?

"here it's xml and you've got other topic for this, " which one ?

DBA100.
"The text of the sql will be the same, or it's not the same sql anymore."

So this is true only after I restart the SQL service, right? I agree with this that's why I wondering how to do this.

What about I don't compare the execution plan as I can't store the execution plan in a column of the new table, right? even it is a text base we can't store it in a single row, right?

I think we can simple from the new table, find the same sql text, but only compare the rest of the column, like physical read, physcial write, elapsed time, etc. right?

"here it's xml and you've got other topic for this", so that following query will generate the execution plan in XML format but I can't save the XML format in a column, right? this is what I am thinking how..

select * FROM sys.dm_exec_query_stats qs
CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) qt
CROSS APPLY sys.dm_exec_query_plan(qs.plan_handle) qp
INNER JOIN sys.dm_exec_cached_plans cp
      ON qs.plan_handle=cp.plan_handle

Anyway to export the execution plan in text ? so that I simple export everything in a excel file and compare it later on? However it will be hard to read..




SOLUTION
Avatar of Mark Wills
Mark Wills
Flag of Australia image

Link to home
membership
This solution is only available to members.
To access this solution, you must be a member of Experts Exchange.
Start Free Trial
@mark_wills
Measuring is for system changes before and after (half in other topic)

@marrowyung
>>What about I don't compare the execution plan as I can't store the execution plan in a column of the new table, right? even it is a text base we can't store it in a single row, right?<<
When you can have it in a query it has a datatype sql can handle ..... so store it in its datatype .. maybe if you have followed the links to the dmv-doc you could have found its the xml-type.

But now it's realy my last comment on this
jogos:

Good and I understnad the concept as I have just trial run your procedure/way, thank for coaching.

Mark_wills,

I just make the moderator enable my right to ask again.

thanks for you all for coaching and I will keep learning from you all.

Sorry that there are too much task for me recently and no time to read more. I have read many links here and learn a lot.

DBA100.
jogos very good indeed. Thanks for everyone for helping.