Click here to monitor SSC
SQLServerCentral is supported by Red Gate Software Ltd.
 
Log in  ::  Register  ::  Not logged in
 
 
 

Instant File Initialization and restores

By Johan Bijnens,

SQLServer has been able to take advantage of using Instant File Initialization (IFI) for quite some time. The SQL Server instance service account can use Instant File Initialization if it has been granted the “Perform volume maintenance tasks” at the Windows level, via a Local Group Policy.

To grant this right, use this process:

  • Start secpol.msc
  • Navigate to Security Settings / Local Policies / User Rights Assignment and add the service account (or even better, the Windows group in use for that instance’s service accounts) the “Perform volume maintenance tasks” right (aka SeManageVolumePrivilege).
  • Restart your SQLServer instance.

In many posts, Instant File Initialisation is highlighted as a database creation and (automatic) file growth time saver.

However, Instant file initilization also helps at recovery time. 

When you restore a database, SQLServer will zero-out all associated database files if the service account has not been granted the “Perform volume maintenance tasks” privilege, just as it does during a create database command.

I recently needed to restore a 100GB database on a new server was surprised my restore needed so much time. I reviewed my install checklist and noticed I didn’t check the “Perform volume maintenance tasks” authority.

Trace flags 3004 + 3605 show more in detail what the engine does for your database during restore, so I started them and re-launched the restore. I performed this restore on two different servers ( D008 and CL008 ) to see its impact on an older server and on our new clustered instance. 

Below you’ll find the results I found in the errorlog files. Check for mentions of .mdf file actions (or whatever you name your data files at restore time).

I have clipped the content and highlighted the meant zero-out operations for your convenience.

Here is the result in the errorlog with INITIAL FILE INITIALIZATION NOT ENABLED

---    ( Instance D008)    -----------

2012-03-06 15:21:54.67 Server      Microsoft SQL Server 2008 R2 (SP1) - 10.50.2500.0 (Intel X86)     Jun 17 2011 00:57:23    Copyright (c) Microsoft Corporation   Enterprise Edition on Windows NT 6.0 <X86> (Build 6002: Service Pack 2)

2012-03-06 15:22:23.16 spid54      DBCC TRACEON 3004, server process ID (SPID) 54. This is an informational message only; no user action is required.

2012-03-06 15:22:23.16 spid54      DBCC TRACEON 3605, server process ID (SPID) 54. This is an informational message only; no user action is required.

2012-03-06 15:22:45.72 spid57      RestoreDatabase: Database MyDb

2012-03-06 15:22:45.80 spid57      Opening backup set

...

2012-03-06 15:23:40.35 spid57      Restore: BeginRestore (offline) on MyDb

2012-03-06 15:23:40.35 spid57      Restore: Attached database MyDb as DBID=24

2012-03-06 15:23:40.35 spid57      Restore: PreparingContainers

2012-03-06 15:23:40.51 spid57      Zeroing E:\MSSQL10_50.DV008\MSSQL\DataUserDb\MyDb.mdf from page 1 to 12763568 (0x2000 to 0x1858360000)

2012-03-06 15:23:40.51 spid57      Zeroing D:\MSSQL10_50.DV008\MSSQL\DataUserLog\MyDb_log.ldf from page 1 to 1344000 (0x2000 to 0x290400000)

2012-03-06 15:24:08.36 spid52      Attempting to load library 'xpstar.dll' into memory. This is an informational message only. No user action is required.

2012-03-06 15:24:08.40 spid52      Using 'xpstar.dll' version '2009.100.1600' to execute extended stored procedure 'xp_instance_regread'. This is an informational message only; no user action is required.

2012-03-06 15:25:27.93 spid57      RestoreDatabase: Database MyDb

2012-03-06 15:25:27.99 spid57      Opening backup set

2012-03-06 15:25:28.06 spid57      Restore: Configuration section loaded

2012-03-06 15:25:28.06 spid57      Restore: Backup set is open

2012-03-06 15:25:28.06 spid57      Restore: Planning begins

2012-03-06 15:25:28.09 spid57      Restore: Planning complete

2012-03-06 15:25:28.09 spid57      Restore: BeginRestore (offline) on MyDb

2012-03-06 15:25:28.09 spid57      Restore: Attached database MyDb as DBID=24

2012-03-06 15:25:28.09 spid57      Restore: PreparingContainers

2012-03-06 15:25:28.24 spid57      Zeroing D:\MSSQL10_50.DV008\MSSQL\DataUserLog\MyDb_log.ldf from page 1 to 1344000 (0x2000 to 0x290400000)

2012-03-06 15:25:28.24 spid57      Zeroing E:\MSSQL10_50.DV008\MSSQL\DataUserDb\MyDb.mdf from page 1 to 12763568 (0x2000 to 0x1858360000)

2012-03-06 15:29:43.01 spid57      Zeroing completed on D:\MSSQL10_50.DV008\MSSQL\DataUserLog\MyDb_log.ldf

