¿Qué puede hacer que una sesión de duplicación agote el tiempo de espera y luego la conmutación por error?

22

Tenemos dos servidores SQL de producción que ejecutan SQL Server 2005 SP4 con actualización acumulativa 3. Ambos servidores se ejecutan en máquinas físicas que son idénticas. DELL PowerEdge R815 con 4 CPU de 12 núcleos y 512 GB (sí GB) de ram, con unidades conectadas iSCSI SAN de 10 GB para todas las bases de datos y registros de SQL. El sistema operativo es Microsoft Windows Server 2008 R2 Enterprise Edition con todas las actualizaciones de SP y Windows. La unidad del sistema operativo es una matriz RAID 5 de 3 unidades de disco duro SAS 72k 2.5 "15k. SAN es una Dell EqualLogic 6510 con unidades de 48 x 10K SAS 3.5", configurada en RAID 50, dividida en varios LUN para los 2 servidores SQL, y también compartida con una máquina de Exchange y varios servidores VMWare.

Tenemos más de 20 bases de datos, 11 de las cuales se reflejan con alta disponibilidad utilizando un servidor testigo. El servidor testigo es una máquina de menor potencia que ejecuta una instancia de SQL Server que se usa para nada más que proporcionar servicios de testigo. La base de datos reflejada más grande es de 450 GB y genera alrededor de 100-300 iops. El Monitor de creación de reflejo de la base de datos informa una velocidad de envío actual de alrededor de 100 kb a 10 mb por segundo, y una sobrecarga de confirmación espejo de (típicamente) 0 milisegundos. El servidor espejo no tiene problemas para mantenerse al día con el director.

Constantemente estamos experimentando failovers reflejados. Algunas veces una sola base de datos fallará, otras veces casi todas las bases de datos fallarán simultáneamente. Por ejemplo, anoche, tuvimos 10 de 11 bases de datos de conmutación por error, la base de datos restante permaneció accesible hasta que fallé manualmente.

He seguido varios pasos de solución de problemas para intentar identificar el problema, pero hasta ahora no he podido resolver el problema:

1) La máquina venía con un adaptador de red Broadbit BCM5709C NetXtreme II de 4 puertos Gigabit que inicialmente utilizamos como conexión de red primaria. Desde entonces, hemos instalado un adaptador de servidor de puerto dual Intel (R) PRO / 1000 PT en ambas máquinas para eliminar la NIC como problema.

2) Todas las bases de datos tienen una copia de seguridad completa automática todas las noches junto con una copia de seguridad de registro para las bases de datos involucradas en la duplicación. El uso del archivo de registro se monitorea y rara vez se usa por encima del 15%. El archivo de registro para la base de datos principal es de 125 GB, que consta de 159 archivos de registro virtuales que varían en tamaño de 511 MB a 1 GB. TempDB está en su propio LUN y consta de archivos de 24 x 2 GB.

3) El registro de SQL Server en el testigo no muestra ningún error que no sea: La conexión de duplicación a "TCP: //SQL02.DOMAIN.INET: 5022" ha excedido el tiempo de espera para la base de datos "Datos" después de 30 segundos sin respuesta. Verifique el servicio y las conexiones de red.

El registro de SQL Server en los servidores primario y secundario muestra mensajes relacionados con la duplicación:

La conexión de duplicación a "TCP: //SQL01.DOMAIN.INET: 5022" ha excedido el tiempo de espera para la base de datos "Datos" después de 30 segundos sin respuesta. Verifique el servicio y las conexiones de red.

La base de datos reflejada "Datos" está cambiando roles de "PRINCIPAL" a "ESPEJO" debido a la Sincronización de Roles. (La sincronización está mal escrita aquí a propósito, ya que es precisamente así como se muestra el mensaje real).

La base de datos reflejada "Datos" está cambiando los roles de "PRINCIPAL" a "ESPEJO" debido a la conmutación por error.

La base de datos reflejada "Datos" está cambiando los roles de "ESPEJO" a "PRINCIPAL" debido a la conmutación por error del socio.

Los servicios de SQL Server continúan ejecutándose y las conexiones de red parecen mantenerse activas. Constantemente tenemos entre 500 y 2500 sesiones conectadas a cada servidor (principalmente aplicaciones robóticas que se conectan a colas de intermediario de servicios en una sola base de datos).

4) TCP Chimney y RSS, etc. están deshabilitados usando la sintaxis NET SH.

