Administrators are choosing Windows Server Backup to backup their Exchange 2007 and Exchange 2010 installations.  In some cases administrators are reporting that backups are not completing in a timely fashion. 

 

Remember that a Windows Server Backup of an Exchange solution is basically a 4 step process:

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).

 

The first step of this process can always be expected to complete fairly quickly.  A matter of fact this step must complete within 30 seconds of being initiated.  If the process cannot be completed within 30 seconds the volume shadow copy framework will abort the backup operation.

 

The second steps is the consistency check of Exchange data.  This ensures that the log files and databases in the backup set are free from page level corruption prior to transfer to the backup destination.  This process is not optional and must complete.  It is important for an administrator to realize that the consistency check is performed against every log file that existed on the disk at the time the backup is taken.  For example, if a recent move mailbox operation was performed that resulted in 10,000 logs being generated and included with the backup all 10,000 logs must have a consistency check performed against them.  Therefore the number of logs generated due to operations or on a daily basis effect the time it takes for the backup to complete since they directly impact the amount of time it takes for consistency check to complete.  Also each database within the backup must be consistency checked.  Larger databases will obviously take longer to have a consistency check performed then smaller databases.  Another contributing factor to the time it takes consistency check to be completed is the disk performance of where both the shadow copy is created and the production data hosted. 

 

The third step is the transfer of data to the desired backup media.  Administrators can increase the performance of this step by utilizing backup media that is locally mounted on the server.  For example, an iscsi drive or locally attached disk may be a good performing candidate as the storage location for backup data.  Backup to network location, although supported, can be slower than utilizing locally attached disks.  In Windows 2008 R2 administrators also have an additional backup location “Back up to a hard disk that is dedicated for backups (recommended).  By using this option rather then a lettered volume the administrator may realize faster backup times since the disk is dedicated solely to backups and may not have additional data stored on it. 

 

 

With an understanding of these factors and administrator should be able to understand the time to backup completion and the factors that may cause backups to run longer then expected.

Some administrators choose Windows Server Backup to backup their Exchange 2007 and Exchange 2010 mailbox databases.  In some instances administrators report that during the backup process they experience performance issues on the server and issues with the length of time it takes for a backup to complete.  It should go without saying that it is preferred that backups not be taken during production hours when resources should be dedicated to end user access.  There maybe times though where this is not feasible.

 

In many cases the performance issues coincide with the consistency check portion of the Exchange backup.  Remember that using Windows Server Backup to backup Exchange is essentially a 4 step process:

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).

 

The consistency check process is utilizing eseutil on the local box in order to perform log file and database verification.  (The administrator can run a similar command using eseutil /k).  When the verification process is running it is technically occurring at two different locations:

1)  Against the changed blocks in the shadow copy storage.

2)  Against the production database and log files (via the shadow copy).

 

An important note here is that eseutil is not throttled during this verification routine which can incur performance impacts on your disks.  (It is ultimately this performance impact which causes performance issues with client access etc).

 

Let’s take a look at an example.   In our example we will backup a Windows 2008 R2 / Exchange 2010 SP1 installation on server MBX-1. 

 

Let’s inventory the information we are going to backup.  In this instance all public folder databases and mailbox databases that reside on the server.

 

[PS] C:Windowssystem32>Get-MailboxDatabase -Server MBX-1 | fl name,logfolderpath,edbfilepath

Name          : MBX-1-DB0
LogFolderPath : D:MBX-1MBX-1-DB0MBX-1-DB0-Logs
EdbFilePath   : E:MBX-1MBX-1-DB0MBX-1-DB0-DatabaseMBX-1-DB0.edb

[PS] C:Windowssystem32>Get-PublicFolderDatabase -Server MBX-1 | fl name,logfolderpath,edbfilepath

Name          : MBX-1-DB1
LogFolderPath : d:MBX-1MBX-1-DB1MBX-1-DB1-Logs
EdbFilePath   : e:MBX-1MBX-1-DB1MBX-1-DB1-DatabaseMBX-1-DB1.edb

Since all of the Exchange files reside on the D and E volumes I can expect to see the consistency check occurring against shadow storage created on the root of those volumes and the production paths.

 

Using VSSAdmin and can verify the shadow storage configuration for each volume on my server. 

 

C:>vssadmin list shadowstorage
vssadmin 1.1 – Volume Shadow Copy Service administrative command-line tool
(C) Copyright 2001-2005 Microsoft Corp.

Shadow Copy Storage association
   For volume: (\?Volume{a693b28b-a5f0-11de-813d-806e6f6e6963})\?Volume{a693b28b-a5f0-11de-813d-806e6f6e6963}
   Shadow Copy Storage volume: (\?Volume{a693b28b-a5f0-11de-813d-806e6f6e6963})\?Volume{a693b28b-a5f0-11de-813d-806e6f6e6963}
   Used Shadow Copy Storage space: 0 B (0%)
   Allocated Shadow Copy Storage space: 0 B (0%)
   Maximum Shadow Copy Storage space: 32 MB (32%)

Shadow Copy Storage association
   For volume: (D:)\?Volume{cd015911-a5f1-11de-9f02-00155d00010c}
   Shadow Copy Storage volume: (D:)\?Volume{cd015911-a5f1-11de-9f02-00155d00010c}
   Used Shadow Copy Storage space: 0 B (0%)
   Allocated Shadow Copy Storage space: 0 B (0%)
   Maximum Shadow Copy Storage space: 2.5 GB (10%)

Shadow Copy Storage association
   For volume: (E:)\?Volume{cd015918-a5f1-11de-9f02-00155d00010c}
   Shadow Copy Storage volume: (E:)\?Volume{cd015918-a5f1-11de-9f02-00155d00010c}
   Used Shadow Copy Storage space: 0 B (0%)
   Allocated Shadow Copy Storage space: 0 B (0%)
   Maximum Shadow Copy Storage space: 5 GB (10%)

