¿Cómo depurar la causa de mi plan de mantenimiento de copias de seguridad de bases de datos que de repente funciona extremadamente lento?

¿Cómo depurar la causa de mi plan de mantenimiento de copias de seguridad de bases de datos que de repente funciona extremadamente lento?

(Publicado originalmente en DBA.StackExchange.com pero cerrado, espero que sea más relevante aquí).

Alexander y los terribles, horribles, malos, muy malos... copias de seguridad.

La puesta en marcha:

tengo un localSQL Server 2016 Edición estándarinstancia ejecutándose en unmáquina virtualde VMware.

@@Versión:

Microsoft SQL Server 2016 (SP2-CU17) (KB5001092) - 13.0.5888.11 (X64) 19 de marzo de 2021 19:41:38 Copyright (c) Microsoft Corporation Standard Edition (64 bits) en Windows Server 2016 Datacenter 10.0 (compilación 14393: ) (hipervisor)

El servidor en sí está actualmente asignado8 procesadores virtuales, tiene32 GB de memoria, y todo ellos discos son NVMeque se mueven1 GB/s de E/S. Las bases de datos se encuentran en la unidad G: y las copias de seguridad se almacenan por separado en la unidad P:. El tamaño total de todas las bases de datos es de aproximadamente 500 GB (antes de comprimirse en los archivos de copia de seguridad).

El plan de mantenimiento se ejecuta una vez por noche (alrededor de las 10:30 p. m.) para realizar una copia de seguridad completa de cada base de datos del servidor. No se está ejecutando nada más fuera de lo común en el servidor, ni tampoco se está ejecutando nada en ese momento en particular. El plan de energía fuera del servidor está configurado en "Equilibrado" (y "Apagar el disco duro después" está configurado en 0 minutos, es decir, nunca lo apague).

Qué pasó:

Durante el último año, el tiempo total de ejecución del trabajo del plan de mantenimiento tomó alrededor de 15minutostotal para completar. Desde la semana pasada, se ha disparado hasta tardar aproximadamente 40 veces más, aproximadamente 15horascompletar.

Lo único que sé que cambió el mismo día que el plan de mantenimiento se ralentizó fue que se instalaron las siguientes actualizaciones de Windows en la máquina antes de que se ejecutara el plan de mantenimiento:

Actualizaciones de Windows

  1. KB890830
  2. KB5004752
  3. KB5005043
  4. VMWare - Adaptador SCSI - 1.3.17.0
  5. VMWare - Pantalla - 8.17.2.14

También tenemos otra instancia de SQL Server aprovisionada de manera similar en otra máquina virtual que experimentó las mismas actualizaciones de Windows y luego experimentó copias de seguridad más lentas. Pensando que las actualizaciones de Windows eran directamente la causa, las revertimos por completo y, de todos modos, el plan de mantenimiento de las copias de seguridad sigue funcionando extremadamente lento. Curiosamente, la restauración de las copias de seguridad de una base de datos determinada ocurre muy rápidamente y utiliza casi 1 GB/seg completo de E/S en los NVMe.

Cosas que he probado:

Al utilizar sp_whoisactive de Adam Mechanic, identifiqué que los tipos de última espera de los procesos de respaldo siempre son indicativos de un problema de rendimiento del disco. Siempre veo BACKUPBUFFERy BACKUPIOespero tipos, además de ASYNC_IO_COMPLETION:

sp_whoisactive

Al observar el Monitor de recursos en el servidor, durante las copias de seguridad, la sección E/S de disco muestra que la E/S total que se utiliza es solo de aproximadamente 14 MB/s (lo máximo que he visto desde que ocurrió este problema es 30 MB/s):

Monitor de recursos

Después de tropezar con esta útilArtículo de Brent Ozar sobre el uso de DiskSpd, Intenté ejecutarlo yo mismo con parámetros similares (solo reduje el número de subprocesos a 8 ya que tengo 8 procesadores virtuales en el servidor y configuré las escrituras al 50%). Este es el comando exacto diskspd.exe -b2M -d60 -o32 -h -L -t8 -W -w50 "C:\Users\...\Desktop\Microsoft DiskSpd\Test\LargeFile.txt". Utilicé un archivo de texto que generé manualmente y que tiene poco menos de 1 GB de tamaño. Creo que la E/S que midió parece estar bien, pero las latencias del disco mostraban algunos números ridículos:

Resultados de DiskSpd 1

Resultados de DiskSpd 2

Los resultados de DiskSpd parecen literalmente increíbles. Después de leer más, me topé con una consulta de Paul Randall que devuelve métricas de latencia del disco por base de datos. Estos fueron los resultados:

Paul Randal - Métricas de latencia del disco

La peor latencia de escritura fue de 63 milisegundos y la peor latencia de lectura fue de 6 milisegundos, por lo que parece ser una gran variación con respecto a DiskSpd y no parece lo suficientemente terrible como para ser la causa principal de mi problema. Para comprobar más a fondo las cosas, ejecuté algunos contadores de PerfMon en el servidor mismo, segúneste artículo de Microsoft, y estos fueron los resultados:

Resultados de PerformanceMon

