Mensajes de FlushCache que aparecen en el registro en momentos específicos

22

Últimamente hemos tenido muchos problemas de rendimiento de la base de datos y he estado tratando de ver si puedo entender por qué. No tenemos un DBA (soy un desarrollador de software), así que simplemente lo estoy usando, y gran parte de lo que encuentro en línea me parece un idioma extranjero.

Hemos reiniciado SQL Server todas las mañanas porque esa es la única forma en que funciona durante la jornada laboral. Noté que todas las mañanas alrededor de las 5 am comenzamos a recibir este mensaje cada dos minutos en el registro:

FlushCache: limpió 11848 bufs con 7432 escrituras en 97168 ms (evitó 8139 bufs sucios nuevos) para db 9: 0

último objetivo pendiente: 4, avgWriteLatency 32

rendimiento promedio: 0,72 MB / seg, saturación de E / S: 11635, cambios de contexto 18849

Los números difieren cada vez, por supuesto, pero es el mismo mensaje una y otra vez en ese patrón hasta que reinicie el servidor. No estoy seguro de cómo interpretar esto, he estado tratando de buscarlo en Google y todo lo que he reunido es que significa que puede haber algo mal con la E / S y que algo está tomando más tiempo de lo que se supone. Recientemente cambiamos al uso de SSD, así que no pensé que debería ser un problema de escritura.

¿Alguien podría arrojar algo de luz sobre esto?

eddie_cat
fuente
Continuemos esta discusión en el chat .
eddie_cat

Respuestas:

29

El mensaje FlushCache en el registro de errores es causado por el registro del punto de control y, en este caso, por un punto de control largo (que se define como un punto de control que tarda más que el intervalo de recuperación). Ya sea que esté registrado o no, el comportamiento es diferente en pre-2012 y 2012+. Antes de SQL Server 2012, para obtener el registro del punto de control, tenía que activar un indicador de seguimiento (T3504). Pero a partir de SQL Server 2012, ese mensaje se registra de manera predeterminada cuando se encuentra un punto de control largo.

Ahora en cuanto a la pregunta de "¿es esto realmente malo ?" , realmente necesita comenzar a mirar estos números dado su contexto. Le llevó más de 97 segundos limpiar solo unos 93 MB de búferes sucios. Parece que esto podría ser una mezcla de una gran cantidad de cambios de datos (durante el punto de control real, también se ensuciaron aproximadamente 64 MB de almacenamientos intermedios) y un almacenamiento potencial que no está al día con la modificación de datos y / o el resto de la carga de trabajo de E / S.

Lo que haría es verificar el estado de su subsistema de almacenamiento , mirar las esperas y simplemente obtener una imagen general del rendimiento de la instancia. Eche un vistazo a los contadores de rendimiento de disco lógico y vea cuál es la rotación general de E / S con rendimiento , latencia e IOps . Le ayudará a pintar una imagen más vívida de cómo funcionan los discos. Si tiene la capacidad de comparar su almacenamiento, si aún no lo ha establecido, debería ver de qué son capaces estos volúmenes en cuestión ( SQLIO es una gran utilidad para eso) y lo que están haciendo en este momento (es bueno tener una referencia de referencia cuando los volúmenes se pusieron de pie para compararlos con una referencia actual).

Aquí hay un gran artículo que explica este mensaje: cómo funciona: ¿Cuándo se agrega el mensaje FlushCache al registro de errores de SQL Server?

EDITAR : releyendo su pregunta, debo haberme perdido este comentario:

Noté que todas las mañanas alrededor de las 5 de la mañana comenzamos a recibir este mensaje

Vea lo que está sucediendo en su almacenamiento en este momento según las instrucciones anteriores. Eso suena como una operación programada de un libro de texto que está afectando el almacenamiento causando que el rendimiento del punto de control se vea afectado y sea "largo".

Thomas Stringer
fuente
2
SQLIO ha sido reemplazado por Diskspd.exe de acuerdo con el enlace proporcionado. Aquí está el enlace a Diskspd.exe: gallery.technet.microsoft.com/DiskSpd-a-robust-storage-6cd2f223
Tim Coker