Shadow Copy Storage association
   For volume: (C:)\?Volume{a693b28c-a5f0-11de-813d-806e6f6e6963}
   Shadow Copy Storage volume: (C:)\?Volume{a693b28c-a5f0-11de-813d-806e6f6e6963}
   Used Shadow Copy Storage space: 0 B (0%)
   Allocated Shadow Copy Storage space: 0 B (0%)
   Maximum Shadow Copy Storage space: 7.19 GB (10%)

 

This output is telling us what we expect to see.  As of now shadow storage is configured for volume D  [(D:)\?Volume{cd015911-a5f1-11de-9f02-00155d00010c}] to use a shadow storage location on volume D [(D:)\?Volume{cd015911-a5f1-11de-9f02-00155d00010c}].

 

At this time we will initiate a Windows Server Backup (Backup once) job of the volumes D and E.

 

As indicated the first step of the backup is creating the shadow copy.  We can see that shadow copies by running vssadmin list shadows while the backup is in progress.  Here is a sample output.

 

C:>vssadmin list shadows
vssadmin 1.1 – Volume Shadow Copy Service administrative command-line tool
(C) Copyright 2001-2005 Microsoft Corp.

Contents of shadow copy set ID: {f267c79e-cfd3-4952-94f3-c6384dc83c28}
   Contained 2 shadow copies at creation time: 1/9/2011 12:53:44 PM
      Shadow Copy ID: {b8b737a1-8765-4896-9526-b069294458aa}
         Original Volume: (D:)\?Volume{cd015911-a5f1-11de-9f02-00155d00010c}
         Shadow Copy Volume: \?GLOBALROOTDeviceHarddiskVolumeShadowCopy64
         Originating Machine: MBX-1.domain.com
         Service Machine: MBX-1.domain.com
         Provider: ‘Microsoft Software Shadow Copy provider 1.0’
         Type: ApplicationRollback
         Attributes: Persistent, No auto release, Differential

      Shadow Copy ID: {50e65eca-6b2e-457c-8ccf-5673598e7f96}
         Original Volume: (E:)\?Volume{cd015918-a5f1-11de-9f02-00155d00010c}
         Shadow Copy Volume: \?GLOBALROOTDeviceHarddiskVolumeShadowCopy65
         Originating Machine: MBX-1.domain.com
         Service Machine: MBX-1.domain.com
         Provider: ‘Microsoft Software Shadow Copy provider 1.0’
         Type: ApplicationRollback
         Attributes: Persistent, No auto release, Differential

From this output you can see that shadow copies have been created for information on both the D and E drives.

 

The next step of the backup is the consistency check. 

 

Using process monitor we can verify that eseutil is running against the databases and log files in shadow storage.

Log Files:

12:54:31.1154221 PM    eseutil.exe    5248    ReadFile    DeviceHarddiskVolumeShadowCopy64MBX-1MBX-1-DB0MBX-1-DB0-LogsE0000006088.log    SUCCESS    Offset: 4,096, Length: 262,144, I/O Flags: Non-cached, Priority: Normal

Database File

12:54:29.1153106 PM    eseutil.exe    2304    ReadFile    DeviceHarddiskVolumeShadowCopy65MBX-1MBX-1-DB0MBX-1-DB0-DatabaseMBX-1-DB0.edb    SUCCESS    Offset: 4,434,755,584, Length: 65,536, I/O Flags: Non-cached, Priority: Normal

 

 

The administrator may choose to change the shadow copy storage location.  For example, for the D and E volumes the administrator may select to change the shadow storage location to the C drive.  In some instances the administrator performs this activity in an attempt to alleviate the performance issues that may occur when the consistency check is running.  Let’s take a look at what impact this has:

 

In this example I will utilize vssadmin to move the shadow storage for the D volume to the C volume:

 

vssadmin add shadowstorage /for=D: /on=C: /maxsize=unbounded

 

The same command can be utilized for other disks.  Using VSSAdmin List ShadowStorage I can verify that the C volume is now being utilized as shadow copy space for both D and E.  The following is example output:

 

Shadow Copy Storage association
   For volume: (D:)\?Volume{cd015911-a5f1-11de-9f02-00155d00010c}
   Shadow Copy Storage volume: (C:)\?Volume{a693b28c-a5f0-11de-813d-806e6f6e6963}
   Used Shadow Copy Storage space: 0 B (0%)
   Allocated Shadow Copy Storage space: 0 B (0%)
   Maximum Shadow Copy Storage space: UNBOUNDED (100%)

Shadow Copy Storage association
   For volume: (E:)\?Volume{cd015918-a5f1-11de-9f02-00155d00010c}
   Shadow Copy Storage volume: (C:)\?Volume{a693b28c-a5f0-11de-813d-806e6f6e6963}
   Used Shadow Copy Storage space: 0 B (0%)
   Allocated Shadow Copy Storage space: 0 B (0%)
   Maximum Shadow Copy Storage space: UNBOUNDED (100%)

 

At the time the consistency check is performed the administrator can observe in performance monitor disk activity now at two locations.  The first location is the volume shadow copy location and the second location is the production location of Exchange data.  Remember that a shadow copy only contains changed data (copy on write data).  When accessing shadow storage, if the shadow storage does not contain a changed block then the IO is passed to the original location.  Therefore it is not possible to completely eliminate the disk impact of a consistency check on the storage hosting the production data.

 

The last stage of the backup is the copying of the backup data from the VSS shadow copy location to the backup destination.  In our example process monitor shows a read occurring from the VSS shadow copy location and a subsequent write occurring to the backup destination – in this case the B: drive.

 

12:54:55.0625394 PM    wbengine.exe    372    ReadFile    DeviceHarddiskVolumeShadowCopy65    SUCCESS    Offset: 514,981,888, Length: 65,536, I/O Flags: Non-cached, Priority: Normal

