Exchange and Windows Server Backup

When using Windows Server Backup to backup Exchange 2007 and Exchange 2010 there are essentially four processes that must occur in order for the backup to be successful:

 

1)  Volume Shadow copy is made of the Exchange data on the host where the backup is initiated.

2)  All Exchange log files and database files in the backup set must have a consistency check performed.

3)  The data on the drives is written to the desired backup media.

4)  Backup complete is performed allowing for log truncation activities (if applicable).

 

Step #1: Create shadow copies

image

 

The first part of all Exchange backups using Windows Server Backup is the creation of the shadow copy.  An administrator should expect the shadow copy process to complete quickly.  The previous screen shot provides an example of the Windows Server Backup status.  The following events may also be noted in the application log.

 

Time: 11/28/2010 12:29:47 PM
ID: 9606
Level: Information
Source: MSExchangeIS
Machine: Server1-A.domain.com
Message: Exchange VSS Writer (instance 3d2f77ec-302d-42d4-9eac-e38082398947) has prepared for backup successfully.

Time: 11/28/2010 12:29:49 PM
ID: 2005
Level: Information
Source: ESE
Machine: Server1-A.domain.com
Message: Information Store (5340) Shadow copy instance 2 starting. This will be a Full shadow copy.

For more information, click https://www.microsoft.com/contentredirect.asp.

Time: 11/28/2010 12:29:49 PM
ID: 9811
Level: Information
Source: MSExchangeIS
Machine: Server1-A.domain.com
Message: Exchange VSS Writer (instance 2) has successfully prepared the database engine for a full or copy backup of database 'DATABASE'.

Time: 11/28/2010 12:29:50 PM
ID: 2001
Level: Information
Source: ESE
Machine: Server1-A.domain.com
Message: Information Store (5340) Shadow copy instance 2 freeze started.

For more information, click https://www.microsoft.com/contentredirect.asp.

Time: 11/28/2010 12:29:50 PM
ID: 2001
Level: Information
Source: ESE
Machine: Server1-A.domain.com
Message: Information Store (5340) DATABASE: Shadow copy instance 2 freeze started.

For more information, click https://www.microsoft.com/contentredirect.asp.

Time: 11/28/2010 12:29:50 PM
ID: 9610
Level: Information
Source: MSExchangeIS
Machine: Server1-A.domain.com
Message: Exchange VSS Writer (instance 3d2f77ec-302d-42d4-9eac-e38082398947:2) has frozen the database(s) successfully.

Time: 11/28/2010 12:29:52 PM
ID: 2003
Level: Information
Source: ESE
Machine: Server1-A.domain.com
Message: Information Store (5340) Shadow copy instance 2 freeze ended.

For more information, click https://www.microsoft.com/contentredirect.asp.

Time: 11/28/2010 12:29:52 PM
ID: 9612
Level: Information
Source: MSExchangeIS
Machine: Server1-A.domain.com
Message: Exchange VSS Writer (instance 3d2f77ec-302d-42d4-9eac-e38082398947:2) has thawed the database(s) successfully.

Time: 11/28/2010 12:29:54 PM
ID: 9622
Level: Information
Source: MSExchangeIS
Machine: Server1-A.domain.com
Message: Exchange VSS Writer (instance 3d2f77ec-302d-42d4-9eac-e38082398947:2) has processed the post-snapshot event successfully.

 

Step #2: Running consistency check

image

 

The second part of the backup is running consistency check.  The consistency check will verify the integrity of each log file and each database that is a part of the backup set.  Should a corrupted log file <or> database be found, the backup job will be cancelled.  The consistency check is not optional and must occur in order for the backup to continue. 

 

The length of time that a consistency check takes is dependent on two main factors:

1)  The number of log files in the backup set.

2)  The size of the database files.

 

Recently we have seen several cases where it appears that consistency check never completes or in some instances takes multiple hours / days to complete.  In most cases there was a common theme – the number of log files to be backed up.  In many of these cases they were the first backup taken after a migration, when log file creation is high and the number of logs in the backup set is large.   (For example, in one case reviewed there were over 50 gigs of log files in the backup set along with a 750 gig mailbox store).

 

When consistency check fails to complete in the desired time there are very limited options.  The only option that is generally effective is lowering the size of the backup set.  For example, this may require manually removing log files (it would be advisable to contact support for assistance) or lower the size of the database file.  For customers using a Database Availability Group, you may also be able to distribute your databases among several DAG members, and backup those individual members.  In the DAG example the backup set size is not changing but only the number of active databases require consistency checking, which lowers the size of the backup set requiring consistency check.

 

Step #3: Writing data to backup media

image

 

At this stage the shadow copies and consistency check has completed.  The data in the backup set is now being streamed to the user specified location. 

 

The amount of time for data transfer is both dependent on the overall size of the backup set as well as the destination chosen.  The backup cannot be fully completed until all data in the backup set has been streamed to media (this includes non-Exchange related data such as system state / bare metal recovery).

 

Step #4: Backup complete

image

 

At this stage the shadow copies, consistency check, and data transfer to media has completed.  At this time the Exchange writer can be informed that the backup completed successfully.  It is also at this time that if a full backup was performed that log truncation can occur for logs that are eligible for truncation.  This is a very important step, if backup complete is not called by the application future backups are subject to fail with an error that a backup is already in progress.  (This may necessitate restarting the Information Store service in order to clear this condition).  Please note that log truncation no longer occurs as a part of the backup process, therefore it is not necessary for logs to truncate in order for the backup to be completed successfully.  It may be several minutes until the log file truncation is actually processed on the hosts.

 

The following events may be found in the application log regarding the Exchange backup.

 

Index: 2
Time: 11/28/2010 12:50:06 PM
ID: 224
Level: Information
Source: ESE
Machine: Server1-A.domain.com
Message: Information Store (5340) DATABASE: Deleting log files d:\Logs\DATABASE\E020000201E.log to d:\Logs\DATABASE\E0200002046.log.

For more information, click https://www.microsoft.com/contentredirect.asp.

Index: 3
Time: 11/28/2010 12:50:06 PM
ID: 9780
Level: Information
Source: MSExchangeIS
Machine: Server1-A.domain.com
Message: Exchange VSS Writer (instance 3d2f77ec-302d-42d4-9eac-e38082398947:2) has successfully completed the full or incremental backup of storage group 'DATABASE'.

The database engine has also successfully executed log file truncation procedures for this storage group. (Note that this may or may not have resulted in the actual truncation of log files, depending on whether any log files existed that were candidates for truncation.)

Index: 12
Time: 11/28/2010 12:50:06 PM
ID: 2006
Level: Information
Source: ESE
Machine: Server1-A.domain.com
Message: Information Store (5340) Shadow copy instance 2 completed successfully.

For more information, click https://www.microsoft.com/contentredirect.asp.

Index: 13
Time: 11/28/2010 12:50:06 PM
ID: 9616
Level: Information
Source: MSExchangeIS
Machine: Server1-A.domain.com
Message: Exchange VSS Writer (instance 3d2f77ec-302d-42d4-9eac-e38082398947:2) has processed the backup completion event successfully.

Index: 14
Time: 11/28/2010 12:50:07 PM
ID: 9648
Level: Information
Source: MSExchangeIS
Machine: Server1-A.domain.com
Message: Exchange VSS Writer (instance 3d2f77ec-302d-42d4-9eac-e38082398947:2) has processed the backup shutdown event successfully.