Finding Potential Bottlenecks with DMVs.

July 28, 2010

The following query is a great way to get a look into how your stored procedure driven application is performing. I wouldn’t recommend running this during your peak hours. What I have done is scheduled it to run in the off hours and store into a table in my dummy DB. I then query that table as it is less intensive then quering the DMVs. What this query shows me is area’s a I need to tune within my application. If a query is executed many times and has a high number of logical reads perhaps my index needs to be tuned. Same goes if I look into area’s where physical data processing is happening… If your data isn’t being found in the cache you may have a bottleneck or perhaps you are just pulling to much data. It’s also great to see which queries are executed most frequently as there is always room for improvement and it’s important to understand how your data is being accessed.

select
substring(text,patindex(‘%create %’,text),50),
 SUBSTRING(st.text, (qs.statement_start_offset/2) + 1,
    ((CASE statement_end_offset
        WHEN -1 THEN DATALENGTH(st.text)
        ELSE qs.statement_end_offset END
            – qs.statement_start_offset)/2) + 1) as statement_text,
db_name(dbid) DB,
creation_time,
last_execution_time,
execution_count,
(total_elapsed_time/execution_count)/1000000 as time
,total_physical_reads
,last_physical_reads
,min_physical_reads
,max_physical_reads
,total_logical_writes
,last_logical_writes
,min_logical_writes
,max_logical_writes
,total_logical_reads
,last_logical_reads
,min_logical_reads
,max_logical_reads
,getdate()
FROM sys.dm_exec_query_stats as qs
CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) as st
where db_name(dbid) =’YourDB’


Table Scan

June 24, 2010

When reviewing execution plans I often look for table scans as an indicator of an area which performance can be improved. A table scan or a clustered index scan is when the query optimizer has to search the data entirely to find the row you are requesting.  The reason this can be costly is when you have a scan on a large table  SQL has to load all the data into the buffer this will slow performance and tax your resources. On smaller tables SQL Server may determine that a table scan is faster then an index seek, it can keep the entire data set in the buffer without issue.  A table scan would be caused by a query with no where clause. SELECT COLUMN1 from TABLE1. It can also be caused by a query with a WHERE clause which is not on the clustered index. SELECT COLUMN1 from TABLE1 where NOTPKEY=5.


What does a query plan show you?

June 18, 2010

I like to describe a query plan as a road map to your data. Your query plan shows you the steps the SQL Server engine is taking to fetch your data. Typical things you want to avoid in query plans are table scans, hash matching, bookmark lookups, excessive looping, spooling and excessive compute scalar operators.
To view a query plan you can use several set statements, for example: SET SHOWPLAN_TEXT or XML on, SET STATISTICS IO ON.
You can also see the plan in graphical format by using the SSMS from the query drop down menu. You can see even more information by selecting properties when you have a plan step highlighted.

When you write TSQL you want to get your data in the most effecient way possible. It is good practive to become familar with what the plan looks like and how even small things can have a large impact on performance.

Lets start with compute scalar for todays post. When you see a compute scalar step in your query plan SQL Server is doing an implicit conversion on a variable or column. Imagine if you are selecting 500,000 rows and for each row SQL Server is doing a conversion. How much over head do you think that will add? Just today I was tuning a piece of code. This code populated a table variable from a string of comma seperated values which were seperated by calling a function. The string passed to the function was a varchar, however the function was expecting a nvarchar and thus SQL was performing an implicit conversion on the string variable.  I changed the function to expect a varchar and the execution time of my stored procedure was reduced by 15 seconds. The number of rows I was processing was 32000.  A simple yet costly mistake.  Always make sure your variable declaration have the same data type as the data they will be holding, the same should be applied to parameters for stored procedures and functions.

In our next post we will discuss table scans.


Finding Procedures with largest Compile times

June 7, 2010

First you need to store the sql server plan cache into a table..

You can create a view then store the contents of that view into a table or query your view directly.
Create this in the master database

CREATE VIEW [dbo].[MYCache]
as
SELECT sp.*
FROM sys.dm_exec_cached_plans as cp
CROSS APPLY SqlAndPlan(cp.plan_handle) as sp

You can select the above data into a table for querying.. The reason I suggest ths is the cache querying can be intensive depending on the number of objects in your cache.

The below query gives you Compile Time, Estimated Rows, and Compile Memory..
You can use this information to determine your worst performing stored procedures.