12:54:55.0627246 PM    wbengine.exe    372    WriteFile    B:WindowsImageBackupMBX-1Backup 2011-01-09 175320cd015918-a5f1-11de-9f02-00155d00010c.vhd    SUCCESS    Offset: 134,617,600, Length: 65,536, I/O Flags: Non-cached, Priority: Normal

 

 

At this point we should have a basic understanding of how the backup process can cause performance issues on a disk.  First the checksum runs against both the databases and log files without any throttling using both the shadow copy location and the production storage locations.  Second the streaming of data to the backup media occurs off the same shadow storage and production data locations to the backup media (although this process is less disk intensive then eseutil non the less it is additional IO to the volumes in question).

Today’s backup and restore operations require close coordination between backup applications, the line-of-business application being backed up (for example, Exchange 2010), and the storage management hardware and software. The Volume Shadow Copy Service (VSS) in Windows Server 2008, which was first introduced in Windows Server 2003, facilitates the conversation between these components to allow them to work together. When all of the components support VSS, you can use them to back up your application data, such as mailbox and public folder databases.

 

VSS coordinates the actions that are required to create a consistent shadow copy (also known as a snapshot or a point-in-time copy) of the data that is to be backed up. Shadow copies use differential copy-on-write technology to maintain consistency during the lifecycle of the snapshot.  For more information on how this works, see http://en.wikipedia.org/wiki/Shadow_Copy and http://en.wikipedia.org/wiki/Snapshot_(computer_storage).

 

There are three primary VSS components: providers, requestors, and writers. The provider is the system-level component that performs the actual work of creating and representing shadow copies. The requestor is the backup application, such as Windows Server Backup, System Center Data Protection Manager, etc., that requests a backup from the provider. And the writer is application (or component within an application) that coordinates its I/O operations with VSS shadow copy and shadow copy related operations (such as backups and restores) so that their data contained on the shadow copied volume is in a consistent state.

 

Before choosing a VSS-based backup application for Exchange, I recommend that you check with the vendor to determine which provider their application (the requestor) uses, and specifically, what differential block sizes are used. This is important because the block size used impacts how efficiently storage will be utilized.

 

Let me explain why.

 

The built-in provider in Windows, which leverages VOLSNAP.sys, uses a differential block size of 16K.

 

 

If a snapshot has been created, VOLSNAP.sys begins to intercept writes to the volume.  If a single byte in 16K has changed, VOLSNAP.sys moves the original 16K to differential storage and allows the new write to proceed to the volume. 

 

 

If a write happens to span more than one 16K block then all blocks that are changed are moved to differential storage.

 

 

Let’s look at how this might impact an application like Exchange.  Exchange writes in a static page size. 

 

• Exchange 2003 – 4K
• Exchange 2007 – 8K
• Exchange 2010 – 32K

 

In the Exchange 2007 example, if a single write of 8K was located on a single 16K differential block size, only 16K is moved to differential storage.  If the 8K spanned two 16K differential blocks then 32K would be moved to differential storage. 

 

Most VSS-based backup applications leverage the built-in VSS provider.  However, it is not a requirement to do so, and some vendors instead implement their own providers.  In these cases, the vendor may also choose to implement a larger or smaller differential block size.

 

Let’s look at the example of a hardware-based provider that implements a VSS solution with a block size of 1024K.  In this example, if a single byte changes in a 1024K differential block, then 1024K of data is moved to differential storage.  For applications like Exchange that write data in static pages, this can have can negative consequences.

 

For example, Exchange 2007 writes an 8K page to a single 1024K differential block.  This results in 1024K being written to shadow storage.  Therefore, 1 MB of storage is used to store 8K of data change.

 

 

Worse, if the write of 8K spans two 1024K differential blocks this results in 2048K being written to shadow storage.  In this case, 2 MB of storage is used to store 8K of data change.

 

 

In some cases, the custom block size used by a vendor’s custom provider has a range of configurations.  And in some cases, it cannot be configured at all. Before implementing a solution, consult with the vendor to determine which provider they use. If they use a custom provider, verify that it works efficiently with your version of Exchange.

 

*I want to thank Scott Schnoll and Dennis Middleton for tech reviewing and editing this post.

http://blogs.technet.com/b/exchange/archive/2011/05/31/exchange-2010-high-availability-misconceptions-addressed.aspx

http://blogs.technet.com/b/exchange/archive/2011/05/06/exchange-2010-mailbox-moves-and-mailbox-resiliency.aspx

Restore-DatabaseAvailabilityGroup is one of the cmdlets used as part of the datacenter switchover process.  The purpose of Restore-DatabaseAvailabilityGroup is to read the DAG’s list of stopped servers and evict the listed servers from the DAG’s underlying cluster.  The list of servers in this scenario typically includes all DAG members in the failed primary datacenter. This allows the DAG and the cluster to shrink, and because it now has fewer members, it requires fewer servers to maintain quorum and perform DAG operations.

Restore-DatabaseAvailabilityGroup:

1)  Starts a surviving node in the second datacenter using /forceQuourm.

2)  Forcibly evicts each server listed on the stopped servers list.

I have worked support cases where this eviction process fails with an exception.  In these cases, restore-databaseAvailabilityGroup issued the eviction while the Cluster service was still initializing (even though service control manager reported the service as started).  When the Cluster service is initializing it is unable to process eviction requests.  As a result, the commands failed.  For a few customers, the error is consistently reproducible necessitating the use of a workaround in order for restore-databaseAvailabiltyGroup to work.

Note: Customers upgrade to Exchange 2010 Service Pack 1 before following these instructions. These instructions will only work with Exchange 2010 SP1.

Prior to SP1, the Cluster service must be found in a stopped state in order to utilize restore-databaseAvailabilityGroup.  After SP1, the Cluster service no longer needs to be in a stopped state in order to proceed.

The following error may be noted when running

restore-databaseAvailabilityGroup –site <DRSite>

