Query Store SQL Server: cómo un plan forzado convirtió 10 minutos en 26 horas

Este artículo documenta un incidente real en un entorno de producción. Los nombres de servidores, bases de datos, tablas y empresa han sido modificados por confidencialidad. Los datos de rendimiento son reales.

El problema: una ETL que debería tardar 10 minutos lleva 26 horas ejecutándose

Era la mañana del 13 de marzo. El equipo de BI llegó al trabajo y encontró que una cadena ETL de Data Warehouse llevaba corriendo desde las 11:00 del día anterior — más de 22 horas. Lo normal: entre 2 y 4 horas.

No era la primera vez esa semana. El 11 de marzo la habían cancelado manualmente después de 30 horas sin que terminara. Y el día anterior, 12 de marzo, pasó exactamente lo mismo.

Sin errores visibles. Sin bloqueos. El proceso simplemente no avanzaba.

Este artículo documenta el diagnóstico completo de ese incidente real en un servidor SQL Server 2019 Enterprise de producción.

---

Entorno y contexto técnico

• SQL Server 2019 Enterprise sobre Windows Server
• Servidor de Data Warehouse de producción (listener AlwaysOn)
• Cadena ETL con más de 60 stored procedures encadenados que cargan un datamart de hechos y dimensiones
• Query Store habilitado en modo READ_WRITE con captura automática (220 MB / 1000 MB usados)

El punto de atasco siempre era el mismo: un INSERT INTO ... SELECT ... OUTER APPLY que carga una tabla de hechos desde una tabla temporal, correlacionándose con una tabla de dimensiones para resolver un ID de control histórico.

---

Fase 1: Diagnóstico de la sesión activa

SELECT
    r.session_id,
    r.status,
    r.blocking_session_id,
    r.wait_type,
    r.total_elapsed_time / 1000 AS elapsed_sec,
    r.cpu_time / 1000 AS cpu_sec,
    r.logical_reads,
    r.writes,
    r.granted_query_memory * 8 / 1024 AS memory_grant_mb
FROM sys.dm_exec_requests r
WHERE r.session_id > 50
  AND r.status != 'sleeping'
ORDER BY r.total_elapsed_time DESC;

Los datos de la sesión problemática eran inequívocos:

10 mil millones de lecturas lógicas en una query que normalmente hace ~57 millones. Es decir, 175 veces más lecturas de lo normal.

El wait type SOS_SCHEDULER_YIELD indica que el proceso está en un bucle de CPU puro, sin esperar I/O ni bloqueos. No hay deadlocks, no hay contención de recursos externos — el proceso simplemente está trabajando muchísimo más de lo que debería.

Wait stats detallados

SELECT
    wait_type,
    waiting_tasks_count,
    wait_time_ms / 1000.0 AS wait_time_sec
FROM sys.dm_exec_session_wait_stats
WHERE session_id = 
ORDER BY wait_time_ms DESC;

El CPU representa el ~100% del problema. No es disco, no es red, no son bloqueos. Es un plan de ejecución que hace 175 veces más trabajo del necesario.

---

Fase 2: La query problemática

-- Estructura anonimizada del INSERT que se quedaba atascado
INSERT INTO [destino].[hechos_operaciones]
SELECT
    T.cod_referencia,
    D.id_control,
    CONVERT(VARCHAR(8), @fecha, 112),
    -- resto de columnas
FROM tmp.hechos_origen T
OUTER APPLY (
    SELECT MAX(M.id_control) AS id_control
    FROM [destino].[dim_contratos] M
    WHERE T.cod_referencia = M.cod_referencia
      AND RIGHT(M.id_control, 8) <= CONVERT(VARCHAR(8), @fecha, 112)
) D;

El patrón es típico en cargas de datamarts tipo SCD (Slowly Changing Dimensions): para cada fila de la tabla de hechos, busca en la tabla de dimensiones el ID de control vigente en una fecha. El OUTER APPLY con MAX() es la forma natural de resolverlo en T-SQL.