SELECT SUBSTRING(TEXT, CHARINDEX(‘CREATE PROCEDURE’, text)+16,50) as ProcName,
text,
query_plan.value(‘
     declare namespace AWMI=”http://schemas.microsoft.com/sqlserver/2004/07/showplan”;
     sum(//AWMI:RelOp/@EstimateRows)’, ‘float’) as EstRows,
query_plan.value(‘
     declare namespace AWMI=”http://schemas.microsoft.com/sqlserver/2004/07/showplan”;
     sum(//AWMI:QueryPlan/@CompileMemory)’, ‘float’) as EstMemory,
query_plan.value(‘
     declare namespace AWMI=”http://schemas.microsoft.com/sqlserver/2004/07/showplan”;
     sum(//AWMI:QueryPlan/@CompileTime)’, ‘float’) as CompileTime
FROM PlayDB..Mycache


Yet another Performance issue….

September 28, 2009

This article is related to the article I wrote a while back on parameter sniffing. We recently had another problem with a production application that started to experience poor performance. The C# web application using a SQL 2005 database starting timing out. The timeout was set to 30 seconds. I wasn’t seeing deadlocks on the database and we had some blocking but it wasn’t extreme. So this problem lasted over about two weeks. Here are the steps taken to troubleshoot.

1) Began running SQL Profiler. I started tracing only RPC calls using a filter on the trace for duration > 30000 (30 seconds). My first thoughts were I better figure out which procs are taking the time. The trace showed one particular proc which was executed many times and always took alot of time on the DB. This procedure was also blocking others. We spent some time tuning this procedure and testing it and pushed it into production.

2) The tuned procedure reduced the timeouts from around 150 a day to about 50 a day. A huge improvement but still not a great user experience. I changed my trace for duration > 10,000 and monitored it for many days. I started seeing that one proc to fetch information used for a drop down list was taking more and more time each day. If I took the call from the trace and executed it from SSMS the query would execute in 1 second. If I ran the same call from OSQL on a different machine it would take 30 seconds. The application timeout setting was also increased to 60 seconds.  

3) Next I checked my indexes for fragmentation and rebuilt them old style. I mean I dropped and recreated them I didn’t use DBCC commands.

4) I increased the number of times update statistics with full scan from once a week to twice a week.

We still had issues with this one proc and it is now causing the majority of the timeouts.  When I looked at the query plan from SSMS in the GUI format it’s doing two index seeks. But when I look at the plan generated from OSQL it’s doing an index scan and generating over 3 million reads on a table that has only about 400K rows in it.

5) At this point an advisory case with Microsoft was opened.  My gut was telling me that it has to be related to the query plan but I couldn’t understand why SSMS is picking an efficient plan and OSQL is not.

I checked the connection settings for the database properties coming from my application and I compared these to the settings used by SSMS and OSQL. They are all the same. To check the login set options you use profiler to trace the Audit:Login event. Microsoft told me that these settings can affect your query plan.

6) Next thing to do is start looking at the trace when I execute the stored procedure call from SSMS and OSQL. What I found partially answered my question as to why the procedure call executes quickly from SSMS.  I traced all the events under Stored Procedures for my spid and I found that whenever I execute the proc from SSMS it was doing a cache miss. AKA not finding it in the procedure cache. Ok Why? When I do a call from OSQL it’s also doing a cache miss but then picking an inefficient plan. Well at least I can recreate the issue….

7) Next thing is to start looking at is the plans that are actually in the cache. You can do this by using the Dynamic management views. Create the function and view below for an easy look into the cache.

create function SqlAndPlan(@handle varbinary(max))
returns table
as
return select sql.text, cp.usecounts,cp.cacheobjtype,
cp.objtype, cp.size_in_bytes,
qp.query_plan
 from
 sys.dm_exec_sql_text(@handle) as sql cross join
 sys.dm_exec_query_plan(@handle) as qp
 join sys.dm_exec_cached_plans as cp
 on cp.plan_handle = @handle;

create view PlanCache
as
select sp.* from sys.dm_exec_cached_plans   as cp
cross apply SqlAndPlan(cp.plan_handle) as sp

8 ) When viewing the results you will get the XMLversion of your query plan. If you click on the results you can open it and save it as .sqlplan and when you open it again it will be in the graphical format. However the XML Plan gives you views into some things that the graphical plan does not. Some of this information is extremely useful. The thing I personally thought is the greatest is that I can actually see what parameters are used for my procedure execution when the plan is stored in the cache. You can always reverse engineer your procedure calls from this. To find the parameter values search the xml plan for parameter list. You will see something similar to the following:

<ParameterList>ColumnReference Column=”@Default” ParameterCompiledValue=”(1)” />
ColumnReference Column=”@Role” ParameterCompiledValue=”(8)” />
ColumnReference Column=”@Page” ParameterCompiledValue=”Start” />
ColumnReference Column=”@user” ParameterCompiledValue=”(1)” />
…. n  

From this information I can see if my plan is an atypical call. For example if 90% of my users have role 1 and the plan cached is for role 8 perhaps you should remove this plan from the cache and replace it with a more efficient one. This happened to be the situation in my case. To change the value in the cache you need to recompile the stored proc and execute it with different set of parameters then verify that is stored in your cache. Another useful bit of information in the cache is the compile time. The proc which was causing us issues took .001 seconds to compile the plan. We decided with the advice of Microsoft to add the recompile option to this proc to ensure the correct plan is always chosen.  The over head in this case was .001 seconds. I don’t recommend adding this option all the time and this should be carefully weighed based on the stored procedure and other tuning options available.  


Index This Index That

