When to use restore-storagegroupcopy with the –force switch and standby continuous replication (SCR)

Recently there was a lively internal debate regarding how to use restore-storagegroupcopy and the –force switch.

The documentation regarding the restore-storagegroupcopy command can be found at https://technet.microsoft.com/en-us/library/aa996024.aspx.

According to the TechNet documentation:

“The Force parameter can be used when the task is run programmatically and prompting for administrative input is inappropriate. If Force is not provided in the cmdlet, administrative input is prompted. If Force is provided in the cmdlet, but the value is omitted, its default value is $true. When the Restore-StorageGroupCopy cmdlet is run to make an SCR target viable for mounting, the Force parameter must be included when the SCR source is not available.”

You’ll notice in this text that –force is required for standby continuous replication when the SCR source is not available.

So the first question is what constitutes the source being unavailable.  In the most general terms the source is unavailable when the shares where the log files reside are not available such that the restore-storagegroupcopy command can be run and the remaining logs copied between machines.

For Windows 2003 based sources, and Windows 2008 non-shared storage clusters, the shares are generally not available when the entire machine is offline.  For Windows 2008 shared storage clusters, the shares may not be available because their corresponding file server resources are offline in the clustered mailbox server group (for example, a stop-clusteredmailboxserver was issued taking the entire CMS offline, including the file server resources).  Of course there are other reasons that shares may not be available, like network issues / misc hardware issues / etc.

The reason I point this out is that if the source is available, and the –force command is being used, we will not copy the delta logs over to the SCR source and mark the databases mountable.  This effectively causes the database mount process to fail indicating log files necessary for recovery are not present.  Manual recovery using eseutil /r /a would have to be performed in order for the databases to mount.

The second question is how can I overcome this limitation so this does not happen to me?  The answer to that is simple.  If you run the restore-storagegroupcopy without the –force we will attempt to copy delta logs.  Should the source be unavailable, we will fail the copy procedure with a meaningful message indicating that the delta logs cannot be copied, and –force is necessary.  After receiving this error you can repeat the restore-storagegroupcopy, this time specifying the –force.  Since –force was required, the logs will not be copied (source unavailable) but the databases will be marked mountable.

Rule of Thumb:  First try restore-storagegroupcopy and only run restore-storagegroupcopy –force if indicated to do so in the error text of the command.

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

Example of successful activation using restore-storagegroupcopy where the shares are available (no –force used).

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

Environment:  Source cluster / target standalone.

The source clustered mailbox server was stopped using stop-clusteredmailboxserver.

An eseutil /ml of the source log directory was run, the end of the log file can be seen here.  You will see that the log stream is complete through the E01.log.

      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000070.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000071.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000072.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000073.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000074.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000075.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000076.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E01.log - OK

No damaged log files were found.

Operation completed successfully in 14.921 seconds.

Prior to running the restore-storagegroupcopy an eseutil /ml was run against the logs on the SCR target.  You will note that the same logs are present with the exception of the E01.log.  (This is expected, even when the source CMS is shutdown gracefully the last log in the series is not copied to the SCR target.)

      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000070.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000071.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000072.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000073.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000074.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000075.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000076.log - OK

No damaged log files were found.

Operation completed successfully in 7.63 seconds.

At this time the shares on the source are available, and the mailbox stores dismounted.  A restore-storagegroupcopy –standbymachine <machine> is run and completes without error.  The following events are noted in the application log.

Log Name:      Application
Source:        MSExchangeRepl
Date:          4/30/2009 8:20:16 AM
Event ID:      2114
Task Category: Service
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
The replication instance for storage group MBX-2\MBX-2-SG2 has started copying transaction log files. The first log file successfully copied was generation 119.

Log Name:      Application
Source:        MSExchangeRepl
Date:          4/30/2009 8:20:16 AM
Event ID:      2085
Task Category: Action
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
The Restore-StorageGroupCopy operation on MBX-2\MBX-2-SG2 was successful. All logs were successfully copied.

I then re-ran the eseutil /ml against the log series.  You will note that after the restore-storagegroupcopy –standbymachine:<machine> that the e01.log is now present, it was successfully copied as a part of the restore process.

