SSAS Cube Processing Performance Troubleshooting – A platform perspective

Analysing Index Usage

The first step I use in order to troubleshoot cube processing performance issues is index usage.

SELECT DB_NAME(S.database_id) AS [Database],
 OBJECT_NAME(S.[OBJECT_ID]) AS [Table],
 I.name AS [Index],
 user_seeks,
 user_scans,
 user_lookups,
 user_updates
FROM sys.dm_db_index_usage_stats AS s
 JOIN sys.indexes AS i
 ON i.object_id = s.object_id
 AND I.index_id = s.index_id
WHERE
 OBJECTPROPERTY(s.object_id,'IsUserTable') = 1
 AND s.database_id = DB_ID()

Look at any recently added indexes. Are the indexes being used? Seeks, or scans? Is there an index that has a large no. of user lookups?

Where there is an index that is not being used consider whether it is required. Having too many indexes on a table can have an adverse effect on performance. When rows are inserted, deleted or updated in a table the index needs to be maintained. Maintenance has an overhead. The above query has an output column called user_updates. This is the no. of times an index has been changed as a result of data changes within the table.

Find Missing Indexes

Use the following query to identify missing indexes.

SELECT TOP 25
 DB_NAME(dm_mid.database_id) AS DatabaseID,
 dm_migs.avg_user_impact*(dm_migs.user_seeks+dm_migs.user_scans) Avg_Estimated_Impact,
 OBJECT_NAME(dm_mid.OBJECT_ID,dm_mid.database_id) AS [TableName],
 'CREATE INDEX [IX_' + OBJECT_NAME(dm_mid.OBJECT_ID,dm_mid.database_id) + '_'
 + REPLACE(REPLACE(REPLACE(ISNULL(dm_mid.equality_columns,''),', ','_'),'[',''),']','') +
 CASE
 WHEN dm_mid.equality_columns IS NOT NULL AND dm_mid.inequality_columns IS NOT NULL THEN '_'
 ELSE ''
 END
 + REPLACE(REPLACE(REPLACE(ISNULL(dm_mid.inequality_columns,''),', ','_'),'[',''),']','')
 + ']'
 + ' ON ' + dm_mid.statement
 + ' (' + ISNULL (dm_mid.equality_columns,'')
 + CASE WHEN dm_mid.equality_columns IS NOT NULL AND dm_mid.inequality_columns IS NOT NULL THEN ',' ELSE
 '' END
 + ISNULL (dm_mid.inequality_columns, '')
 + ')'
 + ISNULL (' INCLUDE (' + dm_mid.included_columns + ')', '') AS Create_Statement
FROM
 sys.dm_db_missing_index_groups dm_mig
 INNER JOIN sys.dm_db_missing_index_group_stats dm_migs ON dm_migs.group_handle = dm_mig.index_group_handle
 INNER JOIN sys.dm_db_missing_index_details dm_mid ON dm_mig.index_handle = dm_mid.index_handle
WHERE
 dm_mid.database_ID = DB_ID()
ORDER BY
 Avg_Estimated_Impact DESC

Be aware that the DMV’s will highlight several indexes for the same table. Be sure not to add multiple indexes that may be duplicates or subsets of other indexes. The create index statement is provided in the output.

Finding Query Plans in the Cache

The following query will help you identify long running queries in the plan cache:

SELECT TOP 20
 DB_NAME(qt.dbid) AS [Database],
 [Query] = 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),
 [TotalRunTime (s)] = CAST(qs.total_elapsed_time/ 1000000.0 AS DECIMAL(28,2)),
 [TotalTimeWaiting (s)] = CAST((qs.total_elapsed_time - qs.total_worker_time) / 1000000.0 AS DECIMAL(28,2)),
 [%TimeRunning] = CAST(qs.total_worker_time * 100.0 / qs.total_elapsed_time AS DECIMAL(28,2)),
 [%TimeWaiting] = CAST((qs.total_elapsed_time - qs.total_worker_time)* 100.0 / qs.total_elapsed_time AS DECIMAL(28, 2)),
 [ExecutionCount] = qs.execution_count,
 [AverageRunTime] = CAST(qs.total_elapsed_time / 1000000.0 / qs.execution_count AS DECIMAL(28, 2)),
 [AverageTimeWaiting (s)] = CAST((qs.total_elapsed_time - qs.total_worker_time) / 1000000.0 / qs.execution_count AS DECIMAL(28, 2)),
 [QueryPlan] = 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