5) He ejecutado el Analizador de mejores prácticas de SQL Server 2005 en ambas máquinas y no encuentro nada más que el muy ocasional error 833 del registro de eventos de la aplicación, ninguno de los cuales coincide con los eventos de conmutación por error:

SQL Server ha encontrado 1 aparición (s) de solicitudes de E / S que tardan más de 15 segundos en completarse en el archivo [F: \ Data.MDF] en la base de datos [Datos] (9). El identificador del archivo del sistema operativo es 0x00000000000010A0. El desplazamiento de la última E / S larga es: 0x000007d4b10000).

6) Ocasionalmente vemos "El cliente no pudo reutilizar una sesión con SPID XXX, que se había restablecido para la agrupación de conexiones. Este error puede haber sido causado por una falla de operación anterior. Verifique los registros de error para operaciones fallidas inmediatamente antes de este mensaje de error ". generado por ambos servidores. Parece que no hay mensajes "anteriores" que indiquen algún problema.

7) Ocasionalmente, el correo de la base de datos escribe un error en el registro de eventos de la aplicación:

Tipo de excepción: Microsoft.SqlServer.Management.SqlIMail.Server.Common.BaseException Mensaje: Hubo un error en la conexión. Motivo: Tiempo de espera expirado. El período de tiempo de espera transcurrido antes de la finalización de la operación o el servidor no responde., Parámetros de conexión: Nombre del servidor: MGSQL02, Nombre de la base de datos: msdb Datos: System.Collections.ListDictionaryInternal TargetSite: Void OpenConnection (Microsoft.SqlServer.Management.Common. SqlConnectionInfo) Enlace de ayuda: NULL Fuente: DatabaseMailEngine

StackTrace Information en Microsoft.SqlServer.Management.SqlIMail.Server.DataAccess.ConnectionManager.OpenConnection (SqlConnectionInfo ci) en Microsoft.SqlServer.Management.SqlIMail.Server.DataAccess.DataAccessAdapter.OpenConnection, String String, nombre de usuario ) en Microsoft.SqlServer.Management.SqlIMail.IMailProcess.QueueItemProcesser.ProcessQueueItems (String dbName, String dbServerName, Int32 LifetimeMinimumSec, LogLevel loggingLevel)

Creo que los tiempos de espera están causando la conmutación por error; ¿Qué podría causar estos tiempos de espera? Obviamente, si hubo un problema de red real, como un cable defectuoso o un interruptor defectuoso, que podría causar la pérdida de paquetes y, por lo tanto, un tiempo de espera, sin embargo, ¿qué otras cosas podrían causar tiempos de espera? Bloqueo? Si MSDB, o alguna otra base de datos del sistema tuviera un tiempo de espera de E / S, ¿podría causar la conmutación por error de duplicación?

Gracias por cualquier consejo!

MSDN tiene lo siguiente que decir sobre el mecanismo de tiempo de espera en sí :

El mecanismo de tiempo de espera reflejado

Debido a que los errores de software no son detectables directamente por una instancia de servidor, un error de software podría hacer que una instancia de servidor espere indefinidamente. Para evitar esto, la creación de reflejo de la base de datos implementa su propio mecanismo de tiempo de espera, basado en cada instancia del servidor en una sesión de creación de reflejo que envía un ping en cada conexión abierta en un intervalo fijo.

Para mantener una conexión abierta, una instancia del servidor debe recibir un ping en esa conexión en el período de tiempo de espera definido, más el tiempo necesario para enviar un ping más. Recibir un ping durante el tiempo de espera indica que la conexión aún está abierta y que las instancias del servidor se están comunicando a través de ella. Al recibir un ping, una instancia del servidor restablece su contador de tiempo de espera en esa conexión.

Si no se recibe ping en una conexión durante el período de tiempo de espera, una instancia del servidor considera que la conexión ha excedido el tiempo de espera. La instancia del servidor cierra la conexión de tiempo de espera y maneja el evento de tiempo de espera de acuerdo con el estado y el modo operativo de la sesión.

netsh interface tcp show global muestra:

Receive-Side Scaling State          : disabled
Chimney Offload State               : disabled
NetDMA State                        : enabled
Direct Cache Acess (DCA)            : disabled
Receive Window Auto-Tuning Level    : disabled
Add-On Congestion Control Provider  : ctcp
ECN Capability                      : disabled
RFC 1323 Timestamps                 : disabled

