Transaction Log, LSN, DBCC LOGINFO e VLFs (Backup/Restore – Parte 2 de ?)

Continuando com o assunto de backup e restore, é importante que o funcionamento do log de transação esteja claro para todos, pois esse é um dos pilares para garantirmos a integridade dos nossos dados. Nesse artigo vamos mostrar alguns detalhes internos do TLog (transaction log) e sua relação com o crescimento do log e backups.

Como já é de conhecimento, o log de transação registra as transações que são executadas nos bancos de dados utilizando-se do protocolo WAL (write-ahead logging), fundamental para garantir que depois de confirmada (commit) uma transação nunca será perdida, mesmo se houver uma falha de energia por exemplo.

Internamente o TLog é divido em virtal log files (VLFs) que podem estar ativos ou não. Um VLF está ativo se este possue transações abertas ou que ainda não foram salvas em um backup. Para um maior detalhamento da estrutura do logs, leia o tópico Transaction Log Architecture no BOL.

Utilize o script anexado a este artigo para acompanhar a execução dos passos, lembrando sempre de que os resultados podem variar, mas o entendimento será o mesmo. Após a execução do passo 0, estamos com o nosso famoso banco de dados Inside criado.

No passo 01 eu apresento o comando DBCC LOGINFO. Esse comando não é documentado pela Microsoft, mas já é de conhecimento público há bastante tempo. Após conversar com Paul Randal fui autorizado a detalhar a instrução no artigo e, segundo ele mesmo disse: “DBCC LOGINFO is a well known undocumented command”.

DBCC TRACEON(3604)

DBCC LOGINFO('Inside')

go

/*

FileId FileSize StartOffset FSeqNo Status Parity CreateLSN

----------- --------------------------------------- --------------------------------------- ----------- ----------- ------ ---------------------------------------

2 253952 8192 6 2 64 0

2 253952 262144 0 0 0 0

*/

Aqui podemos tirar algumas informações do TLog:

- Atualmente ele é composto de 2 VLFs de 248 KB cada um.

- O primeiro VLF começa no offset 8192, pois os primeiros 8K são sempre reservados para o cabeçalho do TLog.

- O VLF de FSeqNo igual a seis está ativo (status = 2), enquanto o outro VLF ainda não foi utilizado.

- O tamanho mínimo de cada VLF é de 248 KB (1024 * 248 = 253952 bytes).

- O LSN de quando o VLF foi criado (CreateLSN) é zero, o que indica que ele existe desde a criação do banco de dados.

Após a execução dos passos 3 e 4, podemos ver que um novo VLF de 270336 bytes (264 KB) foi adicionado ao TLog e está ativo (status = 2), com número de seqüência igual a sete. O novo LSN possui um CreateLSN igual a 6000000047900001, o que indica que ele foi adicionado após a criação do banco de dados. Vale notar que neste momento existem dois VLFs ativos, seis e sete.

DBCC LOGINFO('Inside')

go

/*

FileId FileSize StartOffset FSeqNo Status Parity CreateLSN

----------- --------------------------------------- --------------------------------------- ----------- ----------- ------ ---------------------------------------

2 253952 8192 6 2 64 0

2 253952 262144 0 0 0 0

2 270336 516096 7 2 64 6000000047900001

*/

O log do SQL Server possui um crescimento automático de 10% e estava com 504 KB quando cresceu, porém como não podemos ter VLFs menores que 248 KB, o tamanho de 50,4 KB para o crescimento foi ignorado.

Fica aqui uma pergunta: porque o SQL Server não utilizou o VLF que já existia (estava zerado) e criou outro, utilizando-o primeiro?

Após inserir mais 300 registros (passo 5) era esperado que mais VLFs fossem criados para o TLog, mas não foi isso que o DBCC LOGINFO mostrou:

DBCC LOGINFO('Inside')

go

/*

FileId FileSize StartOffset FSeqNo Status Parity CreateLSN

----------- --------------------------------------- --------------------------------------- ----------- ----------- ------ ---------------------------------------

2 253952 8192 6 0 64 0

2 253952 262144 8 2 64 0

2 270336 516096 7 0 64 6000000047900001

*/

Neste momento temos o VLF do meio (FSeqNo = 8) sendo utilizado enquanto os outros dois estão inativos. Para isso eu tenho outra pergunta capciosa: se o banco de dados está configurado com RECOVERY MODEL = FULL (veja passo 06), porque o SQL Server marcou dois VLFs como inativos (Status = 0) sem que eu tenha feito um backup de log?

Vamos responder essa pergunta com outra pergunta (quem não adora isso!).

P: O que é necessário restaurar antes utilizarmos um backup do log de transação?

R: Um backup full do banco de dados.

Um backup completo já foi feito? Não?! Faz algum sentido para o SQL Server manter as transações no log se elas simplesmente não poderão ser recuperadas em caso de falha? Não! Até que seja feito o primeiro backup completo, o banco de dados vai trabalhar com recovery model SIMPLE, Mesmo com a configuração estando definida como FULL. Um comportamento perfeito, pois dessa forma não existe desperdício do log sem necessidade.