WHERE
 qs.total_elapsed_time > 0
 AND DB_NAME(qt.dbid) IS NOT NULL
 AND qt.text LIKE '%<INSERT SEARCH STRING HERE>%'
ORDER BY
 [AverageRunTime] DESC

Using this query, currently ordered by average run time, will allow you to identify queries that take a long time to run. The queries with the highest average run time are likely to be the SSAS cube partition processing queries. The query above will allow you to look at the query plans associated with the query. Look for expensive scans and key lookups.

Alter the where clause of the above query if you are looking for queries that use specific views or tables.

Add indexes to support long running queries.

Eliminating Key Lookups

keylookup

Eliminate key lookups by altering existing indexes or add new covering indexes.

To identify columns that need adding to existing indexes look at the output columns associated with the keylookup plan operator. A screenshot of this is shown above. Keylookups are an expensive operation that needs to be performed for every row in a result set. By adding these keys to the existing index as included columns SQL Server can read the data it needs straight from the index pages.

Advertisements

Finding Poorly Performing Stored Procedures

Hi,

Following on from my script that looks at poorly performing queries, here’s one that helps to find procedures that may be performing poorly. It makes use of sys.dm_exec_procedure_stats and produces a result set that shows the following:

  • [Object]
  • [SQLText]
  • [QueryPlan]
  • [execution_count]
  • [Avg. CPU Time(s)]
  • [Avg. Physical Reads]
  • [Avg. Logical Reads]
  • [Avg. Logical Writes]
  • [Avg. Elapsed Time(s)]
  • [Total CPU Time(s)]
  • [Last CPU Time(s)]
  • [Min CPU Time(s)]
  • [Max CPU Time(s)]
  • [Total Physical Reads]
  • [Last Physical Reads]
  • [Min Physical Reads]
  • [Max Physical Reads]
  • [Total Logical Reads]
  • [Last Logical Reads]
  • [Min Logical Reads]
  • [Max Logical Reads],
  • [Total Logical Writes]
  • [Last Logical Writes]
  • [Min Logical Writes]
  • [Max Logical Writes]
  • [Total Elapsed Time(s)]
  • [Last Elapsed Time(s)]
  • [Min Elapsed Time(s)]
  • [Max Elapsed Time(s)]
  • cached_time
  • last_execution_time

I hope you find it useful.


SET NOCOUNT ON;

/*****************************************************
 Setup a temporary table to fetch the data we need from
 sys.dm_exec_procedure_stats.
 ******************************************************/
 IF OBJECT_ID('tempdb..#temp') IS NOT NULL DROP TABLE #temp
 CREATE TABLE #temp
 (
 database_id INT,
 object_id INT,
 [SQLText] VARCHAR(MAX),
 [QueryPlan] XML,
 [execution_count] bigint,
 [Avg. CPU Time(s)] DECIMAL(28,2),
 [Avg. Physical Reads] bigint,
 [Avg. Logical Reads] bigint,
 [Avg. Logical Writes] bigint,
 [Avg. Elapsed Time(s)] DECIMAL(28,2),
 [Total CPU Time(s)] DECIMAL(28,2),
 [Last CPU Time(s)] DECIMAL(28,2),
 [Min CPU Time(s)] DECIMAL(28,2),
 [Max CPU Time(s)] DECIMAL(28,2),
 [Total Physical Reads] bigint,
 [Last Physical Reads] bigint,
 [Min Physical Reads] bigint,
 [Max Physical Reads] bigint,
 [Total Logical Reads] bigint,
 [Last Logical Reads] bigint,
 [Min Logical Reads] bigint,
 [Max Logical Reads] bigint,
 [Total Logical Writes] bigint,
 [Last Logical Writes] bigint,
 [Min Logical Writes] bigint,
 [Max Logical Writes] bigint,
 [Total Elapsed Time(s)] DECIMAL(28,2),
 [Last Elapsed Time(s)] DECIMAL(28,2),
 [Min Elapsed Time(s)] DECIMAL(28,2),
 [Max Elapsed Time(s)] DECIMAL(28,2),
 cached_time DATETIME,
 last_execution_time DATETIME,
 [object] VARCHAR(MAX) NULL
 )