netsh interface ipv4 show dynamicportrange tcp

Protocol tcp Dynamic Port Range

Start Port      : 1025
Number of Ports : 64510

SELECT name, value_in_use FROM sys.configurations

    Consultas distribuidas ad hoc 0         
    Máscara de E / S de afinidad 0         
    máscara de afinidad 0         
    affinity64 I / O mask 0         
    affinity64 máscara 0         
    Agent XPs 1         
    permitir actualizaciones 0         
    temor habilitado 0         
    umbral de proceso bloqueado 5         
    c2 modo de auditoría 0         
    clr habilitado 1         
    cumplimiento de criterios comunes habilitado 0         
    umbral de costo para paralelismo 4         
    propiedad db cruzada encadenamiento 0         
    umbral del cursor -1        
    Base de datos de correo electrónico XP 1         
    idioma de texto completo predeterminado 1033      
    idioma predeterminado 0         
    rastreo predeterminado habilitado 1         
    rechazar resultados de desencadenantes 0         
    factor de relleno (%) 0         
    ancho de banda de rastreo de pies (máx.) 100       
    ancho de banda de rastreo ft (min) 0         
    ft notificar ancho de banda (max) 100       
    ft notificar ancho de banda (min) 0         
    índice crear memoria (KB) 0         
    en duda xact resolución 0         
    agrupación ligera 0         
    cerraduras 0         
    grado máximo de paralelismo 6         
    rango máximo de rastreo de texto completo 4         
    memoria máxima del servidor (MB) 393216    
    tamaño máximo de respuesta de texto (B) 65536     
    máximo de hilos de trabajo 0         
    retención de medios 0         
    memoria mínima por consulta (KB) 2048      
    memoria mínima del servidor (MB) 52427     
    disparadores anidados 1         
    tamaño de paquete de red (B) 1400      
    Procedimientos de Automatización Ole 1         
    objetos abiertos 0         
    Tiempo de espera de PH 60        
    precalculación rango 0         
    aumento de prioridad 0         
    consulta gobernador límite de costo 0         
    consulta espera (s) -1        
    intervalo de recuperación (min) 0         
    acceso remoto 1         
    conexiones administrativas remotas 0         
    tiempo de espera de inicio de sesión remoto 20        
    control remoto trans 0         
    tiempo de espera de consulta remota 600       
    XP de replicación 0         
    buscar procs de inicio 0         
    recursividad de activación del servidor 1         
    establecer el tamaño del conjunto de trabajo 0         
    Mostrar opciones avanzadas 1         
    SMO y DMO XPs 1         
    SQL Mail XPs 0         
    transformar palabras de ruido 0         
    corte de año de dos dígitos 2049      
    conexiones de usuario 0         
    opciones de usuario 4216      
    Procedimientos de asistente web 0         
    xp_cmdshell 1         

Hace un tiempo, modifiqué manualmente el mirroring_connection_timeoutvalor de todas las bases de datos duplicadas a 30 segundos para intentar solucionar el problema; esto simplemente ha aumentado la cantidad de tiempo entre eventos de conmutación por error. Con la mirroring_connection_timeoutconfiguración establecida en el valor predeterminado de 10 segundos, vemos muchas más failovers.

Un comentario me había pedido que me asegurara de que IPSec esté deshabilitado, así que publico el contenido de varios netshcomandos que muestran la configuración de IPSec del sistema operativo:

C: \> netsh ipsec dinámico mostrar todo
Ninguna política asignada actualmente
Políticas de modo principal no disponibles.
Políticas de modo rápido no disponibles.
Los filtros genéricos de modo principal no están disponibles.
Los filtros específicos del modo principal no están disponibles.
Los filtros genéricos de modo rápido no están disponibles.
Los filtros específicos de modo rápido no están disponibles.
IPsec MainMode Security Associations no disponible.
Las asociaciones de seguridad de IPsec QuickMode no están disponibles.

Parámetros de configuración de IPsec
------------------------------
StrongCRLCheck: 1
IPsecexempt: 3

Estadísticas de IPsec
----------------
Asociación activa: 0
Descarga de SA: 0
Clave pendiente: 0
Agregados clave: 0
Eliminaciones clave: 0
ReKeys: 0
Túneles activos: 0
Malos paquetes SPI: 0
Paquetes no descifrados: 0
Paquetes no autenticados: 0
Paquetes con detección de repetición: 0
Bytes confidenciales enviados: 0
Bytes confidenciales recibidos: 0
Bytes autenticados enviados: 0
Bytes autenticados recibidos: 0
Bytes de transporte enviados: 0
Bytes de transporte recibidos: 0
Bytes enviados en túneles: 0
Bytes recibidos en túneles: 0
Bytes descargados enviados: 0
Bytes descargados recibidos: 0