December 30, 2008

So let me ask you this… Do you really know how SQL Server storage engine works? You would be surprised how many people can’t answer simple questions about indexes on interviews. Sorry Folks if you can’t tell me what the difference between and clustered and a non-clustered index your interview score just went down.

That being said this is a very simple question I like to ask people on interviews. If your going to rebuild the indexes on a large table which has no Forgein keys. How would you do it and why? You cannot use any  dbcc or online index operations. We are going old school. To keep it simple assume your table is 5GB, has a clustered index and 5 Non-clustered indexes some of which are composite.

When I ask this my goal is to find out if you truly understand how the data is stored. If you do then the answer is quite easy.

I’ll give you the answer I am looking for first then I will explain why.

“You would drop the NON-Clustered indexes first. Then drop the Clustered index. Next you would create the CLustered index then the Non-CLustered indexes.”

Now the why.

A clustered index in the simplest explaination is that it is your data. A classic example of a clustered index is a phone book. Now of course we can get into B-Tree structures but lets save that for another post. That being said If I drop my clustered index first the operation will also drop and recreate my non-clustered indexes and can potentially take alot of time. To speed up the process drop the NC indexes first. (AFTER YOU SCRIPTED them of course)


Poor performance from Application

December 1, 2008

Have you ever come across the senario where a query or stored procedure performs just fine from Query Analyzer but performs terrible from the application? Most of us have. How do you go about troubling shooting this? Here is the senario I ran into and the steps taken.

During the stress testing phase of our application release we came to a situation when loadrunner hit two particular tabs in our application and it would report back timeout errors. The web developers were called in as well as the DBA team.  So obviously our first step was to run a trace and find out the exact call to the stored procedure which is taking time. (I assume you already know how to use SQL Profiler if not check it out in books online) . The events I wanted to see for this run of the trace are:

SP:Starting
SP:Completed
SP:StmtStarting
SP:StmtCompleted

The reason I chose these are because my application is stored procedure driven so I want to know which proc and which statement in that proc is taking time. I need to look at the Duration column, Reads and writes as well. Remeber to pay attention to column/event compatibility in your trace. For example if I want to see the duration value populated in my trace. I need to make sure that I am capturing the XXX:completed event. That being said, I reached my goal of getting the statement and the call to the stored procedure which is taking time. I noticed in my trace that the reads were through the roof. (Over three million)

So my next step obviously was to run the call to this stored procedure. This particular stored proc is a read proc. I ran it and of course it came back in 1 second while in the trace it reported 32 seconds. Hmmmmm, intersting.

Now lets examine the procedure and see whats going on and what the tables look like. The stored procedure is pretty straight forward. It’s a child proc and its parents have most of the logic in it. It’s checking if data exists in a particular table which has 42 million rows and if it does it returns a flag which is processed by the outer proc. So now my first thought is to check when statistics have last been updated on this table and if there is any index fragmentation.

I ran showcontig (this is a SQL 2000 app) and saw my scan density to be about 30 percent.  So next I planned and rebuilt the indexes on this table. I started to think maybe the fragmentation was negatively affecting the query plan when it was coming from the app. On examination of the query plan when I ran the proc from Query Analyzer I didn’t see anything negative.

After the index maintenance the test was run again and again the same thing happened but now the issue was sparatic. This makes it even more difficult now because the same call still takes one second for me. So next I started to think that maybe there was some excessive locking or blocking happening on this table. So I had my testor run the test again for a single user to reduce contention. Even when running the test as a single user the issue appeared.  I used the Deadlock even in profiler and that was not it either.

I started to go back to the idea of the query plan. Maybe when the call is coming from the application a different query plan is being used but how do I verify this. SQL Profiler has an event class for the query plan so that was my next step.  I captured the plan during the load test and compared it with the results from my machine. Sure enough when run through the application the query plan being used was scanning the table. You can imaging scanning 42 million rows will take some time but why when I run it from my machine does it do an index seek. I started to think my procedure cache was somehow corrupted so you guessed it. My next step was to clear the procedure cache.

Same results again. Ok I am ready to pull my hair out now. Why is this happening. Back to google and I found a topic called Parameter sniffing. This is something new to me but it was the exact reason for my problem. In a nut shell parameter sniffing is a side effect of parameter use. When you use parameters in your stored procedures SQL Server will generate plans based on common parameter use.  (It’s a bit more complicated this this. check out his link http://blogs.msdn.com/queryoptteam/archive/2006/03/31/565991.aspx)  If a atypical call to the proc is made and then a typical call. The typical call will have a plan which is not optimal for that situation.

Now that I know what is happening how do I avoid this? We need to fool the optimizer. Here is some simple code

Create procedure proc_myparasniffer

AS @office varchar(255), @offfice_template varchar(255) =”Main Street”

SET @office_template=@office

SELECT A,B,C from Order where OfficeName = @office_template

It’s pretty easy we are filtering the query on office_Template because @office_template is set with a default value when SQL sniffs the parameters it will always generate the same plan.