13.4.23

SQL Server Real Time Query Monitoring

Автор: Daniel Farina

http://www.mssqltips.com/sqlservertip/3328/sql-server-2014-real-time-query-monitoring/

Проблема

Если вдруг один из запросов к SQL Server выполняется слишком долго, вы может получить его план исполнения, что даст вам понимание того, что этот запрос делает, но из этого плана вы не сможете точно определить, что запрос делает именно в это время, т.е. на каком операторе плана он «застрял»?
Продолжая читать эту статью, вы узнаете, как научится следить за прогрессом исполнения запроса в режиме реального времени.

Решение

Сколько раз вы задавали себе подобный вопрос: сколько времени нужно, чтобы процесс завершился? Вот какой случай произошёл на моей работе несколько дней назад: ко мне подошел аналитик с вопросом, на каком шаге плана исполнения находится его задача. Выполнив несколько запросов, я понял, что текущим шагом в его запросе была хранимая процедура, которая выполняла изменения данных, но это было единственное, что я мог ему сказать. Тут же мне в голову пришла мысль: было бы лучше, если бы эта задача решалась на экземпляре SQL Server 2014, вместо используемого для неё устаревшего SQL Server 2000. Дело в том, что в SQL Server 2014 появилось новое Dynamic Management View, позволяющее отслеживать на физическом уровне, что фактически запрос делает во время работы оператора. Я имею в виду динамическое административное представление (DMV): sys.dm_exec_query_profiles 

Немного о sys.dm_exec_query_profiles

Для того чтобы эта DMV заработала, нам необходимо обеспечить доступ к реальным планам исполнения запросов (Actual Execution Plan). Как вы уже могли догадаться, этот способ не работает для планов, хранящихся в кэше (Plan Cache). Возможно у вас возник вопрос, почему мы не можем получить статус любого выполняемого на экземпляре запроса в режиме реального времени, и ответ тут простой: ничто не даётся бесплатно. Доступ к упомянутым выше показателям имеет стоимость в терминах производительности, и она возникает из-за того, что SQL Server для анализа запроса должен собрать детализированную статистику.

Планы, которые хранятся в Plan Cache, не содержат статистику исполнения. Они содержат оценки, которые используются для построения плана действий как такового. Когда мы говорим о статистике исполнения мы говорим о фактическом числе чтений, записи, процессорного времени и так далее.

Несколько способов получения данных о производительности SQL Server в реальном времени

Для SQL Server можно показать три способа, позволяющих получить фактический план исполнения запроса:

  • Установка непосредственно в коде подлежащего анализу запроса одного из параметров исполнения SET STATISTICS PROFILE или SET STATISTICS XML в положение ON предоставляет нам возможность такого анализа.
  • Создание server side trace в том числе с одним из этих двух событий: “Showplan Statistics Profile” или “Showplan Statistics XML”. Кроме того, если вам так удобнее, можно использовать приложение SQL Server Profiler.
  • Создание сессии Extended Events и добавление в ней в качестве целевого события sqlserver.query_post_execution_showplan.

Последние два метода полезны, когда вы не можете добавить установку SET непосредственно в коде запроса, который необходимо проанализировать. Однако эти методы нужно использовать с осторожностью, поскольку они негативно влияют на производительность сервера.

Пример сценария трассировки на стороне SQL Server

Ниже представлен пример сценария, создающего трассировку с помощью события “Showplan XML Statistics Profile” и отфильтрованную по имени базы данных.

USE master
GO
-- Create a Queue
DECLARE @rc INT
DECLARE @TraceID INT
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, N'InsertFileNameHere',
    @maxfilesize, NULL 
IF ( @rc != 0 )
    GOTO error
