Tracking BACKUP operation

No blog post anterior, falei um pouco sobre o conceito que envolve este novo XE bem como os traceflags que tínhamos disponíveis até então, e uma das formas para se mapear as atividades realizadas durante um procedimento de BACKUP ou RESTORE.

Dando continuidade, neste neste post será feito um teste do mesmo XE, porém para uma operação de RESTORE.

O teste

A mesma base de dados do teste anterior foi utilizada, conforme os dados abaixo:

• Database_Size: 36.698 MB
• DataFileSize: 30.553 MB
• LogFileSize: 6.146 MB
• BackupSize: 24.153 MB
• CompressedBackupSize: 4.364 MB

Para maiores detalhes da configuração e introdução a este Extended Event, acesse o post [XE SQL 2016] – Track Backup e Restore – Parte 1 sobre este novo XE.

Lembrando que a mesma sessão do XE pode ser utilizada para acompanhar o progresso das operações de BACKUP e também de RESTORE.

Código T-SQL do backup:

BACKUP DATABASE BDXeTeste
TO DISK = ‘D:MSSQLSQL2016BACKUPBDXeTeste.bak’
WITH STATS = 1

Resultado do teste

Conforme executado no teste anterior, abaixo será exibido o output do XE, bem como uma explicação detalhada dos principais itens.

Figura 1:

• BACKUP DATABASE started
  • Início da operação de backup do banco de dados.
• Opening the database with S lock
  • Neste momento é adquirido um lock do tipo “shared” no banco de dados, para início da leitura dos dados.
• Acquiring bulk-op lock on the database
  • Adquirido um lock do tipo “bulk-op” para cópia dos dados.
• Synchronizing with other operations on the database is complete
• Opening the backup media set
  • Neste ponto é iniciado a verificação do acesso ao diretório onde o backup será criado, bem como espaço disponível para criação do arquivo de backup.
• The backup media set is open
• Preparing the media set for writing
  • Após o arquivo ter sido previamente “alocado” e validadas as possibilidades de gravação no diretório, o “media set” é preparado para iniciar o processo de escrita (gravação).
• The media set is ready for backup
• Efective options: Checksum=0, Compression=0, Encryption=0, BufferCount=7, MaxTransferSize=1024 KB
  • Neste ponto são checadas as opções adicionais do backup, como: Checksum, Compressão, Criptografia, além das tão importantes BufferCount e MaxTransferSize, que podem ser de grande valia quando deseja-se aumentar o throughput do backup,  reduzindo consequentemente o tempo total de execução do mesmo. Um pouco mais detalhado em outro post que escrevi “[SQL Server Backup Internals] – Backup Full“
• Clearing differential bitmaps
  • Uma das fases do backup full é limpar (ou zerar) a DCM (Differential Change Map), que é a página com Page_id = 6, responsável por mapear as alterações realizadas após o backup full, para fins de geração de backups do tipo “Differential”. Neste ponto é realizado a limpeza da DCM, fazendo com que este backup full seja a base para novos backups diferenciais.
• Differential bitmaps are cleared
• Writing a checkpoint
• Checkpoint is complete (elapsed = 16 ms)
  • Realizado um checkpoint, para marcar o início do backup, bem como o LSN inicial.

Figura 2:

• Start LSN: 293881:2670:1, SERepl LSN: 0:0:0
  • Gravado o LSN inicial.
• Scanning allocation bitmaps
• Scanning allocation bitmaps is complete
  • Neste ponto é realizado um scan nas páginas de alocação para fins de cálculo de espaço e tamanho do backup.
• Calculating expected size of total data
  • Realizando o cálculo esperado do tamanho total de dados a serem copiados.
• FID=1, ExpectedExtents=379167, IsDifferentialMapAccurate=0
  • Informação sobre o(s) arquivo(s) de dados, e quantidade de extents esperados para o backup, neste caso 379167 (extents) * 64 (KB por extent) =~ 24.266.688 Kilobytes
• TotalSize=24849088512 bytes
  • Tamanho total em bytes