2012-03-06 15:57:24.38 spid57      Zeroing completed on E:\MSSQL10_50.DV008\MSSQL\DataUserDb\MyDb.mdf

2012-03-06 15:57:24.38 spid57      Restore: Containers are ready

2012-03-06 15:57:24.40 spid57      Restore: Restoring backup set

...

2012-03-06 17:28:17.36 spid57      RestoreDatabase: Finished

...

Errorlog with INITIAL FILE INITIALIZATION ENABLED

---    ( Instance D008)    ---- complete list -------

2012-03-06 10:34:38.360,Server,Microsoft SQL Server 2008 R2 (SP1) - 10.50.2500.0 (Intel X86)    Jun 17 2011 00:57:23    Copyright (c) Microsoft Corporation   Enterprise Edition on Windows NT 6.0 <X86> (Build 6002: Service Pack 2) 

2012-03-06 18:46:00.330 spid55      DBCC TRACEON 3004, server process ID (SPID) 55. This is an informational message only; no user action is required.

2012-03-06 18:46:00.330 spid55      DBCC TRACEON 3605, server process ID (SPID) 55. This is an informational message only; no user action is required.

2012-03-06 18:46:20.250 spid53      RestoreDatabase: Database MyDb

2012-03-06 18:46:20.310 spid53      Starting up database 'MyDb'.

2012-03-06 18:46:20.360 spid53      The database 'MyDb' is marked RESTORING and is in a state that does not allow recovery to be run.

2012-03-06 18:46:20.360 spid53      X-locking database: MyDb

2012-03-06 18:46:20.360 spid53      Opening backup set

2012-03-06 18:46:20.440 spid53      Restore: Configuration section loaded

2012-03-06 18:46:20.440 spid53      Restore: Backup set is open

2012-03-06 18:46:20.440 spid53      Restore: Planning begins

2012-03-06 18:46:20.460 spid53      Dismounting FullText catalogs

2012-03-06 18:46:20.460 spid53      Restore: Planning complete

2012-03-06 18:46:20.460 spid53      Restore: BeginRestore (offline) on MyDb

2012-03-06 18:46:20.480 spid53      Restore: PreparingContainers

2012-03-06 18:46:20.520 spid53      Restore: Containers are ready

2012-03-06 18:46:20.520 spid53      Zeroing D:\MSSQL10_50.DV008\MSSQL\DataUserLog\MyDb_log.ldf from page 1 to 1344000 (0x2000 to 0x290400000)

2012-03-06 18:46:20.810 spid53      Restore: Restoring backup set

2012-03-06 18:46:20.810 spid53      Restore: Transferring data to MyDb

2012-03-06 18:49:46.580 spid53      Zeroing completed on D:\MSSQL10_50.DV008\MSSQL\DataUserLog\MyDb_log.ldf

2012-03-06 20:17:42.850 spid53      Restore: Waiting for log zero on MyDb

2012-03-06 20:17:42.850 spid53      Restore: LogZero complete

2012-03-06 20:17:43.390 spid53      FileHandleCache: 0 files opened. CacheSize: 12

2012-03-06 20:17:43.390 spid53      Restore: Data transfer complete on MyDb

2012-03-06 20:17:43.430 spid53      Restore: Backup set restored

2012-03-06 20:17:43.440 spid53      Starting up database 'MyDb'.

2012-03-06 20:17:43.470 spid53      The database 'MyDb' is marked RESTORING and is in a state that does not allow recovery to be run.

2012-03-06 20:17:43.490 spid53      Restore-Redo begins on database MyDb

2012-03-06 20:17:45.380 spid53      Rollforward complete on database MyDb

2012-03-06 20:17:45.420 spid53      Restore: Done with fixups

2012-03-06 20:17:45.460 spid53      Restore: Writing history records

2012-03-06 20:17:45.460 Backup      Database was restored: Database: MyDb, creation date(time): 2012/02/08(22:55:21), first LSN: 18456:144700:290, last LSN: 18456:144876:1, number of dump devices: 1, device information: (FILE=1, TYPE=DISK: {'\\mysafezone\SQLBackupCL008$\MyDbFull.bak'}). Informational message. No user action required.

2012-03-06 20:17:45.470 spid53      Writing backup history records

2012-03-06 20:17:45.520 spid53      Restore: Done with MSDB maintenance

2012-03-06 20:17:45.520 spid53      RestoreDatabase: Finished 

--- result in errorlog --- INITIAL FILE INITIALIZATION NOT ENABLED -------

---    ( Instance CL008)    -----------

02/20/2012 00:00:00 spid57      Microsoft SQL Server 2008 R2 (SP1) - 10.50.2500.0 (X64) <nl/>     Jun 17 2011 00:54:03 <nl/>   Copyright (c) Microsoft Corporation<nl/>   Enterprise Edition (64-bit) on Windows NT 6.1 <X64> (Build 7601: Service Pack 1)

.......

02/23/2012 08:11:01 spid120      RestoreDatabase: Database MyDb

...

