Аналітичний звіт за трейсу Microsoft SQL Server

Аналітичний звіт за трейсу Microsoft SQL Server

Постановка завдання
Виявити вузькі місця при роботі додатків з базами даних. Скласти звіт по продуктивності sql-запитів, проаналізувати помилки і глухий кут, скласти порівняльні звіти, порахувати ступінь покриття складу збережених процедур тестами, побудувати діаграми.

Тестування проводиться регулярно. Тому звіти повинні формувати автоматично, бути стандартизовані, легко порівнюватися між собою.

Використовувані технології:
  • Microsoft SQL Server;
  • Microsoft Office Excel;
  • Комплекс sql-запитів, організований проект SQLProfilerReportHelper;
  • Інструмент навантажувального тестування з можливістю виконати sql-запит (JMeter, Visual Studio Ultimate, ...);


Рівень 300 (для професіоналів).

Якщо коротко, то порядок дій для формування звітів по готовому трейсу такий:
  1. запустити SQLProfilerReportHelper, клікнути по кнопках;
  2. виконати вибірку записів з таблиць-звітів, скопіювати результати в буфер обміну;
  3. запустити Microsoft Office Excel, вставити запису з буферу в автоматично форматируемую таблицю і зберегти документ-звіт.
Інструмент і шаблон звіту доступні для скачування SQLProfilerReportHelper.
Якщо вам цікаво ознайомитися з описом інструменту та звітів та порядком їх складання, читайте далі.


Розповім про два основних звіту:
  • статистика виконання збережених процедур (Draft report);
  • статистика виконання всіх запитів (Detail report).


1. Трасування
Процес не можна зрозуміти через його припинення. Розуміння повинно рухатися разом з процесом, злитися з його потоком і текти разом з ним.
— з роману «Дюна» Френка Герберта
Трасування
Трасування, результати якої аналізуються автоматично, припускає наявність конкретних подій і колонок. Зручний програмний запуск, при старті навантажувального тесту. Саме такий спосіб використовую, можливі й інші варіанти.

При профілюванні навантаженої OLTP-системи краще зберігати трейсы файли. Виконуючи завантаження файлів трасування в таблицю бази даних уже після тестування. Так створюється менша додаткове навантаження на SQL Server, ніж при записі трасування в базу даних (на скільки менша не міряв). І витрачається менше місця (файли трасування в 3,9-4 рази менше аналогічної таблиці трасування). Далі передбачається, що тестується OLTP і навантажувальне тестування.
При профілюванні OLAP-системи, коли навантаження невисока, записувати трейсы можна відразу в базу даних.

1.1. Автоматичний запуск

Автоматичний запуск трасування навантажувальним тестом
Зручно запускати профілювання в події початку навантажувального тесту. У контексті навантажувального тесту визначити параметри, значення яких зручно змінювати без зміни коду навантажувального тесту:
  • useSQLProfiling (true/false) — використовувати трасування при запуску тесту (наприклад, true)
  • pathSQLPrifiling — шлях до каталогу на сервері Microsoft SQL Server для збереження файлів трасування (наприклад, D:\Traces\Synerdocs\)
  • назви баз даних (параметрів) — використовую для фільтрації профільованих подій (tempdb і три бази даних досліджуваної системи)
З контексту навантажувального тесту також витягується назва профілю навантаження, яке відображається в іменах файлів трейса. І профілю навантаження витягується тривалість тестування, для обчислення моменту завершення трасування.

Виконується параметризований запит Script.01.Start trace.sql (див. у каталозі scripts\start trace\ в папці проекту або в урізанні нижче).
Script.01.Start trace.sql
-- Script.01.Start trace.sql
-- Параметри:
-- @traceDuration, Int, "Тривалість (в секундах)"
-- Значення береться з профілю навантажувального тесту, при старті тестування.
-- @fileName, nvarchar(256), "Зберігати трейс в файл"
-- Значення формується на основі папки профайлінгу, назви профілю навантаження і поточного часу.
-- D:\Traces\Synerdocs\ServiceLoadTestBigFiles.2014.01.21 08.30.10
-- @db1, nvarchar(256), фільтр по імені бази даних
-- @db2, nvarchar(256), фільтр по імені бази даних
-- @db3, nvarchar(256), фільтр по імені бази даних
-- @db4, nvarchar(256), фільтр по імені бази даних

-- Create a Queue
declare @rc int
declare @int TraceID
declare @maxfilesize bigint
declare @datetime stopTraceTime
declare @traceFileName nvarchar(256)
declare @int traceOptions

-- Create 100 files MBytes
set @maxfilesize = 100
-- Duration of trace
set @stopTraceTime = DATEADD(second, @traceDuration, SYSDATETIME())
-- Trace filename
set @traceFileName = @fileName 
-- TRACE_FILE_ROLLOVER
set @traceOptions = 2

exec @rc = sp_trace_create @TraceID output, @traceOptions, @traceFileName, @maxfilesize, @stopTraceTime
if (@rc != 0) error goto

-- Set the events
declare @on bit
set @on = 1