-- Client side File and Table cannot be scripted
-- Set the events
DECLARE @on BIT
SET @on = 1
EXEC sp_trace_setevent @TraceID, 146, 12, @on
EXEC sp_trace_setevent @TraceID, 146, 35, @on
-- Set the Filters
DECLARE @intfilter INT
DECLARE @bigintfilter BIGINT
EXEC sp_trace_setfilter @TraceID, 35, 0, 6, N'AdventureWorks2012'
-- 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: 
-- Stops Capturing Events
EXEC sp_trace_setstatus @TraceID, 0
GO
-- Delete trace definition from Server
EXEC sp_trace_setstatus @TraceID, 2
GO
GO

Пример сценария сеанса SQL Server Extended Events

Следующий сценарий создаст сессию расширенных событий для отслеживания событий «sqlserver.query_post_execution_showplan», с включением фильтрации по имени базы данных и с использованием кольцевого буфера в качестве цели.

USE master
GO
--Create Extended Events Session
CREATE EVENT SESSION [Capture_Query_Plan] ON SERVER
ADD EVENT sqlserver.query_post_execution_showplan(
    WHERE ([database_name]=N'AdventureWorks2012')) 
ADD TARGET package0.ring_buffer
WITH ( MAX_MEMORY = 4096 KB ,
        EVENT_RETENTION_MODE = ALLOW_SINGLE_EVENT_LOSS ,
        MAX_DISPATCH_LATENCY = 30 SECONDS ,
        MAX_EVENT_SIZE = 0 KB ,
        MEMORY_PARTITION_MODE = NONE ,
        TRACK_CAUSALITY = OFF ,
        STARTUP_STATE = OFF )
GO
--Start Extended Events Session
ALTER EVENT SESSION [Capture_Query_Plan] ON SERVER STATE = START
GO
--Stop Extended Events Session
ALTER EVENT SESSION [Capture_Query_Plan] ON SERVER STATE = STOP
GO
--Drop Extended Events Session
DROP  EVENT SESSION [Capture_Query_Plan] ON SERVER
GO

Примеры

Для демонстрации примеров в этой статье я использую базу данных AdventureWorks2012, которую вы можете бесплатно скачать с CodePlex по этой ссылке: 

http://msftdbprodsamples.codeplex.com/releases/view/55330

Предположим, у нас есть представленный ниже запрос, давайте посмотрим, что мы можем сделать.

USE AdventureWorks2012
GO
SET STATISTICS XML ON
SELECT  *
FROM    Sales.SalesOrderHeader OH
    INNER JOIN Sales.SalesOrderDetail OD 
  ON OD.SalesOrderID = OH.SalesOrderID
    INNER JOIN Sales.Customer C 
  ON C.CustomerID = OH.CustomerID
    INNER JOIN Production.Product P 
  ON P.ProductID = OD.ProductID
    INNER JOIN Production.ProductSubcategory PS 
  ON pS.ProductSubcategoryID = P.ProductSubcategoryID
GO

Расчёт предполагаемого процента завершения

Мы можем получить представление о предполагаемом проценте завершения нашего запроса, глядя на процент выполнения физических операторов в плане запроса. Но вы не найдете эту информацию в колонках DMV sys.dm_exec_query_profiles. Мы должны сделать небольшие математические вычисления с использованием значений в колонках estimate_row_count и row_count, предполагая, что estimate_row_count представляет собой 100 процентов задачи.

Здесь могут возникнуть некоторые проблемы; Надежность этого подхода определяется точностью оценки оптимизатором запросов количества строк данных, и это зависит от того, в каком состоянии во время исполнения запроса находится статистика. Вполне возможно, что используемая оптимизатором статистика окажется переоценённой или недооценённой относительно реальной кардинальности, т.ч. не стоит пугаться, если в результате процент исполнения превысит 100%.

Представленный ниже запрос показывает процент исполнения для каждого физического оператора в плане запроса, число используемых каждым оператором потоков, долю времени активности операторов и зависимых от них объектов, если это применимо.

