SQL Server 2016:sys.dm_exec_function

No SQL Server 2016 CTP 2.1, há um novo objeto que apareceu após o CTP 2.0:sys.dm_exec_function_stats. O objetivo é fornecer funcionalidade semelhante a sys.dm_exec_procedure_stats, sys.dm_exec_query_stats e sys.dm_exec_trigger_stats.

Portanto, agora é possível rastrear métricas de tempo de execução agregadas para funções definidas pelo usuário.

Ou é?

No CTP 2.1, pelo menos, eu só poderia derivar quaisquer métricas significativas aqui para funções escalares regulares – nada foi registrado para TVFs inline ou multi-statement. Não estou surpreso com as funções embutidas, pois elas são essencialmente expandidas antes da execução. Mas como os TVFs de várias instruções geralmente são problemas de desempenho, eu esperava que eles também aparecessem. Eles ainda aparecem em sys.dm_exec_query_stats, então você ainda pode derivar suas métricas de desempenho a partir daí, mas pode ser complicado realizar agregações quando você realmente tem várias instruções que realizam parte do trabalho – nada é acumulado para você.

Vamos dar uma olhada rápida em como isso acontece. Digamos que temos uma tabela simples com 100.000 linhas:

SELECT TOP (100000) o1.[object_id], o1.create_date
  INTO dbo.src
  FROM sys.all_objects AS o1
  CROSS JOIN sys.all_objects AS o2
  ORDER BY o1.[object_id];
GO
CREATE CLUSTERED INDEX x ON dbo.src([object_id]);
GO
-- prime the cache
SELECT [object_id], create_date FROM dbo.src;

Eu queria comparar o que acontece quando investigamos UDFs escalares, funções com valor de tabela de várias instruções e funções com valor de tabela em linha, e como vemos qual trabalho foi feito em cada caso. Primeiro, imagine algo trivial que podemos fazer no SELECT cláusula, mas que podemos querer compartimentalizar, como formatar uma data como uma string:

CREATE PROCEDURE dbo.p_dt_Standard
  @dt_ CHAR(10) = NULL
AS
BEGIN
  SET NOCOUNT ON;
  SELECT @dt_ = CONVERT(CHAR(10), create_date, 120)
    FROM dbo.src
    ORDER BY [object_id];
END
GO

(Eu atribuo a saída a uma variável, o que força a verificação de toda a tabela, mas impede que as métricas de desempenho sejam influenciadas pelos esforços do SSMS para consumir e renderizar a saída. Obrigado pelo lembrete, Mikael Eriksson.)

Muitas vezes você verá pessoas colocando essa conversão em uma função, e ela pode ser escalar ou TVF, como estas:

CREATE FUNCTION dbo.dt_Inline(@dt_ DATETIME)
RETURNS TABLE
AS
  RETURN (SELECT dt_ = CONVERT(CHAR(10), @dt_, 120));
GO
 
CREATE FUNCTION dbo.dt_Multi(@dt_ DATETIME)
RETURNS @t TABLE(dt_ CHAR(10))
AS
BEGIN
  INSERT @t(dt_) SELECT CONVERT(CHAR(10), @dt_, 120);
  RETURN;
END
GO
 
CREATE FUNCTION dbo.dt_Scalar(@dt_ DATETIME)
RETURNS CHAR(10)
AS
BEGIN
  RETURN (SELECT CONVERT(CHAR(10), @dt_, 120));
END
GO

Eu criei wrappers de procedimento em torno dessas funções da seguinte forma:

CREATE PROCEDURE dbo.p_dt_Inline
  @dt_ CHAR(10) = NULL
AS
BEGIN
  SET NOCOUNT ON;
  SELECT @dt_ = dt.dt_
    FROM dbo.src AS o
    CROSS APPLY dbo.dt_Inline(o.create_date) AS dt
    ORDER BY o.[object_id];
END
GO
 
CREATE PROCEDURE dbo.p_dt_Multi
  @dt_ CHAR(10) = NULL