C: \> netsh ipsec estático mostrar todo
ERR IPsec [05072]: No hay políticas en el almacén de políticas




ACTUALIZACIÓN: 2012-12-20

Ahora hemos trasladado nuestros sistemas de producción a SQL Server 2012. Lo hemos estado ejecutando desde la mañana del 17 de diciembre, hasta el momento no hay failovers. Sin embargo, un par de días está dentro de lo que vimos con los sistemas basados ​​en 2005.

En un esfuerzo por documentar el rendimiento de nuestros nuevos sistemas, he estado analizando con sys.dm_os_wait_statsmás cuidado; y notado DBMIRROR_DBM_EVENT, que es un tipo de espera indocumentado. Graham Kent de Microsoft tiene un interesante artículo sobre la resolución de fallas inesperadas y este tipo de espera. Recapitularé sus hallazgos aquí:

El cliente estaba experimentando una enorme cadena de bloqueo construida en una base de datos OLTP de alto volumen donde todos los bloqueadores de cabeza estaban esperando DBMIRROR_DBM_EVENT. Aquí está la secuencia de eventos por los que pasé:

  1. Revise la cadena de bloqueo en sí; ayudemos aquí, ya que todo lo que podemos ver es que estamos esperando DBMIRROR_DBM_EVENT

  2. Revise la fuente del tipo de espera no documentado. Obviamente, no puede hacer esto fuera de MS, pero puedo decir que al momento de escribir este tipo de espera representa la espera utilizada cuando el principal está esperando que el espejo endurezca un LSN, lo que significa que la transacción de la que forma parte no puede comprometerse . Esto apunta inmediatamente de manera bastante específica al problema de que el principal no puede confirmar transacciones ya que está esperando en el espejo. Ahora tenemos que investigar por qué el espejo no está confirmando transacciones o por qué el director no sabe si lo es.

  3. Revise las tablas del sistema msdb

