Click here to monitor SSC
SQLServerCentral is supported by Red Gate Software Ltd.
 
Log in  ::  Register  ::  Not logged in
 
 
 
        
Home       Members    Calendar    Who's On


Add to briefcase

procedures used Expand / Collapse
Author
Message
Posted Thursday, December 5, 2013 6:48 AM


SSCrazy

SSCrazySSCrazySSCrazySSCrazySSCrazySSCrazySSCrazySSCrazy

Group: General Forum Members
Last Login: Thursday, July 17, 2014 6:40 AM
Points: 2,567, Visits: 3,799
Hi Experts,

we have a list of procedures used when accessing a particular application.

Is there anyway to check how long this procedures take to complete?

If i ran profiler and click on the app buttons i can see those procedures running behind. Can i get the time it ran? Is there any other way other than profiler??
Post #1520034
Posted Thursday, December 5, 2013 7:04 AM


SSC-Forever

SSC-ForeverSSC-ForeverSSC-ForeverSSC-ForeverSSC-ForeverSSC-ForeverSSC-ForeverSSC-ForeverSSC-ForeverSSC-ForeverSSC-ForeverSSC-ForeverSSC-ForeverSSC-ForeverSSC-Forever

Group: General Forum Members
Last Login: Yesterday @ 4:54 PM
Points: 42,434, Visits: 35,488
There are, but what's wrong with running profiler (or preferably a server-side trace) and recording the duration column?


Gail Shaw
Microsoft Certified Master: SQL Server 2008, MVP
SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability

We walk in the dark places no others will enter
We stand on the bridge and no one may pass

Post #1520047
Posted Monday, December 9, 2013 2:05 PM


SSC Eights!

SSC Eights!SSC Eights!SSC Eights!SSC Eights!SSC Eights!SSC Eights!SSC Eights!SSC Eights!

Group: General Forum Members
Last Login: Wednesday, July 16, 2014 8:52 AM
Points: 980, Visits: 1,324
I've been using a procedure written by Gregory A. Larsen. It will display the top worst performing queries. It comes in quite handy and may help you out. Here is the code:

USE [master]
GO
/****** Object: StoredProcedure [dbo].[usp_Worst_TSQL] Script Date: 12/09/2013 16:03:41 ******/
SET ANSI_NULLS ON
GO
SET QUOTED_IDENTIFIER ON
GO
ALTER PROC [dbo].[usp_Worst_TSQL]
/*
Written by: Gregory A. Larsen
Copyright © 2008 Gregory A. Larsen. All rights reserved.
Name: usp_Worst_TSQL
Description: This stored procedure displays the top worst performing queries based on CPU, Execution Count,
I/O and Elapsed_Time as identified using DMV information. This can be display the worst
performing queries from an instance, or database perspective. The number of records shown,
the database, and the sort order are identified by passing pararmeters.
Parameters: There are three different parameters that can be passed to this procedures: @DBNAME, @COUNT
and @ORDERBY. The @DBNAME is used to constraint the output to a specific database. If
when calling this SP this parameter is set to a specific database name then only statements
that are associated with that database will be displayed. If the @DBNAME parameter is not set
then this SP will return rows associated with any database. The @COUNT parameter allows you
to control the number of rows returned by this SP. If this parameter is used then only the
TOP x rows, where x is equal to @COUNT will be returned, based on the @ORDERBY parameter.
The @ORDERBY parameter identifies the sort order of the rows returned in descending order.
This @ORDERBY parameters supports the following type: CPU, AE, TE, EC or AIO, TIO, ALR, TLR, ALW, TLW, APR, and TPR
where "ACPU" represents Average CPU Usage
"TCPU" represents Total CPU usage
"AE" represents Average Elapsed Time
"TE" represents Total Elapsed Time
"EC" represents Execution Count
"AIO" represents Average IOs
"TIO" represents Total IOs
"ALR" represents Average Logical Reads
"TLR" represents Total Logical Reads
"ALW" represents Average Logical Writes
"TLW" represents Total Logical Writes
"APR" represents Average Physical Reads
"TPR" represents Total Physical Read
Typical execution calls

Top 6 statements in the AdventureWorks database base on Average CPU Usage:
EXEC usp_Worst_TSQL @DBNAME='AdventureWorks',@COUNT=6,@ORDERBY='ACPU';

Top 100 statements order by Average IO
EXEC usp_Worst_TSQL @COUNT=100,@ORDERBY='ALR';
Show top 100 statements by Average IO
EXEC usp_Worst_TSQL;

- Updated: 4/14/2014 Added "LET" represents Last Execution Time

*/
(
--declare
@DBNAME VARCHAR(128) = ''
,@COUNT INT = 99999
,@ORDERBY VARCHAR(4) = 'AIO'
,@FromDateTime DATETIME = null
,@ToDateTime DATETIME = null
)
AS

