«

»

set 16

Análise de Lentidão – II

Mais um caso interessante onde a soma de fatores fez com que uma transação que deveria demorar 1 segundo demorasse mais de uma hora, mesmo com memória de sobra, processamento abaixo dos 10% e nenhum usuário conectado além do administrator.

 

 

 

 

Cenário

1.   SQL Server 2008 R2 Standard com Failover Cluster em um par de servidores Dell R720, 2x Xeon de 6 cores (24 com HT), 96GB de RAM, 1 volume de 1TB (unidade S) em storage High-end conectados através de fibra em HBA Dual, onde se concentram todos os arquivos do SQL Server de dados e TLog;

 

2.   Os servidores ainda não estavam em produção, durante a fase de testes observou-se lentidão generalizada na aplicação, principalmente em uma query específica que fazia apenas um SELECT de 38colunas de 5 tabelas. Esta query utiliza a cláusula WHERE ao invés de INNER JOIN, fazendo um sort com ORDER BY em 4 colunas;

 

3.   O tempo da query variava de 35 a 75 minutos e era executada enquanto nenhum outro usuário estava conectado na instância;

 

4.   Em outros ambientes a mesma query era retornada em menos de 1 segundo;

 

5.   O servidor ficou meses parado e tinha 48 horas para entrar em produção;

 

 

Simulação

Para simular o problema neste cenário era muito simples, bastava executar a query fornecida pelo fabricante da aplicação. Com os contadores do Perfmon configurados a query foi executada sozinha e depois de um intervalo, quatro conexões simultâneas executaram a mesma query, acentuando ainda mais as evidências.

 

Análise

Costumo configurar o Perfmon para exibir os últimos 10 minutos e de olho nos gráficos durante a primeira execução da query foi possível observar um consumo relativamente alto de I/O na unidade S (volume de 1TB), se pensarmos que é apenas uma query sendo executada sem concorrência com outros usuários, praticamente sem consumo de CPU e memória. Então a mesma query foi executada por 4 processos simultaneamente e ficou bem mais evidente. Vejam que o tempo de disco e o consumo de IOPS ocasionam uma fila média de quase 6,5:

 

Tempo de disco e IOPS

 

Fila de CPU

Fila de CPU

 

Consumo de Memória

Consumo de Memória

 

Buffer Manager

Buffer Manager

 

Vejam que realmente não temos atividade no servidor:

 

Atividade

 

Com estas informações (e olhando o contador Page File Usage %) dá pra perceber que não é paginação, mas com Cache Hit Ratio em 100,00% cravado fica difícil entender o que é que está sendo buscado no disco que consome tanto I/O, ainda mais depois de executar a mesma query repetidas vezes. Consultando as esperas tivemos um resultado interessante: 

Ao invés de encontrar PAGEIOLATCH, a espera era por IO_COMPLETION. Acompanhando a utilização da TempDB vemos que por conta do SORT em 4 colunas há um consumo de cerca de 1GB no arquivo de dados e 24MB de TLog, que está com tamanho inicial de 1MB e Autogrowth de 10%:

TempDB antes

TempDB antes

TempDB durante

TempDB durante

TempDB depois

TempDB depois

Vamos aproveitar pra lembrar que a TempDB, apesar de estar com o Recovery Model em SIMPLE, possui um comportamento diferente das bases de usuário. Como a TempDB é refeita a cada inicialização da Instância, não é feito o auto-checkpoint ao final da transação e o checkpoint também não obedece a configuração do Recovery Interval. Isso significa que a TempDB mantém páginas sujas e evita tocar o disco para gravá-las, já que são temporárias. Este comportamento resulta em utilização diferenciada do TLog, mantendo até os VLFs de transações comitadas marcados como ativos. No caso de TLogs com VLFs pequenos (fácil de supor pelo tamanho inicial e configuração de Autogrowth) a fragmentação pode ser um problema.