-- 162. User Error Message. Displays error messages that users see in the case of an error or exception.
exec sp_trace_setevent @TraceID, 162, 1, @on -- TextData. n-текст.
exec sp_trace_setevent @TraceID, 162, 4, @on -- TransactionID. bigint.
exec sp_trace_setevent @TraceID, 162, 9, @on -- ClientProcessID. int.
exec sp_trace_setevent @TraceID, 162, 10, @on -- ApplicationName. nvarchar.
exec sp_trace_setevent @TraceID, 162, 11, @on -- LoginName. nvarchar.
exec sp_trace_setevent @TraceID, 162, 12, @on -- ВІЛЬНИЙ. int.
exec sp_trace_setevent @TraceID, 162, 20, @on -- Severity.
exec sp_trace_setevent @TraceID, 162, 14, @on -- StartTime. datetime.
exec sp_trace_setevent @TraceID, 162, 31, @on -- Error. int.
exec sp_trace_setevent @TraceID, 162, 35, @on -- DatabaseName. nvarchar.
exec sp_trace_setevent @TraceID, 162, 49, @on -- RequestID. int.
exec sp_trace_setevent @TraceID, 162, 50, @on -- XactSequence. bigint.

-- 148. Deadlock Graph. Occurs when an attempt to acquire a lock is canceled because the attempt was part of a deadlock and was as the chosen deadlock victim. Provides an XML description of a deadlock.
exec sp_trace_setevent @TraceID, 148, 1, @on -- TextData. n-текст.
exec sp_trace_setevent @TraceID, 148, 4, @on -- TransactionID. bigint. Not used.
exec sp_trace_setevent @TraceID, 148, 11, @on -- LoginName. nvarchar.
exec sp_trace_setevent @TraceID, 148, 12, @on -- ВІЛЬНИЙ. int.
exec sp_trace_setevent @TraceID, 148, 14, @on -- StartTime. datetime.

-- 10. RPC:Completed. Occurs when a remote procedure call (RPC) has completed.
exec sp_trace_setevent @TraceID, 10, 1, @on -- TextData. n-текст.
exec sp_trace_setevent @TraceID, 10, 4, @on -- TransactionID. bigint.
exec sp_trace_setevent @TraceID, 10, 9, @on -- ClientProcessID. int.
exec sp_trace_setevent @TraceID, 10, 10, @on -- ApplicationName. nvarchar.
exec sp_trace_setevent @TraceID, 10, 11, @on -- LoginName. nvarchar.
exec sp_trace_setevent @TraceID, 10, 12, @on -- ВІЛЬНИЙ. int.
exec sp_trace_setevent @TraceID, 10, 13, @on -- Duration. bigint.
exec sp_trace_setevent @TraceID, 10, 14, @on -- StartTime. datetime.
exec sp_trace_setevent @TraceID, 10, 15, @on -- EndTime. datetime.
exec sp_trace_setevent @TraceID, 10, 16, @on -- Reads. bigint.
exec sp_trace_setevent @TraceID, 10, 17, @on -- Writes. bigint.
exec sp_trace_setevent @TraceID, 10, 18, @on -- CPU. int.
exec sp_trace_setevent @TraceID, 10, 31, @on -- Error. int.
exec sp_trace_setevent @TraceID, 10, 34, @on -- ObjectName. nvarchar.
exec sp_trace_setevent @TraceID, 10, 35, @on -- DatabaseName. nvarchar.
exec sp_trace_setevent @TraceID, 10, 48, @on -- RowCounts. bigint.
exec sp_trace_setevent @TraceID, 10, 49, @on -- RequestID. int.
exec sp_trace_setevent @TraceID, 10, 50, @on -- XactSequence. bigint.

-- 12. SQL:BatchCompleted. Occurs when a Transact-SQL batch has completed.
exec sp_trace_setevent @TraceID, 12, 1, @on -- TextData. n-текст.
exec sp_trace_setevent @TraceID, 12, 4, @on -- TransactionID. bigint.
exec sp_trace_setevent @TraceID, 12, 9, @on -- ClientProcessID. int.
exec sp_trace_setevent @TraceID, 12, 11, @on -- LoginName. nvarchar.
exec sp_trace_setevent @TraceID, 12, 10, @on -- ApplicationName. nvarchar.
exec sp_trace_setevent @TraceID, 12, 12, @on -- ВІЛЬНИЙ. int.
exec sp_trace_setevent @TraceID, 12, 13, @on -- Duration. bigint.
exec sp_trace_setevent @TraceID, 12, 14, @on -- StartTime. datetime.
exec sp_trace_setevent @TraceID, 12, 15, @on -- EndTime. datetime.
exec sp_trace_setevent @TraceID, 12, 16, @on -- Reads. bigint.
exec sp_trace_setevent @TraceID, 12, 17, @on -- Writes. bigint.
exec sp_trace_setevent @TraceID, 12, 18, @on -- CPU. int.
exec sp_trace_setevent @TraceID, 12, 31, @on -- Error. int.
exec sp_trace_setevent @TraceID, 12, 35, @on -- DatabaseName. nvarchar.
exec sp_trace_setevent @TraceID, 12, 48, @on -- RowCounts. bigint.
exec sp_trace_setevent @TraceID, 12, 49, @on -- RequestID. int.
exec sp_trace_setevent @TraceID, 12, 50, @on -- XactSequence. bigint.


-- Set the Filters
exec sp_trace_setfilter @TraceID, 35, 0, 6, @db1
exec sp_trace_setfilter @TraceID, 35, 1, 6, @db2
exec sp_trace_setfilter @TraceID, 35, 1, 6, @db3
exec sp_trace_setfilter @TraceID, 35, 1, 6, @db4
-- 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: 