I followed up with an eseutil /ml of the target log directory, you can now see that the E01.log is present in the directory.

      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000071.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000072.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000073.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000074.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000075.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000076.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E01.log - OK

No damaged log files were found.

Operation completed successfully in 7.250 seconds.

The last operation was to mount the databases.  At this time the databases mounted successfully – eseutil /r /a was not required.

Log Name:      Application
Source:        MSExchangeIS Mailbox Store
Date:          4/30/2009 8:25:06 AM
Event ID:      9523
Task Category: General
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
The Microsoft Exchange Database "MBX-3-SG2\MBX-3-SG2-DB1" has been started.

Database File: G:\MBX-2\MBX-2-SG2-Database\MBX-2-SG2-DB1.edb
Transaction Logfiles: F:\MBX-2\MBX-2-SG2-Logs\
Base Name (logfile prefix): E01
System Path: E:\MBX-2\MBX-2-SG2-System\

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

 

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

Example of successful activation using restore-storagegroupcopy where the shares are not available (-force used).

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

Environment:  Source cluster / target standalone.

The clustered nodes comprising the source solution were completely shutdown making them completely unavailable.

Prior to shutting the nodes down, after issuing a stop-clusteredmailboxserver, and eseutil /ml was run against the log directory.  You will see the log stream is complete through E01.log.

Verifying log files...
     Base name: e01

      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000092.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000093.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000094.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E01.log - OK

No damaged log files were found.

Operation completed successfully in 0.78 seconds

Prior to running the restore-storagegroupcopy, an eseutil /ml was run against the logs on the SCR target.  You will note that the E01.log is not present.

Verifying log files...
     Base name: e01

      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000092.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000093.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000094.log - OK

No damaged log files were found.

Operation completed successfully in 0.64 seconds.

At this time a restore-storagegroupcopy –standbymachine <MACHINE> was issued.  The following error was noted and expected since the source is no longer available.

[PS] G:\>Restore-StorageGroupCopy -Identity MBX-2\MBX-2-SG2 -StandbyMachine MBX-3
Restore-StorageGroupCopy : Restore failed to verify if the database on 'MBX-2' is mounted. Verify that the database is dismounted and then use the -Force parameter to restore the storage group copy.
At line:1 char:25
+ Restore-StorageGroupCopy  <<<< -Identity MBX-2\MBX-2-SG2 -StandbyMachine MBX-3

After receiving an error that –force was necessary, the command was re-run using restore-storagegroupcopy –standbymachine –force.  The following information was presented in the Exchange Management Shell window:

[PS] G:\>Restore-StorageGroupCopy -Identity MBX-2\MBX-2-SG2 -StandbyMachine MBX-3    -force
WARNING: Performing a Restore-StorageGroupCopy operation on storage group
'MBX-2-SG2' with the Force option. Data loss is expected for this storage group.

The following events were noted in the application log:

Log Name:      Application
Source:        MSExchangeRepl
Date:          5/3/2009 10:37:39 AM
Event ID:      2139
Task Category: Action
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
The forced Restore-StorageGroupCopy operation on MBX-2\MBX-2-SG2 was successful. However, there may be some data loss.

After the command complete successfully, an eseutil /ml was performed against the log stream.  You will note that the e01.log is not present in the target log directory, since the remaining logs could not be copied due to the SCR source being unavailable.

Verifying log files...
     Base name: e01

      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000092.log – OK 
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000093.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000094.log - OK

No damaged log files were found.

Operation completed successfully in 0.64 seconds.

At this time the database was successfully mounted as indicated by the following event in the application log.

Log Name:      Application
Source:        MSExchangeIS Mailbox Store
Date:          5/3/2009 10:44:06 AM
Event ID:      9523
Task Category: General
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
The Microsoft Exchange Database "MBX-3-SG2\MBX-3-SG2-DB1" has been started.

Database File: G:\MBX-2\MBX-2-SG2-Database\MBX-2-SG2-DB1.edb
Transaction Logfiles: F:\MBX-2\MBX-2-SG2-Logs\
Base Name (logfile prefix): E01
System Path: E:\MBX-2\MBX-2-SG2-System\

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

 

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

