Database
 sql >> Base de Dados >  >> RDS >> Database

T-SQL terça-feira #67:Novos eventos estendidos de backup e restauração




Para o T-SQL terça-feira do mês passado, escrevi sobre alguns sinalizadores de rastreamento não documentados que ajudam você a cuidar de operações de backup e restauração de longa duração. Este mês, o tópico de Jes Borland é Eventos Estendidos, e pensei em mostrar novos recursos no SQL Server 2016 que tornam esses sinalizadores de rastreamento obsoletos.

Se você estiver jogando com CTP2 (você pode baixá-lo aqui), você pode notar uma nova categoria backup_restore e novo evento backup_restore_progress_trace :

Descobrindo um novo evento na caixa de diálogo Nova sessão do CTP2

Aqui está uma sessão XE rápida e suja para capturar os dados para este evento (adicionei comentários para filtrar apenas operações de backup ou restauração; por padrão, ambos estão incluídos):
CREATE EVENT SESSION [Backup progress] ON SERVER 
ADD EVENT sqlserver.backup_restore_progress_trace
(
    ACTION(package0.event_sequence)
 
    -- to only capture backup operations:
    --WHERE [operation_type] = 0
 
    -- to only capture restore operations:
    --WHERE [operation_type] = 1 
)
ADD TARGET package0.event_file 
(
  SET filename = N'C:\temp\BackupProgress.xel'
); -- default options are probably ok
GO
 
ALTER EVENT SESSION [Backup progress] ON SERVER STATE = START;
GO

Agora, digamos que eu execute as seguintes operações – criar um banco de dados, fazer backup de alguns dados, soltá-lo e restaurá-lo:
USE [master];
GO
CREATE DATABASE floob;
GO
SELECT s1.* INTO floob.dbo.what 
  FROM sys.all_objects AS s1 
  CROSS JOIN sys.all_objects;
GO
BACKUP DATABASE floob TO DISK = 'c:\temp\floob.bak' 
  WITH INIT, COMPRESSION, STATS = 30;
GO
DROP DATABASE floob;
GO
RESTORE DATABASE floob FROM DISK = 'c:\temp\floob.bak' 
  WITH REPLACE, RECOVERY;

Agora, podemos consultar os dados do arquivo de destino do evento:
;WITH x AS 
(
  SELECT ts,op,db,msg,es
  FROM 
  (
   SELECT 
    ts  = x.value(N'(event/@timestamp)[1]', N'datetime2'),
    op  = x.value(N'(event/data[@name="operation_type"]/text)[1]', N'nvarchar(32)'),
    db  = x.value(N'(event/data[@name="database_name"])[1]', N'nvarchar(128)'),
    msg = x.value(N'(event/data[@name="trace_message"])[1]', N'nvarchar(max)'),
    es  = x.value(N'(event/action[@name="event_sequence"])[1]', N'int')
   FROM 
   (
    SELECT x = CONVERT(XML, event_data) 
     FROM sys.fn_xe_file_target_read_file
          (N'c:\temp\Backup--Progress*.xel', NULL, NULL, NULL)
   ) AS y
  ) AS x 
  WHERE op = N'Backup' -- N'Restore'
  AND db = N'floob'
  AND ts > CONVERT(DATE, SYSUTCDATETIME())
)
SELECT /* x.db, x.op, x.ts, */ 
  [Message] = x.msg, 
  Duration = COALESCE(DATEDIFF(MILLISECOND, x.ts, 
             LEAD(x.ts, 1) OVER(ORDER BY es)),0)
FROM x
ORDER BY es;