Tamaño de las tablas involucradas:

---

Fase 3: Query Store — La causa raíz

-- Buscar planes activos para esta query en Query Store
SELECT
    q.query_id,
    p.plan_id,
    p.is_forced_plan,
    p.count_compiles,
    FORMAT(p.initial_compile_start_time, 'dd/MM/yyyy HH:mm:ss') AS compiled_at,
    rs.avg_duration / 1e6 AS avg_duration_sec,
    rs.avg_logical_io_reads,
    rs.count_executions
FROM sys.query_store_query q
JOIN sys.query_store_plan p ON q.query_id = p.query_id
JOIN sys.query_store_runtime_stats rs ON p.plan_id = rs.plan_id
WHERE q.query_id = 
ORDER BY p.plan_id;

Resultado: is_forced_plan = 1 en el plan que estaba usando la sesión problemática.

Había dos planes para la misma query:

---

La diferencia entre ambos planes: el Index Spool

Esta es la clave técnica de todo el incidente.

Plan A (bueno): con Index Spool

Nested Loops (Left Outer Join)
├── Table Scan: hechos_origen [3.4M filas]
└── Index Spool (Eager Spool)  ← ESTE OPERADOR ES CRÍTICO
    └── Table Scan: dim_contratos [11.8M filas — una sola vez]
        └── Filter: cod_referencia = T.cod_referencia

El Index Spool (Eager Spool) funciona así: 1. Al inicio del plan, escanea dim_contratos una sola vez (11.8M filas) 2. Construye un índice temporal en TempDB sobre las columnas relevantes 3. Para cada una de las 3.4M filas del loop exterior, hace un Index Seek contra ese índice temporal

Resultado: 1 scan completo + 3.4M seeks = ~57 millones de lecturas lógicas totales.

Rendimiento histórico con este plan: - 7 marzo: 396 seg (6.6 min), 57.7M lecturas lógicas - 8 marzo: 562 seg (9.4 min), 57.7M lecturas lógicas

Plan B (malo): sin Index Spool

Nested Loops (Left Outer Join)
├── Table Scan: hechos_origen [estimado: 1 fila(!)]
└── Table Scan: dim_contratos [11.8M filas — POR CADA FILA DEL LOOP]

Sin el Index Spool, el Nested Loop hace un Table Scan completo de dim_contratos por cada fila de hechos_origen:

• 3.400.000 filas × 11.800.000 filas = ~40 billones de lecturas teóricas

La estimación de "1 fila" en hechos_origen es la señal clave: este plan se compiló cuando la tabla temporal estaba vacía. El optimizador vio 0 filas, generó un plan trivial, y alguien lo forzó creyendo que era bueno.

Rendimiento con el plan forzado: - 9 marzo: 0.0003 seg (tabla vacía al compilarse — parecía perfecto) - 11 marzo: 108.243 seg (30 horas), 10.850 millones de lecturas - 13 marzo: 94.200 seg (26.2 horas), 12.810 millones de lecturas

---

Por qué se forzó: la trampa del plan "perfecto"

Entre las 23:34 y las 23:48 del 9 de marzo, alguien forzó 8 planes diferentes de la misma cadena ETL — todos en el mismo margen de 14 minutos.

El patrón es comprensible: los ETLs hacen DELETE sobre las tablas temporales antes del INSERT. En ese momento, la tabla está vacía. Si en ese preciso instante se fuerza un plan nuevo, el compilador lo genera con estimación de 0-1 filas. El plan parece ejecutarse en milisegundos (porque la tabla está vacía). Alguien lo forzó pensando que había encontrado un plan ultra-rápido.

El problema solo se manifiesta en la siguiente ejecución real, cuando las tablas tienen millones de filas.