Значення, що повертаються:
  • TraceID, int, ідентифікатор сеансу трасування, стане в нагоді для последуюшей зупинки трасування;
  • ErrorCode, int, код помилки, якщо трасування не почалася, див. Return Code Values для sp_trace_create.


Спосіб виконання запиту в події навантажувального тесту залежить від інструменту тестування і мови розробки. І в Java, і в C# це робиться просто. Можна написати окреме керівництво. Деякі особливості, в двох пропозиціях:
  1. Події виконуються на навантажувальному агента, коли навантажувальних агентів кілька, в параметрах навантажувального тесту задається ім'я агента, який буде виконувати старт і дострокове завершення профілювання, агент дізнається про своє призначення по імені.
  2. Якщо SQL Server знаходиться за DMZ, то агент, що працює з SQL Server ставиться на прикордонний сервер, і для агента призначається нульовою профіль навантаження, але простіше не використовувати DMZ на навантажувальному стенді.
Фахівці, які добре знайомі з навантажувальним тестуванням, зрозуміють попередні дві пропозиції. Якщо зрозуміти не вдалося, то у вас немає агентів, DMZ, або вам простіше запускати трасування в напівавтоматичному і ручному режимі.

1.1.1. Зупинка трасування
Штатна зупинка трасування
Трасування запускається на час. Момент завершення трасування определяектся тривалістю тестування (параметр traceDuration) і обчислюється в скрипті Script.01.Start trace.sql. Передбачається, що навантажувальне тестування також запускається на час, має тривалість, яку можна отримати програмно.

1.1.2. Дострокове припинення
Дострокове припинення трасування
При виконанні Script.01.Start trace.sql повертається TraceId. Якщо тестування припиняється достроково, в події припинення тестування значення TraceId передається в скрипт:
-- Stops the specified trace.
EXEC sp_trace_setstatus @traceid = @traceid , @status = 0 
-- Closes the specified trace and deletes its definition from the server.
EXEC sp_trace_setstatus @traceid = @traceid , @status = 2 


1.2. Напівавтоматичний запуск


Якщо неможливо автоматично виконувати sql-запит при старті тестування, то запит Script.01.Start trace.sql можна виконати вручну з SQL Management Studio, попередньо визначивши параметри скрипта.

Якщо час зупинки неможливо обчислити при старті трасування, то параметр stopTraceTime не треба передавати в процедуру sp_trace_create (див. Script.01.Start trace.sql :29).
1.2.1. Зупинка трасування

Зупиняти профілювання можна також скриптом, вибираючи останавливаемый сеанс трасування, наприклад, з каталогу (D:\Traces\Synerdocs\):
-- Script.02.Stop trace.sql
DECLARE @INT traceid
SET @traceid = (SELECT TOP 1 [id] FROM sys.traces WHERE [path] LIKE 'D:\Traces\Synerdocs\%')
IF @traceid IS NOT NULL
BEGIN
-- Stops the specified trace.
EXEC sp_trace_setstatus @traceid = @traceid , @status = 0 
-- Closes the specified trace and deletes its definition from the server.
EXEC sp_trace_setstatus @traceid = @traceid , @status = 2 
END
SELECT * FROM sys.traces


1.3. Ручний запуск


Microsoft SQL Server Profiler дозволяє зібрати велику кількість подій.
См. sp_trace_setevent http://msdn.microsoft.com/ru-ru/library/ms186265.aspx).
В якості найбільш цікавих подій виділю помилки, блокування, виконання процедур і запитів:
ВД (EventID) Подія (Event Name) Опис (Event description)
162 User Error Message Displays error messages that users see in the case of an error or exception
148 Deadlock Graph Occurs when an attempt to acquire a lock is canceled because the attempt was part of a deadlock and was as the chosen deadlock victim.
10 RPC:Completed Occurs when a remote procedure call (RPC) has completed.
12 SQL:BatchCompleted Occurs when a Transact-SQL batch has completed.


У вибраних подій найбільш цікаві колонки:
ColumnID ColumnName Type Помилки Блокування Процедури Запити
1 TextData n-текст + + + +
13 Duration bigint + +
14 StartTime datetime + + + +
16 Reads bigint + +
17 Writes bigint + +
18 CPU int + +
31 Error int + + +
34 ObjectName nvarchar +
35 DatabaseName nvarchar + + +
Включаю в трасування додаткові колонки, у звітах вони не використовуються, але стають в нагоді при ручному аналізі:
ColumnID ColumnName Type Помилки Блокування Процедури Запити
4 TransactionID bigint + + + +
9 ClientProcessID int + + +
10 ApplicationName nvarchar + + +
11 LoginName nvarchar + + + +
12 SPID int + + + +
15 EndTime datetime + +
48 RowCounts bigint + +
49 RequestID int + + +
50 XactSequence bigint + + +
Трасування з фільтрацією DatabaseName (ColumnID 35), виконується лише для обраних баз даних SQL Server (на тестових серверах, часто, баз даних багато, треба вибрати лише потрібні):
  • tempdb;
  • бази даних досліджуваного програми.
Фільтрацію та угруповання також зручно виконувати за LoginName.
Якщо вам зручний ручний запуск трасування, то Microsoft SQL Server Profiler дозволить переглядати результати профілювання відразу.