/*****************************************************
 Fetch the data we need from
 sys.dm_exec_procedure_stats.
 ******************************************************/
 insert into #temp
 select
 database_id,
 object_id,
 st.text,
 ep.query_plan,
 execution_count,

-- Averages
 CAST(total_worker_time * 1.0 / execution_count / 1000000.0 as DECIMAL(28,2)) AS [Avg. CPU Time(s)],
 total_physical_reads / execution_count AS [Avg Physical Reads],
 total_logical_reads / execution_count AS [Avg. Logical Reads],
 total_logical_writes / execution_count AS [Avg. Logical Writes],
 CAST(total_elapsed_time * 1.0 / execution_count / 1000000.0 as DECIMAL(28,2)) AS [Avg. Elapsed Time(s)],

-- CPU Details
 CAST(total_worker_time / 1000000.0 as DECIMAL(28,2)) AS [Total CPU Time(s)],
 CAST(last_worker_time / 1000000.0 as DECIMAL(28,2)) AS [Last CPU Time(s)],
 CAST(min_worker_time / 1000000.0 as DECIMAL(28,2)) AS [Min CPU Time(s)],
 CAST(max_worker_time / 1000000.0 as DECIMAL(28,2)) AS [Max CPU Time(s)],

-- Physical Reads
 total_physical_reads AS [Total Physical Reads],
 last_physical_reads AS [Last Physical Reads],
 min_physical_reads AS [Min Physical Reads],
 max_physical_reads AS [Max Physical Reads],

-- Logical Reads
 total_logical_reads AS [Total Logical Reads],
 last_logical_reads AS [Last Logical Reads],
 min_logical_reads AS [Min Logical Reads],
 max_logical_reads AS [Max Logical Reads],

-- Logical Writes
 total_logical_writes AS [Total Logical Writes],
 last_logical_writes AS [Last Logical Writes],
 min_logical_writes AS [Min Logical Writes],
 max_logical_writes AS [Max Logical Writes],

-- Elapsed Time
 CAST(total_elapsed_time / 1000000.0 as DECIMAL(28,2)) AS [Total Elapsed Time(s)],
 CAST(last_elapsed_time / 1000000.0 as DECIMAL(28,2)) AS [Last Elapsed Time(s)],
 CAST(min_elapsed_time / 1000000.0 as DECIMAL(28,2)) AS [Min Elapsed Time(s)],
 CAST(max_elapsed_time / 1000000.0 as DECIMAL(28,2)) AS [Max Elapsed Time(s)],

cached_time,
 last_execution_time,
 null
 from
 sys.dm_exec_procedure_stats
 CROSS APPLY sys.dm_exec_sql_text(sql_handle) st
 CROSS APPLY sys.dm_exec_query_plan(plan_handle) ep
 where
 database_id <> 32767

/*****************************************************
 This section of code is all about getting the object
 name from the dbid and the object id.
 ******************************************************/

-- Declare a Cursor
 DECLARE FetchObjectName CURSOR FOR
 SELECT
 object_id, database_id
 FROM
 #temp

-- Open the cursor
 OPEN FetchObjectName

-- Declare some vars to hold the data to pass into the cursor
 DECLARE @var1 INT,
 @var2 INT
 DECLARE @sql VARCHAR(MAX)
 DECLARE @object VARCHAR(MAX)

-- Create a temporary table to hold the result of the dynamic SQL
 IF OBJECT_ID('tempdb..#object') IS NOT NULL DROP TABLE #object
 CREATE TABLE #object
 (
 objectname VARCHAR(MAX)
 )