AS
BEGIN
  SET NOCOUNT ON;
  SELECT @dt_ = dt.dt_
    FROM dbo.src
    CROSS APPLY dbo.dt_Multi(create_date) AS dt
    ORDER BY [object_id];
END
GO
 
CREATE PROCEDURE dbo.p_dt_Scalar
  @dt_ CHAR(10) = NULL
AS
BEGIN
  SET NOCOUNT ON;
  SELECT @dt_ = dt = dbo.dt_Scalar(create_date)
    FROM dbo.src
    ORDER BY [object_id];
END
GO

(E não, o dt_ convenção que você está vendo não é uma coisa nova que eu acho que é uma boa ideia, foi apenas a maneira mais simples que eu poderia isolar todas essas consultas nos DMVs de todo o resto sendo coletado. Também facilitou anexar sufixos para distinguir facilmente entre a consulta dentro do procedimento armazenado e a versão ad hoc.)

Em seguida, criei uma tabela #temp para armazenar tempos e repeti esse processo (executando o procedimento armazenado duas vezes e executando o corpo do procedimento como uma consulta ad hoc isolada duas vezes e acompanhando o tempo de cada um):

CREATE TABLE #t
(
  ID INT IDENTITY(1,1), 
  q VARCHAR(32), 
  s DATETIME2, 
  e DATETIME2
);
GO
 
INSERT #t(q,s) VALUES('p Standard',SYSDATETIME());
GO
 
EXEC dbo.p_dt_Standard;
GO 2
 
UPDATE #t SET e = SYSDATETIME() WHERE ID = 1;
GO
 
INSERT #t(q,s) VALUES('ad hoc Standard',SYSDATETIME());
GO
 
DECLARE @dt_st CHAR(10);
  SELECT @dt_st = CONVERT(CHAR(10), create_date, 120)
    FROM dbo.src
    ORDER BY [object_id];
GO 2
 
UPDATE #t SET e = SYSDATETIME() WHERE ID = 2;
GO
-- repeat for inline, multi and scalar versions

Em seguida, executei algumas consultas de diagnóstico e aqui estavam os resultados:

sys.dm_exec_function_stats

SELECT name = OBJECT_NAME(object_id), 
  execution_count,
  time_milliseconds = total_elapsed_time/1000
FROM sys.dm_exec_function_stats
WHERE database_id = DB_ID()
ORDER BY name;

Resultados:

name        execution_count    time_milliseconds
---------   ---------------    -----------------
dt_Scalar   400000             1116

Isso não é um erro de digitação; apenas a UDF escalar mostra alguma presença no novo DMV.

sys.dm_exec_procedure_stats

SELECT name = OBJECT_NAME(object_id), 
  execution_count,
  time_milliseconds = total_elapsed_time/1000
FROM sys.dm_exec_procedure_stats
WHERE database_id = DB_ID()
ORDER BY name;

Resultados:

name            execution_count    time_milliseconds
-------------   ---------------    -----------------
p_dt_Inline     2                  74
p_dt_Multi      2                  269
p_dt_Scalar     2                  1063
p_dt_Standard   2                  75

Este não é um resultado surpreendente:o uso de uma função escalar leva a uma penalidade de desempenho de ordem de magnitude, enquanto o TVF multi-instrução foi apenas cerca de 4x pior. Em vários testes, a função inline sempre foi tão rápida ou um milissegundo ou dois mais rápida do que nenhuma função.

sys.dm_exec_query_stats

SELECT 
  query = SUBSTRING([text],s,e), 
  execution_count, 
  time_milliseconds
FROM
(
  SELECT t.[text],
    s = s.statement_start_offset/2 + 1,
    e = COALESCE(NULLIF(s.statement_end_offset,-1),8000)/2,
    s.execution_count,
    time_milliseconds = s.total_elapsed_time/1000
  FROM sys.dm_exec_query_stats AS s
  OUTER APPLY sys.dm_exec_sql_text(s.[sql_handle]) AS t
  WHERE t.[text] LIKE N'%dt[_]%' 
) AS x;

Resultados truncados, reordenados manualmente:

query (truncated)                                                       execution_count    time_milliseconds
--------------------------------------------------------------------    ---------------    -----------------
-- p Standard:
SELECT @dt_ = CONVERT(CHAR(10), create_date, 120) ...                   2                  75
-- ad hoc Standard:
SELECT @dt_st = CONVERT(CHAR(10), create_date, 120) ...                 2                  72
 
-- p Inline:
SELECT @dt_ = dt.dt_ FROM dbo.src AS o CROSS APPLY dbo.dt_Inline...     2                  74
-- ad hoc Inline:
SELECT @dt_in = dt.dt_ FROM dbo.src AS o CROSS APPLY dbo.dt_Inline...   2                  72
 
-- all Multi:
INSERT @t(dt_) SELECT CONVERT(CHAR(10), @dt_, 120);                     184                5
-- p Multi:
SELECT @dt_ = dt.dt_ FROM dbo.src CROSS APPLY dbo.dt_Multi...           2                  270
-- ad hoc Multi:
SELECT @dt_m = dt.dt_ FROM dbo.src AS o CROSS APPLY dbo.dt_Multi...     2                  257
 
-- all scalar:
RETURN (SELECT CONVERT(CHAR(10), @dt_, 120));                           400000             581
-- p Scalar:
SELECT @dt_ = dbo.dt_Scalar(create_date)...                             2                  986
-- ad hoc Scalar:
SELECT @dt_sc = dbo.dt_Scalar(create_date)...                           2                  902

Uma coisa importante a notar aqui é que o tempo em milissegundos para o INSERT no TVF multi-instrução e o comando RETURN na função escalar também são contabilizados dentro dos SELECTs individuais, então não faz sentido apenas somar todos os os horários.

Cronogramas manuais

E, finalmente, os tempos da tabela #temp:

SELECT query = q, 
    time_milliseconds = DATEDIFF(millisecond, s, e) 
  FROM #t 
  ORDER BY ID;

Resultados:

query             time_milliseconds
---------------   -----------------
p Standard        107
ad hoc Standard   78
p Inline          80
ad hoc Inline     78
p Multi           351
ad hoc Multi      263
p Scalar          992
ad hoc Scalar     907

Resultados interessantes adicionais aqui:o wrapper do procedimento sempre teve alguma sobrecarga, embora o quão significativo isso possa ser realmente subjetivo.

Resumo

Meu ponto aqui hoje era apenas mostrar o novo DMV em ação e definir as expectativas corretamente - algumas métricas de desempenho para funções ainda serão enganosas e algumas ainda não estarão disponíveis (ou pelo menos será muito tedioso juntar as peças por si mesmo ).

Eu acho que esse novo DMV cobre uma das maiores partes do monitoramento de consulta que o SQL Server estava faltando antes:que as funções escalares às vezes são assassinos de desempenho invisíveis, porque a única maneira confiável de identificar seu uso era analisar o texto da consulta, que está longe de ser infalível. Não importa o fato de que isso não permitirá que você isole seu impacto no desempenho ou que você precise saber para procurar UDFs escalares no texto da consulta em primeiro lugar.

Apêndice

Anexei o script:DMExecFunctionStats.zip

Além disso, a partir do CTP1, aqui está o conjunto de colunas:

`database_id`	`object_id`	`type`	`type_desc`
`sql_handle`	`plan_handle`	`cached_time`	`last_execution_time`	`execution_count`
`total_worker_time`	`last_worker_time`	`min_worker_time`	`max_worker_time`
`total_physical_reads`	`last_physical_reads`	`min_physical_reads`	`max_physical_reads`
`total_logical_writes`	`last_logical_writes`	`min_logical_writes`	`max_logical_writes`
`total_logical_reads`	`last_logical_reads`	`min_logical_reads`	`max_logical_reads`
`total_elapsed_time`	`last_elapsed_time`	`min_elapsed_time`	`max_elapsed_time`

Colunas atualmente em sys.dm_exec_function_stats

SQL Server 2016:sys.dm_exec_function_stats

sys.dm_exec_function_stats

sys.dm_exec_procedure_stats

sys.dm_exec_query_stats

Cronogramas manuais

Resumo

Apêndice