set nocount on
-- Check for valid @ORDERBY parameter
IF ((SELECT CASE WHEN @ORDERBY in ('ACPU','TCPU','AE','TE','EC','AIO','TIO','ALR','TLR','ALW','TWL','APR','TPR', 'LET') THEN 1 ELSE 0 END) = 0)
BEGIN
-- abort if invalid @ORDERBY parameter entered
RAISERROR('@ORDERBY parameter not ACPU, TCPU, AE, TE, EC, AIO, TIO, ALR, TLR, ALW, TLW, APR, LET or TPR',11,1)
RETURN
END
declare @IgnoreDB table (ID int primary key identity (1,1)
,Database_Name varchar(300)
)
insert into @IgnoreDB (Database_Name) values ('ProjectServer_Draft')
insert into @IgnoreDB (Database_Name) values ('ProjectServer_Published')
insert into @IgnoreDB (Database_Name) values ('Resource')
insert into @IgnoreDB (Database_Name) values ('Search_Service_Application_DB_c8785b3aa44a4764b0033694e891b403')
insert into @IgnoreDB (Database_Name) values ('Search_Service_Application_PropertyStoreDB_3ec06be4caa54e6d903263a2940815eb*')
insert into @IgnoreDB (Database_Name) values ('SharePoint_Config')
insert into @IgnoreDB (Database_Name) values ('WSS_Logging')
insert into @IgnoreDB (Database_Name) values ('WSS_Content')
insert into @IgnoreDB (Database_Name) values ('Search_Service_Application_CrawlStoreDB_af930aab0a8b48609df53c5572fb5213')
insert into @IgnoreDB (Database_Name) values ('Managed Metadata Service_77e8fbe186ba4becbd25cfb12d4b41ff')
insert into @IgnoreDB (Database_Name) values ('Managed Metadata Service_77e8fbe186ba4becbd25cfb12d4b41ff*')
insert into @IgnoreDB (Database_Name) values ('msdb')


SELECT TOP (@COUNT)
COALESCE(DB_NAME(st.dbid), DB_NAME(CAST(pa.value AS INT)) + '*', 'Resource') AS [Database Name]
-- find the offset of the actual statement being executed
,SUBSTRING(text,
CASE WHEN statement_start_offset = 0
OR statement_start_offset IS NULL THEN 1
ELSE statement_start_offset/2 + 1 END,
CASE WHEN statement_end_offset = 0
OR statement_end_offset = -1
OR statement_end_offset IS NULL THEN LEN(text)
ELSE statement_end_offset/2 END -
CASE WHEN statement_start_offset = 0
OR statement_start_offset IS NULL
THEN 1
ELSE statement_start_offset/2 END + 1
) AS [Statement]
,OBJECT_SCHEMA_NAME(st.objectid,dbid) AS [Schema Name]
,OBJECT_NAME(st.objectid,dbid) AS [Object Name]
,case when @ORDERBY = 'ACPU' then qs.total_worker_time / qs.execution_count
when @ORDERBY = 'TCPU' then qs.total_worker_time
when @ORDERBY = 'AE' then qs.total_elapsed_time / qs.execution_count
when @ORDERBY = 'TE' then total_elapsed_time
when @ORDERBY = 'EC' then execution_count
when @ORDERBY = 'AIO' then (total_logical_reads + total_logical_writes + total_physical_reads) / execution_count
when @ORDERBY = 'TIO' then total_logical_reads + total_logical_writes + total_physical_reads
when @ORDERBY = 'ALR' then total_logical_reads / execution_count
when @ORDERBY = 'TLR' then total_logical_reads
when @ORDERBY = 'ALW' then total_logical_writes / execution_count
when @ORDERBY = 'TLW' then total_logical_writes
when @ORDERBY = 'APR' then total_physical_reads / execution_count
when @ORDERBY = 'TPR' then total_physical_reads
-- when @ORDERBY = 'LET' then last_execution_time
end AS [Sorted Column]
,qs.last_execution_time AS [Last Execution Time]
,objtype AS [Cached Plan objtype]
,qs.execution_count AS [Execution Count]
,(qs.total_logical_reads + qs.total_logical_writes + qs.total_physical_reads )/qs.execution_count AS [Average IOs]
,qs.total_logical_reads + qs.total_logical_writes + qs.total_physical_reads AS [Total IOs]
,qs.total_logical_reads/qs.execution_count AS [Avg Logical Reads]
,qs.total_logical_reads AS [Total Logical Reads]
,qs.total_logical_writes/qs.execution_count AS [Avg Logical Writes]
,qs.total_logical_writes AS [Total Logical Writes]
,qs.total_physical_reads/qs.execution_count AS [Avg Physical Reads]
,qs.total_physical_reads AS [Total Physical Reads]
,qs.total_worker_time / qs.execution_count AS [Avg CPU]
,qs.total_worker_time AS [Total CPU]
,qs.total_elapsed_time / qs.execution_count AS [Avg Elapsed Time]
,qs.total_elapsed_time AS [Total Elasped Time]

