Thursday, 1 September 2022

SQL Server : Capture expensive queries using Server side trace


You can follow the below steps to capture the expensive queries by creating the trace and also from SQL cache plan DMV's :

1. Create Server Side trace: by defining a trace, its the events and columns to captured, and add the filter condition.

You can use the below Script to create the trace:

-- Create Server-side trace
-- Create a Queue
DECLARE @rc int
DECLARE @TraceID int
DECLARE @maxfilesize bigint
set @maxfilesize = 2048

-- Please replace the text InsertFileNameHere, with an appropriate
-- filename prefixed by a path, e.g., c:\MyFolder\MyTrace. The .trc extension
-- will be appended to the filename automatically. If you are writing from
-- remote server to local drive, please use UNC path and make sure server has
-- write access to your network share

DECLARE @MyFileName nvarchar(256)
SELECT @MyFileName='D:\RDSDBDATA\Log\RDSSQLTrace_' + CONVERT(nvarchar(10),GetDate(),121) + '_' + REPLACE(CONVERT(nvarchar(10),GetDate(),108),':','-')


exec @rc = sp_trace_create @TraceID output, 0, @MyFileName, @maxfilesize, NULL
if (@rc != 0) goto error

-- Client side File and Table cannot be scripted
-- Set the events
DECLARE @on bit
set @on = 1 --sp_trace_setevent @traceid ,@eventid ,@columnid,@on

-- Capturing the RPC:Completed event

EXEC sp_trace_setevent @TraceID, 10, 16, @on
EXEC sp_trace_setevent @TraceID, 10, 1, @on
EXEC sp_trace_setevent @TraceID, 10, 17, @on
EXEC sp_trace_setevent @TraceID, 10, 14, @on
EXEC sp_trace_setevent @TraceID, 10, 18, @on
EXEC sp_trace_setevent @TraceID, 10, 12, @on
EXEC sp_trace_setevent @TraceID, 10, 13, @on
EXEC sp_trace_setevent @TraceID, 10, 8, @on
EXEC sp_trace_setevent @TraceID, 10, 10, @on
EXEC sp_trace_setevent @TraceID, 10, 11, @on
EXEC sp_trace_setevent @TraceID, 10, 35, @on

--Capturing the SQL:BatchCompleted event

EXEC sp_trace_setevent @TraceID, 12, 16, @on
EXEC sp_trace_setevent @TraceID, 12, 1, @on
EXEC sp_trace_setevent @TraceID, 12, 17, @on
EXEC sp_trace_setevent @TraceID, 12, 14, @on
EXEC sp_trace_setevent @TraceID, 12, 18, @on
EXEC sp_trace_setevent @TraceID, 12, 12, @on
EXEC sp_trace_setevent @TraceID, 12, 13, @on
EXEC sp_trace_setevent @TraceID, 12, 8, @on
EXEC sp_trace_setevent @TraceID, 12, 10, @on
EXEC sp_trace_setevent @TraceID, 12, 11, @on
EXEC sp_trace_setevent @TraceID, 12, 35, @on

-- Set the Filters
EXEC sp_trace_setfilter @TraceID,11,0,7,N'%NT AUTHORITY%' --SQL login
EXEC sp_trace_setfilter @TraceID, 10, 0, 7, N'RdsAdminService'

-- Set the trace status to start
EXEC sp_trace_setstatus @TraceID, 1

-- display trace id and file name, Note these details for future references
SELECT @TraceID,@MyFileName

goto finish

error:
select ErrorCode=@rc

finish:
go

2. Start the Trace using below command :

-- To Start the trace (Please update the trace_id as you may recived at the time of creation)
Exec sp_trace_setstatus @traceid = 2 , @on = 1 -- start

3. Start the application test run

4. Once test run is completed, Stop the trace using below command:

-- To Stop the trace (Please update the trace_id as you may recived at the time of creation)

Exec sp_trace_setstatus @traceid = 2 , @on = 0 -- stop
-- To Delete the trace, once application test is completed.
--Exec sp_trace_setstatus @traceid = 2 , @on = 0 -- Delete definition from server

5. Insert the trace output in dummy table, this helps to get the data in easy to read format.

USE [DB_name]
GO
SELECT * INTO RDSSQLTrace_20210722_1215 FROM ::fn_trace_gettable ('D:\RDSDBDATA\Log\RDSSQLTrace_2021-07-22_12-15-19.trc', default)
6. Capture the output of below commands and update the output in the attached excel sheet template in the TraceData sheet (File Name : Capture_ExpensiveQueries_Template.xlsx)

--To collect queries based on max Duration 
SELECT TOP 10 StartTime,EndTime,Reads, Writes, 
Duration/1000000 DurationSec,CPU, TextData,RowCounts,sqlHandle,[DatabaseName],
SPID,LoginName,EventClass FROM [gptst].[dbo].[RDSSQLTrace_20210722] 
ORDER BY Duration DESC

--To collect queries based on max CPU utilization
SELECT TOP 10 StartTime,EndTime,Reads, Writes, 
Duration/1000000 DurationMs,CPU, TextData,RowCounts,sqlHandle,[DatabaseName],
SPID,LoginName,EventClass FROM [gptst].[dbo].[RDSSQLTrace_20210722] 
ORDER BY CPU DESC

