Dicas do dia a dia – Melhorando a performance reduzindo os waits do T-Log

Olá pessoal tudo certo?

No post de hoje quero compartilhar com vocês uma situação que é bastante comum no meu dia a dia de Consultor de Banco de Dados SQL Server.

Estava realizando uma atividade de tuning em um cliente e percebi que quando executava algo que escrevia no log de transação e acompanhava o progresso através da sp_whoisactive ( http://whoisactive.com/ ) eu visualizava alguns WAITs relacionados ao log de transação.

Antes de simular o problema, vamos entender de maneira rápida e simples como funciona o Transaction Log no SQL Server.

Como sabemos, quando estamos executando algum comando que faça a alteração, inserção ou exclusão de dados, o SQL Server primeiro grava a operação no Transaction Log para depois escrever no disco, correto?

R: NÃO!!!

Nesse meio aí tem um outro camarada chamado Log Buffer, que é uma região em memória que está dentro do buffer pool do SQL Server. Somente após o checkpoint que vai acontecer um flush dos dados que estão em memória e eles serão movidos para o disco.

Agora vamos simular o problema.

Para simular o problema eu vou criar uma nova database na minha instância chamada “Wait_Log” e armazenei o Transanction Log em um HD externo. Após criar a database, criei uma tabela e depois vou fazer umas inserções através do QueryStress.

CREATE TABLE TBL_PAGAMENTO
(ID_Pessoa INT,
Dt_Pagamento DATETIME,
Vl_Pagamento DECIMAL,
)

Ao executar a seguinte query em 10 threads no QueryStress, comecei a ter os seguintes WAITs.

DECLARE @id INT
SET @id = 1
   WHILE @id < 10000
   BEGIN
	INSERT INTO TBL_PAGAMENTO
       	VALUES
           (@id,
		   DATEADD(MINUTE,+75,GETDATE())
           ,53.232+0.05)
	SET @id = @id + 1
   END

Com o cenário criado, encontramos dois WAITs diferentes relacionados ao Transaction Log: “WRITELOG” e “LATCH-EX [LOG_MANAGER]”.

WRITELOG – De maneira simples, esse é o WAIT mais comum relacionado ao T-Log. Ele está relacionado ao tempo que a Engine do SQL Server está esperando para escrever no T-Log.

LATCH-EX [LOG_MANAGER] – Esse WAIT é comum quando o SQL Server está realizando o auto-growth do arquivo do T-Log. Repare que no print acima as transações com esse WAIT estão sendo bloqueadas pela transação com o ID 74, justamente a transação que está fazendo o arquivo do T-Log crescer.

Também podemos ver o valor alto de “Log Flush Waits” no perfmon, além do nosso valor de batch request estar baixo.

Como podemos tentar resolver ou amenizar esse problema?

Bom, a primeira opção seria fazer uma optimização no código, tentando quebrar o código em intervalos menores, ou então uma opção que testei foi a dica que o Fabiano Amorim deu no seu treinamento, 25 Dicas de Performance, na plataforma de treinamentos do #TeamFabricioLima, que é colocar o WHILE dentro de uma transação.

DECLARE @id INT
SET @id = 1
begin tran
   WHILE @id < 10000
   BEGIN
    INSERT INTO TBL_PAGAMENTO
           VALUES
           (@id,
           DATEADD(MINUTE,+75,GETDATE())
           ,53.232+0.05)
    SET @id = @id + 1
   END
 commit

Vamos comparar a performance.Os WAITs reduziram drasticamente, praticamente não consegui capturar mais o WRITELOG.

Vamos comparar a performance.

Os WAITs reduziram drasticamente, praticamente não consegui capturar mais o WRITELOG.

As estatísticas do consumo também melhoraram bastante!

Como podemos observar, o contator “Log Flush Wait Time” ficou zerado, o contador “Log Flushes/sec” também reduziu bastante!

E tempo de execução tivemos alguma melhora?

R: SIM!!!

O tempo de execução baixou de mais de 2 minutos para 45 segundos! Ou seja, foi reduzido mais da metade do tempo!

Por que tivemos essa melhora?

Essa melhora ocorreu por que o SQL Server processou as 10 mil inserções em uma única transação. Nem sempre é possível realizar essa otimização, mas ela pode ser uma boa solução. Já imaginou todo o trabalho que o SQL Server tem para abrir e fechar 10 mil transações? Agora imagine como seria muito mais simples fazer tudo em uma única transação!

Podemos realizar outras melhorias?

R: SIM!!!

Podemos utilizar uma funcionalidade do SQL Server chamada Delayed Durability. Quando habilitamos essa funcionalidade o SQL Server passa a “ignorar” o log de transação e escreve direto no disco.

Se você quiser conhecer mais sobre essa funcionalidade, o Caio Amante tem um vídeo no seu blog (O funcionamento do Delayed Durability) que demonstra como utilizar, os benefícios e os riscos.

--- O VALOR DEFAULT É DISABLED
ALTER DATABASE Wait_Log SET DELAYED_DURABILITY = FORCED

Vamos executar a query novamente e verificar se vamos ter alguma melhora no tempo e nos contadores.

DECLARE @id INT
SET @id = 1
begin tran
   WHILE @id < 10000
   BEGIN
    INSERT INTO TBL_PAGAMENTO
           VALUES
           (@id,
           DATEADD(MINUTE,+75,GETDATE())
           ,53.232+0.05)
    SET @id = @id + 1
   END
 commit

Vamos as comparações.

Os contadores tiveram uma melhora considerável.

O “Log Flush Wait Time” ficou zerado e quase triplicou os “Batch Requests”.

Novamente não consegui capturar o WAIT WRITELOG.

Além disso, o tempo de execução da nossa query caiu de 45 para 20 segundos!

Como podemos ver, os benefícios de habilitar o “Delayed Durability” são grandes, ainda mais se for uma base ou instância de BI e ETL, onde uma perda mínima de dados e tolerável.

Poxa Tiago, legal até aí, mas tem mais alguma coisa que podemos melhorar?

R: SIM!!!

Até aqui conseguimos obter grandes melhorias sem realizar investimentos financeiros (“R$$$$$$$”), mas agora o patrão liberou uma verba e vamos torrar essa grana em um hardware TOP. Em ambientes OLTP, normalmente devemos privilegiar o arquivo de log em um disco rápido, então se você tem condições de mover o seu transaction log para um disco mais rápido, ou SSD, você vai melhorar ainda mais a performance da nossa query.

Para finalizar, vou fazer um último teste. Agora o meu arquivo de T-Log também está armazenado em um disco SSD. Os contadores de performance tiveram alguns ganhos.

O “Log Flush Wait Time” ficou zerado e chegamos a quase 14 mil “Batch Requests/Sec”!

Novamente não tivemos o WAIT WRITELOG.

Além do tempo de execução ter baixado de 20 para 13 segundos.

Além disso, existem outras boas práticas que podemos utilizar para melhorar ainda mais a performance do T-Log, como por exemplo na hora de criar a database, alterar o auto-growth do T-Log para crescer em “MB” e não em “%”. Além disso, se você puder estimar o tamanho do T-Log e já criá-lo no tamanho ideal, você evita operações de growth no T-Log e consequentemente o WAIT LATCH-EX [LOG_MANAGER] (vide o print do início do post).

Além dessas dicas, sempre tomem cuidado com a fragmentação dos VLFs (Virtual Log File), eles podem impactar na performance das suas queries, no tempo do restore dos seus backups e o tempo de sua instância voltar no caso de algum crash.

Se você quiser saber mais sobre os cuidados com a fragmentação do T-Log, segue uma série de posts que recomendo a leitura.

Controle Automático dos VLFs – Edvaldo Castro

Fragmentação do Transaction Log – Parte 1 – Leandro Ribeiro

Fragmentação do Transaction Log – Parte 2 – Leandro Ribeiro

Transaction Log VLFs – too many or too few? – Kimberly L. Tripp

Se você quiser fazer um curso sinistro e o melhor de tudo de forma gratuita, tem um treinamento de T-Log Internals do Luti no Youtube.

https://www.youtube.com/playlist?list=PLGaWZx_3bztdZNnrFSluDpaPjaB6IAx6-

Bom pessoal por hoje é isso.

Um grande abraço.

Tiago Neves

Curta a minha página no facebook e fique por dentro das novidades do mundo SQL Server.