T-SQL tisdag #67:Nya utökade händelser för säkerhetskopiering och återställning

För förra månadens T-SQL-tisdag skrev jag om några odokumenterade spårningsflaggor som hjälper dig att vara barnvakt under långvariga backup- och återställningsoperationer. Den här månaden är Jes Borlands ämne Extended Events, och jag tänkte visa nya funktioner i SQL Server 2016 som till stor del gör dessa spårningsflaggor föråldrade.

Om du spelar med CTP2 (du kan ladda ner det här), kanske du märker en ny kategori backup_restore och ny händelse backup_restore_progress_trace :

Upptäcker en ny händelse i CTP2:s dialogruta för ny session

Här är en snabb och smutsig XE-session för att fånga data för den här händelsen (jag har lagt till kommentarer för att filtrera endast till säkerhetskopiering eller endast återställning; som standard ingår båda):

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

Låt oss nu säga att jag kör följande operationer – skapa en databas, säkerhetskopiera lite data, släpp den och återställ den:

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;

Nu kan vi fråga efter data från händelsemålfilen:

;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;

För en säkerhetskopia undertrycker inte spårningsflaggan 3226 någon av utdata som fångas av utökade händelser. Jag har utelämnat utdatakolumner, på grund av filtren, för korthetens skull:

Händelsedata för en säkerhetskopiering

För en återställning kommer du att se dessa rader:

Händelsedata för en återställning

Om du felsöker en långsam säkerhetskopiering eller återställning kan du enkelt filtrera på varaktigheten, så att du till exempel bara ser händelser som tog längre tid än n millisekunder. Det enda jag inte ser i denna utdata är något sätt att avgöra om omedelbar filinitiering var i kraft under återställningen – du kan fortfarande behöva spårningsflagga 3004, som beskrivs i mitt inlägg för förra månadens T-SQL-tisdag.

Glöm inte att stoppa sessionen (men behåll gärna sessionsdefinitionen på servern så att du kan använda den igen):

ALTER EVENT SESSION [Backup progress] ON SERVER STATE = STOP;

Jag utförde inga prestandatester eller konsekvensanalyser, men generellt sett skulle jag säga att – som spårningsflaggor – detta inte är något du vill köra hela tiden, utan bara när du felsöker en specifik operation. Det är lite lättare att ställa in den här sessionen och fråga efter data, IMHO, än att aktivera spårningsflaggor och analysera all utdata från SQL Servers fellogg.