WARNING: Server ‘PrimarySiteServer’ was marked as stopped in database availability
group ‘DAG’ but couldn’t be removed from the cluster. Error: A server-side
database availability group administrative operation failed. Error: The
operation failed. CreateCluster errors may result from incorrectly configured
static addresses. Error: An error occurred while attempting a cluster
operation. Error: Cluster API
‘"EvictClusterNodeEx(node.domain.com) failed with 0x46.
Error: The remote server has been paused or is in the process of being
started"’ failed. [Server: DRSiteServer.domain.com]
WARNING: The operation wasn’t successful because an error was encountered. You
may find more details in log file
"C:ExchangeSetupLogsDagTasksdagtask_2010-09-02_14-54-39.766_restore-databaseavailabilitygroup.log".

The error 0x46 translates to

  ERROR_SHARING_PAUSED                                           winerror.h
# The remote server has been paused or is in the process of
# being started.

Upon further review, the Service Control Manager reported the Cluster service as started, and Failover Cluster Manager will connect to the cluster service.  Despite the error message, the attempt to start the Cluster service by using /forceQuorum was successful.

So the solution is simply to re-run restore-databaseAvailabilityGroup and the stopped DAG members will be successfully evicted.

When using continuous replication in Exchange 2007, an operation that sometimes needs to be performed is a database seed.  This operation is first performed as part of enabling replication, and thereafter it is performed infrequently as part of the process for recovering from divergence.

There are a few ways to perform a database seed, but seeding is most often performed by using the Update-StorageGroupCopy cmdlet. With this cmdlet, an ESE streaming backup is performed on the source database and the backup copy is then copied to the target.

Another way to seed a database copy is to perform a manual offline seeding. In this operation, the source database is dismounted, verified to be in a clean shutdown state, and then manually copied offline to the target. This can obviously be inconvenient, since the source database has to be down while the copy procedure is being performed.

A third method is to use a VSS backup of the database to seed the database copy, which I discuss in my previous post, Exchange 2007 – Using VSS to perform an online offline database seed.

Finally, yet another method is to utilize LCR as an SCR seeding source. In this blog post, I’ll show you how to do that.

====================================

The first step is to enable LCR for the source database by using the Enable-DatabaseCopy and Enable-StorageGroupCopy cmdlets.

(LCR)
Enable-DatabaseCopy –Identity <ServerNameDatabaseName> –CopyEdbFilePath “pathdatabase.edb”

If you have already enabled continuous replication for the storage group, proceed to the second step.

====================================

The second step is to enable standby continuous replication on the storage groups by using the Enable-StorageGroupCopy cmdlet.

(SCR)
Enable-StorageGroupCopy –Identity <ServerNameStorageGroupName> –StandbyMachine <SCRTargetName> –SeedingPostponed

For more information on enabling SCR, please see my blog post at http://blogs.technet.com/timmcmic/archive/2009/01/22/inconsistent-results-when-enabling-standby-continuous-replication-scr-in-exchange-2007-sp1.aspx

If you have already enabled continuous replication for the storage group, proceed to the third step.

====================================

The third step is to suspend the storage group copy.  Storage group copies can be suspended either in bulk or one at a time.  The following are example commands:

(All Storage Groups)
Get-StorageGroup –Server <SourceServerName> | Suspend-StorageGroupCopy –StandbyMachine <TargetMachineName>

(Single Storage Group)
Suspend-StorageGroupCopy –Identity <ServerNameStorageGroupName> –StandbyMachine <TargetMachineName>

It is important that in the SCR environment these commands are run on both the source and target servers.  All servers should indicate a suspended status, reflecting that both Active Directory replication and the Microsoft Exchange Replication service configuration updates occurred successfully.

====================================

The fourth step is to note the important paths that are necessary to complete the rest of these steps. Specifically, we are interested in the storage group log file path, the system folder path and copy system folder path, and the log file prefix.  For the mailbox database we are interested in the database file path and copy database file paths.

To get all paths for all storage groups on the source, use the following command:

Get-StorageGroup –Server <ServerName> | fl Name,LogFolderPath,SystemFolderPath,CopyLogFolderPath,CopySystemFolderPath,LogFilePrefix

This will give you a formatted list of storage group names, log paths, and system paths.

To get the paths for all mailbox databases, use the following command:

Get-MailboxDatabase –Server <ServerName> | fl Name,EdbFilePath,CopyEdbFilePath

This will give you a formatted list of mailbox database names and mailbox database paths.

Here is an example of the output you can expect to see (copy path attributes will only be populated if you are utilizing LCR):

Name            : Mailbox Database LCR
EdbFilePath     : d:SG1DB1.edb
CopyEdbFilePath : d:SG1-LCRDB1.edb

Name            : Mailbox Database CCR or SCR
EdbFilePath     : d:SG2DB2.edb
CopyEdbFilePath :

Name                 : Storage Group LCR
LogFolderPath        : d:SG1
SystemFolderPath     : d:SG1
CopyLogFolderPath    : d:SG1-LCR
CopySystemFolderPath : d:SG1-LCR
LogFilePrefix        : E00

Name                 : Storage Group CCR or SCR
LogFolderPath        : d:SG2
SystemFolderPath     : d:SG2
CopyLogFolderPath    :
CopySystemFolderPath :
LogFilePrefix        : E01

====================================

The fifth step is to verify that the source log file sequence is in order.  If the source log file sequence has been manually manipulated, and if any log file gaps are present, this results in a failure of the seed operation.  This step ensures that log files are in sequence on the source machine.

To ensure that the log sequence on the source machine is in the correct order, perform the following operations:

1. Open a command prompt and navigate to the log directory of the storage group.  This path can be found from the output gathered in step 3 above.

2. Run the following eseutil command:

eseutil /ml <LogFilePrefix>

The log file prefix can be found from the output gathered in step 3.

When you run this command it will scan every log file found in the source directory.  If any gaps or errors are identified, you cannot continue with these steps.  If the command completes and errors on the last log file in the series this is expected, as the Exx.log is currently open for writing and cannot be scanned.  The following is sample output that you should receive for a storage group that is online.

