Cómo las actualizaciones automáticas de las estadísticas pueden afectar el rendimiento de las consultas

En mi publicación anterior, exploré diferentes métodos para realizar un seguimiento de las actualizaciones automáticas de las estadísticas para determinar si estaban afectando el rendimiento de las consultas. En la segunda mitad de la publicación, incluí opciones, una de las cuales era habilitar la configuración de la base de datos de actualización automática de estadísticas de forma asíncrona. En esta publicación, quiero ver cómo cambia el rendimiento de las consultas cuando se produce la actualización automática antes de la ejecución de la consulta y qué sucede con el rendimiento si la actualización es asíncrona.

La configuración

Comencé con una copia de la base de datos AdventureWorks2012 y luego creé una copia de la tabla SalesOrderHeader con más de 200 millones de filas usando este script. La tabla tiene un índice agrupado en SalesOrderID y un índice no agrupado en CustomerID, OrderDate, SubTotal. [Nota:si va a realizar pruebas repetidas, realice una copia de seguridad de esta base de datos en este punto para ahorrar tiempo]. Después de cargar los datos y crear el índice no agrupado, verifiqué el recuento de filas y calculé cuántas filas (aproximadamente) tendrían que modificarse para invocar una actualización automática.

SELECT
OBJECT_NAME([p].[object_id]) [TableName],
[si].[name] [IndexName],
[au].[type_desc] [Type],
[p].[rows] [RowCount],
([p].[rows]*.20) + 500 [UpdateThreshold],
[au].total_pages [PageCount],
(([au].[total_pages]*8)/1024)/1024 [TotalGB]
FROM [sys].[partitions] [p]
JOIN [sys].[allocation_units] [au] ON [p].[partition_id] = [au].[container_id]
JOIN [sys].[indexes] [si] on [p].[object_id] = [si].object_id and [p].[index_id] = [si].[index_id]
WHERE [p].[object_id] = OBJECT_ID(N'Sales.Big_SalesOrderHeader');

Información de CIX y NCI de Big_SalesOrderHeader

También verifiqué el encabezado de estadísticas actual para el índice:

DBCC SHOW_STATISTICS ('Sales.Big_SalesOrderHeader',[IX_Big_SalesOrderHeader_CustomerID_OrderDate_SubTotal]);

Estadísticas del NCI:al inicio

Luego creé el procedimiento almacenado que usaría para probar. Es un procedimiento sencillo que consulta Sales.Big_SalesOrderHeader y agrega datos de ventas por CustomerID y OrderDate para su análisis:

CREATE PROCEDURE Sales.usp_GetCustomerStats
@CustomerID INT,
@StartDate DATETIME,
@EndDate DATETIME
AS
BEGIN
  SET NOCOUNT ON;
 
  SELECT CustomerID, DATEPART(YEAR, OrderDate), DATEPART(MONTH, OrderDate), COUNT([SalesOrderID]) as Computed
    FROM [Sales].[Big_SalesOrderHeader]
    WHERE CustomerID = @CustomerID
    AND OrderDate BETWEEN @StartDate and @EndDate
    GROUP BY CustomerID, DATEPART(YEAR, OrderDate), DATEPART(MONTH, OrderDate)
    ORDER BY DATEPART(YEAR, OrderDate), DATEPART(MONTH, OrderDate);
END

Finalmente, antes de ejecutar el procedimiento almacenado, creé una sesión de eventos extendidos para poder rastrear la duración de la consulta usando sp_statement_starting y sp_statement_completed. También agregué el evento auto_stats, porque aunque no esperaba que ocurriera una actualización, quería usar esta misma definición de sesión más tarde.

CREATE EVENT SESSION [StatsUpdate_QueryPerf]
ON SERVER
ADD EVENT sqlserver.auto_stats,
ADD EVENT sqlserver.sp_statement_completed(
SET collect_statement=(1)
),
ADD EVENT sqlserver.sp_statement_starting
ADD TARGET package0.event_file(
SET filename=N'C:\temp\StatsUpdate_QueryPerf.xel'
)
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=ON,STARTUP_STATE=OFF);
GO