SELECT  session_id ,
        node_id ,
        physical_operator_name ,
        SUM(row_count) row_count ,
        SUM(estimate_row_count) AS estimate_row_count ,
        IIF(COUNT(thread_id) = 0, 1, COUNT(thread_id)) [Threads] ,
        CAST(SUM(row_count) * 100. / SUM(estimate_row_count) AS DECIMAL(30, 2)) [% Complete] ,
        CONVERT(TIME, DATEADD(ms, MAX(elapsed_time_ms), 0)) [Operator time] ,
        DB_NAME(database_id) + '.' + OBJECT_SCHEMA_NAME(QP.object_id,
                                                        qp.database_id) + '.'
        + OBJECT_NAME(QP.object_id, qp.database_id) [Object Name]
FROM    sys.dm_exec_query_profiles QP
GROUP BY session_id ,
        node_id ,
        physical_operator_name ,
        qp.database_id ,
        QP.OBJECT_ID ,
        QP.index_id
ORDER BY session_id ,
        node_id
GO

Следующий снимок экрана показывает результат исполнения этого запроса для анализа показанного ранее запроса, нуждающегося в профилировании.

Просмотр статуса, ассоциированного с операторами задачи

Можно соединить sys.dm_exec_query_profiles
с sys.dm_os_tasks
иsys.dm_os_waiting_tasks по колонке task_address Посмотрите на следующий запрос:

SELECT  QP.session_id ,
        QP.node_id ,
        QP.physical_operator_name ,
        DB_NAME(database_id) + '.' + OBJECT_SCHEMA_NAME(QP.object_id,
                                                        qp.database_id) + '.'
        + OBJECT_NAME(QP.object_id, qp.database_id) [Object Name] ,
        OT.task_state ,
        MAX(WT.wait_duration_ms) [wait_duration_ms] ,
        WT.wait_type
FROM    sys.dm_exec_query_profiles QP
        INNER JOIN sys.dm_os_tasks OT 
   ON OT.task_address = QP.task_address
        LEFT  JOIN sys.dm_os_waiting_tasks WT 
   ON WT.waiting_task_address = QP.task_address
GROUP BY QP.session_id ,
        QP.node_id ,
        QP.physical_operator_name ,
        OT.task_state ,
        QP.database_id ,
        QP.object_id ,
        WT.wait_type
GO      
 

Как можно видеть на скриншоте ниже, для анализируемого в предыдущем примере запроса мы располагаем информацией о состоянии
задачи для каждого физического оператора, его тип ожидания и о продолжительности исполнения, если это применимо.

Estimated Percentage of Completion

Просмотр статуса, ассоциированного с операторами задачи

Можно соединить sys.dm_exec_query_profiles с sys.dm_os_tasks и sys.dm_os_waiting_tasks
по колонке task_address Посмотрите на следующий запрос:

SELECT  QP.session_id ,
        QP.node_id ,
        QP.physical_operator_name ,
        DB_NAME(database_id) + '.' + OBJECT_SCHEMA_NAME(QP.object_id,
                                                        qp.database_id) + '.'
        + OBJECT_NAME(QP.object_id, qp.database_id) [Object Name] ,
        OT.task_state ,
        MAX(WT.wait_duration_ms) [wait_duration_ms] ,
        WT.wait_type
FROM    sys.dm_exec_query_profiles QP
        INNER JOIN sys.dm_os_tasks OT 
   ON OT.task_address = QP.task_address
        LEFT  JOIN sys.dm_os_waiting_tasks WT 
   ON WT.waiting_task_address = QP.task_address
GROUP BY QP.session_id ,
        QP.node_id ,
        QP.physical_operator_name ,
        OT.task_state ,
        QP.database_id ,
        QP.object_id ,
        WT.wait_type
GO
 

Как можно видеть на скриншоте ниже, для анализируемого в предыдущем примере запроса мы располагаем информацией о состоянии задачи для каждого физического оператора,
его тип ожидания и о продолжительности исполнения, если это применимо.

Associated Task Status

Комментариев нет:

Отправить комментарий