Extensible Storage Engine Utilities for Microsoft(R) Exchange Server
Version 08.02
Copyright (C) Microsoft Corporation. All Rights Reserved.
Initiating FILE DUMP mode…

Verifying log files…
     Base name: e00

      Log file: d:SG1E0000001353.log – OK
      Log file: d:SG1E0000001354.log – OK
      Log file: d:SG1E0000001355.log – OK
      Log file: d:SG1E0000001356.log – OK
      Log file: d:SG1E0000001357.log – OK
      Log file: d:SG1E0000001358.log – OK
      Log file: d:SG1E0000001359.log – OK
      Log file: d:SG1E000000135A.log – OK
      Log file: d:SG1E000000135B.log – OK
      Log file: d:SG1E000000135C.log – OK
      Log file: d:SG1E000000135D.log – OK
      Log file: d:SG1E000000135E.log – OK
      Log file: d:SG1E000000135F.log – OK
      Log file: d:SG1E0000001360.log – OK
      Log file: d:SG1E0000001361.log – OK
      Log file: d:SG1E0000001362.log – OK
      Log file: d:SG1E0000001363.log – OK
      Log file: d:SG1E0000001364.log – OK
      Log file: d:SG1E0000001365.log – OK
      Log file: d:SG1E0000001366.log – OK
      Log file: d:SG1E0000001367.log – OK
      Log file: d:SG1E0000001368.log – OK
      Log file: d:SG1E0000001369.log – OK
      Log file: d:SG1E00.log
                ERROR: Cannot open log file (d:SG1E00.log). Error -1032.

Operation terminated with error -1032 (JET_errFileAccessDenied, Cannot access file, the file is locked or in use) after 368.625 seconds.

====================================

The sixth step is to prepare the LCR copies for use in the SCR seeding process.  This starts by verifying the health of the LCR copies.

To verify the health of the LCR copies, on the server hosting the LCR databases run get-storagegroupcopystatus.  If any database shows a status of other than healthy this will need to be corrected before continuing with these instructions.

Get-StorageGroupCopyStatus

Name                      SummaryCopySt CopyQueueLeng ReplayQueueL LastInspecte
                          atus          th            ength        dLogTime
—-                      ————- ————- ———— ————
MBX-1-SG1                 Healthy       0             0            3/6/2011 …

====================================

The seventh step is to ensure that the target paths are ready to have the database moved in place.  The paths referenced in these steps can be obtained from the output gathered in step 3.

For SCR – ensure that the logFolderPath, systemFolderPath, and edbFilePath are empty on the SCR target.

At this point the destination paths are empty and ready for the database to be moved.

We now need to create the directory structure where logs, system, and database files will be copied.

For SCR – create the log, system, and database folder.  In our example logs, system, and database files are located at d:SG1.  Therefore on the SCR target or CCR passive node I would create the directory structure d:SG1.

If you are using nested folders you need to create the entire directory structure.

====================================

The eighth step is to move the restored database to the target directory.  This can be accomplished a few different ways, but I will make a recommendation below.

To being the LCR database copies need to be suspended.  This can be performed in bulk

get-storagegroup –server <LCRHost> | suspend-storagegroupcopy

The success of this command can be verified using get-storagegroupcopystatus.

Get-StorageGroupCopyStatus

Name                      SummaryCopySt CopyQueueLeng ReplayQueueL LastInspecte
                          atus          th            ength        dLogTime
—-                      ————- ————- ———— ————
MBX-1-SG1                 Suspended     0             0            3/6/2011 …

The LCR database file can be located at the CopyEdbFile path noted in step four.  Using a command prompt navigate to this location.

The SCR target location can be mapped as a network drive.  We will assume for this example that the network drive Y is utilized. 

Use eseutil to copy the database from the source directory to the target directory.  The command using our example is:

eseutil /y SG1-DB1.edb /d y:SG1-DB1.edb

Here is the expected output from this command:

Extensible Storage Engine Utilities for Microsoft(R) Exchange Server
Version 08.02
Copyright (C) Microsoft Corporation. All Rights Reserved.

Initiating COPY FILE mode…
     Source File: SG1-DB1.edb

Destination File: y:SG1-DB1.edb

                      Copy Progress (% complete)

          0    10   20   30   40   50   60   70   80   90  100

          |—-|—-|—-|—-|—-|—-|—-|—-|—-|—-|

          ……………………………………………

Operation completed successfully in 13.281 seconds.

At this point the copy has been seeded on the target server.

When the copy is completed the LCR replication can be resumed using

get-storagegroup –server <LCRHost> | resume-storagegroupcopy

Information on the usage of Eseutil can be found here.  http://technet.microsoft.com/en-us/library/aa998249(EXCHG.80).aspx

====================================

The ninth step is to verify the health of the copied database.  We need to ensure that the database was not damaged as a part of the copy process.

Log on locally to the SCR target, open a command prompt, and navigate to the database directory.  In our example this would be d:SG1.

Use Eseutil /k to perform a checksum of the database:

eseutil /k SG1-DB1.edb

The following output will be observed when the command completes:

Extensible Storage Engine Utilities for Microsoft(R) Exchange Server
Version 08.02
Copyright (C) Microsoft Corporation. All Rights Reserved.

Initiating CHECKSUM mode…
        Database: SG1-DB1.edb
  Temp. Database: TEMPCHKSUM3888.EDB

File: SG1-DB1.edb

                     Checksum Status (% complete)

          0    10   20   30   40   50   60   70   80   90  100

          |—-|—-|—-|—-|—-|—-|—-|—-|—-|—-|

          ……………………………………………

514 pages seen
0 bad checksums
0 correctable checksums
129 uninitialized pages
0 wrong page numbers
0x4676 highest dbtime (pgno 0x86)
65 reads performed
4 MB read
1 seconds taken
4 MB/second
2755 milliseconds used
42 milliseconds per read
78 milliseconds for the slowest read
15 milliseconds for the fastest read

Operation completed successfully in 0.140 seconds.