Example of successful activation using restore-storagegroupcopy where the shares are available (-force used).

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

Environment:  Source cluster / target standalone.

The source clustered mailbox server was stopped using stop-clusteredmailboxserver.

An eseutil /ml of the source log directory was run, the end of the log file can be seen here.  You will see that the log stream is complete through the E01.log.

      Log file: F:\MBX-2\MBX-2-SG2-Logs\E010000007A.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E010000007B.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E010000007C.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E010000007D.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E010000007E.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E01.log - OK

No damaged log files were found.

Operation completed successfully in 16.219 seconds.

Prior to running the restore-storagegroupcopy an eseutil /ml was run against the logs on the SCR target.  You will note that the same logs are present with the exception of the E01.log.  (This is expected, even when the source CMS is shutdown gracefully the last log in the series is not copied to the SCR target.)

      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000079.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E010000007A.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E010000007B.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E010000007C.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E010000007D.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E010000007E.log - OK

No damaged log files were found.

Operation completed successfully in 0.359 seconds.

At this time a restore-storagegroupcopy with the –force command was run.  Please note:  The source shares are available so –force is NOT NECESSARY.  Here is sample Exchange Management Shell output.

[PS] C:\Windows\System32>Restore-StorageGroupCopy -Identity MBX-2\MBX-2-SG2 –StandbyMachine MBX-3 –force

WARNING: Performing a Restore-StorageGroupCopy operation on storage group
'MBX-2-SG2' with the Force option. Data loss is expected for this storage
group.

The command completed successfully as indicated by returning to the Exchange Management Shell prompt without error.  The following event was noted in the application log.

Log Name:      Application
Source:        MSExchangeRepl
Date:          5/1/2009 8:29:41 AM
Event ID:      2139
Task Category: Action
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
The forced Restore-StorageGroupCopy operation on MBX-2\MBX-2-SG2 was successful. However, there may be some data loss.

As follow up eseutil /ml was run against the logs on the SCR target machine.  You will note that the E01.log was not copied even though the restore-storagegroupcopy –force command completed successfully.

      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000077.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000078.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E0100000079.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E010000007A.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E010000007B.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E010000007C.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E010000007D.log - OK
      Log file: F:\MBX-2\MBX-2-SG2-Logs\E010000007E.log - OK

No damaged log files were found.

Operation completed successfully in 0.187 seconds.

At this time a database mount attempt was performed, and failed with the following events noted in the application log.

Log Name:      Application
Source:        MSExchangeIS
Date:          5/1/2009 8:32:13 AM
Event ID:      9518
Task Category: General
Level:         Error
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
Error Current log file missing starting Storage Group /DC=com/DC=domain/DC=domain/CN=Configuration/CN=Services/CN=Microsoft Exchange/CN=Organization/CN=Administrative Groups/CN=Exchange Administrative Group (FYDIBOHF23SPDLT)/CN=Servers/CN=MBX-3/CN=InformationStore/CN=MBX-3-SG2 on the Microsoft Exchange Information Store.
Storage Group - Initialization of Jet failed.

Log Name:      Application
Source:        ESE
Date:          5/1/2009 8:32:13 AM
Event ID:      455
Task Category: Logging/Recovery
Level:         Error
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
MSExchangeIS (2984) MBX-3-SG2: Error -1811 (0xfffff8ed) occurred while opening logfile f:\MBX-2\MBX-2-SG2-Logs\E01.log.

The –1811 error translates to:

# for decimal -1811 / hex 0xfffff8ed
  JET_errFileNotFound
# /* File not found */
  JET_errFileNotFound
# /* File not found */
  JET_errFileNotFound
# /* File not found */
# 3 matches found for "-1811"

In this case the –force command was improperly used resulting in logs not being copied to the SCR target.  The databases could be mounted if they were manually recovered using eseutil /r /a or the logs manually copied to the SCR target.

This behavior is BY DESIGN. The –force command does not check to see if the SCR source is available, therefore no log file copy attempts are made.

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