Solicitações de E / S demorando mais de 15 segundos

31

Geralmente, nossos backups completos semanais terminam em cerca de 35 minutos, com os backups diários diferentes terminando em ~ 5 minutos. Desde terça-feira, os diários levaram quase quatro horas para serem concluídos, muito mais do que o necessário. Coincidentemente, isso começou a acontecer logo após termos uma nova configuração de SAN / disco.

Observe que o servidor está em execução na produção e não temos problemas gerais, mas sem problemas - exceto pelo problema de E / S que se manifesta principalmente no desempenho do backup.

Examinando dm_exec_requests durante o backup, o backup está constantemente aguardando ASYNC_IO_COMPLETION. Aha, então temos contenção de disco!

No entanto, nem o MDF (os logs são armazenados no disco local) nem a unidade de backup têm atividade (IOPS ~ = 0 - temos bastante memória). Comprimento da fila de disco ~ = 0 também. A CPU gira em torno de 2-3%, também não há problema.

A SAN é um Dell MD3220i, o LUN que consiste em unidades SAS de 6x10k. O servidor está conectado à SAN por dois caminhos físicos, cada um passando por um switch separado com conexões redundantes à SAN - um total de quatro caminhos, dois deles ativos a qualquer momento. Posso verificar se as duas conexões estão ativas através do gerenciador de tarefas - dividindo a carga perfeitamente de maneira uniforme. Ambas as conexões estão executando 1G full duplex.

Costumávamos usar jumbo-frames, mas desativei-os para descartar qualquer problema aqui - nenhuma alteração. Temos outro servidor (o mesmo OS + config, 2008 R2) conectado a outros LUNs e ele não apresenta problemas. No entanto, ele não está executando o SQL Server, mas apenas compartilhando o CIFS em cima deles. No entanto, um de seus caminhos preferidos de LUNs está no mesmo controlador SAN que os LUNs problemáticos - então eu também descartei isso.

A execução de alguns testes SQLIO (arquivo de teste 10G) parece indicar que o IO é decente, apesar dos problemas:

sqlio -kR -t8 -o8 -s30 -frandom -b8 -BN -LS -Fparam.txt
IOs/sec:  3582.20
MBs/sec:    27.98
Min_Latency(ms): 0
Avg_Latency(ms): 3
Max_Latency(ms): 98
histogram:
ms: 0  1  2  3  4  5  6  7  8  9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24+
%: 45  9  5  4  4  4  4  4  4  3  2  2  1  1  1  1  1  1  1  0  0  0  0  0  2

sqlio -kW -t8 -o8 -s30 -frandom -b8 -BN -LS -Fparam.txt
IOs/sec:  4742.16
MBs/sec:    37.04
Min_Latency(ms): 0
Avg_Latency(ms): 2
Max_Latency(ms): 880
histogram:
ms: 0  1  2  3  4  5  6  7  8  9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24+
%: 46 33  2  2  2  2  2  2  2  1  1  1  1  0  0  0  0  0  0  0  0  0  0  0  1

sqlio -kR -t8 -o8 -s30 -fsequential -b64 -BN -LS -Fparam.txt
IOs/sec:  1824.60
MBs/sec:   114.03
Min_Latency(ms): 0
Avg_Latency(ms): 8
Max_Latency(ms): 421
histogram:
ms: 0  1  2  3  4  5  6  7  8  9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24+
%:  1  3 14  4 14 43  4  2  1  1  1  1  1  1  0  0  0  0  0  0  0  0  0  0  6

sqlio -kW -t8 -o8 -s30 -fsequential -b64 -BN -LS -Fparam.txt
IOs/sec:  3238.88
MBs/sec:   202.43
Min_Latency(ms): 1
Avg_Latency(ms): 4
Max_Latency(ms): 62
histogram:
ms: 0  1  2  3  4  5  6  7  8  9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24+
%:  0  0  0  9 51 31  6  1  0  0  0  0  0  0  0  0  0  0  0  0  0  0  0  0  0

Sei que esses testes não são exaustivos, mas me deixam à vontade em saber que não é um lixo completo. Observe que o desempenho mais alto de gravação é causado pelos dois caminhos MPIO ativos, enquanto a leitura usará apenas um deles.

A verificação do log de eventos do aplicativo revela eventos como estes espalhados:

SQL Server has encountered 2 occurrence(s) of I/O requests taking longer than 15 seconds to complete on file [J:\XXX.mdf] in database [XXX] (150).  The OS file handle is 0x0000000000003294.  The offset of the latest long I/O is: 0x00000033da0000

Eles não são constantes, mas acontecem regularmente (algumas vezes por hora, mais durante os backups). Junto com esse evento, o log de eventos do sistema publicará estes:

Initiator sent a task management command to reset the target. The target name is given in the dump data.
Target did not respond in time for a SCSI request. The CDB is given in the dump data.

Isso também ocorre no servidor CIFS não problemático em execução na mesma SAN / Controller e, no meu Google, eles parecem não ser críticos.

Observe que todos os servidores usam as mesmas NICs - Broadcom 5709Cs com drivers atualizados. Os próprios servidores são do Dell R610.

Não tenho certeza do que verificar em seguida. Alguma sugestão?

Atualização - executando o perfmon
Tentei gravar o Avg. Contadores de disco / sec de leitura e gravação perf enquanto executa um backup. O backup inicia de maneira impressionante e, em seguida, basicamente pára em 50%, subindo lentamente para 100%, mas leva 20 vezes o tempo que deveria.

Monitor de tarefas durante o início do backup Mostra os dois caminhos da SAN que estão sendo utilizados e depois saem.

Executar durante o mesmoO backup foi iniciado por volta das 15:38:50 - observe que tudo está bem e há uma série de picos. Não estou preocupado com as gravações, apenas as leituras parecem travar.

Monitor de tarefas durante o final do backup Observe muito pouca ação de ligar / desligar, apesar de um desempenho impressionante no final.

Perfmon durante o mesmo Observe um máximo de 12 segundos, embora a média seja boa em geral.

Atualização - Fazendo backup no dispositivo NUL
Para isolar problemas de leitura e simplificar as coisas, executei o seguinte:

BACKUP DATABASE XXX TO DISK = 'NUL'

Os resultados foram exatamente os mesmos - começa com uma leitura intermitente e depois pára, retomando as operações de vez em quando:

Resultados

Update - IO barracas
Corri a consulta dm_io_virtual_file_stats de Jonathan Kehayias e Ted Kruegers livro (página 29), como recomendado pelo Shawn. Olhando para os 25 principais arquivos (um arquivo de dados cada um - todos os resultados sendo arquivos de dados), parece que as leituras são piores do que as gravações - talvez porque as gravações vão diretamente para o cache da SAN, enquanto as leituras frias precisam atingir o disco - apenas um palpite .

Paradas de IO

Atualização - Estatísticas de espera
Eu fiz três testes para reunir algumas estatísticas de espera. As estatísticas de espera são consultadas usando o script Glenn Berry / Paul Randals . E apenas para confirmar - os backups não estão sendo feitos em fita, mas em um LUN iSCSI. Os resultados são semelhantes se forem feitos no disco local, com resultados semelhantes ao backup NUL.

Estatísticas limpas. Funcionou por 10 minutos, carga normal: Sem backup

Estatísticas limpas. Funcionou por 10 minutos, carga normal + execução normal de backup (não concluída): Backup normal

Estatísticas limpas. Funcionou por 10 minutos, carga normal + backup NUL em execução (não foi concluído): Backup NUL

Atualização - Wtf, Broadcom?
Com base nas sugestões de Mark Storey-Smiths e nas experiências anteriores de Kyle Brandts com as placas de rede da Broadcom, decidi fazer algumas experiências. Como temos vários caminhos ativos, eu poderia alterar com relativa facilidade a configuração das NICs, uma por uma, sem causar interrupções.

Desabilitar o TOE e o Large Send Offload resultou em uma execução quase perfeita: insira a descrição da imagem aqui

Processed 1064672 pages for database 'XXX', file 'XXX' on file 1.
Processed 21 pages for database 'XXX', file 'XXX' on file 1.
BACKUP DATABASE successfully processed 1064693 pages in 58.533 seconds (142.106 MB/sec).

Então, qual é o culpado, TOE ou LSO? TOE ativado, LSO desativado: insira a descrição da imagem aqui

Didn't finish the backup as it took forever - just as the original problem!

TOE desativado, LSO ativado - com boa aparência: insira a descrição da imagem aqui

