If your code has many nested executions of stored procedures, you can benefit from building popular «flame diagram» of the execution time which is de facto standard for performance profiling.
Here is step-by-step guide.
Creation of a trace
Start SQL profiler and select the following events:
-
SP:Starting
-
SP:Completed
Select the following columns:
-
ObjectName
-
NestLevel
-
StartTime
-
EndTime
-
Spid
In the filters, select condition based on Spid, which must select one particular Spid. The analysis is checking just one execution flow, so different connections should not mix in a trace.
Save you trace in a database when enough events are recorded. In that database, create the following stored procedure:
Скрытый текст
create procedure flame @trname sysname, @spname sysname, @start int=0 as -- Trace must contain Sp:Start, Sp:Completed, StartTime, EndTime, Nestlevel, ObjectName -- 1 SPID should be recorded set nocount on declare @r int, @b int, @e int, @t datetime, @class int, @lev int, @obj varchar(255), @prevt datetime, @stack varchar(max)='', @prevstack varchar(max)='', @sql varchar(1000) create table #trace (RowNumber int, EventClass int, StartTime datetime, EndTime datetime, NestLevel int, ObjectName nvarchar(255)) set @sql = 'insert into #trace select RowNumber,EventClass,StartTime,EndTime,Nestlevel,ObjectName from '+@trname+' where EventClass in (42,43)' exec (@sql) select (select max(RowNumber) from #trace I where I.EventClass=42 and I.ObjectName=@spname and I.Nestlevel=1 and I.RowNumber<O.RowNumber) as [Start], O.RowNumber as [End], StartTime, EndTime, datediff(ms, StartTime, endTime) as DurationMs from #trace O where EventClass=43 and ObjectName=@spname and Nestlevel=1 order by 1 select @b=min(RowNumber) from #trace where EventClass=42 and ObjectName=@spname and NestLevel=1 and RowNumber>=@start if @b is null begin print 'procedure: start not found' return end select @e=min(RowNumber) from #trace where EventClass=43 and ObjectName=@spname and RowNumber>@b and Nestlevel=1 if @e is null begin print 'procedure: end not found' return end select 'Selected', @b as [Start], @e as [End] DECLARE my_cur CURSOR FOR SELECT RowNumber,EventClass,isnull(EndTime,StartTime),NestLevel,ObjectName from #trace where RowNumber>=@b and RowNumber<=@e order by RowNumber OPEN my_cur FETCH NEXT FROM my_cur INTO @r, @class, @t, @lev, @obj WHILE @@FETCH_STATUS = 0 BEGIN if @class=42 set @stack = @stack + ';' + @obj else set @stack=reverse(substring(reverse(@stack),charindex(';', reverse(@stack))+1,100000)) if @prevt is not null print substring(@prevstack,2,100000)+' '+convert(varchar,datediff(ms,@prevt,@t)) set @prevt=@t set @prevstack=@stack FETCH NEXT FROM my_cur INTO @r, @class, @t, @lev, @obj END CLOSE my_cur DEALLOCATE my_cur GOData Generation
Now run the stored procedure flame with the following parameters:
-
trace table name
-
name of a topmost (NestLevel=1) stored procedure, and entry tot he whole execution tree. . Name is specified without [] and schema name, for [dbo].[myProc] specify just myProc
-
3rd parameter is optional, by default it is 0. It allows you to choose a particular execution if more than one execution is recorded.
Example:
The first result set displays all found executions of the specified stored procedure, RowNumber range, time range and duration in milliseconds.
If we want to plot a particular execution (not the very first one, which is a default), in 3rd parameter specify the starting RowNumber. For example, for the 9th execution specify value 10574
Plotting a digram
When everything is ready, check the Messages tab and copy all text from there into a text file, removing text at the very end:
Then go to the site https://www.speedscope.app and upload your text file. Enjoy.
ссылка на оригинал статьи https://habr.com/ru/articles/893004/
Добавить комментарий