Thursday, November 8, 2007

SQL Server 2000 Server Side Performance Tracing

Here is a method, i usually use to collect sqls running on a sql server 2000 with their CPU, duration, read and write info and then calculate cumulative executions, HW usage and time spent statistics of these sqls.

Lets assume there is a database named DBA used for intermediate tables and a path for trace file "S:\MSSQL\trace\batchcompleted".

First of all create trace table on DBA:

CREATE TABLE [dbo].[TRACELOG] (
[EventClass] [int] NULL ,
[TextData] [ntext] COLLATE SQL_Latin1_General_CP1254_CS_AS NULL ,
[NTUserName] [nvarchar] (128) COLLATE SQL_Latin1_General_CP1254_CS_AS NULL ,
[ClientProcessID] [int] NULL ,
[ApplicationName] [nvarchar] (128) COLLATE SQL_Latin1_General_CP1254_CS_AS NULL ,
[LoginName] [nvarchar] (128) COLLATE SQL_Latin1_General_CP1254_CS_AS NULL ,
[SPID] [int] NULL ,
[Duration] [bigint] NULL ,
[StartTime] [datetime] NULL ,
[Reads] [bigint] NULL ,
[Writes] [bigint] NULL ,
[CPU] [int] NULL
) ON [PRIMARY] TEXTIMAGE_ON [PRIMARY]
GO

Lets create a job with 3 steps.

1. On failure action "Go to Next Step" should be set for this step:
declare @trace_id int
select @trace_id = traceid FROM :: fn_trace_getinfo(default) where value='S:\MSSQL\trace\batchcompleted'
exec sp_trace_setstatus @trace_id,0
exec sp_trace_setstatus @trace_id,2

2. On failure action "Go to Next Step" should be set for this step:
insert into DBA.dbo.TRACELOG SELECT EventClass,TextData,NTUserName,ClientProcessID,ApplicationName,LoginName,SPID,Duration,StartTime,Reads,Writes,CPU FROM ::fn_trace_gettable('S:\MSSQL\trace\batchcompleted.trc', default)
exec master.dbo.xp_cmdshell 'del /Q S:\MSSQL\trace\batchcompleted.trc'

3.
declare @rc int
declare @TraceID int
declare @maxfilesize bigint
set @maxfilesize = 1000
exec @rc = sp_trace_create @TraceID output, 0, N'S:\MSSQL\trace\batchcompleted', @maxfilesize, NULL
if (@rc != 0) goto error
-- Set the events
declare @on bit
set @on = 1
exec sp_trace_setevent @TraceID, 10, 1, @on
exec sp_trace_setevent @TraceID, 10, 6, @on
exec sp_trace_setevent @TraceID, 10, 9, @on
exec sp_trace_setevent @TraceID, 10, 10, @on
exec sp_trace_setevent @TraceID, 10, 11, @on
exec sp_trace_setevent @TraceID, 10, 12, @on
exec sp_trace_setevent @TraceID, 10, 13, @on
exec sp_trace_setevent @TraceID, 10, 14, @on
exec sp_trace_setevent @TraceID, 10, 16, @on
exec sp_trace_setevent @TraceID, 10, 17, @on
exec sp_trace_setevent @TraceID, 10, 18, @on
exec sp_trace_setevent @TraceID, 12, 1, @on
exec sp_trace_setevent @TraceID, 12, 6, @on
exec sp_trace_setevent @TraceID, 12, 9, @on
exec sp_trace_setevent @TraceID, 12, 10, @on
exec sp_trace_setevent @TraceID, 12, 11, @on
exec sp_trace_setevent @TraceID, 12, 12, @on
exec sp_trace_setevent @TraceID, 12, 13, @on
exec sp_trace_setevent @TraceID, 12, 14, @on
exec sp_trace_setevent @TraceID, 12, 16, @on
exec sp_trace_setevent @TraceID, 12, 17, @on
exec sp_trace_setevent @TraceID, 12, 18, @on
-- Set the Filters
declare @intfilter int
declare @bigintfilter bigint
exec sp_trace_setfilter @TraceID, 10, 0, 7, N'SQL Profiler'
set @bigintfilter = 1
exec sp_trace_setfilter @TraceID, 13, 0, 4, @bigintfilter
-- Set the trace status to start
exec sp_trace_setstatus @TraceID, 1
-- display trace id for future references
select TraceID=@TraceID
goto finish
error:
select ErrorCode=@rc
finish:
go

Here is the sql code of my job:

BEGIN TRANSACTION
DECLARE @JobID BINARY(16)
DECLARE @ReturnCode INT
SELECT @ReturnCode = 0
IF (SELECT COUNT(*) FROM msdb.dbo.syscategories WHERE name = N'[Uncategorized (Local)]') <>
EXECUTE msdb.dbo.sp_add_category @name = N'[Uncategorized (Local)]'