02/23/2012 08:11:01 spid120      Zeroing S:\MSSQL10_50.CL008\MSSQL\Data\MyDb.mdf from page 1 to 12763568 (0x2000 to 0x1858360000)

02/23/2012 08:11:01 spid120      Zeroing S:\MSSQL10_50.CL008\MSSQL\DATA\MyDb_Log.ldf from page 1 to 640000 (0x2000 to 0x138800000)

02/23/2012 08:11:35 spid120      Zeroing completed on S:\MSSQL10_50.CL008\MSSQL\DATA\MyDb_Log.ldf

02/23/2012 08:15:53 spid120      Zeroing completed on S:\MSSQL10_50.CL008\MSSQL\Data\MyDb.mdf

02/23/2012 08:15:53 spid120      Restore: Containers are ready

...

02/23/2012 08:23:40 spid120      RestoreDatabase: Finished

--- result in errorlog --- INITIAL FILE INITIALIZATION ENABLED -----------

---    ( Instance CL008)    -----------

02/23/2012 12:52:12,Server      Microsoft SQL Server 2008 R2 (SP1) - 10.50.2500.0 (X64) <nl/>     Jun 17 2011 00:54:03 <nl/>   Copyright (c) Microsoft Corporation<nl/>   Enterprise Edition (64-bit) on Windows NT 6.1 <X64> (Build 7601: Service Pack 1)

...

02/23/2012 14:08:09 spid116      RestoreDatabase: Database MyDb

...

02/23/2012 14:08:10 spid116      Zeroing S:\MSSQL10_50.CL008\MSSQL\DATA\MyDb_Log.ldf from page 1 to 640000 (0x2000 to 0x138800000)

...

02/23/2012 14:08:41 spid116      Zeroing completed on S:\MSSQL10_50.CL008\MSSQL\DATA\MyDb_Log.ldf

02/23/2012 14:15:49 spid116      Restore: Waiting for log zero on MyDb

02/23/2012 14:15:49 spid116      Restore: LogZero complete

...

02/23/2012 14:15:50 spid116      Starting up database 'MyDb'.

02/23/2012 14:15:50 spid116      FixupLogTail(progress) zeroing S:\MSSQL10_50.CL008\MSSQL\DATA\MyDb_Log.ldf from 0x1b7f5800 to 0x1b7f6000.

02/23/2012 14:15:50 spid116      Zeroing S:\MSSQL10_50.CL008\MSSQL\DATA\MyDb_Log.ldf from page 56315 to 56795 (0x1b7f6000 to 0x1bbb6000)

02/23/2012 14:15:50 spid116      Zeroing completed on S:\MSSQL10_50.CL008\MSSQL\DATA\MyDb_Log.ldf

...

02/23/2012 14:15:51 spid116      RestoreDatabase: Finished

...

As you can observe in the second set, having IFI enabled, there is no mention of the zero-out operation for the MDF, saving me 33 minutes (D008) and 4 minutes (CL008) of restore time. In a crisis situation, every second counts, right ?

If you haven’t granted your service accounts this privilege, maybe now is the time to do so.

Of course these figures don’t mean a thing, if you don’t know the hardware I tested it on, so here it is:

Serverinfo: D008

DELL PE2600 with 2 2-core CPU (32-bit)

OS:  Windows Server 2008 Standard SP2
Memory:  3072 MB DDR Speed:  266 
Processor:  2 * Intel Xeon CPU 2.40GHz.

        GB       RPM  ultra   cacheMB    raid
C       36     10000    320         8       1
D       73     10000    320         8       1
E     2*73     10000    320         8       0

Serverinfo: CL008

HP ProLiant DL580 G7

OS:  Windows Server 2008 R2 Enterprise (x64) SP1
Memory:  64GB
Processor:  4 * Intel Xeon CPU E7530 @ 1.87GHz.

C-drive 146 GB – 10000RPM- 6Gb/s SAS - 16 – 22

R-drive : SAN luns (+mounted volume Raid5 (data) Raid1(log) )

Hyper-threading turned on

A brand new SAN HP P6300 30TB with a single raid5 pool.

No SAN-mirroring in use
LUN definitions to host the data files : Raid5
LUN definitions to host the Log files: Raid1

Total article views: 4079 | Views in the last 30 days: 7
 
Related Articles
FORUM

restore database

restore database

FORUM

Restoring Database

Restoring Database

FORUM

database restore file name

database restore

FORUM

Database Restoration

Unnecessary database restoration

 
Contribute

Join the most active online SQL Server Community

SQL knowledge, delivered daily, free:

Email address:  

You make SSC a better place

As a member of SQLServerCentral, you get free access to loads of fresh content: thousands of articles and SQL scripts, a library of free eBooks, a weekly database news roundup, a great Q & A platform… And it’s our huge, buzzing community of SQL Server Professionals that makes it such a success.

Join us!

Steve Jones
Editor, SQLServerCentral.com

Already a member? Jump in:

Email address:   Password:   Remember me: Forgotten your password?
Steve Jones