先月のT-SQL火曜日に、長時間実行されるバックアップと復元の操作をベビーシッターするのに役立つ、文書化されていないトレースフラグについて書きました。今月のJesBorlandのトピックは拡張イベントであり、これらのトレースフラグを大幅に廃止するSQLServer2016の新機能を紹介したいと思いました。
CTP2(ここからダウンロードできます)で遊んでいる場合は、新しいカテゴリbackup_restoreに気付くかもしれません。 および新しいイベントbackup_restore_progress_trace :
CTP2の[新しいセッション]ダイアログで新しいイベントを検出する
これは、このイベントのデータをキャプチャするための迅速で汚いXEセッションです(バックアップのみまたは復元操作のみにフィルタリングするためのコメントを追加しました。デフォルトでは、両方が含まれています):
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 ここで、次の操作を実行するとします。データベースを作成し、少しのデータをバックアップし、ドロップして、復元します。
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;
これで、イベントターゲットファイルからデータをクエリできます:
;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; バックアップの場合、トレースフラグ3226は、拡張イベントによってキャプチャされた出力を抑制しません。簡潔にするために、フィルターのために出力列を省略しました:
| メッセージ | 期間 (ミリ秒) |
|---|---|
| バックアップデータベースが開始されました | 0 |
| Sロックでデータベースを開く | 0 |
| データベースの一括操作ロックの取得 | 0 |
| データベースの他の操作との同期が完了しました | 19 |
| バックアップメディアセットを開く | 7 |
| バックアップメディアセットが開いています | 0 |
| 書き込み用のメディアセットの準備 | 0 |
| メディアセットはバックアップの準備ができています | 0 |
| 有効なオプション:Checksum =0、Compression =1、Encryption =0、BufferCount =7、MaxTransferSize =1024 KB | 0 |
| 差分ビットマップのクリア | 4 |
| 差分ビットマップがクリアされます | 0 |
| チェックポイントの作成 | 6 |
| チェックポイントが完了しました(経過=6ミリ秒) | 0 |
| 開始LSN:101:111920:43、SERepl LSN:0:0:0 | 0 |
| 割り当てビットマップのスキャン | 4 |
| 割り当てビットマップのスキャンが完了しました | 0 |
| 合計データの予想サイズを計算する | 0 |
| FID =1、ExpectedExtents =10047、IsDifferentialMapAccurate =0 | 0 |
| TotalSize=658440192バイト | 0 |
| 推定合計サイズ=658460672バイト(データサイズ=658440192バイト、ログサイズ=20480バイト) | 0 |
| 作業の見積もりが完了しました | 0 |
| 最後のLSN:101:111960:1 | 0 |
| 主要なメタデータの書き込み | 0 |
| BackupStream(0):主要なメタデータをデバイスに書き込みますc:\ temp \ float.bak | 1 |
| 合計データの予想サイズを計算する | 0 |
| FID =1、ExpectedExtents =10047、IsDifferentialMapAccurate =0 | 0 |
| TotalSize=658440192バイト | 1 |
| データファイルのコピー | 2 |
| データファイルリーダーの数=1 | 0 |
| データファイルの読み取りD:\ SQL Server \ MSSQL13.SQL16 \ DATA \ float.mdf | 0 |
| BackupStream(0):サイズ10048エクステントのMSDAの書き込み | 391 |
| 30パーセント(198180864/658460672バイト)が処理されました | 554 |
| 60パーセント(395313152/658460672バイト)が処理されました | 576 |
| 90パーセント(593494016/658460672バイト)が処理されました | 184 |
| データファイルD:\ SQL Server \ MSSQL13.SQL16 \ DATA \ float.mdf | の読み取りが完了しました2 |
| BackupStream(0):65536バイトのMSDAのパディング | 0 |
| BackupStream(0):合計MSDAサイズ=10048エクステント | 0 |
| InitialExpectedSize =658440192バイト、FinalSize =658440192バイト、ExcessMode =0 | 0 |
| 最後のLSN:101:111960:1 | 0 |
| データファイルのコピーが完了しました | 0 |
| トランザクションログのコピー | 0 |
| MediaFamily(0):FID =2、VLFID =101、DataStreamSize=65536バイト | 4 |
| トランザクションログのコピーが完了しました | 0 |
| 末尾のメタデータの書き込み | 0 |
| BackupStream(0):デバイスへの末尾のメタデータの書き込みc:\ temp \ float.bak | 0 |
| バックアップセットの終わりを書き込む | 30 |
| 履歴レコードの書き込み | 12 |
| 履歴レコードの書き込みが完了しました(経過=11ミリ秒) | 0 |
| バックアップデータベースが終了しました | 0 |
バックアップ操作のイベントデータ
復元の場合、次の行が表示されます:
| メッセージ | 期間 (ミリ秒) |
|---|---|
| RESTOREDATABASEが開始されました | 0 |
| バックアップセットを開く | 3 |
| 主要なメタデータの処理 | 0 |
| 計画が始まります | 23 |
| 有効なオプション:Checksum =0、Compression =1、Encryption =0、BufferCount =6、MaxTransferSize =1024 KB | 0 |
| 計画が完了しました | 0 |
| オフライン復元の開始 | 0 |
| データベースをDB_ID=5として添付 | 1 |
| コンテナの準備 | 534 |
| コンテナの準備ができました | 1097 |
| バックアップセットの復元 | 0 |
| 転送する推定合計サイズ=658460672バイト | 0 |
| データの転送 | 1 |
| BackupStream(0):サイズ10048エクステントのMSDAを処理しています | 3282 |
| BackupStream(0):完了したMSDA | 0 |
| ログのゼロ化が完了するのを待っています | 3 |
| ログのゼロ化が完了しました | 0 |
| BackupStream(0):MSTLの処理(FID =2、VLFID =101、サイズ=65536バイト) | 1024 |
| データ転送が完了しました | 14 |
| バックアップセットが復元されます | 45 |
| オフラインロールフォワードが開始されます | 1 |
| 68個のVLFヘッダーを処理しています | 69 |
| VLFヘッダーの処理が完了しました | 11 |
| 最初のLSN:101:111920:43、最後のLSN:101:111960:1 | 0 |
| LSNの停止:101:111960:1 | 4 |
| オフラインロールフォワードが完了しました | 17 |
| データベースの修正が完了しました | 2 |
| データベースをオンラインに移行する | 2 |
| オンライン用のデータベースの再起動 | 87 |
| PostRestoreContainerFixupsが始まります | 5 |
| PostRestoreContainerFixupsが完了しました | 2 |
| PostRestoreReplicationFixupが始まります | 107 |
| PostRestoreReplicationFixupが完了しました | 2 |
| データベースが再起動されます | 9 |
| 停止したフルテキストクロールを再開する | 6 |
| 履歴レコードの書き込み | 13 |
| 履歴レコードの書き込みが完了しました(経過=13ミリ秒) | 2 |
| MSDBのメンテナンスが完了しました | 2 |
| データベースの復元が完了しました | 0 |
復元操作のイベントデータ
低速のバックアップまたは復元操作のトラブルシューティングを行っている場合は、期間を簡単にフィルタリングできるため、たとえば、nミリ秒より長くかかったイベントのみが表示されます。この出力に表示されないのは、復元中にファイルの即時初期化が有効であったかどうかを確認する方法だけです。先月の火曜日のT-SQLの投稿で説明したように、トレースフラグ3004が必要になる場合があります。
セッションを停止することを忘れないでください(ただし、セッション定義をサーバーに保持して、再度使用できるようにしてください):
ALTER EVENT SESSION [Backup progress] ON SERVER STATE = STOP;
パフォーマンステストや影響分析は実行しませんでしたが、一般的に、トレースフラグのように、これは常に実行したいものではなく、特定の操作のトラブルシューティングを行う場合にのみ実行する必要があります。トレースフラグをオンにしてSQLServerのエラーログからのすべての出力を解析するよりも、このセッションを設定してデータIMHOをクエリする方が少し簡単です。