-- Query para detectar planes forzados activos en toda la base de datos
SELECT
    OBJECT_NAME(q.object_id) AS procedure_name,
    q.query_id,
    p.plan_id,
    p.is_forced_plan,
    p.force_failure_count,
    FORMAT(p.initial_compile_start_time, 'dd/MM/yyyy HH:mm:ss') AS forced_since,
    rs.avg_duration / 1e6 AS avg_duration_sec,
    rs.count_executions
FROM sys.query_store_plan p
JOIN sys.query_store_query q ON p.query_id = q.query_id
LEFT JOIN sys.query_store_runtime_stats rs ON p.plan_id = rs.plan_id
WHERE p.is_forced_plan = 1
ORDER BY p.initial_compile_start_time;

Todos los planes forzados tenían la misma firma: compilados la misma noche, misma hora, estimaciones de 1 fila, sin Index Spool.

---

Por qué WITH RECOMPILE no sirvió de nada

El stored procedure tenía WITH RECOMPILE. En teoría, esto debería forzar una recompilación completa en cada ejecución, permitiendo al optimizador elegir el mejor plan según los datos actuales.

Pero hay una interacción crítica entre Query Store y WITH RECOMPILE que no está bien documentada:

Cuando Query Store tiene un plan forzado para una query, WITH RECOMPILE recompila el plan en cuanto a estadísticas, pero mantiene la _forma_ del plan forzado. Es decir, si el plan forzado no tiene Index Spool, la recompilación tampoco lo incluirá.

Esto se confirma en los datos de Query Store: count_compiles = 2 para la ejecución de 26 horas. El stored procedure recompiló dos veces (por WITH RECOMPILE), pero usó el plan forzado en ambas.

Ejecutar sp_recompile sobre el procedimiento tampoco tiene efecto mientras el plan siga forzado:

-- Esto NO sirve mientras haya un plan forzado activo:
EXEC sys.sp_recompile N'[schema].[nombre_procedimiento]';
-- Para que tenga efecto, primero hay que des-forzar el plan:
EXEC sp_query_store_unforce_plan @query_id = X, @plan_id = Y;

---

Solución: des-forzar los planes correctos

Paso 1: Identificar todos los planes forzados del SP problemático

-- Buscar todos los planes de una query específica
SELECT
    q.query_id,
    p.plan_id,
    p.is_forced_plan,
    p.count_compiles,
    rs.avg_duration / 1e6 AS avg_duration_sec,
    rs.avg_logical_io_reads,
    FORMAT(p.initial_compile_start_time, 'dd/MM/yyyy HH:mm:ss') AS compiled_at
FROM sys.query_store_plan p
JOIN sys.query_store_query q ON p.query_id = q.query_id
JOIN sys.query_store_runtime_stats rs ON p.plan_id = rs.plan_id
WHERE q.query_id = 
ORDER BY rs.avg_duration DESC;

Paso 2: Des-forzar el plan incorrecto

USE [nombre_base_datos];

-- Des-forzar el plan malo
EXEC sp_query_store_unforce_plan
    @query_id = ,
    @plan_id = ;

-- Forzar recompilación del procedimiento (ahora sí tiene efecto)
EXEC sys.sp_recompile N'[schema].[nombre_procedimiento]';

Paso 3: Auditar toda la cadena ETL

No basta con arreglar el SP que falla hoy. Si alguien forzó planes de forma masiva, hay que auditarlos todos:

-- Auditoría completa de planes forzados en una base de datos
SELECT
    OBJECT_NAME(q.object_id) AS procedure_name,
    q.query_id,
    p.plan_id,
    p.force_failure_count,
    FORMAT(p.initial_compile_start_time, 'dd/MM/yyyy HH:mm') AS forced_since,
    AVG(rs.avg_duration) / 1e6 AS avg_duration_sec,
    AVG(rs.avg_logical_io_reads) AS avg_logical_reads
