SQL Server – Server Side Traces

Introduction

One of our batch processes occasionally fails.

Annoying so, because there is no error messages.

But, we noticed it fails on a specific day.

We have a need to capture the SQL statements and corresponding errors, if any.

Here we try to use SQL Server Profiler and customize the generated code to Server Side Trace.

Code

From SQL Server Profiler Trace to Stored Procedure

Using SQL Server Profiler, we created a trace file.

Here are is quick rework to extend it a bit. The changes are very minimal.

And, there are …

  1. Flexibility
    • Targeted Folder
    • Targeted Login
  2. Terminate Running Traces?

Stored Procedure – dbo.sp_ServerSideTraceInitiate


/****************************************************/
/* Created by: SQL Server Profiler 2005             */
/* Date: 02/16/2016  05:47:49 PM         */
/****************************************************/
use master
go

if object_id('dbo.sp_ServerSideTraceInitiate') is null
begin
	
	exec('create procedure [dbo].[sp_ServerSideTraceInitiate] as select 1/0 as [shell] ')

end
go

alter procedure dbo.sp_ServerSideTraceInitiate
(
	  @tracefolder				sysname
	, @loginname				sysname = null
	, @terminateRunningTraces	bit = 0
	, @createTrace				bit = 1
	, @traceID					int	= null output	
	, @traceRC					int	= null output	
)
as
begin

	set XACT_ABORT ON;
	set nocount on;

	-- Create a Queue
	declare @rc int
	declare @traceIDNull int
	declare @maxfilesize bigint
	declare @on bit

	-- Set the Filters
	declare @intfilter int
	declare @bigintfilter bigint

	--declare @loginname sysname
	declare @tracefolderBackup sysname
	declare @tracefolderBackupTimestamp sysname
	declare @tracefile sysname
	declare @tracefileFullName sysname
	declare @folderAlreadyInUseByRunningTrace sysname
	declare @bCommit bit


	declare @OSCommandSyntaxCreateFolder varchar(600)
	declare @OSCommandSyntaxDeleteFile   varchar(600)
	declare @OSCommandSyntaxMoveFile     varchar(600)

	declare @logSyntaxTraceTerminate	 varchar(600)
	declare @logSyntaxTraceCreating		 varchar(600)
	declare @logSyntaxTraceFilterOnLogin varchar(600)
	declare @logSyntaxTraceStart		 varchar(600)	

	declare @OSCommandCreateFolder					varchar(600)
	declare @OSCommandDeleteFile					varchar(600)
	declare @OSCommandCreateFolderBackup			varchar(600)
	declare @OSCommandCreateFolderBackupTimestamp	varchar(600)
	declare @OSCommandMoveFile						varchar(600)

	declare @logTraceTerminate		varchar(600)
	declare @logTraceCreate			varchar(600)
	declare @logTraceFilterOnLogin	varchar(600)
	declare @logTraceStart			varchar(600)

	declare @dateCurrent datetime

	declare @CHAR_TAB varchar(30)

	declare @waitBetweenTraceTermination varchar(30)

	declare @traceIDRunning int
	declare @strTraceIDRunning varchar(30)
	declare @tracePathRunning sysname
	
	declare @traceActionRequested sysname

	declare @iNumberofRecordsAffected int

	declare @timestamp varchar(100)

	declare @strTraceID varchar(60)

	declare @TRACE_STATUS_REQUEST_STOP int
	declare @TRACE_STATUS_REQUEST_DISCARD int
	declare @TRACE_STATUS_REQUEST_START int

	declare @bFilterLogin bit

	set @traceIDNull = -1
	set @CHAR_TAB = char(9)

	set @TRACE_STATUS_REQUEST_STOP = 0
	set @TRACE_STATUS_REQUEST_DISCARD = 2
	set @TRACE_STATUS_REQUEST_START = 1

	set @on = 1

	set @bFilterLogin = 0
	set @waitBetweenTraceTermination = '00:00:05'

	--set @loginname=N'emmdatafeed'
	if (
			   (@loginname is null)
			or (ltrim(@loginname) = '')
		)
	begin

		set @loginname=N'everyone'
		set @bFilterLogin = 0

	end
	else
	begin

		set @bFilterLogin = 1

	end

	/*
		Set String Format Pattern
	*/
	set @OSCommandSyntaxCreateFolder ='If not exist "%s" mkdir "%s" '
	set @OSCommandSyntaxDeleteFile = 'If exist "%s*" del "%s*" '
	set @OSCommandSyntaxMoveFile = 'If exist "%s\*.trc" move "%s\*.trc" "%s\" '

	set @logSyntaxTraceTerminate
			 ='Terminate Trace ID %s running against %s '

	set @logSyntaxTraceCreating
			= 'Creating Trace. Targeting Folder %s ...'

	set @logSyntaxTraceFilterOnLogin
			= 'Setting Filter on Trace %s. Filtering for login %s ....'

	/*
		Initialize Variables
	*/
	set @maxfilesize = 100
	set @bCommit = 1
	set @dateCurrent = getdate()

	set @tracefile = @loginname 
	set @tracefolderBackup = @tracefolder + '\Backup\'
	set @tracefileFullName = @tracefolder + '\' + @tracefile

	set @timestamp =
				--Year
				+ datename(year, @dateCurrent)

				-- Month
				+ replicate('0', 2 - len(datepart(month, @dateCurrent)))
				+ rtrim(cast(datepart(month, @dateCurrent) as char(2)))

				-- Day
				+ replicate('0', 2 - len(datepart(day, @dateCurrent)))
				+ rtrim(cast(datepart(day, @dateCurrent) as char(2)))

				-- Hour
				+ replicate('0', 2 - len(datepart(hour, @dateCurrent)))
				+ rtrim(cast(datepart(hour, @dateCurrent) as char(2)))

				-- Minute
				+ replicate('0', 2 - len(datepart(minute, @dateCurrent)))
				+ rtrim(cast(datepart(minute, @dateCurrent) as char(2)))

	/*
		Prepare Backup Folder Name Based on Current Date & Time
	*/
	set @tracefolderBackupTimestamp 
			= @tracefolderBackup 
				+ '\'
				+ @timestamp


	/*
		If we are to terminate running Traces, let us do so..

			Access sys.traces to find running traces
	*/
	if (@terminateRunningTraces = 1)
	begin

		print 'Looking for running traces : ....'

		set @traceIDRunning = @traceIDNull
		set @iNumberofRecordsAffected = -1

		while (
				      ( @traceIDRunning is not null )
				  and ( @iNumberofRecordsAffected != 0)
			  )	
		begin

			/*
				Get Trace ID and Path of earliest running Trace
				  targetting same path as our's	
			*/
			select 
					  @traceIDRunning = tblST.id
					, @tracePathRunning = tblST.[path]

			from   sys.traces tblST

			where  tblST.[is_default] != 1

			and   tblST.[id] =
						(

							select min(id)
							from   sys.traces tblST
							where  tblST.[path] like + @tracefolder + '%'

						)

			set @iNumberofRecordsAffected = @@ROWCOUNT

			print '@traceIDRunning : '
					+ cast(isNull(@traceIDRunning, 0) as varchar(30))

			if (
					    ( @traceIDRunning != @traceIDNull)
					and (@iNumberofRecordsAffected >0)
			   )
			begin

				set @strTraceIDRunning = cast(@traceIDRunning as varchar)

				exec master.dbo.xp_sprintf
						   @logTraceTerminate output
						 , @logSyntaxTraceTerminate
						 , @strTraceIDRunning
						 , @tracePathRunning

				print @CHAR_TAB + @logTraceTerminate 

				/*
					Stop the Trace
				*/
				EXEC sp_trace_setstatus 
						   @traceid = @traceIDRunning
						,  @status =  @TRACE_STATUS_REQUEST_STOP

				/*
					Discard the Trace
				*/
				EXEC sp_trace_setstatus
						  @traceid = @traceIDRunning
						, @status = @TRACE_STATUS_REQUEST_DISCARD

				/*
					Wait for trace stop & discard to complete
				*/
				print @CHAR_TAB 
						+ @CHAR_TAB 
						+ 'Waiting between trace terminations...'

				WAITFOR DELAY @waitBetweenTraceTermination

			end

		end

	end


	/*
		If Traces are still running, please say so and exit
	*/
	if exists
		(
	
			select * 
			from   sys.traces tblST
			where  tblST.[is_default] != 1
			and    tblST.[path] like + @tracefolder + '%'
		)
	begin

		set @folderAlreadyInUseByRunningTrace = 'SQL Server Profiler\Trace running against ' 
													+ @tracefolder
			
		raiserror(@folderAlreadyInUseByRunningTrace, 16,1)

		return

	end


	--print '@tracefolderBackupTimestamp : ' + @tracefolderBackupTimestamp


	-- 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

	--set 'If exist "F:\Microsoft\SQLServer\Profiler\emmdatafeed.trc" del "F:\Microsoft\SQLServer\Profiler\emmdatafeed.trc" '
	/*
		Prepare Command
	*/
	exec master.dbo.xp_sprintf
			   @OSCommandCreateFolder output
			 , @OSCommandSyntaxCreateFolder
			 , @tracefolder
			 , @tracefolder

	exec master.dbo.xp_sprintf
			   @OSCommandDeleteFile output
			 , @OSCommandSyntaxDeleteFile
			 , @tracefileFullName
			 , @tracefileFullName

	exec master.dbo.xp_sprintf
			   @OSCommandCreateFolderBackup output
			 , @OSCommandSyntaxCreateFolder
			 , @tracefolderBackup
			 , @tracefolderBackup

	exec master.dbo.xp_sprintf
			   @OSCommandCreateFolderBackupTimestamp output
			 , @OSCommandSyntaxCreateFolder
			 , @tracefolderBackupTimestamp
			 , @tracefolderBackupTimestamp

	exec master.dbo.xp_sprintf
			   @OSCommandMoveFile output
			 , @OSCommandSyntaxMoveFile
			 , @tracefolder
			 , @tracefolder
			 , @tracefolderBackupTimestamp


	/*
		Create Base Folder
	*/
	print '@OSCommandCreateFolder : ' + @OSCommandCreateFolder

	exec master.dbo.xp_cmdshell
			   @OSCommandCreateFolder
			,  no_output 

	/*
		Create Base's Backup Folder
	*/
	print '@OSCommandCreateFolderBackup : ' + @OSCommandCreateFolderBackup

	exec master.dbo.xp_cmdshell
			   @OSCommandCreateFolderBackup
			,  no_output 

	/*
		Create Base's Backup TimeStamp Folder
	*/
	print '@OSCommandCreateFolderBackup : ' + @OSCommandCreateFolderBackupTimestamp

	exec master.dbo.xp_cmdshell
			   @OSCommandCreateFolderBackupTimestamp
			,  no_output 

	/*
		Move files from base to backup\timestamp
	*/
	print '@OSCommandMoveFile : ' + @OSCommandMoveFile

	exec master.dbo.xp_cmdshell
			   @OSCommandMoveFile
			,  no_output 
	

	if (@createTrace = 0)
	begin

		print 'Skipping Trace Creation!'
	end
	else
	begin

		set @traceActionRequested = 'sp_trace_create'

		--exec @rc = sp_trace_create @TraceID output, 0, N'InsertFileNameHere', @maxfilesize, NULL 

		exec master.dbo.xp_sprintf
			   @logTraceCreate output
			 , @logSyntaxTraceCreating
			 , @tracefolder

		print @logTraceCreate

		exec @rc = sp_trace_create 
						  @traceid = @traceID output
						, @options = 0
						, @tracefile = @tracefileFullName
						, @maxfilesize = @maxfilesize
						, @stoptime = NULL 
						, @filecount = NULL

		if (@rc != 0) goto error

		set @strTraceID = cast(@traceID as varchar(30))

		-- Client side File and Table cannot be scripted

		-- Set the events

		set @traceActionRequested = 'sp_trace_setevent'

		exec sp_trace_setevent @TraceID, 22, 7, @on
		exec sp_trace_setevent @TraceID, 22, 31, @on
		exec sp_trace_setevent @TraceID, 22, 8, @on
		exec sp_trace_setevent @TraceID, 22, 64, @on
		exec sp_trace_setevent @TraceID, 22, 1, @on
		exec sp_trace_setevent @TraceID, 22, 9, @on
		exec sp_trace_setevent @TraceID, 22, 41, @on
		exec sp_trace_setevent @TraceID, 22, 49, @on
		exec sp_trace_setevent @TraceID, 22, 6, @on
		exec sp_trace_setevent @TraceID, 22, 10, @on
		exec sp_trace_setevent @TraceID, 22, 14, @on
		exec sp_trace_setevent @TraceID, 22, 26, @on
		exec sp_trace_setevent @TraceID, 22, 3, @on
		exec sp_trace_setevent @TraceID, 22, 11, @on
		exec sp_trace_setevent @TraceID, 22, 35, @on
		exec sp_trace_setevent @TraceID, 22, 51, @on
		exec sp_trace_setevent @TraceID, 22, 4, @on
		exec sp_trace_setevent @TraceID, 22, 12, @on
		exec sp_trace_setevent @TraceID, 22, 20, @on
		exec sp_trace_setevent @TraceID, 22, 60, @on
		exec sp_trace_setevent @TraceID, 33, 7, @on
		exec sp_trace_setevent @TraceID, 33, 31, @on
		exec sp_trace_setevent @TraceID, 33, 8, @on
		exec sp_trace_setevent @TraceID, 33, 64, @on
		exec sp_trace_setevent @TraceID, 33, 1, @on
		exec sp_trace_setevent @TraceID, 33, 9, @on
		exec sp_trace_setevent @TraceID, 33, 41, @on
		exec sp_trace_setevent @TraceID, 33, 49, @on
		exec sp_trace_setevent @TraceID, 33, 6, @on
		exec sp_trace_setevent @TraceID, 33, 10, @on
		exec sp_trace_setevent @TraceID, 33, 14, @on
		exec sp_trace_setevent @TraceID, 33, 26, @on
		exec sp_trace_setevent @TraceID, 33, 30, @on
		exec sp_trace_setevent @TraceID, 33, 50, @on
		exec sp_trace_setevent @TraceID, 33, 3, @on
		exec sp_trace_setevent @TraceID, 33, 11, @on
		exec sp_trace_setevent @TraceID, 33, 35, @on
		exec sp_trace_setevent @TraceID, 33, 51, @on
		exec sp_trace_setevent @TraceID, 33, 4, @on
		exec sp_trace_setevent @TraceID, 33, 12, @on
		exec sp_trace_setevent @TraceID, 33, 20, @on
		exec sp_trace_setevent @TraceID, 33, 60, @on
		exec sp_trace_setevent @TraceID, 162, 7, @on
		exec sp_trace_setevent @TraceID, 162, 31, @on
		exec sp_trace_setevent @TraceID, 162, 8, @on
		exec sp_trace_setevent @TraceID, 162, 64, @on
		exec sp_trace_setevent @TraceID, 162, 1, @on
		exec sp_trace_setevent @TraceID, 162, 9, @on
		exec sp_trace_setevent @TraceID, 162, 41, @on
		exec sp_trace_setevent @TraceID, 162, 49, @on
		exec sp_trace_setevent @TraceID, 162, 6, @on
		exec sp_trace_setevent @TraceID, 162, 10, @on
		exec sp_trace_setevent @TraceID, 162, 14, @on
		exec sp_trace_setevent @TraceID, 162, 26, @on
		exec sp_trace_setevent @TraceID, 162, 30, @on
		exec sp_trace_setevent @TraceID, 162, 50, @on
		exec sp_trace_setevent @TraceID, 162, 3, @on
		exec sp_trace_setevent @TraceID, 162, 11, @on
		exec sp_trace_setevent @TraceID, 162, 35, @on
		exec sp_trace_setevent @TraceID, 162, 51, @on
		exec sp_trace_setevent @TraceID, 162, 4, @on
		exec sp_trace_setevent @TraceID, 162, 12, @on
		exec sp_trace_setevent @TraceID, 162, 20, @on
		exec sp_trace_setevent @TraceID, 162, 60, @on
		exec sp_trace_setevent @TraceID, 14, 1, @on
		exec sp_trace_setevent @TraceID, 14, 9, @on
		exec sp_trace_setevent @TraceID, 14, 6, @on
		exec sp_trace_setevent @TraceID, 14, 10, @on
		exec sp_trace_setevent @TraceID, 14, 14, @on
		exec sp_trace_setevent @TraceID, 14, 11, @on
		exec sp_trace_setevent @TraceID, 14, 12, @on
		exec sp_trace_setevent @TraceID, 20, 7, @on
		exec sp_trace_setevent @TraceID, 20, 23, @on
		exec sp_trace_setevent @TraceID, 20, 31, @on
		exec sp_trace_setevent @TraceID, 20, 8, @on
		exec sp_trace_setevent @TraceID, 20, 12, @on
		exec sp_trace_setevent @TraceID, 20, 60, @on
		exec sp_trace_setevent @TraceID, 20, 64, @on
		exec sp_trace_setevent @TraceID, 20, 1, @on
		exec sp_trace_setevent @TraceID, 20, 9, @on
		exec sp_trace_setevent @TraceID, 20, 21, @on
		exec sp_trace_setevent @TraceID, 20, 49, @on
		exec sp_trace_setevent @TraceID, 20, 6, @on
		exec sp_trace_setevent @TraceID, 20, 10, @on
		exec sp_trace_setevent @TraceID, 20, 14, @on
		exec sp_trace_setevent @TraceID, 20, 26, @on
		exec sp_trace_setevent @TraceID, 20, 3, @on
		exec sp_trace_setevent @TraceID, 20, 11, @on
		exec sp_trace_setevent @TraceID, 20, 35, @on
		exec sp_trace_setevent @TraceID, 20, 51, @on
		exec sp_trace_setevent @TraceID, 15, 15, @on
		exec sp_trace_setevent @TraceID, 15, 16, @on
		exec sp_trace_setevent @TraceID, 15, 9, @on
		exec sp_trace_setevent @TraceID, 15, 13, @on
		exec sp_trace_setevent @TraceID, 15, 17, @on
		exec sp_trace_setevent @TraceID, 15, 6, @on
		exec sp_trace_setevent @TraceID, 15, 10, @on
		exec sp_trace_setevent @TraceID, 15, 14, @on
		exec sp_trace_setevent @TraceID, 15, 18, @on
		exec sp_trace_setevent @TraceID, 15, 11, @on
		exec sp_trace_setevent @TraceID, 15, 12, @on
		exec sp_trace_setevent @TraceID, 17, 12, @on
		exec sp_trace_setevent @TraceID, 17, 1, @on
		exec sp_trace_setevent @TraceID, 17, 9, @on
		exec sp_trace_setevent @TraceID, 17, 6, @on
		exec sp_trace_setevent @TraceID, 17, 10, @on
		exec sp_trace_setevent @TraceID, 17, 14, @on
		exec sp_trace_setevent @TraceID, 17, 11, @on
		exec sp_trace_setevent @TraceID, 10, 15, @on
		exec sp_trace_setevent @TraceID, 10, 16, @on
		exec sp_trace_setevent @TraceID, 10, 9, @on
		exec sp_trace_setevent @TraceID, 10, 17, @on
		exec sp_trace_setevent @TraceID, 10, 2, @on
		exec sp_trace_setevent @TraceID, 10, 10, @on
		exec sp_trace_setevent @TraceID, 10, 18, @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, 6, @on
		exec sp_trace_setevent @TraceID, 10, 14, @on
		exec sp_trace_setevent @TraceID, 12, 15, @on
		exec sp_trace_setevent @TraceID, 12, 16, @on
		exec sp_trace_setevent @TraceID, 12, 1, @on
		exec sp_trace_setevent @TraceID, 12, 9, @on
		exec sp_trace_setevent @TraceID, 12, 17, @on
		exec sp_trace_setevent @TraceID, 12, 6, @on
		exec sp_trace_setevent @TraceID, 12, 10, @on
		exec sp_trace_setevent @TraceID, 12, 14, @on
		exec sp_trace_setevent @TraceID, 12, 18, @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, 13, 12, @on
		exec sp_trace_setevent @TraceID, 13, 1, @on
		exec sp_trace_setevent @TraceID, 13, 9, @on
		exec sp_trace_setevent @TraceID, 13, 6, @on
		exec sp_trace_setevent @TraceID, 13, 10, @on
		exec sp_trace_setevent @TraceID, 13, 14, @on
		exec sp_trace_setevent @TraceID, 13, 11, @on

		/*
			If we are filtering on Login, then set filter appropriately
		*/
		if (@bFilterLogin = 1)
		begin

			set @traceActionRequested = 'sp_trace_setfilter'

			exec master.dbo.xp_sprintf
				   @logTraceFilterOnLogin output
				 , @logSyntaxTraceFilterOnLogin
				 , @strTraceID
				 , @loginname

			print @logTraceFilterOnLogin

			exec @rc = sp_trace_setfilter 
					  @traceid = @TraceID
					, @columnid = 11
					, @logical_operator = 1 -- 1 is OR
					, @comparison_operator = 6 -- 6 is LIKE
					, @value = @loginname

		end

		set @traceActionRequested = 'sp_trace_setstatus'

		exec master.dbo.xp_sprintf
			   @logTraceStart output
			 , @logSyntaxTraceStart
			 , @tracefolder

		print @logTraceStart

		-- Set the trace status to start
		exec @rc = sp_trace_setstatus 
				  @TraceID = @TraceID
				, @status = @TRACE_STATUS_REQUEST_START

		-- display trace id for future references
		select 
				TraceID=@TraceID

	end

	goto finish

	error: 

		set @traceRC = @rc

		select 
			   [ErrorCode] =@rc

			, [TraceActionRequested]
				= @traceActionRequested

	finish: 