Nada extraordinario aquí, el valor máximo de todos los contadores que medí fue 0,007 (¿que creo que son milisegundos?). Finalmente, hice que mi equipo de infraestructura verificara las métricas de latencia del disco que VMWare estaba registrando durante el trabajo de respaldo y estos fueron los resultados:

Registros de E/S y latencia de disco de VMWare

Parece que, en el peor de los casos, hubo un pico de latencia de aproximadamente 200 milisegundos alrededor de la medianoche, y la E/S más alta fue de 600 KB/s (lo cual no entiendo realmente ya que el Monitor de recursos muestra que las copias de seguridad al menos están usando alrededor de 14 MB/s de E/S).

Otras cosas que he probado:

Intenté restaurar una de las bases de datos más grandes (tiene aproximadamente 250 GB) y solo me llevó unos 8 minutos en total restaurarla. Luego intenté ejecutarlo DBCC CHECKDBy tardó un total de 16 minutos en ejecutarse (no estoy seguro si esto es normal) pero Resource Monitor mostró problemas de E/S similares (la mayor E/S que utilizó fue 100 MB/s), con nada más corriendo:

Monitor de recursos para DBCC CHECKDB

Aquí están los resultados de sp_whoisactive cuando ejecuté por primera vez DBCC CHECKDBy luego, después de completar el 5%, observe que el tiempo restante estimado aumentó aproximadamente 5 minutos incluso después de que ya estaba completado el 5%.

Comenzar: sp_whoisactive DBCC CHECKDB Iniciar

5% hecho: sp_whoisactive DBCC CHECKDB 5% Hecho

Supongo que esto es normal, ya que es solo una estimación, y 16 minutos no parece tan malo para una base de datos de 250 GB (aunque no estoy seguro de si eso es normal), pero nuevamente la E/S solo estaba alcanzando su máximo en aproximadamente el 10% de las capacidades de la unidad, sin nada más ejecutándose en el servidor o la instancia de SQL.

Estos son los resultadosde DBCC CHECKDB, no se informaron errores.

También he experimentado problemas extraños de lentitud con el SHRINKcomando. Intenté acceder a SHRINKla base de datos que tenía un 5% de espacio para liberar (aproximadamente 14 GB). Solo le tomó alrededor de 1 minuto completar el 90% de SHRINK:

Reducir rápidamente al 90%

Aproximadamente 5 minutos más tarde, todavía está atascado en el mismo porcentaje de finalización, y mis copias de seguridad del registro de transacciones (que generalmente finalizan en 1 o 2 segundos) han estado en disputa durante aproximadamente 30 segundos:

Reducción atascada al 90%

15 minutos más tarde y SHRINKacaba de terminar, mientras que las copias de seguridad del registro de transacciones todavía están en disputa durante aproximadamente 6 minutos y solo están completas en un 50%. Creo que terminaron inmediatamente después de eso desde que SHRINKterminaron. Todo el tiempo, el Monitor de recursos mostró que las E/S seguían succionando:

Termoencogido

Monitor de recursos para reducción

Luego recibí un error con el SHRINKcomando cuando terminó:

Error de contracción

Lo intenté SHRINKnuevamente y obtuve exactamente el mismo resultado que el anterior.

Luego intenté programar manualmente una copia de seguridad T-SQL en un archivo en la unidad P: y funcionó lento al igual que el trabajo de copia de seguridad del plan de mantenimiento:

Copia de seguridad manual de T-SQL

Terminé cancelándolo después de unos 3 minutos e inmediatamente retrocedió.

Resumen:

Casualmente, el trabajo del plan de mantenimiento de las copias de seguridad se volvió aproximadamente 40 veces más lento (de 15 minutos a 15 horas) cada noche, justo después de que se instalaron las actualizaciones de Windows. Revertir esas actualizaciones de Windows no solucionó el problema. Los tipos de espera de SQL Server, Resource Monitor y Microsoft DiskSpd indican un problema de disco (E/S en particular), pero todas las demás mediciones de la consulta de Paul Randall, PerfMon y VMWare Logs no informan ningún problema con los discos. La restauración de las copias de seguridad de una base de datos en particular es rápida y utiliza casi la E/S completa de 1 GB/s. Me estoy rascando la cabeza...

Respuesta1

En este caso, realmente tuvimos un problema de disco y no era un problema interno de SQL Server para esta máquina virtual en particular. De hecho, terminó siendo un caso de error que encontramos con Veeam y VMWare.

Para resumir mi comprensión de lo sucedido, aparentemente VMWare no reconocía que nuestras copias de seguridad de Veeam se habían completado. Entonces, todos los días, cuando llegaba el momento de hacer una copia de seguridad del servidor, VMWare le indicaba a Veeam que volviera a realizar la copia de seguridad del día anterior, lo que se convirtió en este problema creciente y acumulativo en el transcurso de dos semanas. (Estoy seguro de que destruí esa explicación, pero eso es más o menos todo lo que sé).

Veeam/VMWare tuvo que eliminar cada archivo de instantánea, y el archivo de cada día era más grande que el anterior, por lo que su soporte de nivel 3 tardó aproximadamente 26 horas en finalizar. Después de eso, la VM volvió a funcionar bien. Aparentemente, este no es un problema poco común según su soporte técnico.

Lo sentimos, este fue un problema muy específico y probablemente no ayude a muchos otros, pero espero que sí.

información relacionada