FROM sys.query_store_plan p
JOIN sys.query_store_query q ON p.query_id = q.query_id
LEFT JOIN sys.query_store_runtime_stats rs ON p.plan_id = rs.plan_id
WHERE p.is_forced_plan = 1
GROUP BY
    OBJECT_NAME(q.object_id), q.query_id, p.plan_id,
    p.force_failure_count, p.initial_compile_start_time
ORDER BY p.initial_compile_start_time;

En este caso encontramos 8 planes forzados creados en 14 minutos. Los 5 críticos correspondían a SPs de carga de tablas de hechos con el mismo patrón OUTER APPLY. Todos des-forzados en la misma intervención.

---

Resultado: comparativa antes y después

Lecturas lógicas SP1: 12.810 millones → 60 millones (213x menos).

La cadena ETL completa, que había necesitado cancelación dos veces en días consecutivos, completó al día siguiente en tiempo normal.

---

Mejoras a largo plazo: índices permanentes vs. Index Spool

El Index Spool es la forma que tiene el optimizador de compensar la falta de índices permanentes. En este caso, dim_contratos no tenía índice en la columna del JOIN (cod_referencia). El optimizador creaba uno temporal en TempDB en cada ejecución.

Solución permanente: crear el índice real.

-- Índice sugerido por el optimizador (impacto estimado: 99.98%)
CREATE NONCLUSTERED INDEX [IX_dim_contratos_cod_referencia]
ON [dim_contratos] ([cod_referencia]);

Con este índice, el plan puede hacer Index Seek directamente sin necesitar el Spool. El resultado: menos dependencia de TempDB, menos variabilidad en tiempos de ejecución, y planes más estables ante cambios en el volumen de datos.

El problema de RIGHT(columna, n) — non-SARGable

La condición RIGHT(M.id_control, 8) <= @fecha aplica una función sobre la columna, lo que impide usar índices sobre id_control. El optimizador no puede hacer un range scan.

Si la lógica de negocio lo permite, la solución es una columna calculada PERSISTED con su propio índice:

ALTER TABLE [dim_contratos]
ADD fecha_desde_control AS CAST(RIGHT(id_control, 8) AS CHAR(8)) PERSISTED;

CREATE NONCLUSTERED INDEX [IX_dim_contratos_fecha]
ON [dim_contratos] (fecha_desde_control)
INCLUDE (cod_referencia, id_control);

Esto permite que el optimizador use el índice para la condición de fecha, eliminando por completo la necesidad del Spool. La cadena ETL estimada pasaría de 2-4 horas a menos de 30 minutos.

---

Lecciones clave

1. Query Store es para diagnóstico, no para optimización manual sin análisis sp_query_store_force_plan existe para estabilizar regressions específicas. Forzar planes en producción sin entender exactamente por qué son buenos es arriesgado. Especialmente si el plan se compiló con datos no representativos (tablas vacías).

2. Audita regularmente los planes forzados Añade esta query a tu monitorización diaria:

SELECT
    OBJECT_NAME(q.object_id) AS procedure_name,
    p.plan_id,
    FORMAT(p.initial_compile_start_time, 'dd/MM/yyyy') AS forced_since,
    rs.avg_duration / 1e6 AS avg_sec
FROM sys.query_store_plan p
JOIN sys.query_store_query q ON p.query_id = q.query_id
LEFT JOIN sys.query_store_runtime_stats rs ON p.plan_id = rs.plan_id
WHERE p.is_forced_plan = 1
ORDER BY rs.avg_duration DESC;

Un plan forzado con rendimiento muy superior a la media histórica de esa query es una señal de alerta inmediata.

3. WITH RECOMPILE no supera a Query Store Si tienes SPs con WITH RECOMPILE y planes forzados en Query Store, el plan forzado gana. Para que WITH RECOMPILE sea efectivo, primero hay que des-forzar.

4. Cuando el plan se compila importa tanto como cómo se compila Un plan compilado con tablas vacías nunca será representativo para producción. Si necesitas estabilizar un plan, hazlo con datos de producción reales.