Processed 1064680 pages for database 'XXX', file 'XXX' on file 1.
Processed 29 pages for database 'XXX', file 'XXX' on file 1.
BACKUP DATABASE successfully processed 1064709 pages in 59.073 seconds (140.809 MB/sec).

E, como controle, desabilitei o TOE e o LSO para confirmar que o problema havia desaparecido: insira a descrição da imagem aqui

Processed 1064720 pages for database 'XXX', file 'XXX' on file 1.
Processed 13 pages for database 'XXX', file 'XXX' on file 1.
BACKUP DATABASE successfully processed 1064733 pages in 60.675 seconds (137.094 MB/sec).

Em conclusão, parece que o mecanismo de transferência de TCP de placas de rede Broadcom habilitado causou os problemas. Assim que o TOE foi desativado, tudo funcionou como um encanto. Acho que não encomendarei mais placas de rede Broadcom daqui para frente.

Atualização - inatividade do servidor CIFS
Hoje, o servidor CIFS idêntico e em funcionamento começou a exibir solicitações de E / S pendentes. Este servidor não estava executando o SQL Server, apenas o Windows Web Server 2008 R2 servindo compartilhamentos pelo CIFS. Assim que desativei o TOE, tudo voltou ao normal.

Apenas confirma que nunca mais voltarei a usar o TOE nas placas de rede da Broadcom, se é que não consigo evitar as placas de rede da Broadcom.

Mark S. Rasmussen
fonte
Os arquivos de dados estão em um LUN RAID10 de 6 discos dedicado. Os arquivos de backup são armazenados em um LUN separado. Até agora, não vejo indicações de que a unidade / arquivos de backup sejam afetados, apenas parece ser a unidade de dados.
Mark S. Rasmussen
O cache de gravação está ativado para todos os LUNs, configurações padrão em geral. Não acho que seja relacionado ao cache, pois até os backups NUL mostram problemas - eliminando, assim, os problemas de gravação. Para leitura, cada controlador possui 2 GB de cache de leitura, além da memória no host (que possui um PLE infinito com bastante memória).
Mark S. Rasmussen

Respostas:

14

Observe que todos os servidores usam as mesmas NICs - Broadcom 5709Cs com drivers atualizados. Os próprios servidores são do Dell R610.

Kyle Brandt tem uma opinião sobre as placas de rede Broadcom que ecoam minha própria experiência (repetida).

Broadcom, Die Mutha

Meus problemas sempre foram associados aos recursos de transferência TCP e, em 99% dos casos, desativar ou alternar para outra placa de rede resolveu os sintomas. Um cliente que (como no seu caso) usa servidores Dell, sempre solicita placas de rede Intel separadas e desativa as placas Broadcom integradas na montagem.

Conforme descrito nesta postagem do blog do MSDN , eu começaria desativando o SO com:

netsh int ip set chimney DISABLED

Segundo o IIRC, em algumas circunstâncias, pode ser necessário desativar os recursos no nível do driver da placa; certamente não fará mal fazê-lo.

Mark Storey-Smith
fonte
4

Não que eu seja um especialista em SAN / disco (existem pessoas aqui que sabem mais do que eu) ... Eu só compartilho o que fiz um pouco e li principalmente :)

Jonathan Kehayias e Ted Krueger escreveram um livro "Solucionando problemas do SQL Server", com boas informações sobre o desempenho do disco. Você pode obter o PDF gratuitamente a partir daqui . (Também posso comprar a edição impressa para a minha mesa.)

De qualquer forma, eles têm uma boa consulta que pode ser usada para verificar o sys.dm_io_virtual_file_stats e a latência média nos arquivos de dados. Você pode achar que o RAID10 não é a configuração ideal para os arquivos de dados residirem.

Shawn Melton
fonte
Mesmo que o RAID10 não tenha sido a configuração ideal, não vejo esse problema aqui. Há praticamente zero atividade nos discos durante o uso normal, e um nível RAID incorreto não seria capaz de explicar solicitações de E / S lentas como essas. Como o SQLIO mostra, sou capaz de escrever com 200MB / s + e ler com 100MB / s + com 2-4k IOPS - então há muita capacidade. Atualizei a postagem com os resultados da consulta dm_io_virtual_file_stats. Observe que a imagem é maior se você a abrir diretamente.
Mark S. Rasmussen