(a) Observe la tabla [conjunto de copias de seguridad] para ver si el tamaño de los registros producidos en el momento del problema es significativamente mayor de lo normal. Si fueran excepcionalmente grandes, puede ser que el espejo se haya inundado de transacciones y simplemente no pueda mantenerse al día con el volumen. Esta es la razón por la cual los libros en línea le dirán a veces que desactive la duplicación si necesita realizar una operación de registro excepcionalmente grande, como una reconstrucción de índice. (referencia de por qué esto está en http://technet.microsoft.com/en-us/library/cc917681.aspx ). Aquí utilicé el siguiente TSQL

SELECT backup_set_id,backup_start_date,database_name,has_bulk_logged_data,backup_size / 1000
FROM [backupset]
where backup_start_date between '2011-01-05 14:00:00' and '2011-01-05 19:30:00'
go

select round((AVG(backup_size)/1000),0)
FROM [backupset]
where database_name = 'mydatabase'

(b) en segundo lugar, miré los datos en las tablas [dbm_monitor_data]. La clave aquí es localizar el período de tiempo en el que tuvimos un problema y luego ver si experimentamos cambios significativos en cualquiera de los siguientes:

log_flush_rate
send_queue_size
send_rate
redo_queue_size
redo_rate

Todos estos son indicadores similares a la parte (a) en que podrían mostrar un componente o una pieza de arquitectura que no respondía. Por ejemplo, si send_queue comienza a crecer repentinamente pero la cola re_do no crece, implicaría que el principal no puede enviar los registros de registro al espejo, por lo que quizás desee ver la conectividad o las colas de intermediario de servicios lidiando con las transmisiones reales.

En este escenario en particular, notamos que todos los contadores parecían tener valores extraños, ya que había copias de seguridad de registros de tamaños normales, pero no hubo cambios de estado, 0 cola de envío, 0 cola de rehacer, una tasa de envío plana y una plana tasa de rehacer. Esto es muy extraño, ya que implica que el monitor DBM no pudo registrar ningún valor desde ningún lugar durante el período del problema.

  1. Revise los registros de errores de SQL Server. En este caso no hubo errores ni mensajes de información, pero en otros escenarios como este, es muy común que se reporten errores en el rango de 1400, ejemplos de los cuales puede encontrar en otros lugares en mis otros blogs reflejados, como este error 1413 ejemplo

  2. Revise los archivos de rastreo predeterminados: en este escenario no se me proporcionaron los rastreos predeterminados, sin embargo, son fuentes fantásticas de información sobre problemas de DBM, ya que registran eventos de cambio de estado en todos los socios. Esto se documenta aquí:

Clase de evento de cambio de estado de reflejo de la base de datos

Esto a menudo le brinda una excelente imagen de escenarios como cuando la conectividad de la red falló entre uno o todos los socios y luego en qué se convirtió el estado de la asociación después.

CONCLUSIONES

En este escenario particular, actualmente me faltan 2 puntos clave de datos, pero aparte de eso, todavía puedo hacer una hipótesis razonable sobre la información anterior. Ciertamente podemos decir que el bloqueo fue causado por el hecho de que DBM estaba habilitado debido a que todos los bloqueadores esperaban en el tipo de espera DBMIRROR_DBM_EVENT. Como sabemos que no inundaron el espejo con una operación registrada grande y que esta implementación normalmente se ejecuta correctamente en este modo, podemos excluir operaciones grandes inusuales. Esto significa que tenemos 2 candidatos potenciales en esta etapa:

  1. Problemas de hardware en la conectividad entre algunos o todos los socios.

  2. El agotamiento de la CPU en el servidor espejo, simplemente incapaz de mantenerse al día con los cambios, el agotamiento de la CPU podría ser de un proceso fuera de SQL Server o fuera de esta asociación espejo.

  3. Un problema con el código de duplicación en sí (aunque realmente necesitaríamos algunos volcados de memoria para confirmar esto).

Según la experiencia, sospecharía que 1 o 2, pero siempre mantengo una mente abierta sobre 3, estamos tratando de recopilar más datos ahora para ver este problema con más detalle.

Max Vernon
fuente
Otra cosa para verificar sería IPSec. A menudo, IPSec puede retrasar o bloquear el intento de conexión. Deshabilite IPSec para ver si se detienen los tiempos de espera.
Robert L Davis

Respuestas:

6

Parece que se está quedando sin puertos TCP en el servidor SQL. ¿Cuántas conexiones está viendo al servidor a la vez?

Tiempos de espera como ese definitivamente estarían causando el problema.

mrdenny
fuente
Gracias por la respuesta. Ese es ciertamente un problema que identificamos como una posible causa del problema. Windows Server 2003 tiene un límite listo para usar de 5,000 puertos llamados "efímeros", sin embargo, Windows Server 2008 R2 está configurado para usar 16,000 (creo) listos para usar. Independientemente, hemos configurado la configuración MaxUserPort de ambos servidores SQL en 65534 en HKLM \ SYSTEM \ CurrentControlSet \ Services \ Tcpip \ Parameters.
Max Vernon el
Acabo de marcar ambas casillas: la principal tiene 1.387 puertos en uso, la secundaria tiene 682 en uso en este momento. Para verificar esto, abrí un indicador de cmd e ingresé: netstat -n | find "TCP" / c
Max Vernon
El siguiente paso que probablemente tomaría sería disparar cables de conexión en el testigo y el servidor primario y esperar el próximo tiempo de espera para ver qué está sucediendo realmente a nivel TCP.
mrdenny
mmmmm ... Captura de paquetes. ¿Alguna idea de cómo descifrar la transmisión tcp en el puerto 5022 que es el transporte reflejado? Sin esa información, Wireshark realmente no me puede decir mucho. Lo intentaré y veré qué pasa. ¡Gracias por la ayuda!
Max Vernon el
2

¿Puedes revisarlo sys.dm_os_schedulers? Específicamente, ¿se work_queue_countdesvía de 0 por algún tiempo significativo? Esto indicaría el hambre del trabajador y explicaría muchos de sus síntomas.

Remus Rusanu
fuente
He agregado una tabla que enumera la configuración del servidor. Max Worker Threads se establece en 0, para permitir que el servidor elija el valor apropiado. sys.dm_os_schedulersno muestra resultados para SELECT * FROM sys.dm_os_schedulers WHERE work_queue_count > 0;- ¿Debo grabar esto cada minuto?
Max Vernon
Debe verificarlo cuando ocurran fallas.
Remus Rusanu