-- Loop through the 20 records from above and fetch the object names
 FETCH NEXT FROM FetchObjectName INTO @var1, @var2
 WHILE ( @@FETCH_STATUS <> -1 )
 BEGIN
 IF ( @@FETCH_STATUS <> -2 )

-- Set the SQL we need to execute
 SET @sql = 'USE [' + DB_NAME(@var2) + '];
 SELECT OBJECT_SCHEMA_NAME(' + CONVERT(VARCHAR(MAX),@var1) + ',' + CONVERT(VARCHAR(MAX),@var2) + ') + ''.'' + ' + 'OBJECT_NAME(' + CONVERT(VARCHAR(MAX),@var1) + ');'

-- Make sure the table is empty!
 TRUNCATE TABLE #object

-- Fetch the name of the object
 INSERT INTO #object
 EXEC(@sql)

-- Set the object name to the local var.
 SELECT @object = objectname FROM #object

-- Update the original results
 UPDATE #temp
 SET
 [Object] = RTRIM(LTRIM(@object))
 WHERE
 object_id = @var1
 and database_id = @var2

-- Go around the loop....
 FETCH NEXT FROM FetchObjectName INTO @var1, @var2
 END
 CLOSE FetchObjectName
 DEALLOCATE FetchObjectName
 /*****************************************************
 Output the final restults....
 ******************************************************/
 SELECT TOP 50
 db_name(database_id) + '.' + [Object] AS [Object],
 [SQLText],
 [QueryPlan],
 [execution_count],
 [Avg. CPU Time(s)],
 [Avg. Physical Reads],
 [Avg. Logical Reads],
 [Avg. Logical Writes],
 [Avg. Elapsed Time(s)],
 [Total CPU Time(s)],
 [Last CPU Time(s)],
 [Min CPU Time(s)],
 [Max CPU Time(s)],
 [Total Physical Reads],
 [Last Physical Reads],
 [Min Physical Reads],
 [Max Physical Reads],
 [Total Logical Reads],
 [Last Logical Reads],
 [Min Logical Reads],
 [Max Logical Reads],
 [Total Logical Writes],
 [Last Logical Writes],
 [Min Logical Writes],
 [Max Logical Writes],
 [Total Elapsed Time(s)],
 [Last Elapsed Time(s)],
 [Min Elapsed Time(s)],
 [Max Elapsed Time(s)],
 cached_time,
 last_execution_time
 FROM
 #temp
 ORDER BY
 [Avg. Logical Reads] DESC

Finding Queries to Tune

Just a quick post because I’ve written a script I’m quite proud of this afternoon to help find queries that need tuning.

It Fetches the following information using sys.dm_exec_query_stats:

  • Object/Database
  • IndividualQuery
  • TotalRunTime (s)
  • TotalTimeWaiting (s)
  • %TimeRunning
  • %TimeWaiting
  • ExecutionCount
  • AverageRunTime
  • AverageTimeWaiting (s)
  • QueryPlan

FindingQueriesToTune