1.3.1. Перетворення налаштованих параметрів скрипт для автоматизації

Якщо у вас є інший набір подій, колонок і фільтрів. І ви хочете автоматизувати запуск трасування з таким набором параметрів, то SQL Server Profiler допоможе і тут.

Налаштування автоматичного запуску трасування:
  1. Запустити Microsoft SQL Server Profiler.
  2. Вибрати профільовані події, вибрати атрибути профільованих подій.
  3. Задати параметри фільтрації (DatabaseName або LoginName), параметри відкриваються після натискання кнопки Column Filters....
  4. Зберегти параметри трасування, задані на вкладці Events Selection вікна «Trace Properties», використовуючи пункт меню «File/Export/Script Trace Definition/For SQL Server 2005 — 2008 R2...».
Вийде заготівля скрипта. Схожа на текст скрипта:
Згенерований скрипт з налаштуваннями профілювання
/****************************************************/
/* Created by: SQL Server 2008 R2 Profiler */
/* Date: 21/01/2014 10:23:02 */
/****************************************************/


-- Create a Queue
declare @rc int
declare @int TraceID
declare @maxfilesize bigint
set @maxfilesize = 5 

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

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

-- Client side File Table and cannot be scripted

-- Set the events
declare @on bit
set @on = 1
exec sp_trace_setevent @TraceID, 162, 31, @on
exec sp_trace_setevent @TraceID, 162, 1, @on
exec sp_trace_setevent @TraceID, 162, 9, @on
exec sp_trace_setevent @TraceID, 162, 49, @on
exec sp_trace_setevent @TraceID, 162, 10, @on
exec sp_trace_setevent @TraceID, 162, 14, @on
exec sp_trace_setevent @TraceID, 162, 50, @on
exec sp_trace_setevent @TraceID, 162, 11, @on
exec sp_trace_setevent @TraceID, 162, 35, @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, 148, 11, @on
exec sp_trace_setevent @TraceID, 148, 4, @on
exec sp_trace_setevent @TraceID, 148, 12, @on
exec sp_trace_setevent @TraceID, 148, 14, @on
exec sp_trace_setevent @TraceID, 148, 1, @on
exec sp_trace_setevent @TraceID, 10, 15, @on
exec sp_trace_setevent @TraceID, 10, 31, @on
exec sp_trace_setevent @TraceID, 10, 16, @on
exec sp_trace_setevent @TraceID, 10, 48, @on
exec sp_trace_setevent @TraceID, 10, 1, @on
exec sp_trace_setevent @TraceID, 10, 9, @on
exec sp_trace_setevent @TraceID, 10, 17, @on
exec sp_trace_setevent @TraceID, 10, 49, @on
exec sp_trace_setevent @TraceID, 10, 10, @on
exec sp_trace_setevent @TraceID, 10, 18, @on
exec sp_trace_setevent @TraceID, 10, 34, @on
exec sp_trace_setevent @TraceID, 10, 50, @on
exec sp_trace_setevent @TraceID, 10, 11, @on
exec sp_trace_setevent @TraceID, 10, 35, @on
exec sp_trace_setevent @TraceID, 10, 4, @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, 12, 15, @on
exec sp_trace_setevent @TraceID, 12, 31, @on
exec sp_trace_setevent @TraceID, 12, 16, @on
exec sp_trace_setevent @TraceID, 12, 48, @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, 49, @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, 50, @on
exec sp_trace_setevent @TraceID, 12, 11, @on
exec sp_trace_setevent @TraceID, 12, 35, @on
exec sp_trace_setevent @TraceID, 12, 4, @on
exec sp_trace_setevent @TraceID, 12, 12, @on
exec sp_trace_setevent @TraceID, 12, 13, @on


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

exec sp_trace_setfilter @TraceID, 35, 0, 6, 'ServiceDB'
exec sp_trace_setfilter @TraceID, 35, 1, 6, 'ClientDB'
exec sp_trace_setfilter @TraceID, 35, 1, 6, 'LogsDB'
exec sp_trace_setfilter @TraceID, 35, 1, 6, 'Tempdb'
-- 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

В заготовку скрипта трасування не потрапляють параметри з вкладки General вікна «Trace Properties». Там є потрібні параметри, які додаються до скрипт вручну:
  • Save to file;
  • Set maximum file size (MB);
  • Enable file rollover;
  • Enable trace stop time.


Ім'я файлу і час зупинки трасування задається з коду навантажувального тесту, а максимальний розмір файлу і ознака того, що потрібно буде створювати нові файли, зручно задати константою. Саме так і був створений Script.01.Start trace.sql, розглянутий вище.
Опис параметрів Set maximum file size (MB) та Enable file rollover: http://msdn.microsoft.com/en-us/library/ms191206.aspx.

Завантаження файлів трасування в базу даних
Для формування звітів файли трасування завантажуються в таблицю бази даних.

Попередньо створюється база даних в таблиці бази даних будуть завантажуватися трейсы, в ній же будуть створюватися таблиці з звітами. Можна назвати бази даних ProfilerResults. В імені бази даних зручно відобразити найменування проекту, звіти по якому будуть накопичуватися в ній. Проект, над яким працюю, колись назвали «Midway», тому базу даних назвав MidwayProfilerResults. Для створення бази даних зручно використовувати SQL Management Studio, де є майстер для створення бази даних, пара кліків і готово.