We are interested in ensuring that there are 0 bad checksums (bolded line above).

====================================

The last step in the process is to resume the storage group copy:

Get-StorageGroup –Server <SourceServerName> | Resume-StorageGroupCopy –StandbyMachne <SCRTargetName>

(Note:  This command resumes storage group copy for all storage groups.  If you have a storage group that is suspended for another reason it may be necessary to resume storage groups individually).

When replication has resumed successfully, you can note the following events in the Application event log indicating that replication began copying log files.

Event Type:    Information
Event Source: MSExchangeRepl
Event Category:   Action
Event ID:    2084
Date:        3/16/2010
Time:        10:12:50 AM
User:        N/A
Computer:    SERVER
Description: Replication for storage group SERVERStorage Group SCR or CCR has been resumed.

For more information, see Help and Support Center at http://go.microsoft.com/fwlink/events.asp.

Event Type:    Information
Event Source:    MSExchangeRepl
Event Category:   Service
Event ID:    2114
Date:        3/16/2010
Time:        10:13:19 AM
User:        N/A
Computer:    SERVER
Description: The replication instance for storage group SERVERStorage Group SCR or CCR has started copying transaction log files. The first log file successfully copied was generation 31201.

For more information, see Help and Support Center at http://go.microsoft.com/fwlink/events.asp.

====================================

The following are links to references from this post.

