Per il martedì di T-SQL del mese scorso, ho scritto di alcuni flag di traccia non documentati che ti aiutano a fare da babysitter a operazioni di backup e ripristino di lunga durata. Questo mese, l'argomento di Jes Borland è Eventi estesi e ho pensato di mostrare nuove funzionalità in SQL Server 2016 che rendono ampiamente obsoleti questi flag di traccia.
Se stai giocando con CTP2 (puoi scaricarlo qui), potresti notare una nuova categoria backup_restore
e il nuovo evento backup_restore_progress_trace
:
Scoperta di un nuovo evento nella finestra di dialogo Nuova sessione di CTP2
Ecco una sessione XE rapida e sporca per acquisire i dati per questo evento (ho aggiunto commenti per filtrare solo le operazioni di backup o di ripristino; per impostazione predefinita, sono inclusi entrambi):
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
Ora, supponiamo che io esegua le seguenti operazioni:creare un database, eseguirne il backup di alcuni dati, rilasciarlo e ripristinarlo:
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;
Ora possiamo interrogare i dati dal file di destinazione dell'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;
Per un backup, il flag di traccia 3226 non sopprime l'output acquisito dagli eventi estesi. Ho tralasciato le colonne di output, a causa dei filtri, per brevità:
Messaggio | Durata (millisecondi) |
---|---|
BACKUP DATABASE avviato | 0 |
Apertura del database con S lock | 0 |
Acquisizione del blocco operazioni in blocco sul database | 0 |
La sincronizzazione con altre operazioni sul database è completa | 19 |
Apertura del set di supporti di backup | 7 |
Il set di supporti di backup è aperto | 0 |
Preparazione del set di supporti per la scrittura | 0 |
Il set di supporti è pronto per il backup | 0 |
Opzioni efficaci:Checksum=0, Compressione=1, Crittografia=0, BufferCount=7, MaxTransferSize=1024 KB | 0 |
Cancellazione di bitmap differenziali | 4 |
Le bitmap differenziali vengono cancellate | 0 |
Scrivere un checkpoint | 6 |
Il checkpoint è completo (scaduto =6 ms) | 0 |
LSN iniziale:101:111920:43, LSN SERepl:0:0:0 | 0 |
Scansione delle bitmap di allocazione | 4 |
La scansione delle bitmap di allocazione è completa | 0 |
Calcolo della dimensione prevista dei dati totali | 0 |
FID=1, ExpectedExtents=10047, IsDifferentialMapAccurate=0 | 0 |
TotalSize=658440192 byte | 0 |
Dimensione totale stimata =658460672 byte (dimensione dati =658440192 byte, dimensione registro =20480 byte) | 0 |
La stima del lavoro è completa | 0 |
Ultimo LSN:101:111960:1 | 0 |
Scrittura dei principali metadati | 0 |
BackupStream(0):scrittura di metadati iniziali sul dispositivo c:\temp\floob.bak | 1 |
Calcolo della dimensione prevista dei dati totali | 0 |
FID=1, ExpectedExtents=10047, IsDifferentialMapAccurate=0 | 0 |
TotalSize=658440192 byte | 1 |
Copiare file di dati | 2 |
Numero di lettori di file di dati =1 | 0 |
Lettura del file di dati D:\SQL Server\MSSQL13.SQL16\DATA\floob.mdf | 0 |
BackupStream(0):scrittura di MSDA di dimensioni 10048 estensioni | 391 |
30 percento (198180864/658460672 byte) elaborato | 554 |
60 percento (395313152/658460672 byte) elaborato | 576 |
90 percento (593494016/658460672 byte) elaborato | 184 |
Completata la lettura del file di dati D:\SQL Server\MSSQL13.SQL16\DATA\floob.mdf | 2 |
BackupStream(0):riempimento MSDA con 65536 byte | 0 |
BackupStream(0):dimensione totale MSDA =10048 estensioni | 0 |
InitialExpectedSize=658440192 byte, FinalSize=658440192 byte, ExcessMode=0 | 0 |
Ultimo LSN:101:111960:1 | 0 |
La copia dei file di dati è completata | 0 |
Copia registro transazioni | 0 |
MediaFamily(0):FID=2, VLFID=101, DataStreamSize=65536 byte | 4 |
La copia del registro delle transazioni è completa | 0 |
Scrittura dei metadati finali | 0 |
BackupStream(0):scrittura di metadati finali sul dispositivo c:\temp\floob.bak | 0 |
Scrittura della fine del set di backup | 30 |
Scrittura dei record della cronologia | 12 |
La scrittura dei record della cronologia è completa (trascorso =11 ms) | 0 |
BACKUP DATABASE terminato | 0 |
Dati evento per un'operazione di backup
Per un ripristino, vedrai queste righe:
Messaggio | Durata (millisecondi) |
---|---|
RIPRISTINO DATABASE avviato | 0 |
Apertura del set di backup | 3 |
Elaborazione dei principali metadati | 0 |
La pianificazione inizia | 23 |
Opzioni efficaci:Checksum=0, Compressione=1, Crittografia=0, BufferCount=6, MaxTransferSize=1024 KB | 0 |
La pianificazione è completa | 0 |
Inizio ripristino OFFLINE | 0 |
Database allegato come DB_ID=5 | 1 |
Preparazione contenitori | 534 |
I contenitori sono pronti | 1097 |
Ripristino del set di backup | 0 |
Dimensione totale stimata da trasferire =658460672 byte | 0 |
Trasferimento dati | 1 |
BackupStream(0):elaborazione di MSDA di dimensioni 10048 estensioni | 3282 |
BackupStream(0):MSDA completato | 0 |
In attesa del completamento dell'azzeramento del registro | 3 |
L'azzeramento del registro è completo | 0 |
BackupStream(0):elaborazione MSTL (FID=2, VLFID=101, size=65536 byte) | 1024 |
Il trasferimento dei dati è completo | 14 |
Il set di backup è stato ripristinato | 45 |
Inizia il rollforward offline | 1 |
Elaborazione di 68 intestazioni VLF | 69 |
L'elaborazione delle intestazioni VLF è completa | 11 |
Primo LSN:101:111920:43, Ultimo LSN:101:111960:1 | 0 |
Interrompi LSN:101:111960:1 | 4 |
Il rollforward offline è completo | 17 |
La correzione del database è completa | 2 |
Transizione database in ONLINE | 2 |
Riavvio del database per ONLINE | 87 |
Inizia PostRestoreContainerFixups | 5 |
PostRestoreContainerFixups è completo | 2 |
Inizia PostRestoreReplicationFixup | 107 |
PostRestoreReplicationFixup è completo | 2 |
Il database viene riavviato | 9 |
Ripresa di qualsiasi scansione del testo completo interrotta | 6 |
Scrittura dei record della cronologia | 13 |
La scrittura dei record della cronologia è completa (trascorso =13 ms) | 2 |
La manutenzione di MSDB è completa | 2 |
RIPRISTINO DATABASE terminato | 0 |
Dati evento per un'operazione di ripristino
Se stai risolvendo un'operazione di backup o ripristino lenta, puoi facilmente filtrare in base alla durata, in modo da visualizzare solo gli eventi che hanno richiesto più di n millisecondi, ad esempio. L'unica cosa che non vedo in questo output è un modo per sapere se l'inizializzazione del file istantanea era attiva durante il ripristino:potresti comunque aver bisogno del flag di traccia 3004, come descritto nel mio post per il martedì di T-SQL del mese scorso.
Non dimenticare di interrompere la sessione (ma sentiti libero di mantenere la definizione della sessione sul server, in modo da poterla riutilizzare):
ALTER EVENT SESSION [Backup progress] ON SERVER STATE = STOP;
Non ho eseguito alcun test delle prestazioni o analisi dell'impatto, ma in generale, direi che, come i flag di traccia, questo non è qualcosa che vorresti eseguire tutto il tempo, ma solo durante la risoluzione dei problemi di un'operazione specifica. È un po' più semplice impostare questa sessione e interrogare i dati, IMHO, piuttosto che attivare i flag di traccia e analizzare tutto l'output dal log degli errori di SQL Server.