La prueba

Inicié la sesión de eventos extendidos y luego ejecuté el procedimiento almacenado varias veces, usando diferentes ID de cliente:

ALTER EVENT SESSION [StatsUpdate_QueryPerf]
ON SERVER
STATE = START;
GO
 
EXEC Sales.usp_GetCustomerStats 11331, '2012-08-01 00:00:00.000', '2012-08-31 23:59:59.997'
GO
EXEC Sales.usp_GetCustomerStats 11330, '2013-01-01 00:00:00.000', '2013-01-31 23:59:59.997'
GO
EXEC Sales.usp_GetCustomerStats 11506, '2012-11-01 00:00:00.000', '2012-11-30 23:59:59.997'
GO
EXEC Sales.usp_GetCustomerStats 17061, '2013-01-01 00:00:00.000', '2013-01-31 23:59:59.997'
GO
EXEC Sales.usp_GetCustomerStats 11711, '2013-03-01 00:00:00.000', '2013-03-31 23:59:59.997'
GO
EXEC Sales.usp_GetCustomerStats 15131, '2013-02-01 00:00:00.000', '2013-02-28 23:59:59.997'
GO
EXEC Sales.usp_GetCustomerStats 29837, '2012-10-01 00:00:00.000', '2012-10-31 23:59:59.997'
GO
EXEC Sales.usp_GetCustomerStats 15750, '2013-03-01 00:00:00.000', '2013-03-31 23:59:59.997'
GO

Verifiqué el conteo de ejecuciones y el plan consultando el caché de procedimientos:

SELECT
OBJECT_NAME([st].[objectid]),
[st].[text],
[qs].[execution_count],
[qs].[creation_time],
[qs].[last_execution_time],
[qs].[min_worker_time],
[qs].[max_worker_time],
[qs].[min_logical_reads],
[qs].[max_logical_reads],
[qs].[min_elapsed_time],
[qs].[max_elapsed_time],
[qp].[query_plan]
FROM [sys].[dm_exec_query_stats] [qs]
CROSS APPLY [sys].[dm_exec_sql_text]([qs].plan_handle) [st]
CROSS APPLY [sys].[dm_exec_query_plan]([qs].plan_handle) [qp]
WHERE [st].[text] LIKE '%usp_GetCustomerStats%'
AND OBJECT_NAME([st].[objectid]) IS NOT NULL;

Planificar caché:al inicio

Plan de consulta para procedimiento almacenado, usando SQL Sentry Plan Explorer

Pude ver que el plan se creó en 2014-04-08 18:59:39.850. Con el plan en caché, detuve la sesión de eventos extendidos:

ALTER EVENT SESSION [StatsUpdate_QueryPerf]
ON SERVER
STATE = STOP;

A continuación, agregué alrededor de 47 millones de filas de datos a la tabla usando este script, muy por encima del umbral necesario para invalidar las estadísticas actuales. Después de agregar los datos, verifiqué el número de filas en la tabla:

Big_SalesOrderHeader CI:después de la carga de datos

Antes de volver a ejecutar mi procedimiento almacenado, revisé el caché del plan para asegurarme de que nada había cambiado y verifiqué que las estadísticas aún no se habían actualizado. Recuerde, aunque las estadísticas se invalidaron en este punto, no se actualizarán hasta que se ejecute una consulta que use la estadística (para referencia:Comprender cuándo se actualizarán automáticamente las estadísticas). Para el paso final, comencé la sesión de eventos extendidos nuevamente y luego ejecuté el procedimiento almacenado varias veces. Después de esas ejecuciones, revisé el caché del plan nuevamente:

Plan Cache:después de la carga de datos

La cuenta_ejecución es 8 nuevamente, y si observamos la hora_creación del plan, podemos ver que ha cambiado a 2014-04-08 19:32:52.913. Si revisamos el plan, podemos ver que es el mismo, aunque el plan fue recompilado:

Plan de consulta para procedimiento almacenado, usando SQL Sentry Plan Explorer

Análisis de salida de eventos extendidos

Tomé el primer archivo de eventos extendidos, antes de que se cargaran los datos, y lo abrí en SSMS, luego apliqué un filtro para que solo se enumeraran las declaraciones del procedimiento almacenado:

Salida de eventos extendidos:después de la ejecución inicial del SP

Puede ver que hay ocho (8) ejecuciones del procedimiento almacenado, con duraciones de consulta que varían ligeramente.

Tomé el segundo archivo de eventos extendidos, después de que se cargaron los datos, lo abrí SSMS y lo filtré nuevamente para que solo se enumeraran las declaraciones del procedimiento almacenado, así como los eventos de auto_stats:

Salida de eventos extendidos:ejecución del SP después de la carga de datos

La salida se trunca, ya que no se necesita todo para mostrar el resultado principal. Las entradas resaltadas en azul representan la primera ejecución del procedimiento almacenado y tenga en cuenta que hay varios pasos:la actualización de las estadísticas es parte de la ejecución. Se inicia la instrucción SELECT (attach_activity_id.seq =3), y luego se ejecutan las actualizaciones de las estadísticas. En nuestro ejemplo, en realidad tenemos actualizaciones de tres estadísticas. Una vez que se completa la última actualización (adjuntar_actividad_id.seq =11), el procedimiento almacenado comienza y finaliza (adjuntar_actividad_id.seq =13 y adjuntar_actividad_id.seq =14). Curiosamente, hay un segundo evento sp_statement_starting para el procedimiento almacenado (presumiblemente, el primero se ignora), por lo que la duración total del procedimiento almacenado se calcula sin la actualización de las estadísticas.

En este escenario, hacer que las estadísticas se actualicen automáticamente de inmediato, es decir, cuando se ejecuta una consulta que usa estadísticas invalidadas, hace que la consulta se ejecute por más tiempo, aunque la duración de la consulta basada en el evento sp_statement_completed aún sea inferior a 14000. El resultado final es que no no hay ningún beneficio para el rendimiento de las consultas, ya que el plan es exactamente el mismo antes y después de la actualización de las estadísticas. En este escenario, el plan de consulta y la duración de la ejecución no cambian después de agregar más datos a la tabla, por lo que la actualización de las estadísticas solo dificulta su rendimiento. Ahora veamos qué sucede cuando activamos la opción Actualización automática de estadísticas de forma asíncrona.

La Prueba, Versión 2

Comenzamos restaurando la copia de seguridad que hice antes de comenzar la primera prueba. Recreé el procedimiento almacenado y luego cambié la opción de la base de datos para actualizar las estadísticas de forma asíncrona:

USE [master];
GO
ALTER DATABASE [AdventureWorks2012_Big] SET AUTO_UPDATE_STATISTICS_ASYNC ON WITH NO_WAIT
GO

Inicié la sesión de eventos extendidos y nuevamente ejecuté el procedimiento almacenado varias veces, usando diferentes ID de cliente:

ALTER EVENT SESSION [StatsUpdate_QueryPerf]
ON SERVER
STATE = START;
GO
 
EXEC Sales.usp_GetCustomerStats11331, '2012-08-01 00:00:00.000', '2012-08-31 23:59:59.997'
GO
EXEC Sales.usp_GetCustomerStats11330, '2013-01-01 00:00:00.000', '2013-01-31 23:59:59.997'
GO
EXEC Sales.usp_GetCustomerStats11506, '2012-11-01 00:00:00.000', '2012-11-30 23:59:59.997'
GO
EXEC Sales.usp_GetCustomerStats17061, '2013-01-01 00:00:00.000', '2013-01-31 23:59:59.997'
GO
EXEC Sales.usp_GetCustomerStats11711, '2013-03-01 00:00:00.000', '2013-03-31 23:59:59.997'
GO
EXEC Sales.usp_GetCustomerStats15131, '2013-02-01 00:00:00.000', '2013-02-28 23:59:59.997'
GO
EXEC Sales.usp_GetCustomerStats29837, '2012-10-01 00:00:00.000', '2012-10-31 23:59:59.997'
GO
EXEC Sales.usp_GetCustomerStats15750, '2013-03-01 00:00:00.000', '2013-03-31 23:59:59.997'
GO