-- Delete the job with the same name (if it exists)
SELECT @JobID = job_id
FROM msdb.dbo.sysjobs
WHERE (name = N'PERFSTAT_COLLECT')
IF (@JobID IS NOT NULL)
BEGIN
-- Check if the job is a multi-server job
IF (EXISTS (SELECT *
FROM msdb.dbo.sysjobservers
WHERE (job_id = @JobID) AND (server_id <> 0)))
BEGIN
-- There is, so abort the script
RAISERROR (N'Unable to import job ''PERFSTAT_COLLECT'' since there is already a multi-server job with this name.', 16, 1)
GOTO QuitWithRollback
END
ELSE
-- Delete the [local] job
EXECUTE msdb.dbo.sp_delete_job @job_name = N'PERFSTAT_COLLECT'
SELECT @JobID = NULL
END

BEGIN

-- Add the job
EXECUTE @ReturnCode = msdb.dbo.sp_add_job @job_id = @JobID OUTPUT , @job_name = N'PERFSTAT_COLLECT', @owner_login_name = N'sa', @description = N'No description available.', @category_name = N'[Uncategorized (Local)]', @enabled = 1, @notify_level_email = 0, @notify_level_page = 0, @notify_level_netsend = 0, @notify_level_eventlog = 2, @delete_level= 0
IF (@@ERROR <> 0 OR @ReturnCode <> 0) GOTO QuitWithRollback

-- Add the job steps
EXECUTE @ReturnCode = msdb.dbo.sp_add_jobstep @job_id = @JobID, @step_id = 1, @step_name = N'stop_trace', @command = N'declare @trace_id int
select @trace_id = traceid FROM :: fn_trace_getinfo(default) where value=''S:\MSSQL\trace\batchcompleted''
exec sp_trace_setstatus @trace_id,0
exec sp_trace_setstatus @trace_id,2
', @database_name = N'master', @server = N'', @database_user_name = N'', @subsystem = N'TSQL', @cmdexec_success_code = 0, @flags = 0, @retry_attempts = 0, @retry_interval = 1, @output_file_name = N'', @on_success_step_id = 0, @on_success_action = 3, @on_fail_step_id = 0, @on_fail_action = 3
IF (@@ERROR <> 0 OR @ReturnCode <> 0) GOTO QuitWithRollback
EXECUTE @ReturnCode = msdb.dbo.sp_add_jobstep @job_id = @JobID, @step_id = 2, @step_name = N'save_remove_trace', @command = N'insert into DBA.dbo.TRACELOG SELECT EventClass,TextData,NTUserName,ClientProcessID,ApplicationName,LoginName,SPID,Duration,StartTime,Reads,Writes,CPU FROM ::fn_trace_gettable(''S:\MSSQL\trace\batchcompleted.trc'', default)
exec master.dbo.xp_cmdshell ''del /Q S:\MSSQL\trace\batchcompleted.trc''
', @database_name = N'master', @server = N'', @database_user_name = N'', @subsystem = N'TSQL', @cmdexec_success_code = 0, @flags = 0, @retry_attempts = 0, @retry_interval = 1, @output_file_name = N'', @on_success_step_id = 0, @on_success_action = 3, @on_fail_step_id = 0, @on_fail_action = 3
IF (@@ERROR <> 0 OR @ReturnCode <> 0) GOTO QuitWithRollback
EXECUTE @ReturnCode = msdb.dbo.sp_add_jobstep @job_id = @JobID, @step_id = 3, @step_name = N'start_trace', @command = N'declare @rc int
declare @TraceID int
declare @maxfilesize bigint
set @maxfilesize = 1000
exec @rc = sp_trace_create @TraceID output, 0, N''S:\MSSQL\trace\batchcompleted'', @maxfilesize, NULL
if (@rc != 0) goto error
-- Set the events
declare @on bit
set @on = 1
exec sp_trace_setevent @TraceID, 10, 1, @on
exec sp_trace_setevent @TraceID, 10, 6, @on
exec sp_trace_setevent @TraceID, 10, 9, @on
exec sp_trace_setevent @TraceID, 10, 10, @on
exec sp_trace_setevent @TraceID, 10, 11, @on
exec sp_trace_setevent @TraceID, 10, 12, @on
exec sp_trace_setevent @TraceID, 10, 13, @on
exec sp_trace_setevent @TraceID, 10, 14, @on
exec sp_trace_setevent @TraceID, 10, 16, @on
exec sp_trace_setevent @TraceID, 10, 17, @on
exec sp_trace_setevent @TraceID, 10, 18, @on
exec sp_trace_setevent @TraceID, 12, 1, @on
exec sp_trace_setevent @TraceID, 12, 6, @on
exec sp_trace_setevent @TraceID, 12, 9, @on
exec sp_trace_setevent @TraceID, 12, 10, @on
exec sp_trace_setevent @TraceID, 12, 11, @on
exec sp_trace_setevent @TraceID, 12, 12, @on
exec sp_trace_setevent @TraceID, 12, 13, @on
exec sp_trace_setevent @TraceID, 12, 14, @on
exec sp_trace_setevent @TraceID, 12, 16, @on
exec sp_trace_setevent @TraceID, 12, 17, @on
exec sp_trace_setevent @TraceID, 12, 18, @on
-- Set the Filters
declare @intfilter int
declare @bigintfilter bigint
exec sp_trace_setfilter @TraceID, 10, 0, 7, N''SQL Profiler''
set @bigintfilter = 1
exec sp_trace_setfilter @TraceID, 13, 0, 4, @bigintfilter
-- Set the trace status to start
exec sp_trace_setstatus @TraceID, 1
-- display trace id for future references
select TraceID=@TraceID
goto finish
error:
select ErrorCode=@rc
finish:
go', @database_name = N'master', @server = N'', @database_user_name = N'', @subsystem = N'TSQL', @cmdexec_success_code = 0, @flags = 0, @retry_attempts = 0, @retry_interval = 1, @output_file_name = N'', @on_success_step_id = 0, @on_success_action = 1, @on_fail_step_id = 0, @on_fail_action = 2
IF (@@ERROR <> 0 OR @ReturnCode <> 0) GOTO QuitWithRollback
EXECUTE @ReturnCode = msdb.dbo.sp_update_job @job_id = @JobID, @start_step_id = 1