• Estimated total size = 26291393536 bytes (data size = 24849088512 bytes, log size = 1442305024 bytes)
  • Tamanho total estimado em bytes dos dados, e do log.
• Work estimation is complete
  • Conclusão do trabalho de estimativa sobre o backup que será realizado.
• Last LSN: 293925:219912:1
  • LSN final dos dados que farão parte do backup.
• Writing the leading metadata
• BackupStream(0): Writing leading metadata to device D:MSSQLSQL2016BACKUPBDXeTeste.bak
  • Neste ponto é realizado a gravação dos metadados no arquivo de destino do backup. Estas informações podem ser recuperadas posteriormente pelas opções: FILELISTONLY e HEADERONLY
• Calculating expected size of total data
• FID=1, ExpectedExtents=379167, IsDifferentialMapAccurate=0
• TotalSize=24849088512 bytes
• Copying data files
  • Copiando os dados dos arquivos de dados.
• Number of data file readers = 1
  • Número de readers que farão as leituras nos arquivos de dados para execução do backup.
• Reading the data file D:MSSQLSQL2016|DATABDXeTeste.mdf
  • Informação de leitura do arquivo de dados (.mdf), o backup é lido diretamente do arquivo de dados, copiado em uma área de memória (MEMORYCLERK_SQLUTILITIES) específica para este fim e em seguida gravado no arquivo de destino (geralmente .bak)
• BackupStream(0): Writing MSDA of size 379168
  • Escrevendo os dados lidos do datafile .
• 1 percent (263061504/26291393536 bytes) processed
  • Percentual já processado. Note que o cálculo é exibido em detalhe e mostrado exatamente o size do que já foi copiado.

Figura 3

• 94 percent (24714018816/26291393536) processed
  • Percentual já processado
• Completed reading the data file D:MSSQLSQL2016DATABDXeTest.mdf
  • Fim da leitura de TODOS os extents do arquivo de dados, que irão para o arquivo de backup.
• BackupStream(0): Padding MSDA with 65536 bytes
  • Completando a cópia dos dados com 65536 bytes
• BackupStream(0): Total MSDA size = 379168 extents
  • Informação do tamanho total de extents copiados.
• InitialExpectedSize=24849088512 bytes, FinalSize=24849088512 bytes, ExcessMode=0
  • Balanço entre tamanho inicial experado e tamanho final atingido, bem como a informação de divergências.
• Last LSN: 293925:219912:1
  • Último LSN do backup.
• Copying data files is complete
  • Informação de conclusão da cópia do(s) datafile(s)
• Copying transaction log
  • Iniciando a cópia do arquivo de transaction log. Esta é a porção ativa do log de transações contendo todas as transações que realizadas após o primeiro checkpoint e anteriores ao último checkpoint.
• MediaFamily(0): FID=2, VLFID=293887, DataStreamSize=26214400 bytes
  • Informação sobre cópia do VLF 293887 do arquivo com ID=2 com tamanho de 26214400 bytes
• MediaFamily(0): FID=2, VLFID=293888, DataStreamSize=26214400 bytes
  • Informação sobre cópia do VLF 293887 do arquivo com ID=2 com tamanho de 26214400 bytes

Figura 4

• 100 percent (26291393536/26291393536 bytes) processed
  • Percentual processado:
• Copying transaction log is complete
  • Informação de finalização da cópia do log de transações.
• Writing the trailing metadata
  • Escrevendo os metadados finais.
• BackupStream(0): Writing trailing metadata to the device D:MSSQLSQL2016BACKUPBDXeTeste.bak
  • Finalizando a escrita dos metadados no arquivo de backup (.bak)
• Writing the end of backup set
• Writing history records
  • Escrevendo os registros da operação nas tabelas de sistema no banco de dados MSDB.
• Writing history records is complete (elapsed = 19 ms)
• BACKUP DATABASE finished
  • BACKUP FINALIZADO COM SUCESSO.

Se gostou, deixe um like, comentário, crítica ou um abraço nos comentários…

Grande Abraço,

Edvaldo Castro

Curta a página do Facebook:

http://facebook.com/edvaldocastro

Siga no Twitter

http://twitter.com/edvaldocastro02