FROM sys.dm_exec_query_stats qs join
sys.dm_exec_cached_plans cp ON qs.plan_handle = cp.plan_handle cross apply
sys.dm_exec_sql_text(qs.plan_handle) st outer apply
sys.dm_exec_plan_attributes(qs.plan_handle) pa left join
@IgnoreDB idb on DB_NAME(st.dbid) = idb.Database_Name left join
@IgnoreDB idb1 on DB_NAME(CAST(pa.value AS INT)) = idb1.Database_Name

WHERE attribute = 'dbid' AND
CASE when @DBNAME = '' THEN '' ELSE COALESCE(DB_NAME(st.dbid),DB_NAME(CAST(pa.value AS INT)) + '*', 'Resource') END IN (RTRIM(@DBNAME),RTRIM(@DBNAME) + '*')

-- AND cast(qs.last_execution_time as datetime) >= isnull(@FromDateTime, cast('01/01/2001 00:00:00' as datetime))
AND cast(qs.last_execution_time as datetime) between isnull(@FromDateTime, cast('01/01/2001 00:00:00' as datetime)) and isnull(@ToDateTime, GETDATE())
and ISDATE(qs.last_execution_time) = 1
and idb.ID is null
and idb1.ID is null

ORDER BY CASE WHEN @ORDERBY = 'ACPU' THEN total_worker_time / execution_count
WHEN @ORDERBY = 'TCPU' THEN total_worker_time
WHEN @ORDERBY = 'AE' THEN total_elapsed_time / execution_count
WHEN @ORDERBY = 'TE' THEN total_elapsed_time
WHEN @ORDERBY = 'EC' THEN execution_count
WHEN @ORDERBY = 'AIO' THEN (total_logical_reads + total_logical_writes + total_physical_reads) / execution_count
WHEN @ORDERBY = 'TIO' THEN total_logical_reads + total_logical_writes + total_physical_reads
WHEN @ORDERBY = 'ALR' THEN total_logical_reads / execution_count
WHEN @ORDERBY = 'TLR' THEN total_logical_reads
WHEN @ORDERBY = 'ALW' THEN total_logical_writes / execution_count
WHEN @ORDERBY = 'TLW' THEN total_logical_writes
WHEN @ORDERBY = 'APR' THEN total_physical_reads / execution_count
WHEN @ORDERBY = 'TPR' THEN total_physical_reads
-- WHEN @ORDERBY = 'LET' THEN cast(last_execution_time as datetime)
END DESC
, cast(last_execution_time as datetime) desc

Kurt


Kurt W. Zimmerman
SR DBA
Lefrak Organization
New York, NY

http://www.linkedin.com/in/kurtwzimmerman
Post #1521298
Posted Thursday, December 26, 2013 1:56 PM
SSC Rookie

SSC RookieSSC RookieSSC RookieSSC RookieSSC RookieSSC RookieSSC RookieSSC Rookie

Group: General Forum Members
Last Login: Monday, April 28, 2014 10:18 AM
Points: 39, Visits: 91
I would say Profiler is still the best, as it gives you a lot of flexibility in analyzing the collected trace data (doing such analysis via T-SQL on the trace data saved into table (via trace files first) is better than just using Profiler GUI)).

As far as taking a look at your most often executed procedures/sql statements that take the longest duration as well,
I find the following DMV based query very useful (as it contains Query Plans in XML format that you can click on and see plans):

SELECT TOP 50
CAST(qs.total_elapsed_time / 1000000.0 AS DECIMAL(28, 2))
AS [Total Duration (s)]
, qs.execution_count
, SUBSTRING (qt.text, (qs.statement_start_offset/2) + 1,
((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) + 1)) [indiv/query]

, qt.text AS [Parent Query]
, DB_NAME(qt.dbid) AS DatabaseName
, 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
ORDER BY total_elapsed_time DESC



Voldemar
likes to play chess
Post #1526045
« Prev Topic | Next Topic »

Add to briefcase

Permissions Expand / Collapse