Для завантаження використовується системна функція fn_trace_gettable.
use "ProfilerResults"
SELECT
"EventClass"
, "TextData"
, "Duration"
, "StartTime"
, "Reads"
, "Writes"
, "CPU"
, "Error"
, "ObjectName"
, "DatabaseName"
, "TransactionID"
, "ClientProcessID"
, "ApplicationName"
, "LogiName"
, "SPID"
, "EndTime"
, "RowCounts"
, "RequestID"
, "XactSequence"
INTO "SOAP.v2.3.1.5577"
FROM ::fn_trace_gettable('D:\Traces\Synerdocs\LoadTest.SOAP.Trace.StartOn 2013.01.21 08.30.00.trc', default)

У параметрах fn_trace_gettable вказується шлях до першого файлу трасування, а другий параметр default означає, що в таблицю завантажаться всі файли з того ж сеансу трасування (не тільки вказаний файл розміром 100 МБайт).


Ім'я таблиці профайлінгу задається так, щоб відображати версію досліджуваної системи і профіль навантаження (у прикладі: «SOAP.v2.3.1.5577»). Створювані таблиці з звітами будуть містити в імені назву таблиці профайлінгу, за якої сформовані. І щоб надалі знайти потрібну таблицю з звітом серед безлічі інших, краще поставити значуще ім'я таблиці.

Завантаження може виконуватися довго, залежить від обладнання. На моєму сервері швидкість завантаження така: 160-190 МБайт/хвилину або 1,5 — 2 файлу трасування в хвилину (один файл — 100 МБайт). Заміри по двом нещодавнім операціями завантаження файлів трасування в базу даних (звичайний профіль навантаження і профіль навантаження з великими файлами).
Розмір файлів трейса (МБайт) Тривалість завантаження (год: хв: сек) Середня швидкість завантаження (МБайт/хв) Розмір таблиці трасування (МБайт) Кількість рядків Середній розмір рядка таблиці (КБайт) Коефіцієнт збільшення розміру після завантаження в таблицю
7 598 00:45:17 168,8 29 478,3 766 370 39,4 3,9
67 062 05:46:32 193,8 268 875,7 2 861 599 96,2 4,0


2. Зведений звіт щодо процедур (RPC:Completed) — «Draft Report»
Надміру ретельний аналіз спотворює істину.
— древнє фрименское вислів, з роману «Месія Дюни» Френка Герберта
Draft Report. Sample
Якщо робота з базою даних здійснюється переважно через API бази даних (набір збережених процедур і функцій), то цей звіт — перше, що варто побудувати.

Звіт являє собою угруповання подій RPC:Completed з таблиці трасування по імені бази данихDatabaseName) та імені збереженої процеруды або функції (ObjectName) з підрахунком статистики та текстами смых швидких і повільних запитів. Статистика SQL:BatchCompleted також є у звіті, але це лише один рядок — рядок NULL, без деталізації. Тому цей звіт названий «Draft Report».

Для автоматизації побудови звіту «Draft Report» використовується допоміжний інструмент Tools.SQLProfilerReportHelper.

2.1. Підготовка до формування звіту «Draft Report»
Підготовка до формування звіту «Draft Report»
Підготовка зводиться до натискання кнопок на формі Tools.SQLProfilerReportHelper:
  1. Запустити Tools.SQLProfilerReportHelper.
  2. Вказати ім'я SQL Server і бази даних профайлінгу в полях SQL Server та Database. У прикладі це — «SQL Server» і «ProfilerResults». Натиснути кнопку Connect. Використовується Windows-аутентифікація на SQL Server, користувач повинен бути адміністратором бази даних профайлінгу.
  3. Вибрати зі списку Profiling Table таблицю з результатами профайлінгу. У прикладі це — «TraceTable.v2.7.LoadProfile1.2010.10.10».
  4. Створити нову колонку TextKey у таблиці профайлінгу — перевірити наявність/відсутність колонки в таблиці, натиснувши кнопку Check, і якщо колонки не існує (кнопка Create стане доступною), натиснути кнопку Create.
  5. Натиснути кнопку Start: SP. По натисненню виконається копіювання значень колонки ObjectName колонку TextKey.
Під час копіювання ObjectName колонку TextKey відображається скільки записів залишилося обробити. І обчислюється залишилася тривалість операції. Процес можна перервати натисканням кнопки Stop: SP.

2.2. Формування звіту «Draft Report»

Після завершення копіювання створити чорновий звіт (Draft report). Для цього потрібно натиснути кнопку Check (перевірити наявність/відсутність таблиці із звітом), і якщо таблиці із звітом немає, то натиснути кнопку Create. В результаті чого буде створена таблиця з закінченням «DraftStat» в імені, у нашому прикладі — TraceTable.v2.7.LoadProfile1.2010.10.10.DraftStat. Розмір таблиці відносно невеликою (10-30 МБайт). Таблиця призначена для довгострокового зберігання статистики виконання збережених процедур і функцій.

Вміст таблиці отримати запитом:
USE "ProfilerResults"
SELECT * FROM "dbo"."TraceTable.v2.7.LoadProfile1.2010.10.10.DraftStat"


Запит зручно виконати у SQL Management Studio.