Em virtude do resultado do Perfmon somado com a informação de que o servidor ficou meses parado, o primeiro passo foi analisar a storage. Storages High-end se utilizam de diversas tecnologias para proporcionar melhor performance e uma delas é chamada popularmente de “Tierização”. Cada fabricante dá um nome diferente, a HP chama de Adaptive Optimization, a Dell chama de Optimize Data Placement, mas o princípio é o mesmo. São Tiers compostos por discos de performance diferentes, onde dados mais acessados ficam nos discos mais velozes, com RAIDs mais performáticos enquanto dados pouco acessados vão descendo até serem alocados em discos mais simples, utilizando RAIDs voltados apenas a redundância. 

Manualmente o volume foi forçado a ficar no Tier mais veloz e o cenário mudou, melhorando a performance do disco mas ainda com resultado insatisfatório. Vejam agora quantos IOPS conseguimos e o tempo de disco com a mesma query rodando em 4 sessões simultaneamente:

 

Disco depois

Disco depois

 

Conseguimos reduzir drasticamente o tempo de disco e obtivemos um aumento na quantidade de IOPS, o que comprova que o volume está mais performático. Porém, apesar de reduzir o tempo da query de minutos para segundos o resultado ainda era insatisfatório.

Não temos nenhum outro tipo de espera, exceto de Log Flush, levando em consideração a quantidade de transações por segundo:

Log Flush Wait Time

Log Flush Wait Time

 

Wait Stats

Wait Stats

 

Já que esta query era executada em menos de 1 segundo em outros ambientes sugeri a comparação dos Planos de Execução, onde pude constatar uma grande diferença na quantidade de linhas retornadas. Enquanto eram trazidas 200 linhas nos ambientes utilizados como parâmetro na comparação, no nosso caso eram retornadas mais de 4.000 linhas. Relacionando este fato com o espanto do desenvolvedor pela quantidade de linhas, pudemos concluir que a base estava poluída com informações utilizadas por testes anteriores.

 

Recomendações

1.   Criar uma nova base, eliminando a poluição da base com informações de testes;

2.   Dividir este volume de 1TB em outros volumes menores, separando arquivo de dados, TempDB e TLog;

3.   Configurar os arquivos de TLog para um tamanho inicial e crescimento adequados, visando diminuir a quantidade de VLFs e de operações de crescimento do arquivo;

4.   Adicionar 7 arquivos à TempDB, apenas preventivamente, com a finalidade de evitar contenção de GAM, SGAM e PFS. Configurar a trace flag 1117, para garantir a eficiência da utilização dos arquivos de dados;

5.   Adicionar o direito de Perform Volume Maintenance Tasks para o usuário do serviço do SQL Server, possibilitando que as operações de crescimento dos arquivos de dados sejam beneficiadas pelo recurso Instant File Initialization;

6.   Substituir a edição do SQL Server para Enterprise, para tornar disponíveis recursos como mais de 64GB de RAM, utilização dos 12 cores físicos disponíveis, Enhanced Read-Ahead Scan, além das opções de disponibilidade para ambientes críticos como Parallel Index Operations, Parallel Consistency Checks (DBCC) e Partitioning;

 

 

Resultado

De todas as recomendações, apenas a recriação das bases pôde ser aprovada de imediato, trazendo realmente para o resultado esperado menor que 1 segundo. Porém, ficou evidente o que pode acontecer se as demais recomendações não forem implantadas.

Assim que todas as ações forem concluídas trago o resultado.

4 comentários

Pular para o formulário de comentário

  1. Angelo Máximo Moreira Silva

    Ótimo artigo. A análise foi bem elaborada, não só coletando dados do ambiente, relacionado ao desempenho da query, como também procurou comparar a mesma query em outros ambientes, rodando de forma satisfatória.
    Parabéns Mercante !

  2. Junior Galvão - MVP

    Mercante, bom dia.

    Parabéns, muito legal o artigo e a sua forma de apresentar os possíveis caminhos para se resolver este problema.

    Até mais.

  3. Luiz Mercante

    Obrigado pessoal, agradeço pelo feedback.

    Abraços

  4. Anderson Souza

    Excelente artigo, parabéns.

Deixe uma resposta