IF (@@ERROR <> 0 OR @ReturnCode <> 0) GOTO QuitWithRollback

-- Add the job schedules
EXECUTE @ReturnCode = msdb.dbo.sp_add_jobschedule @job_id = @JobID, @name = N'stat_sched', @enabled = 1, @freq_type = 4, @active_start_date = 20060717, @active_start_time = 0, @freq_interval = 1, @freq_subday_type = 4, @freq_subday_interval = 30, @freq_relative_interval = 0, @freq_recurrence_factor = 0, @active_end_date = 99991231, @active_end_time = 235959
IF (@@ERROR <> 0 OR @ReturnCode <> 0) GOTO QuitWithRollback

-- Add the Target Servers
EXECUTE @ReturnCode = msdb.dbo.sp_add_jobserver @job_id = @JobID, @server_name = N'(local)'
IF (@@ERROR <> 0 OR @ReturnCode <> 0) GOTO QuitWithRollback

END
COMMIT TRANSACTION
GOTO EndSave
QuitWithRollback:
IF (@@TRANCOUNT > 0) ROLLBACK TRANSACTION
EndSave:

Schedule the job as running every 30 minute whole day. After collecting trace data for a hour, run following to remove parameters in sql texts (in order to be able to group same sqls running with different parameters) and insert into another table.

select
case when substring(TextData,1,7) = 'declare'
Then substring(
cast(TextData as varchar(200)),
charindex('exec',cast(TextData as varchar(300))),200)
else
cast(TextData as varchar(200))
end TextData
,
Duration, StartTime, Reads, Writes, CPU into TBLRESULT from (
select * from dbo.TRACELOG
where StartTime between (getdate()- cast(cast(1 as float)/cast(24 as float) as float)) and getdate() and CPU > 100
)a --where TextData like '%coalesce%'
order by Duration desc

Then a sql like this can help you get cumulative data:

SELECT TOP 100 PERCENT CAST(TextData AS varchar(100)) AS TEXT, COUNT(*) AS EXECUTIONS,AVG(Duration) AVR_Duration, AVG(Reads) AS AVR_READ, SUM(Reads) AS SUM_READ,
SUM(Reads) * 100 /
(SELECT SUM(Reads)
FROM dbo.TBLRESULT) AS PER_READ, AVG(Writes) AS AVR_WRITE, SUM(Writes) AS SUM_WRITE, SUM(Writes) * 100 /
(SELECT SUM(Writes)
FROM dbo.TBLRESULT) AS PER_WRITE, AVG(CPU) AS AVR_CPU, SUM(CPU) AS SUM_CPU, SUM(CPU) * 100 /
(SELECT SUM(CPU)
FROM dbo.TBLRESULT) AS PER_CPU
FROM dbo.TBLRESULT WITH (nolock)
GROUP BY CAST(TextData AS varchar(100))
HAVING (COUNT(*) > 0)
ORDER BY SUM_CPU DESC

At the end, dont forget to stop server side trace. You can use code in first step of the job to stop it.