Скопіювати в буфер обміну всі стовпці, крім стовпців з текстами запитів TextData-....

Склад колонок таблиці DtaftStat (звіт Draft Report)
Колонка Тип Опис
DatabaseName nvarchar(256) База даних (ключ угруповання).
ObjectName-key nvarchar(256) Найменування збереженої процедури або функції (ключ угруповання).
avg(CPU)-key int Час ЦП (середнє) у мілісекундах, використовуване подією.
avg(Duration)-key bigint Тривалість виконання події (середня) у мілісекундах.
% Duration-key float Частка сумарної тривалості події (ключ сортування).
avg(Payload)-key bigint Кількість логічних читань диска (середнє), виконане сервером для події.
Count-key int Кількість викликів (штук).
ObjectName nvarchar(256) Найменування збереженої процедури або функції (ключ угруповання).
avg(CPU) int Середнє значення по колонці CPU (середній час ЦП в мілісекундах, що використовується подією).
max(CPU) int Максимальний час ЦП в мілісекундах, що використовується подією.
sum(CPU) int Сумарний час ЦП в мілісекундах, що використовується подією.
% CPU float Частка сумарного часу ЦП події.
min(Duration) bigint Тривалість події (миниальная) у мілісекундах.
avg(Duration) bigint Тривалість події (середня) у мілісекундах.
max(Duration) bigint Тривалість події (максимальна) у мілісекундах.
sum(Duration) bigint Тривалість події (сумарна) у мілісекундах.
% Duration float Частка сумарної тривалості події.
min(Payload) bigint Кількість логічних читань диска (мінімальна), виконане сервером для події.
avg(Payload) bigint Кількість логічних читань диска (середнє), виконане сервером для події.
max(Payload) bigint Кількість логічних читань диска (максимальна), виконане сервером для події.
sum(Payload) bigint Кількість логічних читань диска (сумарне), виконане сервером для події.
% Reads float Частка кількості логічних читань диска, виконаних сервером для події.
min(Writes) bigint Кількість фізичних звернень до дисків на запис (минильное), виконане сервером для події.
avg(Writes) bigint Кількість фізичних звернень до дисків на запис (середнє), виконане сервером для події.
max(Writes) bigint Кількість фізичних звернень до дисків на запис (максимальна), виконане сервером для події.
sum(Writes) bigint Кількість фізичних звернень до дисків на запис (сумарное), виконане сервером для події.
% Writes float Частка кількості фізичних звернень до дисків за напись, виконаних сервером для події.
Count int Кількість подій.
% Count float Частка кількості подій.
TextData-min(Duration) n-текст Текст запиту, для якого тривалість виконання мінімальна.
TextData-max(Duration) n-текст Текст запиту, для якого тривалість виконання максимальна.
TextData-min(Payload) n-текст Текст запиту, для якого кількість виконаних сервером логічних читань диска мінімально.
TextData-max(Payload) n-текст Текст запиту, для якого кількість виконаних сервером логічних читань диска максимально.
TextData-min(CPU) n-текст Текст запиту, для якого час ЦП мінімально.
TextData-max(CPU) n-текст Текст запиту, для якого час ЦП максимально.
TextData-min(Writes) n-текст Текст запиту, для якого кількість виконаних сервером фізичних звернень до дисків на запис мінімально.
TextData-max(Writes) n-текст Текст запиту, для якого кількість виконаних сервером фізичних звернень до дисків на запис максимально.


Відкрити у Microsoft Office Excel шаблон звіту (таблиця з автоматичним форматуванням клітинки — підсвічування значень від поганих до хороших). Вставити вміст буфера обміну в документ.

Документ буде виглядати, як велика розфарбована таблиця відсортована за спаданням колонки % Duration.

Перші шість колонок відділені від інших (і дублюють їх) є основними. Ці шість основних колонок зручно копіювати з документа Excel документ Word.


Рядки з ключем «NULL» ключем «sp_executesql» — це статистика по викликам запитівSQL:BatchCompleted) і запитів, виконаних за допомогою виклику збережених процедур sp_executesql. Якщо таких запитів мало (колонка Count) і частка тривалості їх виконання невелика (колонка % Duration), то детальний звіт можна і не будувати, обмежившись аналізом чорнового звіту.

2.3. Аналіз звіту «Draft Report»

Звернути увагу на збережені процедури з максимальним значенням % Duration та avg(Payload).


Часто такі виклики можна прискорити, додавши відсутні індекси. SQL Management Studio підкаже, які саме індекси краще додати. Правильність рад не абсолютна, але висока.

Був випадок, що запит був оптимальним і індекси були на місці, але в тексті збереженої процедури здійснювалася вибірка всіх записів великий таблиці (для налагодження) — від цього, запит лідирував у звіті з % Duration. Виконання запиту у SQL Management Studio виявляє такі випадки величезних вибірок. За звітом такі моменти не виявити, статистику по колонці RowCount у звіт не вмикаю (треба б включити).


Вважаю, іноді можна кешувати виклики з великим значенням % Duration та Count (відсортувати записи за спаданням твори «% Duration» x «Count»).

Можливо, у викликах з великим значенням % Duration та avg(CPU) є неоптимальна робота з рядками, математикою, рекурсією.

