超まとめ
データファイルサイズが40GBぐらいのDBバックアップファイルをリストアしてテストしてみたところ、実時間で7～8分、割合で35%ぐらい時間短縮になりました。
実際にやって調べてみた
トレースフラグ3004,3605でバックアップ・リストア処理ログをSQLServerログに出力して調べてみました。
- Instant File Inistialization無効時のログ
日付 , ソース , 重大度 , メッセージ
03/03/2017 14:57:52 , spid76 , 不明 , RestoreDatabase: Finished
03/03/2017 14:57:52 , spid76 , 不明 , Restore: Done with MSDB maintenance
03/03/2017 14:57:52 , spid76 , 不明 , Writing backup history records
03/03/2017 14:57:52 , spid76 , 不明 , Restore: Writing history records
03/03/2017 14:57:52 , spid76 , 不明 , Resuming any halted fulltext crawls
03/03/2017 14:57:52 , spid76 , 不明 , Restore: Database is restarted
03/03/2017 14:57:51 , spid76 , 不明 , CHECKDB for database ‘test_db_a’ finished without errors on 2017-02-19 10:21:45.520 (local time). This is an informational message only; no user action is required.
03/03/2017 14:57:51 , spid76 , 不明 , PostRestoreReplicationFixup for test_db_a complete
03/03/2017 14:57:51 , spid76 , 不明 , PostRestoreReplicationFixup for test_db_a starts
03/03/2017 14:57:51 , spid76 , 不明 , PostRestoreContainerFixups: fixups complete
03/03/2017 14:57:51 , spid76 , 不明 , PostRestoreContainerFixups: running fixups on test_db_a
03/03/2017 14:57:51 , spid76 , 不明 , Zeroing completed on D:\Program Files\Microsoft SQL Server\MSSQL10_50.MSSQL2008R2\MSSQL\DATA\test_db_a_1.ldf
03/03/2017 14:57:51 , spid76 , 不明 , Zeroing D:\Program Files\Microsoft SQL Server\MSSQL10_50.MSSQL2008R2\MSSQL\DATA\test_db_a_1.ldf from page 1407451 to 1407931 (0x2af3b6000 to 0x2af776000)
03/03/2017 14:57:51 , spid76 , 不明 , FixupLogTail(progress) zeroing D:\Program Files\Microsoft SQL Server\MSSQL10_50.MSSQL2008R2\MSSQL\DATA\test_db_a_1.ldf from 0x2af3b5000 to 0x2af3b6000.
03/03/2017 14:57:51 , spid76 , 不明 , Database test_db_a has more than 1000 virtual log files which is excessive. Too many virtual log files can cause long startup and backup times. Consider shrinking the log and using a different growth increment to reduce the number of virtual log files.
03/03/2017 14:57:42 , spid76 , 不明 , Starting up database ‘test_db_a’.
03/03/2017 14:57:42 , spid76 , 不明 , Restore: Restarting database for ONLINE
03/03/2017 14:57:42 , spid76 , 不明 , Restore: Transitioning database to ONLINE
03/03/2017 14:57:42 , spid76 , 不明 , Restore: Done with fixups
03/03/2017 14:57:42 , spid76 , 不明 , Rollforward complete on database test_db_a
03/03/2017 14:57:41 , spid76 , 不明 , Database test_db_a has more than 1000 virtual log files which is excessive. Too many virtual log files can cause long startup and backup times. Consider shrinking the log and using a different growth increment to reduce the number of virtual log files.
03/03/2017 14:57:09 , spid76 , 不明 , Restore-Redo begins on database test_db_a
03/03/2017 14:57:09 , spid76 , 不明 , The database ‘test_db_a’ is marked RESTORING and is in a state that does not allow recovery to be run.
03/03/2017 14:57:08 , spid76 , 不明 , Starting up database ‘test_db_a’.
03/03/2017 14:57:08 , spid76 , 不明 , Restore: Backup set restored
03/03/2017 14:57:08 , spid76 , 不明 , Restore: Data transfer complete on test_db_a
03/03/2017 14:57:08 , spid76 , 不明 , FileHandleCache: 0 files opened. CacheSize: 12
03/03/2017 14:57:08 , spid76 , 不明 , Restore: LogZero complete
03/03/2017 14:57:08 , spid76 , 不明 , Restore: Waiting for log zero on test_db_a
03/03/2017 14:50:31 , spid76 , 不明 , Restore: Transferring data to test_db_a
03/03/2017 14:50:31 , spid76 , 不明 , Restore: Restoring backup set
03/03/2017 14:50:31 , spid76 , 不明 , Restore: Containers are ready
03/03/2017 14:50:31 , spid76 , 不明 , Zeroing completed on D:\Program Files\Microsoft SQL Server\MSSQL10_50.MSSQL2008R2\MSSQL\DATA\test_db_a.mdf
03/03/2017 14:46:46 , spid76 , 不明 , Zeroing completed on D:\Program Files\Microsoft SQL Server\MSSQL10_50.MSSQL2008R2\MSSQL\DATA\test_db_a_1.ldf
03/03/2017 14:38:15 , spid76 , 不明 , Zeroing D:\Program Files\Microsoft SQL Server\MSSQL10_50.MSSQL2008R2\MSSQL\DATA\test_db_a.mdf from page 1 to 5935352 (0x2000 to 0xb521f0000)
03/03/2017 14:38:15 , spid76 , 不明 , Zeroing D:\Program Files\Microsoft SQL Server\MSSQL10_50.MSSQL2008R2\MSSQL\DATA\test_db_a_1.ldf from page 1 to 2984064 (0x2000 to 0x5b1100000)
03/03/2017 14:38:15 , spid76 , 不明 , Restore: PreparingContainers
03/03/2017 14:38:15 , spid76 , 不明 , Restore: Attached database test_db_a as DBID=17
03/03/2017 14:38:15 , spid76 , 不明 , Restore: BeginRestore (offline) on test_db_a
03/03/2017 14:38:15 , spid76 , 不明 , Restore: Planning complete
03/03/2017 14:38:15 , spid76 , 不明 , Restore: Planning begins
03/03/2017 14:38:15 , spid76 , 不明 , Restore: Backup set is open
03/03/2017 14:38:15 , spid76 , 不明 , Restore: Configuration section loaded
03/03/2017 14:38:15 , spid76 , 不明 , Opening backup set
03/03/2017 14:38:15 , spid76 , 不明 , RestoreDatabase: Database test_db_a - Instant File Inistialization有効時のログ
日付 , ソース , 重大度 , メッセージ
03/03/2017 15:57:07 , spid71 , 不明 , RestoreDatabase: Finished
03/03/2017 15:57:07 , spid71 , 不明 , Restore: Done with MSDB maintenance
03/03/2017 15:57:07 , spid71 , 不明 , Writing backup history records
03/03/2017 15:57:07 , spid71 , 不明 , Restore: Writing history records
03/03/2017 15:57:07 , spid71 , 不明 , Resuming any halted fulltext crawls
03/03/2017 15:57:07 , spid71 , 不明 , Restore: Database is restarted
03/03/2017 15:57:07 , spid71 , 不明 , CHECKDB for database ‘test_db_b’ finished without errors on 2017-02-19 10:21:45.520 (local time). This is an informational message only; no user action is required.
03/03/2017 15:57:07 , spid71 , 不明 , PostRestoreReplicationFixup for test_db_b complete
03/03/2017 15:57:06 , spid71 , 不明 , PostRestoreReplicationFixup for test_db_b starts
03/03/2017 15:57:06 , spid71 , 不明 , PostRestoreContainerFixups: fixups complete
03/03/2017 15:57:06 , spid71 , 不明 , PostRestoreContainerFixups: running fixups on test_db_b
03/03/2017 15:57:06 , spid71 , 不明 , Zeroing completed on D:\Program Files\Microsoft SQL Server\MSSQL10_50.MSSQL2008R2\MSSQL\DATA\test_db_b_1.ldf
03/03/2017 15:57:06 , spid71 , 不明 , Zeroing D:\Program Files\Microsoft SQL Server\MSSQL10_50.MSSQL2008R2\MSSQL\DATA\test_db_b_1.ldf from page 1407451 to 1407931 (0x2af3b6000 to 0x2af776000)
03/03/2017 15:57:06 , spid71 , 不明 , FixupLogTail(progress) zeroing D:\Program Files\Microsoft SQL Server\MSSQL10_50.MSSQL2008R2\MSSQL\DATA\test_db_b_1.ldf from 0x2af3b5000 to 0x2af3b6000.
03/03/2017 15:57:06 , spid71 , 不明 , Database test_db_b has more than 1000 virtual log files which is excessive. Too many virtual log files can cause long startup and backup times. Consider shrinking the log and using a different growth increment to reduce the number of virtual log files.
03/03/2017 15:56:53 , spid71 , 不明 , Starting up database ‘test_db_b’.
03/03/2017 15:56:53 , spid71 , 不明 , Restore: Restarting database for ONLINE
03/03/2017 15:56:53 , spid71 , 不明 , Restore: Transitioning database to ONLINE
03/03/2017 15:56:53 , spid71 , 不明 , Restore: Done with fixups
03/03/2017 15:56:53 , spid71 , 不明 , Rollforward complete on database test_db_b
03/03/2017 15:56:53 , spid71 , 不明 , Database test_db_b has more than 1000 virtual log files which is excessive. Too many virtual log files can cause long startup and backup times. Consider shrinking the log and using a different growth increment to reduce the number of virtual log files.
03/03/2017 15:56:21 , spid71 , 不明 , Restore-Redo begins on database test_db_b
03/03/2017 15:56:20 , spid71 , 不明 , The database ‘test_db_b’ is marked RESTORING and is in a state that does not allow recovery to be run.
03/03/2017 15:56:20 , spid71 , 不明 , Starting up database ‘test_db_b’.
03/03/2017 15:56:20 , spid71 , 不明 , Restore: Backup set restored
03/03/2017 15:56:20 , spid71 , 不明 , Restore: Data transfer complete on test_db_b
03/03/2017 15:56:20 , spid71 , 不明 , FileHandleCache: 0 files opened. CacheSize: 12
03/03/2017 15:56:20 , spid71 , 不明 , Restore: LogZero complete
03/03/2017 15:56:20 , spid71 , 不明 , Restore: Waiting for log zero on test_db_b
03/03/2017 15:49:32 , spid71 , 不明 , Zeroing completed on D:\Program Files\Microsoft SQL Server\MSSQL10_50.MSSQL2008R2\MSSQL\DATA\test_db_b_1.ldf
03/03/2017 15:44:43 , spid71 , 不明 , Restore: Transferring data to test_db_b
03/03/2017 15:44:43 , spid71 , 不明 , Restore: Restoring backup set
03/03/2017 15:44:42 , spid71 , 不明 , Restore: Containers are ready
03/03/2017 15:44:42 , spid71 , 不明 , Zeroing D:\Program Files\Microsoft SQL Server\MSSQL10_50.MSSQL2008R2\MSSQL\DATA\test_db_b_1.ldf from page 1 to 2984064 (0x2000 to 0x5b1100000)
03/03/2017 15:44:42 , spid71 , 不明 , Restore: PreparingContainers
03/03/2017 15:44:42 , spid71 , 不明 , Restore: Attached database test_db_b as DBID=18
03/03/2017 15:44:42 , spid71 , 不明 , Restore: BeginRestore (offline) on test_db_b
03/03/2017 15:44:42 , spid71 , 不明 , Restore: Planning complete
03/03/2017 15:44:42 , spid71 , 不明 , Restore: Planning begins
03/03/2017 15:44:42 , spid71 , 不明 , Restore: Backup set is open
03/03/2017 15:44:42 , spid71 , 不明 , Restore: Configuration section loaded
03/03/2017 15:44:42 , spid71 , 不明 , Opening backup set
03/03/2017 15:44:42 , spid71 , 不明 , RestoreDatabase: Database test_db_b - 結果
- Instant File Initialization無効: 19分37秒
- Instant File Initialization有効: 12分25秒
- 短縮時間: 7分12秒
- 短縮率: 36.7%
結構違いますね。
ログをDiffってみた
Instant File Initializationの有効無効で何が違うのかを見るために、それぞれのログのメッセージをDiffってみたところ、無効の場合のみ下記2行が出力されていました。(それ以外は全て同じでした)
03/03/2017 14:50:31 , spid76 , 不明 , Zeroing completed on D:\Program Files\Microsoft SQL Server\MSSQL10_50.MSSQL2008R2\MSSQL\DATA\test_db_a.mdf
03/03/2017 14:38:15 , spid76 , 不明 , Zeroing D:\Program Files\Microsoft SQL Server\MSSQL10_50.MSSQL2008R2\MSSQL\DATA\test_db_a.mdf from page 1 to 5935352 (0x2000 to 0xb521f0000)
mdfファイルのゼロ埋め初期化がスキップされているということですね。