end
		
go

Sample Invocation


	declare @tracefolder sysname
	declare @loginname sysname
	declare @terminateRunningTraces	bit
	declare @createTrace bit

	declare @traceID int
	declare @traceRC int

	set @tracefolder = 'D:\Microsoft\SQLServer\Profiler';
	set @loginname = 'emmdatafeed'
	set @terminateRunningTraces =0
	set @createTrace = 1

	exec dbo.sp_ServerSideTraceInitiate
		  @tracefolder = @tracefolder
		, @loginname = @loginname
		, @terminateRunningTraces = @terminateRunningTraces
		, @createTrace = @createTrace

		, @traceID = @traceID output
		, @traceRC = @traceRC output


	select
		  [@traceID] = @traceID
		, [@traceRC] = @traceRC

serverSideTraces

Review Traces

Code


select *
from sys.traces

Output:

ReviewRunningTraces

 

Explanation:

  1. Trace ID = 1
    • Default Trace ( Blackbox)
  2. Other Traces
    • Path
    • File Position
      • In our case, we read 34078720
        • To get the actual file we use a calculator and divide by 1024
          FileSize
    • Start and Last Event Time

 

Clean up

Code

Here is a quick clean up code.

We are targeting a specific Trace.



Set nocount ON
Set XACT_ABORT ON

DECLARE @TraceID int

DECLARE @statusStop int
DECLARE @statusCloseAndDiscardDefinition int

--Replace with Trace ID
--Select * from sys.traces where is_default != 1
SET @TraceID = 2

SET @statusStop = 1
SET @statusCloseAndDiscardDefinition = 2

if exists
	(
		select *
		from   sys.traces
		where  [id] = @traceID
	)
begin

	begin tran
		
		EXEC sp_trace_setstatus 
				   @traceid = @TraceID
				,  @status = @statusStop

		EXEC sp_trace_setstatus 
				  @traceid = @TraceID
				,  @status = @statusCloseAndDiscardDefinition

	commit tran

end

Leave a Reply

Please log in using one of these methods to post your comment:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s