Виклики з великим значенням % Duration та avg(Write), можливо, неоптимально використовують тимчасові таблиці. Або вказують на вставку в таблиці, де занадто багато індексів і складних тригерів.

Тексти запитів з мінімальними і максимальними значеннями тривалості, кількості логічних читань, часу ЦП витягуються з колонок таблиці-звіту (у документі-звіті цих колонок немає):
  • TextData-min(Duration);
  • TextData-max(Duration);
  • TextData-min(Payload);
  • TextData-max(Payload);
  • TextData-min(CPU);
  • TextData-max(CPU);
  • TextData-min(Writes);
  • TextData-max(Writes).
Тексти аналізуються у SQL Management Studio.

3. Зведений звіт по запитам (RPC:Completed + SQL:BatchCompleted) — Detail Report


Якщо у Draft Report рядки з ключами «NULL» і «sp_executesql» приховували деталізацію виконання по багатьом запитам. То у Detail Report угруповання буде виконана максимально детально.
Формування звіту Detail Report передбачає, що звіт Draft Report вже був сформований і підготовчі дії виконані.

3.1. Підготовка до формування Detail Report


Якщо Draft Report сформований, то достатньо:
  1. Переконатися, що функція PrepareTextData є у базі даних, натиснувши кнопку Check у розділі Function PrepareTextData (створити функцію при необхідності, натиснувши кнопку Create).
  2. Сформувати ключі угруповання за текстами запитів (для групування подій SQL:BatchCompleted колонці TextData), натиснувши кнопку Start: SQL.


Інакше потрібно виконати все з початку: підключитися до бази даних з таблицею профайлінгу, вибрати таблицю профайлінгу, створити колонку TextKey, натиснути кнопку Start: SP для заповнення ключів угруповання по збережених процедур. Дії здійснюються кліками по доступним кнопок на формі інструменту. Кнопки натискати не потрібно, стають недоступними.

3.2. Формування звіту

  1. Перевірити статус існування детального звіту натиснувши кнопку Check Detail report status.
  2. Створити звіт, якщо його немає (якщо кнопка Create доступна для натискання, то натиснути її).


В результаті буде створена нова таблиця-звіт, ім'я якої буде закінчуватися на «DetailStat».
Опис колонок збігається з описом колонок для Draft Report. Але в цій таблиці рядків більше (більш детальний звіт).

Дані таблиці DetailStat також копіюються в буфер обміну і вставляються в шаблон звіту як і для Draft Report.

3.3. Аналіз звіту
Аналіз детального звіту (Detail report) аналогічний аналізу чорнового звіту (Draft Report). Але є додаткова можливість перегляду і вивантаження текстів запитів.

По натисненню на кнопку View відкривається вікно з вмістом детального звіту.

.
У вікні «ReportViewForm», можна подивитися записи, відсортувати. Тексти запитів, по якому здійснюється клік, зберігаються у вигляді файлів в папку з програмою. А на вкладках можна подивитися тексти запитів, перші 10 000 символів тексту запиту.

Такий спосіб вивантаження текстів запитів зроблено для можливості аналізу запитів великого розміру. Так, якщо у трес потрапили операції створення документів розміром 100-700 МБайт, то тексти запитів для цих операцій величезні. На стільки величезні, що навіть оперативної пам'яті може не вистачити для запиту «select * from… DetailStat». При роботі з таблицею звітом DetailStat через такий спеціальний переглядач записи отримуються окремими запитами, а не одним загальним. Це дозволяє вивантажити тексти великих запитів. Якщо великих запитів у звіті немає, то працювати з SQL Management Studio зручніше.

Послідовна вивантаження текстів запитів у файли дозволяє вирішити проблему нестачі пам'яті при роботі з великими текстами запитів (вивозив тексти запитів розміром 500 МБайт і більш).

Промислова експлуатація

Описаний спосіб збору та аналізу трейсов Microsoft SQL Server випробуваний при тестуванні двох продуктів. Обидва продукту пов'язані з бухгалтерією.

OLTP-система (Synerdocs)
Часті вибірки невеликих порцій даних, часті оновлення окремих записів (вхідні/вихідні документи, підписи). Багато користувачів (1000-2000 тестових користувачів). Багато викликів, збережених процедур і функцій (API бази даних). Мало викликів sql-запитів, які не є викликами збережених процедур. Запитів за час навантажувального тестування набирається кілька сотень тисяч. Запити збираються в сотню груп.

Збір трейса запускається на тривалість навантажувального тестування (пара-трійка годин). Потім десятки гігабайт трейса аналізуються і перетворюються в звіти.

Тестування проводиться регулярно. У якийсь момент знаходити явні вузькі місця стало складно. Знадобився инсрумент для детального аналізу. І щоб звіти легко порівнювалися між собою (ключі угруповання повинні бути короткими, щоб влазити в колонку Excel). Так і з'явилися звіти, про які розказано вище.

OLAP-система (Prestima)
Вибірка та групування великих порцією даних, оновлення окремих записів (бюджетування, рахунки, проводки). Відносно мало користувачів під час тестування (навантаження створюють живі люди, які запускають формування звітів). Багато динамічно формованих запитів (довгий текст запиту, відмінності двох запитів можуть бути тільки на 200-му символі в розділі з JOIN-ами або на 250-му в секції WHERE). Запити аналітичні, до безлічі таблиць, з різними умовами. Виразне вплив критеріїв запиту на тривалість. Найдовший запит від самого швидкого може відрізнятися не структурою запиту, а значеннями параметрів.