Para um backup, o sinalizador de rastreamento 3226 não suprime nenhuma saída capturada pelos Eventos Estendidos. Deixei de fora as colunas de saída, devido aos filtros, por brevidade:
Mensagem Duração
(milissegundos)
BACKUP DATABASE iniciado 0
Abrindo o banco de dados com bloqueio S 0
Adquirindo bloqueio de operação em massa no banco de dados 0
A sincronização com outras operações no banco de dados foi concluída 19
Abrindo o conjunto de mídia de backup 7
O conjunto de mídia de backup está aberto 0
Preparando o conjunto de mídia para gravação 0
O conjunto de mídia está pronto para backup 0
Opções efetivas:Checksum=0, Compression=1, Encryption=0, BufferCount=7, MaxTransferSize=1024 KB 0
Limpando bitmaps diferenciais 4
Os bitmaps diferenciais são apagados 0
Escrevendo um ponto de verificação 6
O ponto de verificação foi concluído (decorrido =6 ms) 0
Iniciar LSN:101:111920:43, SERepl LSN:0:0:0 0
Verificando bitmaps de alocação 4
A digitalização de bitmaps de alocação está concluída 0
Calculando o tamanho esperado do total de dados 0
FID=1, ExpectedExtents=10047, IsDifferentialMapAccurate=0 0
TotalSize=658440192 bytes 0
Tamanho total estimado =658460672 bytes (tamanho dos dados =658440192 bytes, tamanho do log =20480 bytes) 0
A estimativa de trabalho foi concluída 0
Último LSN:101:111960:1 0
Escrevendo os metadados principais 0
BackupStream(0):gravando metadados principais no dispositivo c:\temp\floob.bak 1
Calculando o tamanho esperado do total de dados 0
FID=1, ExpectedExtents=10047, IsDifferentialMapAccurate=0 0
TotalSize=658440192 bytes 1
Copiando arquivos de dados 2
Número de leitores de arquivos de dados =1 0
Ler o arquivo de dados D:\SQL Server\MSSQL13.SQL16\DATA\floob.mdf 0
BackupStream(0):escrevendo MSDA de extensão de tamanho 10048 391
30 por cento (198180864/658460672 bytes) processados ​​ 554
60 por cento (395313152/658460672 bytes) processados ​​ 576
90 por cento (593494016/658460672 bytes) processados ​​ 184
Concluída a leitura do arquivo de dados D:\SQL Server\MSSQL13.SQL16\DATA\floob.mdf 2
BackupStream(0):Preenchendo MSDA com 65.536 bytes 0
BackupStream(0):tamanho total do MSDA =10.048 extensões 0
InitialExpectedSize=658440192 bytes, FinalSize=658440192 bytes, ExcessMode=0 0
Último LSN:101:111960:1 0
A cópia dos arquivos de dados está concluída 0
Copiando log de transações 0
MediaFamily(0):FID=2, VLFID=101, DataStreamSize=65536 bytes 4
A cópia do log de transações foi concluída 0
Escrevendo os metadados finais 0
BackupStream(0):gravando metadados finais no dispositivo c:\temp\floob.bak 0
Gravando o final do conjunto de backup 30
Gravando registros de histórico 12
A gravação dos registros do histórico foi concluída (decorrido =11 ms) 0
BACKUP DATABASE finalizado 0

Dados de evento para uma operação de backup

Para uma restauração, você verá estas linhas:
Mensagem Duração
(milissegundos)
RESTORE DATABASE iniciado 0
Abrindo o conjunto de backup 3
Processando os metadados principais 0
O planejamento começa 23
Opções efetivas:Checksum=0, Compression=1, Encryption=0, BufferCount=6, MaxTransferSize=1024 KB 0
O planejamento está concluído 0
Começando a restauração OFFLINE 0
Banco de dados anexado como DB_ID=5 1
Preparando contêineres 534
Os contêineres estão prontos 1097
Restaurando o conjunto de backup 0
Tamanho total estimado para transferência =658460672 bytes 0
Transferindo dados 1
BackupStream(0):Processando MSDA de extensões de tamanho 10048 3282
BackupStream(0):MSDA concluído 0
Aguardando a conclusão da zeragem do log 3
A zeragem do log foi concluída 0
BackupStream(0):Processando MSTL (FID=2, VLFID=101, size=65536 bytes) 1024
A transferência de dados foi concluída 14
O conjunto de backup foi restaurado 45
O rollforward off-line começa 1
Processando 68 cabeçalhos VLF 69
O processamento de cabeçalhos VLF está concluído 11
Primeiro LSN:101:111920:43, Último LSN:101:111960:1 0
Parar LSN:101:111960:1 4
O rollforward off-line foi concluído 17
A correção do banco de dados foi concluída 2
Transição do banco de dados para ONLINE 2
Reiniciando o banco de dados para ONLINE 87
PostRestoreContainerFixups começa 5
PostRestoreContainerFixups está completo 2
PostRestoreReplicationFixup começa 107
PostRestoreReplicationFixup está completo 2
O banco de dados é reiniciado 9
Retomar qualquer rastreamento de texto completo interrompido 6
Gravando registros de histórico 13
A gravação dos registros do histórico foi concluída (decorrido =13 ms) 2
A manutenção do MSDB está concluída 2
RESTORE DATABASE concluído 0

Dados de evento para uma operação de restauração

Se você estiver solucionando problemas de uma operação lenta de backup ou restauração, poderá filtrar facilmente pela duração, para ver apenas eventos que levaram mais de n milissegundos, por exemplo. A única coisa que não vejo nesta saída é alguma maneira de saber se a inicialização instantânea do arquivo estava em vigor durante a restauração – você ainda pode precisar do sinalizador de rastreamento 3004, conforme descrito em meu post para o T-SQL terça-feira do mês passado.

Não se esqueça de parar a sessão (mas fique à vontade para manter a definição da sessão no servidor, para poder usá-la novamente):
ALTER EVENT SESSION [Backup progress] ON SERVER STATE = STOP;

Não realizei nenhum teste de desempenho ou análise de impacto, mas, em geral, diria que – como os sinalizadores de rastreamento – isso não é algo que você deseja executar o tempo todo, mas apenas ao solucionar problemas de uma operação específica. É um pouco mais fácil configurar esta sessão e consultar os dados, IMHO, do que ativar os sinalizadores de rastreamento e analisar toda a saída do log de erros do SQL Server.