Hope someone finds it useful.

 /*****************************************************
 Setup a temporary table to fetch the data we need from
 sys.dm_exec_query_stats.
 ******************************************************/
 IF OBJECT_ID('tempdb..#temp') IS NOT NULL DROP TABLE #temp
 CREATE TABLE #temp
 (
 objectid INT,
 dbid INT,
 [Object] VARCHAR(8000),
 [IndividualQuery] NVARCHAR(MAX),
 [TotalRunTime (s)] DECIMAL(28,2),
 [TotalTimeWaiting (s)] DECIMAL(28,2),
 [%TimeRunning] DECIMAL(28,2),
 [%TimeWaiting] DECIMAL(28,2),
 [ExecutionCount] INT,
 [AverageRunTime] DECIMAL(28,2),
 [AverageTimeWaiting (s)] DECIMAL(28,2),
 [DatabaseName] NVARCHAR(MAX),
 [QueryPlan] XML
 )
 /*****************************************************
 Populate the temporary table with the data we need
 from sys.dm_exec_query_stats.
 ******************************************************/
 INSERT INTO #temp
 SELECT TOP 20
 qt.objectid,
 qt.dbid,
 [Object] = '',
 [IndividualQuery] = 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),
 [TotalRunTime (s)] = CAST(qs.total_elapsed_time/ 1000000.0 AS DECIMAL(28,2)),
 [TotalTimeWaiting (s)] = CAST((qs.total_elapsed_time - qs.total_worker_time) / 1000000.0 AS DECIMAL(28,2)),
 [%TimeRunning] = CAST(qs.total_worker_time * 100.0 / qs.total_elapsed_time AS DECIMAL(28,2)),
 [%TimeWaiting] = CAST((qs.total_elapsed_time - qs.total_worker_time)* 100.0 / qs.total_elapsed_time AS DECIMAL(28, 2)),
 [ExecutionCount] = qs.execution_count,
 [AverageRunTime] = CAST(qs.total_elapsed_time / 1000000.0 / qs.execution_count AS DECIMAL(28, 2)),
 [AverageTimeWaiting (s)] = CAST((qs.total_elapsed_time - qs.total_worker_time) / 1000000.0 / qs.execution_count AS DECIMAL(28, 2)),
 [DatabaseName] = DB_NAME(qt.dbid),
 [QueryPlan] = 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
 WHERE
 qs.total_elapsed_time > 0
 AND DB_NAME(qt.dbid) IS NOT NULL
 ORDER BY
 [TotalTimeWaiting (s)] DESC
 /*****************************************************
 This section of code is all about getting the object
 name from the dbid and the object id.
 ******************************************************/

-- Declare a Cursor
 DECLARE FetchObjectName CURSOR FOR
 SELECT
 objectid, dbid
 FROM
 #temp

-- Open the cursor
 OPEN FetchObjectName

-- Declare some vars to hold the data to pass into the cursor
 DECLARE @var1 INT,
 @var2 INT
 DECLARE @sql VARCHAR(MAX)
 DECLARE @object VARCHAR(MAX)

-- Create a temporary table to hold the result of the dynamic SQL
 IF OBJECT_ID('tempdb..#object') IS NOT NULL DROP TABLE #object
 CREATE TABLE #object
 (
 objectname VARCHAR(MAX)
 )

-- Loop through the 20 records from above and fetch the object names
 FETCH NEXT FROM FetchObjectName INTO @var1, @var2
 WHILE ( @@FETCH_STATUS <> -1 )
 BEGIN
 IF ( @@FETCH_STATUS <> -2 )

-- Set the SQL we need to execute
 SET @sql = 'USE [' + DB_NAME(@var2) + '];
 SELECT OBJECT_SCHEMA_NAME(' + CONVERT(VARCHAR(MAX),@var1) + ',' + CONVERT(VARCHAR(MAX),@var2) + ') + ''.'' + ' + 'OBJECT_NAME(' + CONVERT(VARCHAR(MAX),@var1) + ');'

-- Make sure the table is empty!
 TRUNCATE TABLE #object

-- Fetch the name of the object
 INSERT INTO #object
 EXEC(@sql)

-- Set the object name to the local var.
 SELECT @object = objectname FROM #object

-- Update the original results
 UPDATE #temp
 SET
 [Object] = RTRIM(LTRIM(@object))
 WHERE
 objectid = @var1
 and dbid = @var2

-- Go around the loop....
 FETCH NEXT FROM FetchObjectName INTO @var1, @var2
 END
 CLOSE FetchObjectName
 DEALLOCATE FetchObjectName

SELECT
 [Object] = [DatabaseName] + '.' + [Object],
 [IndividualQuery],
 [TotalRunTime (s)],
 [TotalTimeWaiting (s)],
 [%TimeRunning],
 [%TimeWaiting],
 [ExecutionCount],
 [AverageRunTime],
 [AverageTimeWaiting (s)],
 [QueryPlan]
 FROM
 #temp
 ORDER BY
 [TotalTimeWaiting (s)] DESC