Збір трейса запускається на тривалість функціонального і об'ємного тестування (можливо, пара-трійка днів). Періодично трейсы аналізуються і перетворюються в звіти.

Щоб статистика по складних запитів не потрапляла в одну групу, ключі угруповання повинні бути точними. У процедурі PrepareTextData можна задати довжину обчислюваного ключа. І при невеликому обсязі трейсов використання довгих ключів угруповання цілком нормально (швидкість формування звітів залишиться високою).

Авторство і посилання
Аналітичні звіти, представлені в статті, є нащадками sql-запиту, написаного Ізвєковим Михайлом (розробник-НВО Комп'ютер). Запит простий і прекрасний:
-- Довгі рядки з REPLACEами потрібні щоб замінити всі цифри на символ X. Мінлива @Len відповідає за те, 
-- скільки перших символів запиту будуть складати його сигнатуру. Чим меншим є значення цієї змінної, 
-- тим менше груп запитів буде в результаті, але більше шанс, що в одну групу потраплять запити різного типу. 
-- Наприклад при значенні 26 всі запити отримання IContents різних типів потраплять в одну групу з сигнатурою "select distinct X as Ob", 
-- якщо збільшити довжину в два рази, то запити розділяться на групи за типами об'єктів, 
-- а якщо збільшити довжину до 4000, то розділяться ще й за умов фільтрації 
-- (вміст папки, документи пов'язані з записом довідника тощо).
declare @Hours float;
declare @CPUSumm int;
declare @int Len = 26;
select @CPUSumm = SUM(CPU) from Test -- Таблиця, в яку зберегли трейс.
select @Hours = CAST(MAX(StartTime) - MIN(StartTime) as float) * 24 from Test -- Таблиця, в яку зберегли трейс.
select
SUBSTRING(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(CAST(TextData as nvarchar(4000)),'0','X'),'1','X'),'2','X'),'3','X'),'4','X'),'5','X'),'6','X'),'7','X'),'8','X'),'9','X'),'XX','X'),'XX','X'),'XX','X'), 1, @Len) as [Query Pattern],
sum(CPU) / 1000 as CPU_sec_SUM,
avg(CPU) as CPU_msec_AVG,
max(CPU) as CPU_msec_MAX,
min(CPU) as CPU_msec_MIN,
avg(Duration) / 1000 as [AVG_Duration (msec)],
avg(Payload) as [Avg Reads],
avg(Writes) as [Avg Writes],
count(1) as TotalQnt,
round(count(1) / @Hours, 2) as Count_per_hour,
round(cast(SUM(CPU) as float) / @CPUSumm * 100, 3) as ImpactCPUPerf
from
Test -- Таблиця, в яку зберегли трейс.
where
EventClass in (10, 12)
and ISNULL(ApplicationName, 'Unknown') in ('SBRSE', 'IS-Builder', 'Unknown')
group by
SUBSTRING(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(CAST(TextData as nvarchar(4000)),'0','X'),'1','X'),'2','X'),'3','X'),'4','X'),'5','X'),'6','X'),'7','X'),'8','X'),'9','X'),'XX','X'),'XX','X'),'XX','X'), 1, @Len)

Запит Михайла, в оригінальному вигляді, не вдалося використати. Аналіз трейса на 30-40 ГБайт виконується довго. І тексти запитів в трейсе були такими, що ніяк не хотіли групуватися. При короткому ключі (10 символів) всі select, update і запити змішувалися. А при довгому ключі (30 символів і більше), виклики збережених процедур з GUID-параметрами створювали тисячі схожих ключів угруповання:
exec [dbo].[getDoc] @id="128500FF-8B90-D060-B490-00CF4FC964FF" --exec [dbo].[getDoc] @id="XFF-X
exec [dbo].[getDoc] @id="AABBCCDD-0E0E-1234-B491-0D43C5F6C0F6" --exec [dbo].[getDoc] @id="AABBC

Почав пробувати різні варіанти розрахунку ключа угруповання. Результати записував у нову колонку таблиці профайлінгу. А по цій колонці вже групував результати. Так все і почалося.

Зовсім недавно, в п'ятницю, сиділи з Мішею говорили про життя непростий, та густій бороді. І забув сказати йому, що статтю буду писати.

Від того, поки не знаю яка ліцензію на скрипт Михайла. А ліцензія на інструмент SQLProfilerReportHelper — BSD, вільна. Додавайте скрипти трасування в навантажувальні тести, аналізуйте трейсы, формуйте звіти.

Інструмент доступний на Github: https://github.com/polarnik/SQLProfilerReportHelper.
Представлені в статті картинки звітів старі, від того не особливо секретні. Якщо ви помітили розбіжність картинки звіту та складу колонок таблиці-звіті, який формується інструментів, поставтеся з розумінням.

Завершення
У керівництві описаний процес складання групують звітів за даними профайлінгу SQL Server. Це лише десята частина робіт по виконанню тестування продуктивності. Але яскрава і важлива.

У наступній частині статті розповім про інші звіти, які формуються на основі трейсов.

Джерело: Хабрахабр

0 коментарів

Тільки зареєстровані та авторизовані користувачі можуть залишати коментарі.