Capturar avisos do plano de execução usando eventos estendidos

Estamos ensinando IEPTO2 em Dublin esta semana (e se a Irlanda não estiver na sua lista de lugares para ver nesta vida, você deve adicioná-la… é fantástico aqui) e hoje finalizei o módulo Query Plan Analysis. Uma coisa que abordo são coisas interessantes que você pode encontrar no plano de consulta, por exemplo:

NoJoinPredicate (2005 e superior)
ColumnsWithNoStatistics (2005 e superior)
Indexes sem correspondência (2008 e superior)
PlanAffectingConvert (2012 e superior)

Esses atributos são bons para procurar quando você está olhando para um único plano, ou conjunto de planos, enquanto está ajustando. Mas se você quiser ser um pouco mais proativo, pode começar a minerar o cache do plano e procurá-los lá. Claro, isso requer escrever algum XQuery, já que os planos são XML (para detalhes sobre o esquema showplan, confira:http://schemas.microsoft.com/sqlserver/2004/07/showplan/). Eu não gosto de XML, embora não por falta de tentativa, e quando um dos participantes perguntou se você poderia capturar consultas que tinham o atributo NoJoinPredicate por meio de Eventos Estendidos, pensei:“Que ótima ideia, vou ter que verificar .”

Com certeza, há um evento para isso. Há um evento para todos os quatro que listei acima:

missing_join_predicate
missing_column_statistics
unmatched_filtered_indexes
plan_affecting_convert

Legal. Configurá-los em uma sessão de eventos estendidos é bastante simples. Nesse caso, eu recomendaria usar o destino event_file, pois você provavelmente iniciará a sessão do evento e a deixará executar um pouco antes de voltar e revisar a saída. Incluí algumas ações, com a esperança de que esses eventos não sejam disparados isso frequentemente, então não estamos adicionando muita sobrecarga aqui. Eu incluí sql_text mesmo que não seja uma ação na qual você realmente deva confiar. Jonathan já discutiu isso antes, mas sql_text está apenas fornecendo o buffer de entrada, então você pode não estar recebendo a história completa da consulta. Por esse motivo, também incluí plan_handle. A ressalva é que, dependendo de quando você for procurar o plano, ele pode não estar mais no cache do plano.

-- Remove event session if it exists
IF EXISTS (SELECT 1 FROM [sys].[server_event_sessions]
WHERE [name] = 'InterestingPlanEvents')
BEGIN
  DROP EVENT SESSION [InterestingPlanEvents] ON SERVER
END
GO
 
-- Define event session
CREATE EVENT SESSION [InterestingPlanEvents]
ON SERVER
ADD EVENT sqlserver.missing_column_statistics
(
  ACTION(sqlserver.database_id,sqlserver.plan_handle,sqlserver.sql_text)
  WHERE ([package0].[equal_boolean]([sqlserver].[is_system],(0))
    AND [sqlserver].[database_id]>(4))
),
ADD EVENT sqlserver.missing_join_predicate
(
  ACTION(sqlserver.database_id,sqlserver.plan_handle,sqlserver.sql_text)
  WHERE ([sqlserver].[is_system]=(0) AND [sqlserver].[database_id]>(4))
),
ADD EVENT sqlserver.plan_affecting_convert
(
  ACTION(sqlserver.database_id,sqlserver.plan_handle,sqlserver.sql_text)
  WHERE ([package0].[equal_boolean]([sqlserver].[is_system],(0))
    AND [sqlserver].[database_id]>(4))
),
ADD EVENT sqlserver.unmatched_filtered_indexes
(
  ACTION(sqlserver.plan_handle,sqlserver.sql_text)
  WHERE ([package0].[equal_boolean]([sqlserver].[is_system],(0))
    AND [sqlserver].[database_id]>(4))
)
ADD TARGET package0.event_file
(
  SET filename=N'C:\temp\InterestingPlanEvents' /* change location if appropriate */
)
WITH (MAX_MEMORY=4096 KB,EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,
MAX_DISPATCH_LATENCY=5 SECONDS,MAX_EVENT_SIZE=0 KB,MEMORY_PARTITION_MODE=NONE,
TRACK_CAUSALITY=ON,STARTUP_STATE=OFF)
GO
 
-- Start the event session
ALTER EVENT SESSION [InterestingPlanEvents] ON SERVER STATE=START;
GO

Assim que tivermos a sessão de eventos em funcionamento, podemos gerar esses eventos com o código de exemplo abaixo. Observe que esse código pressupõe uma nova instalação do AdventureWorks2014. Se você não tiver um, talvez não veja o evento missing_column_statistics ser acionado se for consultado na coluna [HireDate] em [HumanResources].[Employee].

-- These queries assume a FRESH restore of AdventureWorks2014
ALTER DATABASE [AdventureWorks2014] SET AUTO_CREATE_STATISTICS OFF;
GO
 
USE [AdventureWorks2014];
GO
 
CREATE INDEX [NCI_SalesOrderHeader] ON [Sales].[SalesOrderHeader] (
[PurchaseOrderNumber], [CustomerID], [TotalDue], [DueDate]
)
WHERE [SubTotal] &gt; 10000.00;
GO
 
/*
No join predicate
NOTE: We clear procedure here because the event ONLY fires for the *initial* compilation
*/
DBCC FREEPROCCACHE; /* Not for production use */
 
SELECT [h].[SalesOrderID], [d].[SalesOrderDetailID], [h].[CustomerID]
FROM [Sales].[SalesOrderDetail] [d],
[Sales].[SalesOrderHeader] [h]
WHERE [d].[ProductID] = 897;
GO
 
-- Columns with no statistics
SELECT [BusinessEntityID], [NationalIDNumber], [JobTitle], [HireDate], [ModifiedDate]
FROM [HumanResources].[Employee]
WHERE [HireDate] &gt;= '2013-01-01';
GO
 
-- Unmatched Index
DECLARE @Total MONEY = 10000.00;
 
SELECT [PurchaseOrderNumber], [CustomerID], [TotalDue], [DueDate]
FROM [Sales].[SalesOrderHeader]
WHERE [SubTotal] &gt; @Total;
GO
 
-- Plan Affecting Convert
SELECT [BusinessEntityID], [NationalIDNumber], [JobTitle], [HireDate], [ModifiedDate]
FROM [HumanResources].[Employee]
WHERE [NationalIDNumber] = 345106466;
GO
 
ALTER EVENT SESSION [InterestingPlanEvents]
ON SERVER
STATE=STOP;
GO
 
DROP EVENT SESSION [InterestingPlanEvents]
ON SERVER;
GO

OBSERVAÇÃO:DEPOIS de terminar de extrair os planos do cache, você pode executar a instrução ALTER para habilitar a opção de criação automática de estatísticas. Fazer isso neste ponto limpará o cache do plano e você terá que começar tudo de novo com seus testes. (E também espere até terminar para descartar o índice.)

ALTER DATABASE [AdventureWorks2014] SET AUTO_CREATE_STATISTICS ON;
GO
 
DROP INDEX [NCI_SalesOrderHeader] ON [Sales].[SalesOrderHeader];
GO

Como parei a sessão do evento, abrirei o arquivo de saída no SSMS para ver o que capturamos:

Saída de eventos estendidos

Para nossa primeira consulta com um predicado de junção ausente, temos um evento que aparece e posso ver o texto da consulta no campo sql_text. No entanto, o que eu realmente quero é olhar para o plano também, para que eu possa pegar o plan_handle e verificar sys.dm_exec_query_plan:

SELECT query_plan FROM sys.dm_exec_query_plan
(0x06000700E2200333405DD12C0000000001000000000000000000000000000000000000000000000000000000);

E abrindo isso no SQL Sentry Plan Explorer:

Predicado de junção ausente

O plano tem um indicador visual do predicado de junção ausente no loop aninhado (o X vermelho) e, se eu passar o mouse sobre ele, vejo o aviso (e está no XML do plano). Excelente… agora posso falar com meus desenvolvedores sobre como reescrever esta consulta.

O próximo evento é para uma estatística de coluna ausente. Forcei completamente essa situação desativando AUTO_CREATE_STATISTICS para o banco de dados AdventureWorks2014. Eu não recomendo isso de forma alguma, forma ou forma. Essa opção está habilitada por padrão e recomendo sempre deixá-la habilitada. No entanto, desativá-lo é a maneira mais fácil de gerar esse evento. Eu novamente tenho a consulta no campo sql_text, mas vou usar o plan_handle novamente para puxar o plano:

SELECT query_plan FROM sys.dm_exec_query_plan
(0x060007004448323810921C360000000001000000000000000000000000000000000000000000000000000000);

Estatística ausente

E novamente temos uma dica visual (o triângulo amarelo com o ponto de exclamação) para indicar que há um problema com o plano e, novamente, está no XML. A partir daqui, primeiro verificaria se AUTO_CREATE_STATISTICS está desabilitado e, caso contrário, começaria a executar a consulta no Management Studio para ver se posso recriar o aviso (e forçar as estatísticas a serem criadas).

Agora, os eventos restantes são um pouco mais interessantes.

Você notará que temos três eventos unmatched_filtered_indexes. Eu ainda tenho que determinar o porquê, mas estou trabalhando nisso e postarei nos comentários se/quando eu conseguir resolver. Por enquanto, basta que eu tenha o evento, e dentro do evento também podemos ver as informações do objeto para que eu saiba o índice em questão:

Índice NCI_SalesOrderHeader referenciado por evento de índice ausente

E posso novamente pegar o plan_handle para encontrar o plano de consulta:

Índice sem correspondência

Desta vez, vejo o aviso no operador SELECT, então sei que há algo que preciso investigar mais. Nesse caso, você tem opções para fazer com que o otimizador use o índice filtrado quando estiver usando parâmetros, e recomendo ler a postagem de Aaron para obter mais informações sobre o uso de índices filtrados.

Por último, temos nove eventos para plan_affecting_convert. Que diabos? Ainda estou descobrindo isso, mas usei a opção Track Causality para minha sessão de eventos (ao testar) para confirmar que todos os eventos fazem parte da mesma tarefa (eles são). Se você observar o elemento de expressão na saída, verá que ele muda um pouco (assim como compile_time), e isso aparece quando você observa os detalhes do aviso no Plan Explorer do SQL Sentry (veja a segunda captura de tela abaixo). Dentro da saída do evento, o elemento de expressão não diga-nos qual coluna está envolvida, o que é um começo, mas não é informação suficiente, então, novamente, precisamos pegar o plano:

SELECT query_plan FROM sys.dm_exec_query_plan
(0x0600070023747010E09E1C360000000001000000000000000000000000000000000000000000000000000000);

Plano que afeta a conversão

Detalhes da conversão do plano

Vemos novamente nosso amigo, o triângulo amarelo, no operador SELECT, e dentro do XML podemos encontrar o atributo PlanAffectingConvert. Esse atributo foi adicionado ao esquema do plano de exibição do SQL Server 2012, portanto, se você estiver executando uma versão anterior, não verá isso no plano. Resolver esse aviso pode exigir um pouco mais de trabalho – você precisa entender onde está havendo uma incompatibilidade de tipo de dados e por quê, e então começar a modificar o código ou o esquema… ambos podem encontrar resistência. Jonathan tem um post que discute a conversão implícita com mais detalhes, o que é um bom ponto de partida, caso você não tenha trabalhado com problemas de conversão anteriormente.

Resumo

A biblioteca de eventos Extended Events continua a crescer, e uma coisa a considerar ao solucionar problemas no SQL Server é se você pode obter as informações que está procurando de outra maneira. Talvez porque seja mais fácil (com certeza prefiro XE ao XML!), ou porque é mais eficiente, ou te dá mais detalhes. Se você está procurando proativamente por problemas de consulta em seu ambiente ou reagindo a um problema que alguém relatou, mas está tendo problemas para encontrá-lo, os eventos estendidos são uma opção viável a ser considerada, principalmente à medida que mais novos recursos são adicionados ao SQL Server.