· Enable-StorageGroupCopy (http://technet.microsoft.com/en-us/library/aa996389(EXCHG.80).aspx)

· Enable-DatabaseCopy (http://technet.microsoft.com/en-us/library/aa996389(EXCHG.80).aspx)

· Suspend-StorageGroupCopy (http://technet.microsoft.com/en-us/library/aa998182(EXCHG.80).aspx)

· Get-StorageGroup (http://technet.microsoft.com/en-us/library/aa998331(EXCHG.80).aspx)

· Get-MailboxDatabase (http://technet.microsoft.com/en-us/library/bb124924(EXCHG.80).aspx)

· ESEUTIL (http://technet.microsoft.com/en-us/library/aa998249(EXCHG.80).aspx)

· Resume-StorageGroupCopy (http://technet.microsoft.com/en-us/library/bb124529(EXCHG.80).aspx)

 

====================================

Updates

6/26/11 – removed LCR enable step in step 1 that included seedingPostponed.  This was not necessary.

====================================

In Exchange 2010 the out of box behavior for a database availability group (DAG) is to utilize native replication based on log shipping.  Some customers choose to leverage solutions provided by vendors that support the third party replication API thereby replacing the inbox replication mechanism.

 

Recently I worked with a customer leveraging the third party replication API and had a move mailbox performance issue.  Overall move mailboxes were under performing what was expected.  After investigation we were able to determine that the databases hosted on the DAG had the default DataMoveReplicationConstraint property specified.  By default this property is set to secondCopy.  The purpose of this property is to allow the mailbox replication service on a client access server to throttle move mailbox based on the replication status of the target database.  In the case of the third party replication API it is not necessary to set this constraint.  By default all vendors leveraging the third party replication API must support synchronous replication, therefore writes are automatically throttled based on the ability to replicate synchronously thereby making it not necessary to utilize the DataMoveReplicationConstraint.

 

When using the third party replication API it is recommended to disable the DataMoveReplicationConstraint using the set-mailboxdatabase commandlet to a value of NONE.

 

================================

Update 10/25/2011

Corrected mis-spelling of the DataMoveReplicationConstraint

================================

Recently I was presented with an interesting case regarding the inability to mount databases.  The history preceding the event was fairly unremarkable and only noted after running patch maintenance on the server and rebooting.  Post reboot every time the customer attempted to mount a public folder database, the following active manager error occurred:

 

Couldn’t mount the database that you specified. Specified database: Public Folder Store NAME; Error code: An Active Manager operation failed. Error: The database action failed. Error: Operation failed with message: Error 0x721 (A security package specific error occurred) from cli_AmMountDatabaseDirectEx [Database: Public Folder Store NAME, Serve r: server.child.domain.local].
    + CategoryInfo          : InvalidOperation: (Public Folder Store NAME:ADObjectId) [Mount-Database], InvalidOperationException
    + FullyQualifiedErrorId : F34E87D0,Microsoft.Exchange.Management.SystemConfigurationTasks.MountDatabase

 

Also when reviewing the application log the following event was noted:

 

Log Name: Application

Source: MSExchange Configuration Cmdlet – Remote Management

Date: 11/7/2010 9:46:17 AM

Event ID: 4

Task Category: General

Level: Error

Keywords: Classic

User: N/A

Computer: SERVER.child.domain.local

Description:

(PID 6364, Thread 43) Task Mount-Database writing error when processing record of index 0. Error: System.InvalidOperationException: Couldn’t mount the database that you specified. Specified database: Public Folder Store NAME; Error code: An Active Manager operation failed. Error: The database action failed. Error: Operation failed with message: Error 0x721 (A security package specific error occurred) from cli_AmMountDatabaseDirectEx [Database: Public Folder Store NAME, Server: SERVER.child.domain.local]. —> Microsoft.Exchange.Cluster.Replay.AmDbActionWrapperException: An Active Manager operation failed. Error: The database action failed. Error: Operation failed with message: Error 0x721 (A security package specific error occurred) from cli_AmMountDatabaseDirectEx —> Microsoft.Exchange.Data.Storage.AmOperationFailedException: An Active Manager operation failed. Error: Operation failed with message: Error 0x721 (A security package specific error occurred) from cli_AmMountDatabaseDirectEx —> Microsoft.Exchange.Rpc.RpcException: Error 0x721 (A security package specific error occurred) from cli_AmMountDatabaseDirectEx

at ThrowRpcException(Int32 rpcStatus, String message)

at Microsoft.Exchange.Rpc.RpcClientBase.ThrowRpcException(Int32 rpcStatus, String routineName)

at Microsoft.Exchange.Rpc.ActiveManager.AmRpcClient.MountDatabaseDirectEx(Guid guid, AmMountArg arg)

at Microsoft.Exchange.Data.Storage.ActiveManager.AmRpcClientHelper.<>c__DisplayClass26.<MountDatabaseDirectEx>b__25(String )

at Microsoft.Exchange.Data.Storage.ActiveManager.AmRpcClientHelper.<>c__DisplayClass4e.<RunRpcOperationWithAuth>b__4c()

at Microsoft.Exchange.Data.Storage.Cluster.HaRpcExceptionWrapperBase`2.ClientRetryableOperation(String serverName, RpcClientOperation rpcOperation)

— End of inner exception stack trace —

at Microsoft.Exchange.Data.Storage.Cluster.HaRpcExceptionWrapperBase`2.ClientHandleRpcException(RpcException ex, String serverName)

at Microsoft.Exchange.Data.Storage.Cluster.HaRpcExceptionWrapperBase`2.ClientRetryableOperation(String serverName, RpcClientOperation rpcOperation)

at Microsoft.Exchange.Data.Storage.ActiveManager.AmRpcClientHelper.RunRpcOperationWithAuth(AmRpcOperationHint rpcOperationHint, String serverName, String databaseName, NetworkCredential networkCredential, Nullable`1 timeoutMs, AmRpcClient& rpcClient, InternalRpcOperation rpcOperation)

at Microsoft.Exchange.Data.Storage.ActiveManager.AmRpcClientHelper.MountDatabaseDirectEx(String serverToRpc, Guid dbGuid, AmMountArg mountArg)

at Microsoft.Exchange.Cluster.ActiveManagerServer.AmDbAction.MountDatabaseDirect(AmServerName serverName, AmServerName lastMountedServerName, Guid dbGuid, MountFlags flags, AmDbActionCode actionCode)

at Microsoft.Exchange.Cluster.ActiveManagerServer.AmDbPamAction.RunMountDatabaseDirect(AmServerName serverToMount, MountFlags mountFlags, Boolean fLossyMountEnabled)

at Microsoft.Exchange.Cluster.ActiveManagerServer.AmDbPamAction.<>c__DisplayClass3.<AttemptMountOnServer>b__1(Object , EventArgs )

at Microsoft.Exchange.Cluster.ActiveManagerServer.AmHelper.HandleKnownExceptions(EventHandler ev)

— End of inner exception stack trace (Microsoft.Exchange.Data.Storage.AmOperationFailedException) —

at Microsoft.Exchange.Cluster.ActiveManagerServer.AmDbOperation.Wait(TimeSpan timeout)

at Microsoft.Exchange.Cluster.ActiveManagerServer.ActiveManagerCore.MountDatabase(Guid mdbGuid, MountFlags flags, DatabaseMountDialOverride mountDialOverride, AmDbActionCode actionCode)

at Microsoft.Exchange.Cluster.ActiveManagerServer.AmRpcServer.<>c__DisplayClass4.<MountDatabase>b__3()

at Microsoft.Exchange.Data.Storage.Cluster.HaRpcExceptionWrapperBase`2.RunRpcServerOperation(String databaseName, RpcServerOperation rpcOperation)

— End of stack trace on server (SERVER.child.domain.local) —

at Microsoft.Exchange.Data.Storage.Cluster.HaRpcExceptionWrapperBase`2.ClientRethrowIfFailed(String databaseName, String serverName, RpcErrorExceptionInfo errorInfo)

at Microsoft.Exchange.Data.Storage.ActiveManager.AmRpcClientHelper.RunDatabaseRpcWithReferral(AmRpcOperationHint rpcOperationHint, Database database, String targetServer, AmRpcClient& rpcClient, InternalRpcOperation rpcOperation)

at Microsoft.Exchange.Data.Storage.ActiveManager.AmRpcClientHelper.MountDatabase(Database database, Int32 flags, Int32 mountDialOverride)

at Microsoft.Exchange.Management.SystemConfigurationTasks.MountDatabase.InternalProcessRecord()

— End of inner exception stack trace —

The error message and event unto themselves are not very telling as to what the issue was.  The important part of the event, which is not unique to Exchange and has been seen with other shell commands, is the security package error:

# for hex 0x721 / decimal 1825
  RPC_S_SEC_PKG_ERROR                                            winerror.h
# A security package specific error occurred.

After some investigation we were able to determine that the active directory forest where Exchange was installed contained a multiple domain structure.  In this case we searched the entire directory, and found that there were two ENABLED machine accounts with the same name residing in two different domain naming contexts in the same forest.  After identifying the machine account that was not being used (in this case the one in a child domain where Exchange servers were not installed) and deleting it – our mount commands proceeded successfully with no issues noted.

In recent weeks I’ve had several peers and customers present with concerns that when using Local Continuous Replication (LCR), Cluster Continuous Replication (CCR), Standby Continuous Replication (SCR), of the Database Availability Group (DAG)  passive database copies appear in a dirty shutdown state.

 

In general a database has two states – Clean Shutdown and Dirty Shutdown.  A clean shutdown state indicates that the database has had all outstanding transaction logs committed to it and the database can now stand on its own.  A dirty shutdown database indicates that the database requires additional transaction logs to be committed in order for the database to stand on its own.

 

Here is a eseutil /mh dump of a database that has been dismounted and therefore should be in a clean shutdown state.

 

Extensible Storage Engine Utilities for Microsoft(R) Exchange Server

Version 08.03

Copyright (C) Microsoft Corporation. All Rights Reserved.

Initiating FILE DUMP mode…
         Database: MBX-1-SG1-DB1.edb

        File Type: Database
   Format ulMagic: 0x89abcdef
   Engine ulMagic: 0x89abcdef
Format ulVersion: 0x620,12
Engine ulVersion: 0x620,12
Created ulVersion: 0x620,12
     DB Signature: Create time:06/30/2010 09:18:04 Rand:205158 Computer:
         cbDbPage: 8192
           dbtime: 49856 (0xc2c0)
            State: Clean Shutdown
     Log Required: 0-0 (0x0-0x0)
    Log Committed: 0-0 (0x0-0x0)
   Streaming File: No
         Shadowed: Yes
       Last Objid: 135
     Scrub Dbtime: 0 (0x0)
       Scrub Date: 00/00/1900 00:00:00
     Repair Count: 0
      Repair Date: 00/00/1900 00:00:00
Old Repair Count: 0
  Last Consistent: (0x30,102,19E)  12/05/2010 11:33:55
      Last Attach: (0x2F,9,86)  12/05/2010 09:23:20
      Last Detach: (0x30,102,19E)  12/05/2010 11:33:55
             Dbid: 1
    Log Signature: Create time:06/30/2010 09:18:03 Rand:202227 Computer:
       OS Version: (6.0.6002 SP 2 NLS 500100.50100)

Previous Full Backup:
        Log Gen: 15-32 (0xf-0x20) – OSSnapshot
           Mark: (0x21,8,16)
           Mark: 07/06/2010 21:08:21

Previous Incremental Backup:
        Log Gen: 0-0 (0x0-0x0)
           Mark: (0x0,0,0)
           Mark: 00/00/1900 00:00:00

Previous Copy Backup:
        Log Gen: 0-0 (0x0-0x0)
           Mark: (0x0,0,0)
           Mark: 00/00/1900 00:00:00

Previous Differential Backup:
        Log Gen: 0-0 (0x0-0x0)
           Mark: (0x0,0,0)
           Mark: 00/00/1900 00:00:00

Current Full Backup:
        Log Gen: 0-0 (0x0-0x0)
           Mark: (0x0,0,0)
           Mark: 00/00/1900 00:00:00

Current Shadow copy backup:
        Log Gen: 0-0 (0x0-0x0)
           Mark: (0x0,0,0)
           Mark: 00/00/1900 00:00:00

     cpgUpgrade55Format: 0
    cpgUpgradeFreePages: 0
cpgUpgradeSpaceMapPages: 0

       ECC Fix Success Count: none
   Old ECC Fix Success Count: none
         ECC Fix Error Count: none
     Old ECC Fix Error Count: none
    Bad Checksum Error Count: none
Old bad Checksum Error Count: none

Operation completed successfully in 0.15 seconds.

This particular database is enabled for LCR.  With the source database mounted and with storage group copy suspended, here is an eseutil /mh dump of the database.  (We should expect the same for a CCR passive, SCR passive, or DAG passive database)

 

Extensible Storage Engine Utilities for Microsoft(R) Exchange Server

Version 08.03

Copyright (C) Microsoft Corporation. All Rights Reserved.

Initiating FILE DUMP mode…
         Database: MBX-1-SG1-DB1.edb

        File Type: Database
   Format ulMagic: 0x89abcdef
   Engine ulMagic: 0x89abcdef
Format ulVersion: 0x620,12
Engine ulVersion: 0x620,12
Created ulVersion: 0x620,12
     DB Signature: Create time:06/30/2010 09:18:04 Rand:205158 Computer:
         cbDbPage: 8192
           dbtime: 49856 (0xc2c0)
            State: Dirty Shutdown
     Log Required: 50-50 (0x32-0x32)
    Log Committed: 0-50 (0x0-0x32)
   Streaming File: No
         Shadowed: Yes
       Last Objid: 135
     Scrub Dbtime: 0 (0x0)
       Scrub Date: 00/00/1900 00:00:00
     Repair Count: 0
      Repair Date: 00/00/1900 00:00:00
Old Repair Count: 0
  Last Consistent: (0x30,102,19E)  12/05/2010 11:33:56
      Last Attach: (0x32,9,86)  12/05/2010 11:38:05
      Last Detach: (0x0,0,0)  00/00/1900 00:00:00
             Dbid: 1
    Log Signature: Create time:06/30/2010 09:18:03 Rand:202227 Computer:
       OS Version: (6.0.6002 SP 2 NLS 500100.50100)

Previous Full Backup:
        Log Gen: 15-32 (0xf-0x20) – OSSnapshot
           Mark: (0x21,8,16)
           Mark: 07/06/2010 21:08:21

Previous Incremental Backup:
        Log Gen: 0-0 (0x0-0x0)
           Mark: (0x0,0,0)
           Mark: 00/00/1900 00:00:00

Previous Copy Backup:
        Log Gen: 0-0 (0x0-0x0)
           Mark: (0x0,0,0)
           Mark: 00/00/1900 00:00:00

Previous Differential Backup:
        Log Gen: 0-0 (0x0-0x0)
           Mark: (0x0,0,0)
           Mark: 00/00/1900 00:00:00

Current Full Backup:
        Log Gen: 0-0 (0x0-0x0)
           Mark: (0x0,0,0)
           Mark: 00/00/1900 00:00:00

Current Shadow copy backup:
        Log Gen: 0-0 (0x0-0x0)
           Mark: (0x0,0,0)
           Mark: 00/00/1900 00:00:00

     cpgUpgrade55Format: 0
    cpgUpgradeFreePages: 0
cpgUpgradeSpaceMapPages: 0

       ECC Fix Success Count: none
   Old ECC Fix Success Count: none
         ECC Fix Error Count: none
     Old ECC Fix Error Count: none
    Bad Checksum Error Count: none
Old bad Checksum Error Count: none

Operation completed successfully in 0.63 seconds.

In this case a state of dirty shutdown is expected.  When a database is enabled for replication we utilize a special replay process called Replay Without Undo.  Essentially we know that if the source database is mounted, and that there is a copy, we will encounter incomplete transactions in a log stream that will eventually be completed in logs that are either being generated or in the process of copying to the target.  With this in mind we do not want to undo these logical transactions, but rather hold them open and wait for subsequent logs that will complete them.

 

With this in mind administrators should not be immediately concerned that their passive database copies show a state of dirty shutdown.