--To collect queries based on max Reads,Writes
SELECT TOP 10 StartTime,EndTime,Reads, Writes, 
Duration/1000000 DurationSec,CPU, TextData,RowCounts,sqlHandle,[DatabaseName],
SPID,LoginName,EventClass FROM [gptst].[dbo].[RDSSQLTrace_20210722]
ORDER BY Reads,Writes DESC
7. Also, capture the output of the below scripts as well and update the same in the attached excel sheet template in the CacheData sheet (File Name : Capture_ExpensiveQueries_Template.xlsx)
--TOP 10 Queries by Duration (Avg Sec) from system dmv's		
			
SELECT TOP 10 DB_NAME(qt.dbid) AS DBName,
o.name AS ObjectName,
qs.total_worker_time / 1000000 / qs.execution_count As Avg_CPU_time_sec,
qs.total_worker_time / 1000000 as Total_CPU_time_sec,
qs.total_elapsed_time / qs.execution_count / 1000000.0 AS Average_Seconds,
qs.total_elapsed_time / 1000000.0 AS Total_Seconds,
'',
qs.execution_count as Count,
qs.last_execution_time as Time,
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
--,qt.text [MainQuenry]
--,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) AS qp
LEFT OUTER JOIN sys.objects o ON qt.objectid = o.object_id
where qs.execution_count>5 and DB_NAME(qt.dbid) not in ( 'master','msdb','model')
--and DB_NAME(qt.dbid) is not null
ORDER BY average_seconds DESC
--TOP 10 Queries by CPU (Avg CPU time) from system dmv's
SELECT TOP 10 DB_NAME(qt.dbid) as DBName,
	qs.total_worker_time / 1000000 / qs.execution_count AS Avg_CPU_time_sec,
	qs.total_worker_time / 1000000 As Total_CPU_time_sec,
	qs.total_elapsed_time / 1000000 / qs.execution_count As Average_Seconds,
	qs.total_elapsed_time / 1000000 As Total_Seconds,
    (total_logical_reads + total_logical_writes) / qs.execution_count as Average_IO,
	total_logical_reads + total_logical_writes as Total_IO,	
    qs.execution_count as Count,
    qs.last_execution_time as Time,
	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
	) as Query
   ,qt.text
	,qp.query_plan
FROM sys.dm_exec_query_stats AS qs
CROSS APPLY sys.dm_exec_sql_text(qs.[sql_handle]) AS qt
CROSS APPLY sys.dm_exec_query_plan(qs.plan_handle) AS qp
LEFT OUTER JOIN sys.objects o ON qt.objectid = o.object_id
where 
DB_NAME(qt.dbid) not in ( 'master','msdb','model')
ORDER BY Avg_CPU_time_sec DESC

-- Top 10 query by IO (Avg IO) from system dmv's

SELECT TOP 10 DB_NAME(qt.dbid) AS DBName,
o.name AS ObjectName,
qs.total_elapsed_time / 1000000 / qs.execution_count As Average_Seconds,
qs.total_elapsed_time / 1000000 As Total_Seconds,
(total_logical_reads + total_logical_writes ) / qs.execution_count AS Average_IO,
(total_logical_reads + total_logical_writes ) AS Total_IO,
'',
qs.execution_count AS Count,
last_execution_time As Time,
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
--,qt.text
--,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) AS qp
LEFT OUTER JOIN sys.objects o ON qt.objectid = o.object_id
where last_execution_time > getdate()-1 
and DB_NAME(qt.dbid) not in ( 'master','msdb','model')
--and DB_NAME(qt.dbid) is not null
and qs.execution_count > 5 
ORDER BY average_IO DESC
Note : Please do capture the output after each run if running the test multiple times, to compare the result set.

Monday, 22 August 2022

RDS SQL Server : Unable to restore and getting an error message : "There is not enough space on the disk to perform restore database operation."


If you are getting an error message as "There is not enough space on the disk to perform restore database operation."

-- This issue appears when rds restore starts, RDS makes an estimate about how much disk space will be required by the database that is going to be restored. If that estimate exceeds the amount of free space left on the disk, you will see this error.

Kindly note that as part of the restore process is trying to look for the data and log file size as was configured on the source and if the amount of space is not available on disk upfront its failing the restore process in the first place while trying perform the restore and also the SQL server restore process will not initiate the Storage Autoscaling.

For example: lets say the source database (On-prem\EC2\RDS sql server instance) is configured with 30 GB of data file and 30 GB of log file sizes and the used space inside the 30 GB data file is only 10 GB and used space inside the 30 GB log file is only 10 GB.The backup size of the database in this case would be only 20 GB(with compression this backup file size can further be reduced) out of actual 60 GB configured on the source database.During the restore of this 20 GB backup file on the RDS SQL server instance the process looks for the 60 GB of space on the underlying storage per the source data and log file configurations.In this case if the Target RDS database instance if it has 50 GB of underlying storage so restore process would fail as it requires 60 GB of storage space to proceed with the restore and it fails with the space issue.

Now I would suggest you to please check the actual database size on the source database using below script:
--Useful script to know the current size of database files and the free space.
USE [DBNAME] -- update your db name
GO
SELECT DB_NAME() AS DbName,
name AS FileName,
size/128.0 AS CurrentSizeMB,
size/128.0 - CAST(FILEPROPERTY(name, 'SpaceUsed') AS INT)/128.0 AS FreeSpaceMB
FROM sys.database_files;

If log is using the most of the storage space then you can try to shrink the log file and then again the backup and try to restore again.