Verifiqué el conteo de ejecuciones y el plan consultando el caché de procedimientos:

Planificar caché:al inicio, prueba 2

Plan de consulta para procedimiento almacenado, usando SQL Sentry Plan Explorer

Para esta prueba, el plan se creó en 2014-04-08 21:15:55.490. Detuve la sesión de Eventos extendidos y nuevamente agregué alrededor de 47 millones de filas de datos a la tabla, usando la misma consulta que antes.

Una vez que se agregaron los datos, revisé el caché del plan para asegurarme de que nada había cambiado y verifiqué que las estadísticas aún no se habían actualizado. Finalmente, volví a iniciar la sesión de eventos extendidos y luego ejecuté el procedimiento almacenado ocho veces más. Un último vistazo a la memoria caché del plan mostró el recuento de ejecución en 16 y un tiempo de creación de 2014-04-08 21:15:55.490. El recuento de ejecución y el tiempo de creación demuestran que las estadísticas no se han actualizado, ya que el plan aún no se ha vaciado de la memoria caché (si lo hubiera hecho, tendríamos un tiempo de creación posterior y un recuento de ejecución de 8).

Planificar caché:después de la carga de datos, prueba 2

Si abrimos la salida de eventos extendidos después de la carga de datos en SSMS y volvemos a filtrar para que solo veamos las declaraciones del procedimiento almacenado, así como los eventos de auto_stats, encontramos esto (tenga en cuenta que la salida se divide en dos capturas de pantalla):

Salida de eventos extendida:prueba 2, ejecución del SP después de la carga de datos, parte I

Salida de eventos extendidos:prueba 2, ejecución del SP después de la carga de datos, parte II

Los eventos para la ejecución de la primera llamada del procedimiento almacenado están resaltados en azul:comienzan en 2014-04-08 21:54:14.9480607 y hay siete (7) eventos. Tenga en cuenta que hay tres (3) eventos de auto_stats, pero ninguno de ellos se completa realmente, como vimos cuando se deshabilitó la opción Actualizar automáticamente las estadísticas de forma asíncrona. Notará que la actualización automática comienza para una de las estadísticas casi inmediatamente (2014-04-08 21:54:14.9481288), y sus tres eventos tienen el texto rojo 'Stat Update #1' junto a ellos. Esa actualización de estadísticas finaliza en 2014-04-08 21:54:16.5392219, poco menos de dos segundos después de que comience, pero después de que se hayan completado todas las demás ejecuciones del procedimiento. Esta es la razón por la cual el recuento de ejecución de sys.dm_exec_query_stats muestra 16. Desde la salida de XE, podemos ver que las otras actualizaciones de estadísticas luego se completan (Actualización de estadísticas #2 y Actualización de estadísticas #3). Todas las actualizaciones son asincrónicas a la ejecución del procedimiento almacenado inicial.

Resumen

Como puede ver, las actualizaciones automáticas de las estadísticas tienen el potencial de afectar negativamente el rendimiento de las consultas. El grado de impacto dependerá de la cantidad de datos que haya que leer para actualizar la estadística y los recursos del sistema. En algunos casos, el rendimiento de las consultas solo aumenta en milisegundos y es muy probable que sea imperceptible para los usuarios. Otras veces, la duración puede aumentar drásticamente, lo que afecta la experiencia del usuario final. En caso de que el plan de consulta no cambie después de una actualización de las estadísticas, vale la pena considerar habilitar la opción Actualización automática de estadísticas de forma asíncrona para mitigar el impacto en el rendimiento de la consulta.