No passo 07 nós vemos como o log de transação se comporta com o modo de recuperação simples, marcando VLFs como inativos quando o log é truncado em cada checkpoint.

Para executarmos esse passo é necessário utilizar duas janelas do Query Analyzer (ou Management Studio), disparando quase que simultaneamente os dois loops. Enquanto as 100.000 inserções são feitas (ou parte delas), o DBCC LOGINFO será executado múltiplas vezes em outra conexão. Lembre-se de cancelar os inserts quando o loop do LOGINFO terminar. Abaixo temos o loop que fica coletando informações do TLog a cada 5 segundos:

DECLARE @CONTADOR INT

SET @CONTADOR = 0

WHILE @CONTADOR < 10

BEGIN

       WAITFOR DELAY '00:00:05'

       DBCC LOGINFO('Inside')

       SET @CONTADOR = @CONTADOR + 1

END

O resultado parcial do loop é:

/*

FileId FileSize StartOffset FSeqNo Status Parity CreateLSN

----------- --------------------------------------- --------------------------------------- ----------- ----------- ------ ---------------------------------------

2 253952 8192 42 2 64 0

2 253952 262144 41 0 128 0

2 270336 516096 40 0 128 6000000047900001

(3 row(s) affected)

DBCC execution completed. If DBCC printed error messages, contact your system administrator.

FileId FileSize StartOffset FSeqNo Status Parity CreateLSN

----------- --------------------------------------- --------------------------------------- ----------- ----------- ------ ---------------------------------------

2 253952 8192 66 0 64 0

2 253952 262144 68 2 64 0

2 270336 516096 67 0 64 6000000047900001

(3 row(s) affected)

DBCC execution completed. If DBCC printed error messages, contact your system administrator.

FileId FileSize StartOffset FSeqNo Status Parity CreateLSN

----------- --------------------------------------- --------------------------------------- ----------- ----------- ------ ---------------------------------------

2 253952 8192 93 2 128 0

2 253952 262144 92 0 64 0

2 270336 516096 94 2 128 6000000047900001

(3 row(s) affected)

(……)

FileId FileSize StartOffset FSeqNo Status Parity CreateLSN

----------- --------------------------------------- --------------------------------------- ----------- ----------- ------ ---------------------------------------

2 253952 8192 300 2 64 0

2 253952 262144 299 0 128 0

2 270336 516096 301 2 64 6000000047900001

*/

Veja que a cada foto do log de transação, um ou dois VLFs estão ativos (até o próximo checkpoint acontecer) e o FSeqNo está sempre crescendo. Aqui podemos ver o TLog circulando, sem necessidade de crescer devido ao comportamento do log no modo de recuperação simples.

Vou tentar explicar em mais detalhes o que está acontecendo:

0) As inserções na tabela LogInfo começam a acontecer.

1) VLF 42 (FSeqNo = 42) está ativo (os outros inativos).

2) As inserções continuam acontecendo e são registradas no VLF 42 até este ser preenchido.

3) Um VLF inativo (antigo FSeqNo 40) recebe o FSeqNo 43 e seu status passa a ser ativo (=2).

4) As inserções continuam acontecendo e passar a ser registradas pelo VLF 43, uma vez que o VLF 42 está cheio (seu status ainda é ativo).

a. Nesse momento temos em todas as transações (TLog) registradas em disco (ou mídia estável – stable media), seguindo o protocolo WAL. Todas as páginas alteradas até o momento (aquelas que receberam registros) estão em memória e marcadas como sujas (dirty), pois ainda não foram escritas em disco.

5) O SQL Server decide que é hora de fazer um checkpoint, de acordo com suas métricas internas, e inicia o procedimento.

6) Um número variável de páginas sujas é escrito em disco. De acordo com o LSN contido no cabeçalho de cada página o SQL Server verifica que todas as páginas modificadas pelas transações contidas no VLF 42 (cada uma numerada com seu LSN) foram escritas em disco.

7) Já que as páginas estão salvas em disco e o modo de recuperação é simples, o SQL Server trunca o log de transação marcando como inativo o VLF 42, deixando este passível de ser reutilizado. Esse comportamento é o famoso “truncate log on checkpoint”.

8) As inserções continuam até que o VLF 43 seja preenchido, quando retornamos para o passo 3 e todo o processo é repetido.

Neste artigo analisamos a instrução DBCC LOGINFO e o comportamento do SQL Server quando está com recovery model simple. No próximo artigo veremos o comportamento do recovery model full e o crescimento do log de transação, que precisa ser gerenciado para evitarmos maiores problemas.

Referências:

· SQL Server 7.0, SQL Server 2000, and SQL Server 2005 logging and data storage algorithms extend data reliability (https://support.microsoft.com/kb/230785)

[]s

Luciano Caixeta Moreira

luciano.moreira@microsoft.com

=============================================================

This posting is provided "AS IS" with no warranties, and confers no rights

=============================================================

20070430 - Transaction Log - LSN - DBCC LOGINGO - VLFs (backup-restore parte 2).zip